One of my nodes running in docker stopped with a fatal error

Node Operators troubleshooting
, ,
1

Hello!

I am running three nodes under Synology Docker, internet and disks are working fine. Each node has a separate ext4 disk without raid.
Node2 stopped working for half an hour, I thought it was updating, but it can’t start.
My log is only set to WARNING level, you can see the following:

2025-03-18T19:46:37Z	ERROR	version	failed to get process version info	{"Process": "storagenode", "error": "version checker client: Get \"https://version.storj.io\": context canceled", "errorVerbose": "version checker client: Get \"https://version.storj.io\": context canceled\n\tstorj.io/storj/private/version/checker.(*Client).All:68\n\tstorj.io/storj/private/version/checker.(*Client).Process:89\n\tstorj.io/storj/private/version/checker.(*Service).checkVersion:104\n\tstorj.io/storj/private/version/checker.(*Service).CheckVersion:78\n\tmain.cmdRun:91\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272"}
2025-03-18T19:46:37Z	ERROR	failure during run	{"Process": "storagenode", "error": "Error migrating tables for database on storagenode: migrate: database: info opening file \"config/storage/info.db\" failed: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabaseWithStat:390\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:367\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).Migration.func1:715\n\tstorj.io/storj/private/migrate.(*Migration).Run:168\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).MigrateToLatest:415\n\tmain.cmdRun:100\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272", "errorVerbose": "Error migrating tables for database on storagenode: migrate: database: info opening file \"config/storage/info.db\" failed: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabaseWithStat:390\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:367\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).Migration.func1:715\n\tstorj.io/storj/private/migrate.(*Migration).Run:168\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).MigrateToLatest:415\n\tmain.cmdRun:100\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272\n\tmain.cmdRun:102\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272"}
2025-03-18T19:46:37Z	FATAL	Unrecoverable error	{"Process": "storagenode", "error": "Error migrating tables for database on storagenode: migrate: database: info opening file \"config/storage/info.db\" failed: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabaseWithStat:390\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:367\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).Migration.func1:715\n\tstorj.io/storj/private/migrate.(*Migration).Run:168\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).MigrateToLatest:415\n\tmain.cmdRun:100\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272", "errorVerbose": "Error migrating tables for database on storagenode: migrate: database: info opening file \"config/storage/info.db\" failed: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabaseWithStat:390\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).openDatabase:367\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).Migration.func1:715\n\tstorj.io/storj/private/migrate.(*Migration).Run:168\n\tstorj.io/storj/storagenode/storagenodedb.(*DB).MigrateToLatest:415\n\tmain.cmdRun:100\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272\n\tmain.cmdRun:102\n\tmain.newRunCmd.func1:33\n\tstorj.io/common/process.cleanup.func1.4:392\n\tstorj.io/common/process.cleanup.func1:410\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:112\n\tmain.main:34\n\truntime.main:272"}

Can anyone help me how to fix this issue?

Thanks!

2

I’d “fsck -y” the filesystem the node is on. But if it’s a persistent error those .db files can all be wiped - and you only lose your stats (doesn’t affect payouts)

3

I tried disabling the bader cache directed to the ssd in config.yaml and it has been working since then.
I found these in the synology docker log:

2025/03/18 22:32:10,stdout,"2025-03-18 21:32:10,145 INFO stopped: processes-exit-eventlistener (terminated by SIGTERM)
"
2025/03/18 22:32:10,stdout,"2025-03-18 21:32:10,144 INFO stopped: storagenode (exit status 2)
"
2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:929 +0x4ce

2025/03/18 22:32:10,stdout,created by github.com/dgraph-io/badger/v4.(*levelsController).compactBuildTables in goroutine 187

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:933 +0x1a5

2025/03/18 22:32:10,stdout,"github.com/dgraph-io/badger/v4.(*levelsController).compactBuildTables.func3({{0xc0000f5bd0, 0x48, 0x48}, {0xc0000f5db0, 0x48, 0x48}, 0x0, 0x0})
"
2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:835 +0x51f

