Nodes going offline and trying do downgrade?

Node Operators troubleshooting
,
1

Hello Storjers,

Over the last two days, some of my nodes started going offline, refusing connections, and showing the strange log below.

It is not affecting all nodes, only some of them, and I don’t see a clear correlation between the affected nodes, at least from my point of view. They appear to get stuck in this loop for hours until I restart the containers.

I’m running the nodes in Docker containers.

Is this happening to anyone else, or is it just on my side?

INFO	Downloading versions.	{"process": "storagenode-updater", "server_address": "https://version.storj.io"}
INFO	Current binary version	{"process": "storagenode-updater", "service": "storagenode", "version": "v1.155.9"}
INFO	Version is up to date	{"process": "storagenode-updater", "service": "storagenode"}
INFO	Current binary version	{"process": "storagenode-updater", "service": "storagenode-updater", "version": "v1.155.4"}
INFO	Version is up to date	{"process": "storagenode-updater", "service": "storagenode-updater"}
2

Oops, something is definitely not right…

After going through the saved logs, I found a lot of errors happening. The logs are a bit extensive, so sorry for the log dump below:

026-08-13 00:13:10.909732+00:002026-08-13T00:13:10Z	ERROR	services	unexpected shutdown of a runner	{"process": "storagenode", "name": "piecestore:monitor", "error": "piecestore monitor: timed out after 1m0s while verifying writability of storage directory", "errorVerbose": "piecestore monitor: timed out after 1m0s while verifying writability of storage directory\n\tstorj.io/storj/storagenode/monitor.(*Service).verifyWritability:194\n\tstorj.io/common/sync2.(*Cycle).Run:163\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func2:124\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}
2026-08-13 00:13:10.909927+00:002026-08-13T00:13:10Z	ERROR	piecemigrate:chore	failed to enqueue for migration	{"process": "storagenode", "error": "couldn't list new pieces to migrate: filewalker: context canceled", "errorVerbose": "couldn't list new pieces to migrate: filewalker: context canceled\n\tstorj.io/storj/storagenode/piecemigrate.(*Chore).enqueueSatellite:338\n\tstorj.io/storj/storagenode/piecemigrate.(*Chore).runOnce:285\n\tstorj.io/common/sync2.(*Cycle).Run:102\n\tstorj.io/storj/storagenode/piecemigrate.(*Chore).Run.func1:267\n\tstorj.io/storj/storagenode/piecemigrate.(*Chore).Run.(*Group).Go.func5:21\n\tsync.(*WaitGroup).Go.func1:258", "sat": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}

2026-08-13 00:13:10.949163+00:002026-08-13T00:13:10Z	ERROR	piecestore	error sending hash and order limit	{"process": "storagenode", "piece_id": "UOG7NDJUUUJ4KYFY7MAEBEC3AAMQ6CVMWLSGPISI4DJFTS727OPA", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "action": "GET_REPAIR", "offset": 0, "size": 3840, "remote_address": "45.137.206.117:52852", "error": "EOF"}

2026-08-13 00:13:10.956055+00:002026-08-13T00:13:10Z	ERROR	piecestore	download failed	{"process": "storagenode", "piece_id": "UOG7NDJUUUJ4KYFY7MAEBEC3AAMQ6CVMWLSGPISI4DJFTS727OPA", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "action": "GET_REPAIR", "offset": 0, "size": 3840, "remote_address": "45.137.206.117:52852", "error": "EOF", "errorVerbose": "EOF\n\tstorj.io/common/rpc/rpcstatus.NamedWrap:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:760\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:302\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:62\n\tstorj.io/common/experiment.(*Handler).HandleRPC:43\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:166\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:108\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:156\n\tstorj.io/drpc/drpcctx.(*Tracker).track:35"}

2026-08-13 00:13:11.029327+00:002026-08-13T00:13:11Z	INFO	lazyfilewalker.used-space-filewalker	subprocess exited with status	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "status": -1, "error": "signal: killed"}

2026-08-13 00:13:11.029484+00:002026-08-13T00:13:11Z	ERROR	pieces	used-space-filewalker failed	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "lazy_file_walker": true, "error": "lazyfilewalker: signal: killed", "errorVerbose": "lazyfilewalker: signal: killed\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*process).run:85\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*Supervisor).WalkAndComputeSpaceUsedBySatellite:134\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:781\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}

2026-08-13 00:13:11.034738+00:002026-08-13T00:13:11Z	ERROR	pieces	used-space-filewalker failed	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "lazy_file_walker": false, "error": "filewalker: used_space_per_prefix_db: context canceled", "errorVerbose": "filewalker: used_space_per_prefix_db: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*usedSpacePerPrefixDB).Get:81\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatelliteWithWalkFunc:163\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatellite:150\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:790\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}

