ERROR lazyfilewalker.gc-filewalker.subprocess failed to save progress in the database

[Qwinn]

@Alexey

This should only fix a discrepancy between the OS reported usage and the piechart on the dashboard.

2024-06-15T10:54:00Z	INFO	lazyfilewalker.used-space-filewalker	starting subprocess	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2024-06-15T10:54:00Z	INFO	lazyfilewalker.used-space-filewalker	subprocess started	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2024-06-15T10:54:00Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	Database started	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Process": "storagenode"}
2024-06-15T10:54:00Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker started	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Process": "storagenode"}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker completed	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Process": "storagenode", "piecesTotal": 8329802328832, "piecesContentSize": 8300118988032}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker	starting subprocess	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker	subprocess started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	Database started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode"}
2024-06-17T18:47:33Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker started	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode"}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker completed	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Process": "storagenode", "piecesTotal": 4647668513808, "piecesContentSize": 4636370778640}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker	starting subprocess	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker	subprocess started	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	Database started	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Process": "storagenode"}
2024-06-19T11:51:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker started	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Process": "storagenode"}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker completed	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Process": "storagenode", "piecesTotal": 122663970304, "piecesContentSize": 122331355136}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker	starting subprocess	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker	subprocess started	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	Database started	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Process": "storagenode"}
2024-06-19T12:32:43Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker started	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Process": "storagenode"}
2024-06-19T15:33:23Z	INFO	lazyfilewalker.used-space-filewalker.subprocess	used-space-filewalker completed	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Process": "storagenode", "piecesTotal": 1667065948160, "piecesContentSize": 1666099034112}
2024-06-19T15:33:23Z	INFO	lazyfilewalker.used-space-filewalker	subprocess finished successfully	{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}

Lazy filewalker finally finished all four satellites a while ago.

Dashboard is still completely wrong. Hasn’t changed at all in fact. My disk has around 14G out of 16TB free at the moment.

I still have the databases on an SSD and there are no “database locked” errors whatsoever.

[Bivvo]

that does not help - I get the first full page with translations into my mother tongue.

[Qwinn]

Pristine means clean, pure, unblemished.

Not sure why it took so long but my dashboard has finally updated:

[Bivvo]

@Qwinn

Pristine means clean, pure, unblemished.

ah, thank you - so it’s not a tool, haha.

[JWvdV]

@Bivvo

ah, thank you - so it’s not a tool, haha

Indeed, it was meant to get some native translations

[ACarneiro]

Well, that gives me hope that one of mine (which has been running for nearly 3 days and hasn’t changed anything) may still be fixed

[Tetricz]

The issue I’m referring to is the title of the topic. I was getting Database locks on some intel optane drives, so I knew it wasn’t a hardware performance issue. I thought it might be the storage drives, but I was getting the database locks on my one SSD node as well.

I’m using Slackware for the stability, with docker installed. Alexey answered how I was limiting the memory. --memory=8G

@Alexey

They likely mean the docker’s --memory option in the docker run command (if you would use it, it should be placed before the image name).

[Alexey]

Because after updating of the databases, the dashboard updates stat after a while. You may enforce it by restarting (but, you know, the scan on startup fill start again… so, it’s better to wait a little bit). By the way, how long it was taken after update of the databases and update of the dashboard (usually it should happen within 12h)?

[Alexey]

@Tetricz

I was getting Database locks on some intel optane drives

this is very weird, it shouldn’t. So this is why I shared this with the team.
But I still believe, that @Toyoo is right

ERROR lazyfilewalker.gc-filewalker.subprocess failed to save progress in the database

Perhaps we have another case of orders.db/bandwidth.db. Orders used to be stored in a SQLite database, and because it had to be inserted into on each upload, it kept locking up. This was changed to append-only log files. Then we had bandwidth.db locking up, as it was also inserted into on each upload—this was changed to keep an in-memory cache instead and only update the totals in the database periodically. Now we have piece expirations that have to be inserted on almost each upload… and we hav…

[Qwinn]

@Alexey

By the way, how long it was taken after update of the databases and update of the dashboard (usually it should happen within 12h)?

I wasn’t timing it as I wasn’t expecting it to take so long and thought it was never going to happen, but if I had to guess, around 4-6 hours.

[Bivvo]

Within a day or two, my both nodes went full - 500 GB trash and rest data (8.5 TB). Strange behaviour. At least for one, there was 500-750 GB free some time ago.

[Qwinn]

So I have more badness to report.

Let me repost here what I posted a few days ago - what I got after 4 filewalkers finished and a few additional hours went by:

Then, over the next day, a bunch of trash accumulated, dropping my used space down to 14.6TB, so I figured once all trash got deleted I’d be pretty close to what I’d allocated, 14.5TB, and maybe I’d be back to normal.

But then I got autoupdated to 1.105.4 a couple days ago, obviously restarting my node. And that undid all of that movement from used space to trash:

It has looked like that ever since, nearly 2 days now, and still looking like it’s going to take 4 days to refinish the filewalkers.

[Alexey]

Yes, it’s true. The 1.104.x version has a bug related to not updated info for the trash. But If the used-space-filewalker is enabled, it should update the stat after the restart. This new version (1.105.x) has a fix for not updating databases by the trash filewalker, so I would hope that your databases now would keep the updated info and it would be close to the used space on the disk.