2025/03/18 22:32:10,stdout,"github.com/dgraph-io/badger/v4.(*levelsController).subcompact(_, {_, _}, {{0xc0000f5bd0, 0x48, 0x48}, {0xc0000f5db0, 0x48, 0x48}, 0x0, ...}, ...)
"
2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:701 +0x144

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4.(*levelsController).subcompact.func3(0xc0000e06c0)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00068e2c0)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:79 +0x4c

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00068e300)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00068e210)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:79 +0x4c

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00068e250)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00068e160)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:81 +0x2d

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00068e1a0)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:529 +0x25

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*ConcatIterator).Next(0xc00017c370)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:406 +0x2a

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*Iterator).Next(0x0?)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:344 +0x189

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*Iterator).next(0xc001020c40)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:168

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*blockIterator).next(...)

2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:101 +0x50d

2025/03/18 22:32:10,stdout,"github.com/dgraph-io/badger/v4/table.(*blockIterator).setIdx(0x41?, 0x0?)
"
2025/03/18 22:32:10,stdout,	/usr/local/go/src/runtime/panic.go:785 +0x132

2025/03/18 22:32:10,stdout,"panic({0x22bae20?, 0xc000fa0168?})
"
2025/03/18 22:32:10,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:97 +0x259

2025/03/18 22:32:10,stdout,github.com/dgraph-io/badger/v4/table.(*blockIterator).setIdx.func1()

2025/03/18 22:32:10,stdout,goroutine 256 [running]:

2025/03/18 22:32:10,stdout,

2025/03/18 22:32:10,stdout,	

2025/03/18 22:32:10,stdout,	EntryOffsets: [0 79 140 185 230 275 320 365 426 471 516 561 606 651 696 741 2147484434 831 876 921 982 1027 1072 1117 1162 1207 1252 1297 1342 1387 1432 1493 1538 1599 1644 1689 1734 1795 1840 1885 1930 1975 2021 2067 2129 2175 2221 2267 2313 2359 2405 2467 2513 2559 2621 2667 2729 2791 2837 2899 2945 2991 3037 3099 3145 3191 3237 3283 3345 3407 3453 3499 3545 3591 3637 3683]

2025/03/18 22:32:10,stdout,	EntryOffsets len: 76

2025/03/18 22:32:10,stdout,	EndOffset: 2147484434

2025/03/18 22:32:10,stdout,	StartOffset: 741

2025/03/18 22:32:10,stdout,	Data len: 3729

2025/03/18 22:32:10,stdout,	Entry Idx: 15

2025/03/18 22:32:10,stdout,	Block ID: 1657

2025/03/18 22:32:10,stdout,	Table ID: 6469

2025/03/18 22:32:10,stdout,	panic: ==== Recovered====

2025/03/18 22:32:10,stdout,panic: runtime error: slice bounds out of range [:2147484434] with capacity 4047 [recovered]

2025/03/18 22:32:08,stdout,"2025-03-18 21:32:08,965 WARN received SIGTERM indicating exit request
"
2025/03/18 22:32:08,stdout,"2025-03-18 21:32:08,569 INFO stopped: storagenode-updater (exit status 0)
"
2025/03/18 22:32:08,stdout,2025-03-18T21:32:08Z	INFO	Got a signal from the OS: "terminated"	{"Process": "storagenode-updater"}

2025/03/18 22:32:08,stdout,"2025-03-18 21:32:08,564 INFO waiting for storagenode, processes-exit-eventlistener, storagenode-updater to die
"
2025/03/18 22:32:08,stdout,"2025-03-18 21:32:08,564 WARN received SIGQUIT indicating exit request
"
2025/03/18 22:32:08,stdout,"2025-03-18 21:32:08,563 INFO spawned: 'storagenode' with pid 47
"
2025/03/18 22:32:07,stdout,"2025-03-18 21:32:07,560 INFO exited: storagenode (exit status 2; expected)
"
2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:929 +0x4ce