2026-08-13 00:13:11.034848+00:002026-08-13T00:13:11Z	ERROR	piecestore:cache	encountered error while computing space used by satellite	{"process": "storagenode", "error": "filewalker: used_space_per_prefix_db: context canceled", "errorVerbose": "filewalker: used_space_per_prefix_db: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*usedSpacePerPrefixDB).Get:81\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatelliteWithWalkFunc:163\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatellite:150\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:790\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2026-08-13 00:13:11.034914+00:002026-08-13T00:13:11Z	INFO	pieces	used-space-filewalker started	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-08-13 00:13:11.034958+00:002026-08-13T00:13:11Z	INFO	lazyfilewalker.used-space-filewalker	starting subprocess	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-08-13 00:13:11.039393+00:002026-08-13T00:13:11Z	ERROR	lazyfilewalker.used-space-filewalker	failed to start subprocess	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "error": "context canceled"}
2026-08-13 00:13:11.039500+00:002026-08-13T00:13:11Z	ERROR	pieces	used-space-filewalker failed	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "lazy_file_walker": true, "error": "lazyfilewalker: context canceled", "errorVerbose": "lazyfilewalker: context canceled\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*process).run:73\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*Supervisor).WalkAndComputeSpaceUsedBySatellite:134\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:781\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}
2026-08-13 00:13:11.039578+00:002026-08-13T00:13:11Z	ERROR	pieces	used-space-filewalker failed	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "lazy_file_walker": false, "error": "filewalker: used_space_per_prefix_db: context canceled", "errorVerbose": "filewalker: used_space_per_prefix_db: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*usedSpacePerPrefixDB).Get:81\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatelliteWithWalkFunc:163\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatellite:150\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:790\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}
2026-08-13 00:13:11.039622+00:002026-08-13T00:13:11Z	ERROR	piecestore:cache	encountered error while computing space used by satellite	{"process": "storagenode", "error": "filewalker: used_space_per_prefix_db: context canceled", "errorVerbose": "filewalker: used_space_per_prefix_db: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*usedSpacePerPrefixDB).Get:81\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatelliteWithWalkFunc:163\n\tstorj.io/storj/storagenode/pieces.(*FileWalker).WalkAndComputeSpaceUsedBySatellite:150\n\tstorj.io/storj/storagenode/pieces.(*Store).WalkAndComputeSpaceUsedBySatellite:790\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:85\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-08-13 00:13:11.347959+00:002026-08-13T00:13:11Z	ERROR	piecestore:cache	error getting current used space for trash: 	{"process": "storagenode", "error": "filestore error: failed to walk trash namespace 7b2de9d72c2e935f1918c058caaf8ed00f0581639008707317ff1bd000000000: context canceled", "errorVerbose": "filestore error: failed to walk trash namespace 7b2de9d72c2e935f1918c058caaf8ed00f0581639008707317ff1bd000000000: context canceled\n\tstorj.io/storj/storagenode/blobstore/filestore.(*blobStore).SpaceUsedForTrash:302\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:104\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93"}

2026-08-13 00:13:25.910693+00:002026-08-13T00:13:25Z	WARN	services	service takes long to shutdown	{"process": "storagenode", "name": "collector"}
2026-08-13 00:13:25.910791+00:002026-08-13T00:13:25Z	WARN	servers	service takes long to shutdown	{"process": "storagenode", "name": "server"}
2026-08-13 00:13:25.915212+00:002026-08-13T00:13:25Z	WARN	services	service takes long to shutdown	{"process": "storagenode", "name": "piecemigrate:chore"}
3

Some of the log lines are very long, so I can’t post the full output here due to post limitations.
They are so big that just one line got more than 16000 characters.
Here is the beginning of one of the log entries:

2026-08-13 00:13:25.983408+00:002026-08-13T00:13:25Z	INFO	services	slow shutdown	{"process": "storagenode", "stack": "goroutine 863\n\tstorj.io/storj/private/lifecycle.(*Group).logStackTrace.func1:107\n\tsync.(*Once).doSlow:78\n\tsync.(*Once).Do:69\n\tstorj.io/storj/private/lifecycle.(*Group).logStackTrace:104\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func1:77\n\truntime/pprof.Do:57\n\ngoroutine 1\n\tsync.runtime_SemacquireWaitGroup:114\n\tsync.(*WaitGroup).Wait:206\n\tgolang.org/x/sync/errgroup.(*Group).Wait:56\n\tstorj.io/storj/storagenode.(*Peer).Run:1130\n\tmain.cmdRun:121\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.InitBeforeExecute.func1.2:389\n\tstorj.io/common/process.InitBeforeExecute.func1:407\n\tgithub.com/spf13/cobra.(*Command).execute:985\n\tgithub.com/spf13/cobra.(*Command).ExecuteC:1117\n\tgithub.com/spf13/cobra.(*Command).Execute:1041\n\tstorj.io/common/process.ExecWithCustomOptions:115\n\tmain.main:34\n\ngoroutine 82\n\tgo.opencensus.io/stats/view.(*worker).start:292\n\ngoroutine 84\n\tstorj.io/monkit-jaeger.(*ThriftCollector).Run:174\n\tstorj.io/common/process.initTracing.func1:120\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:93\n\ngoroutine 98\n\tos/signal.signal_recv:152\n\tos/signal.loop:23\n\ngoroutine 99\n\tstorj.io/common/process.Ctx.func1:142\n\ngoroutine 217\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 7676\n\tstorj.io/drpc/drpcmanager.(*Manager).manageReader:266\n\ngoroutine 210\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 139\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 7480\n\tstorj.io/drpc/drpcmanager.(*Manager).manageStreams:321\n\ngoroutine 171\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 221\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 175\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 176\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 177\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 178\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 179\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 180\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 181\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 182\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 183\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 193\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 200\n\tdatabase/sql.(*DB).connectionOpener:1261\n\ngoroutine 795\n\tstorj.io/storj/private/lifecycle.condenseStack:11\n\tstorj.io/storj/private/lifecycle.(*Group).logStackTrace.func1:114\n\tsync.(*Once).doSlow:78\n\tsync.(*Once).Do:69\n\tstorj.io/storj/private/lifecycle.(*Group).logStackTrace:104\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func1:77\n\truntime/pprof.Do:57\n\ngoroutine 551\n\tstorj.io/storj/storagenode/hashstore.(*DB).backgroundCompactions:575\n\ngoroutine 550\n\tstorj.io/storj/storagenode/hashstore.(*DB).backgroundCompactions:575\n\ngoroutine 749\n\tstorj.io/storj/storagenode/pieces.(*PieceExpirationStore).flushOnTicks:117\n\ngoroutine 750\n\tstorj.io/storj/storagenode/hashstore.
4

You can ignore that one. Maybe increase shutdown time to give the node enough time to finish what ever it was working on (thats the long stack trace behind it). But even if the node gets killed by the operating system after the time is over that shouldn’t be a problem.

5

This is normal behavior. The docker container doesn’t contain a storagenode binary. It downloads the binary on the first start and than keeps checking for updates. So its fine that the docker container is running the updater in an endless loop.

The storagenode log is more important. On log level info you should see uploads and downloads in the logs. On log level error or warn you might not see any activity for hours.

6

This is the root cause. Your disk is too slow to write even a few bytes to the disk.
I would like to recommend to migrate to hashstore: Hashstore Migration Guide.
You can temporary improve the situation with the disk defragmentation.

7

Im a Bit confused, is it still necessary to Migranten to hashstore manually?
I thought this was mirgrated automatically with Updates Long time ago?

8

It will, but you already have an issue with the filesystem speed.

9

Alexey,

Yes, after some debugging, I found the likely culprit was filesystem latency.

With some help from GPT, I narrowed it down to a WD HDD that was increasing write latency across the whole vdev, a 6-disk RAIDZ2. Even with multiple vdevs in the pool, this single disk was causing strange issues for multiple nodes using that same pool.

I replaced it with a new disk and will move the old one to a low-usage pool until it starts showing errors, so I can open an RMA.

The surprising part is that ZFS didn’t report any errors. Usually, when a disk starts failing, ZFS logs errors and I can replace it quickly. This time, even with weekly SMART long tests, the disk didn’t show errors — it just started struggling with writes.

I’ll create IO latency monitors and keep tracking this from now on.

10

6-disk RAIDZ2 makes 0 sense. It performs as the slowest disk in that vdev. Having multiple vdevs in the pool does not magically make a sick disk irrelevant. Vdevs are the failure and performance domains; redundancy is inside the vdev.

Disk latency detection shall not require GPT. This is basic server monitoring. How else will you know when disk is dying?

11

Is there a way to make it so it doesn’t affect the pool? Only separate disks?

12

Pretty much no. A slow or failing disk can hold up everything that needs data from that RAIDZ group, and those delays can affect the rest of the pool too.

ZFS also does not give you a useful way to keep one node on one RAIDZ group and another node on another.

If you want one sick disk to only affect one node, you will have to use separate pool. One disk per pool/node is the simplest arrangement. But this is against the “use what you have”. Because if storj is on a separate pool, that pool will have to be running just for storj.

But this is solving the wrong problem. If disk is dying — it needs to be replaced. Storj or not.