Strange node activity

Adavan · April 11, 2023, 5:58pm

Hi guys.
This is 3 or 4. occurrence, when I spotted, that my node hold his activity and after several time it continue with it. This problem I saw previously, I thought, that something is wrong on my side and I restarted just Docker image.

Look to 3. hour. Node just hold his activity, but was still was available and I not spot any decreasing availability. Metrics in graphs “StorjNode volume usage” and “StorjNode trash usage” are from node API endpoint, rest is from system. After 10. hour node dropped some data from trash and it continue with accepting new data.

I dont see any strange errors or warning in logs.

I would like to ask you to help me discover, what is wrong. For about 6 hours I not get any data without any explanation and this isnt first occurrence.

If you need some additional information, I gladly to add it, please let me know.

Thank you!

elek · April 12, 2023, 7:21am

How do you monitor these numbers? Do you have a node_exporter and a prometheus instance?

If yes, I would suggest to turn on the debug port (STORJ_DEBUG_ADDR=127.0.0.1:...) and save Storj metrics as well… (/metrics on the configured port)

It can give you more insights to understand what’s going on…

Adavan · April 12, 2023, 6:19pm

Hi @elek .

Thank you for feedback. I investigated the problem and I have possible trespasser - LVM, or bug in Storagenode. Let me explain:

my server was restarted 1.4., StorageNode was started as well AND I had in the time of start ~300GB free space
8.4. I added ~300GB as well and store some data on the partition
11.4. StorageNode begin holding and free space is in the time ~300GB

I think, but not sure, that in time, when StorageNode start, he cached free disk space and not spot online resizing made by LVM. In time, when it start holding, it thinks, that it exhausted all free space and start holding no matter, that I have free space and it have assigned (via -e STORAGE= parameter) more space.

Can you please confirm my suspicious? I am not a Golang expert.

If this is true, it is possible to add ability to double check free available space in time, when StorageNode thinks, that it using all available disk space?

Thank you!

Alexey · April 14, 2023, 8:55am

If you updated the STORAGE parameter it will accept it. However, if it recognizes that the actual free space with used space is less than 500MB in the allocation, it will stop to accept any new data.
You may check that in your logs. You likely will see a warning, that provided allocation is greater than actual space and will change it to what your OS is reported.
Search for “less than requested” in your logs.
See also

Adavan · April 14, 2023, 5:19pm

Hi @Alexey .

Yes, I have actually assigned 23TB (via STORAGE), in time, when node start I had 400GB (really 400GB), after some time I add another 300GB (really 400GB), BUT node get stuck, when server have 300GB free space (really 300GB).

So, I think, that node just check free space only in start time and hold the value in all running time.

I try a test - after “lvextend” I restarted container and let see, that this problem happen again in future or not.

Alexey · April 15, 2023, 1:19am

Only the top limit for allocation (it uses min(STORAGE, actual used + disk free space) to set the allocation) - yes. After that it checks the free space in the allocation on each upload, and if there less than 500MB free in the allocation it will stop accept any data.

Did you find the line in the log after start with phrase "less than requested”?

Adavan · April 15, 2023, 9:15am

OK, just for sure - disk free space is discovered only in time, when node start, right? It is not rechecked over time or when some condition occurred, right?

Sure and I am fine with this warning, because I allocating additional free space ad-hoc. So, I have set for node 23TB, but really allocated is only 21TB. When free space on the volume is below 100GB, I adding additional free space to the volume from unallocated pool in LVM on the fly.

Alexey · April 15, 2023, 10:05am

No, it checks it perdiodically, but allocation set only on start.

In this case your would need to restart the node to allocate more space.

Adavan · April 15, 2023, 11:34pm

Uff, I afraid, that we still understand each other.

Lets start again:

I have assign 23TB for node (via STORAGE settings), so, it can use 23TB, no matter, that I have 30TB on the LVM volume group total and I can allocating it over time
I have allocated to the volume for Storj at the moment 21TB (when container start, it generating warning, this is fine for me; server is still running!); let say, it is 1.4.2023
let say, that on the volume (at 1.4.23) is 20TB used and 1TB free space and node is still running (so, was started in time, when it see 1TB free space)
over time it filling the volume
when volume is filled to 20.8TB and 0.2TB are free (let say, it is 10.4.2023), I add additional 0.5TB via lvextend command (free space jump from 0.2TB to 0.7TB) and node continue with filling
it seems, that node stops filling free space, when it reach 21TB (let say, it is 12.4.2023) and on the volume is still 0.5TB free space (still not hit assigned 23TB! and still have some free space as well!)
if is 0.1TB discarded from trash (20.9TB used, 0.6TB free, let say, it is 13.4.2023), node start filling free space again, BUT again stop, when filled 21TB (let say, it is 14.4.2023), again no matter, that it have 0.5TB free space on the volume and node can use 23TB max

If this is true, why node stop filling the free space allocated to the volume (via lvextend command) after node start (I mean, after container start, server is still running)?

Adavan · April 15, 2023, 11:48pm

I made a simple test:

I checked, how much free space see the Docker BEFORE resizing:

operator@server:~# df -h
Súborový systém                     Veľk  Použ  Dost Pou% Pripojený na
...
/dev/mapper/default-LV--StorJStore   22T   21T  889G  96% /mnt/StorjStore
...
operator@server:~# docker exec -it storagenode df -h
Filesystem                          Size  Used Avail Use% Mounted on
...
/dev/mapper/default-LV--StorJStore   22T   21T  889G  96% /app/config
...

I made resizing on the fly (added only 100GB for testing):

operator@server:~# lvextend -L +100G -r /dev/default/LV-StorJStore 
  Size of logical volume default/LV-StorJStore changed from 21,39 TiB (5607965 extents) to 21,49 TiB (5633565 extents).
  Logical volume default/LV-StorJStore successfully resized.
resize2fs 1.46.2 (28-Feb-2021)
Filesystem at /dev/mapper/default-LV--StorJStore is mounted on /mnt/StorjStore; on-line resizing required
old_desc_blocks = 2739, new_desc_blocks = 2751
The filesystem on /dev/mapper/default-LV--StorJStore is now 5768770560 (4k) blocks long.

and checked free space again from OS perspective and Docker perspective:

operator@server:~# df -h
Súborový systém                     Veľk  Použ  Dost Pou% Pripojený na
...
/dev/mapper/default-LV--StorJStore   22T   21T  987G  96% /mnt/StorjStore
...
operator@server:~# docker exec -it storagenode df -h
Filesystem                          Size  Used Avail Use% Mounted on
...
/dev/mapper/default-LV--StorJStore   22T   21T  987G  96% /app/config
...

Result is, that Docker definitely follow FS size on the fly. Why node (I mean software running in Docker) not?

lyoth · April 16, 2023, 2:30am

I think you don’t understand what Alex was trying to say.
It does not matter if you allocate 100G or 100TB to your lvm, your container will only go up to 21TB and stop getting more data. Since that is what you set it to when you started your docker.
That’s why you need to stop your docker container, start your container with a new STORAGE value

-e STORAGE=your_new_size

And then it will start to fill up to that new size you set. And the STORAGE is an Linux environment variable and is only read when the docker starts.

Alexey · April 16, 2023, 4:17am

I will try to explain in a different way.
I understand, that you set 23TB in your STORAGE option, but your volume is actually have only 21.1TB and there are only 100GB free.
When you start the container, it will check the actual free space (in your case it’s 100GB + 21TB of used space) and warn you, that you trying to allocate more (23TB) than you have (21.1TB), so node set the allocation to 21.1TB instead of 23TB and will not update it until the next restart.

From the other side, the node checks the free space in the allocation (21.1TB) on each upload (and report this for the each piece in your logs), but doesn’t update the allocation, even if you added 100GB more, so the node will stop ingress if there is less than 500MB of free space in the allocation (21.1TB), not on the disk (21.2TB).

You have 2 exits from this situation:

or use thin provisioned LVM volumes (you will “lie” to the OS that you have 23TB, while add only 21.1TB of the actual space), but you need to closely monitor a usage, otherwise if the volume would be full, there is a probability of the volume corruption.
or restart the node after you extended the normal volume with additional space.

Please also note, the thin provisioned volumes works noticeable slower than normal volumes (the same is true for COW enabled volumes, i.e. when you made a snapshot, but there are tricks as well).

Adavan · April 16, 2023, 12:12pm

OK, now I understand. So, basically node check free space only on start and “it reconcile my mistake” (if I set usage to 23TB, but volume have free 0.5TB and have used 21TB, after reconcile it set 21.5TB, instead of 23TB).

When later I add on the fly another 0.5TB (expand volume to the 22TB total), node stop receiving ingress, when it used 21.5TB, no matter, that here is still 0.5TB free space, because reconciliation occurred at the start of the node and at the moment node know, that it must not adding more pieces. This is, what I observe on my node.

OK, so solutions are 2:

after every on the fly rising of the volume I must restart container as well
is it possible add the “available space reconciliation” in the time, when container hit previous value?

Basically, it will recheck, or do some additional check, that it really have only that free space. If it have more free space, it can reconcile it on the fly without restarting, if it not have free space (previous reconciliation was right), it will generate warning to the log and stop receiving ingress.

Actually, it silently stop receiving ingress, which may be confused for SNO with “inflatable space”, like in my case.

@Alexey Previously I spot discussion about disable filewalker, but not spot any solution. Is this case still opened? It is possible temporary disable filewalker after node start?

When I restart node to reconcile available free space to enable get more pieces, filewalker in case cost near 2 days to finish. If it will be possible to disable filewalker, this will helps me a lot.

Alexey · April 16, 2023, 12:25pm

only using a thin provisioned volume.

no. Either disable or enable, no option in between.

price for RAID/slow disk.

yes, see

However, in your case (the dynamic provisioning) I would not disable a filewalker to avoid some problems with detecting of used space.

Adavan · April 16, 2023, 12:44pm

I understand, this is for me too risky, I will dont do it.

OK, thank you for recommendation. My plan is:

add free space
disable filewalker
restart node (it start without filewalker)
enable filewalker (next node restart will be with filewalker check)

This will not damage consistency, but restart will be faster, hopefully .