2025/03/18 22:32:07,stdout,created by github.com/dgraph-io/badger/v4.(*levelsController).compactBuildTables in goroutine 237

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:933 +0x1a5

2025/03/18 22:32:07,stdout,"github.com/dgraph-io/badger/v4.(*levelsController).compactBuildTables.func3({{0xc001167e00, 0x48, 0x48}, {0xc001167ea0, 0x48, 0x48}, 0x0, 0x0})
"
2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:835 +0x51f

2025/03/18 22:32:07,stdout,"github.com/dgraph-io/badger/v4.(*levelsController).subcompact(_, {_, _}, {{0xc001167e00, 0x48, 0x48}, {0xc001167ea0, 0x48, 0x48}, 0x0, ...}, ...)
"
2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/levels.go:701 +0x144

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4.(*levelsController).subcompact.func3(0xc00f2703f0)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00083a160)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:79 +0x4c

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00083a1a0)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00083a0b0)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:79 +0x4c

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00083a0f0)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:157 +0x28

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*MergeIterator).Next(0xc00083a000)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/merge_iterator.go:81 +0x2d

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*node).next(0xc00083a040)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:529 +0x25

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*ConcatIterator).Next(0xc001176000)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:406 +0x2a

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*Iterator).Next(0x0?)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:344 +0x189

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*Iterator).next(0xc0064dc2a0)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:168

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*blockIterator).next(...)

2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:101 +0x50d

2025/03/18 22:32:07,stdout,"github.com/dgraph-io/badger/v4/table.(*blockIterator).setIdx(0x41?, 0x0?)
"
2025/03/18 22:32:07,stdout,	/usr/local/go/src/runtime/panic.go:785 +0x132

2025/03/18 22:32:07,stdout,"panic({0x22bae20?, 0xc000ea6078?})
"
2025/03/18 22:32:07,stdout,	/go/pkg/mod/github.com/dgraph-io/badger/v4@v4.5.0/table/iterator.go:97 +0x259

2025/03/18 22:32:07,stdout,github.com/dgraph-io/badger/v4/table.(*blockIterator).setIdx.func1()

2025/03/18 22:32:07,stdout,goroutine 297 [running]:

2025/03/18 22:32:07,stdout,

2025/03/18 22:32:07,stdout,	

2025/03/18 22:32:07,stdout,	EntryOffsets: [0 79 140 185 230 275 320 365 426 471 516 561 606 651 696 741 2147484434 831 876 921 982 1027 1072 1117 1162 1207 1252 1297 1342 1387 1432 1493 1538 1599 1644 1689 1734 1795 1840 1885 1930 1975 2021 2067 2129 2175 2221 2267 2313 2359 2405 2467 2513 2559 2621 2667 2729 2791 2837 2899 2945 2991 3037 3099 3145 3191 3237 3283 3345 3407 3453 3499 3545 3591 3637 3683]

2025/03/18 22:32:07,stdout,	EntryOffsets len: 76

2025/03/18 22:32:07,stdout,	EndOffset: 2147484434

2025/03/18 22:32:07,stdout,	StartOffset: 741

2025/03/18 22:32:07,stdout,	Data len: 3729

2025/03/18 22:32:07,stdout,	Entry Idx: 15

2025/03/18 22:32:07,stdout,	Block ID: 1657

2025/03/18 22:32:07,stdout,	Table ID: 6469

2025/03/18 22:32:07,stdout,	panic: ==== Recovered====

2025/03/18 22:32:07,stdout,panic: runtime error: slice bounds out of range [:2147484434] with capacity 4047 [recovered]

2025/03/18 22:32:07,stdout,"2025-03-18 21:32:07,230 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
"
2025/03/18 22:32:07,stdout,"2025-03-18 21:32:07,230 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
4

You may also just wipe the badger cache directory (storage/filestatcache) and enable it back, it would be rebuilt.

5

its works. Thank you everyone

1 Like