Upgraded storagenode but seeing migration errors

hchung · May 24, 2026, 12:10am

I started up my node after upgrading and noticed logs like this:

2026-05-23T16:55:06-07:00 INFO piecemigrate:chore piecemigrate/chore.go:109 piece migration chore initialized {"process": "storagenode", "old_blobs_path": "/Volumes/DS-M47G09911600353/storj-node1/storage/blobs", "cleanup_enabled": true}

2026-05-23T16:55:06-07:00 WARN piecestore/migrate_backend.go:69 failed to unmarshal migration state {"process": "storagenode", "error": "invalid character 'â' looking for beginning of value", "satellite": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}

storj.io/storj/storagenode/piecestore.NewMigratingBackend.func1

/Volumes/DS-M47G09911600353/storj/storagenode/piecestore/migrate_backend.go:69

storj.io/storj/storagenode/satstore.(*SatelliteStore).Range.func1

/Volumes/DS-M47G09911600353/storj/storagenode/satstore/satstore.go:109

storj.io/storj/storagenode/satstore.(*SatelliteStore).Range

/Volumes/DS-M47G09911600353/storj/storagenode/satstore/satstore.go:110

storj.io/storj/storagenode/piecestore.NewMigratingBackend

/Volumes/DS-M47G09911600353/storj/storagenode/piecestore/migrate_backend.go:65

storj.io/storj/storagenode.New

/Volumes/DS-M47G09911600353/storj/storagenode/peer.go:717

main.cmdRun

/Volumes/DS-M47G09911600353/storj/cmd/storagenode/cmd_run.go:84

main.newRunCmd.func1

/Volumes/DS-M47G09911600353/storj/cmd/storagenode/cmd_run.go:33

storj.io/common/process.InitBeforeExecute.func1.2

/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:389

storj.io/common/process.InitBeforeExecute.func1

/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:407

github.com/spf13/cobra.(*Command).execute

/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:985

github.com/spf13/cobra.(*Command).ExecuteC

/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:1117

github.com/spf13/cobra.(*Command).Execute

/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:1041

storj.io/common/process.ExecWithCustomOptions

/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:115

main.main

/Volumes/DS-M47G09911600353/storj/cmd/storagenode/main.go:34

runtime.main

/Users/bc/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.darwin-arm64/src/runtime/proc.go:285

That shows up for each satellite, and then I see this:

2026-05-23T16:55:06-07:00	WARN	piecestore/migrate_backend.go:75	failed to iterate over migration state directories	{"process": "storagenode", "error": "invalid character 'â' looking for beginning of value; invalid character 'â' looking for beginning of value; invalid character 'â' looking for beginning of value; invalid character 'â' looking for beginning of value", "errorVerbose": "group:\n--- invalid character 'â' looking for beginning of value\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range.func1:109\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range:110\n\tstorj.io/storj/storagenode/piecestore.NewMigratingBackend:65\n\tstorj.io/storj/storagenode.New:717\n\tmain.cmdRun:84\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\truntime.main:285\n--- invalid character 'â' looking for beginning of value\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range.func1:109\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range:110\n\tstorj.io/storj/storagenode/piecestore.NewMigratingBackend:65\n\tstorj.io/storj/storagenode.New:717\n\tmain.cmdRun:84\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\truntime.main:285\n--- invalid character 'â' looking for beginning of value\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range.func1:109\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range:110\n\tstorj.io/storj/storagenode/piecestore.NewMigratingBackend:65\n\tstorj.io/storj/storagenode.New:717\n\tmain.cmdRun:84\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\truntime.main:285\n--- invalid character 'â' looking for beginning of value\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range.func1:109\n\tstorj.io/storj/storagenode/satstore.(*SatelliteStore).Range:110\n\tstorj.io/storj/storagenode/piecestore.NewMigratingBackend:65\n\tstorj.io/storj/storagenode.New:717\n\tmain.cmdRun:84\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\truntime.main:285"}
storj.io/storj/storagenode/piecestore.NewMigratingBackend
	/Volumes/DS-M47G09911600353/storj/storagenode/piecestore/migrate_backend.go:75
storj.io/storj/storagenode.New
	/Volumes/DS-M47G09911600353/storj/storagenode/peer.go:717
main.cmdRun
	/Volumes/DS-M47G09911600353/storj/cmd/storagenode/cmd_run.go:84
main.newRunCmd.func1
	/Volumes/DS-M47G09911600353/storj/cmd/storagenode/cmd_run.go:33
storj.io/common/process.InitBeforeExecute.func1.2
	/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:389
storj.io/common/process.InitBeforeExecute.func1
	/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:407
github.com/spf13/cobra.(*Command).execute
	/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:985
github.com/spf13/cobra.(*Command).ExecuteC
	/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:1117
github.com/spf13/cobra.(*Command).Execute
	/Users/bc/go/pkg/mod/github.com/spf13/cobra@v1.8.1/command.go:1041
storj.io/common/process.ExecWithCustomOptions
	/Users/bc/go/pkg/mod/storj.io/common@v0.0.0-20260328020406-acac5312e030/process/exec_conf.go:115
main.main
	/Volumes/DS-M47G09911600353/storj/cmd/storagenode/main.go:34
runtime.main
	/Users/bc/go/pkg/mod/golang.org/toolchain@v0.0.1-go1.25.0.darwin-arm64/src/runtime/proc.go:285
2026-05-23T16:55:08-07:00	INFO	db.migration	migrate/versions.go:242	Database Version	{"process": "storagenode", "version": 62}
2026-05-23T16:55:09-07:00	INFO	bandwidth	bandwidth/service.go:52	Persisting bandwidth usage cache to db	{"process": "storagenode"}

Is there a way to do something to restart the migration or fix this? It seems like this node isn’t doing anything anymore. I don’t see any of the old piecestore upload/download/GET_AUDIT/etc sort of logs for a week.

arrogantrabbit · May 24, 2026, 1:33am

the message tells you that one of the .migrate files begins with that invalid characters. Check them. They have to contains clean json.

If you don’t know how did you corrupt that file — maybe worth running filesystem scan and stabilizing your storage.

hchung · May 24, 2026, 4:55am

Thanks, I saw there was extra characters and it turns out the cause was following the commands in Cleanup before Hashstore and migration to it - #2 by Walter1

However now that there’s no errors, I still see no traffic and I’m wondering what else I can do to diagnose. The latest logs look just like this:

2026-05-23T21:46:13-07:00	INFO	pieces	pieces/store.go:800	used-space-filewalker completed	{"process": "storagenode", "satellite_id": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "lazy_file_walker": true, "total_pieces_size": 26067335168, "total_pieces_content_size": 26036716032, "total_pieces_count": 59803, "duration": "1.396065916s"}
2026-05-23T21:46:13-07:00	INFO	pieces	pieces/store.go:777	used-space-filewalker started	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-05-23T21:46:13-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:50	starting subprocess	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-05-23T21:46:13-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:76	subprocess started	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-05-23T21:46:13-07:00	INFO	lazyfilewalker.used-space-filewalker.subprocess	internalcmd/used_space_filewalker.go:81	Database started	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "process": "storagenode"}
2026-05-23T21:46:15-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:88	subprocess finished successfully	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2026-05-23T21:46:15-07:00	INFO	pieces	pieces/store.go:800	used-space-filewalker completed	{"process": "storagenode", "satellite_id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "lazy_file_walker": true, "total_pieces_size": 1231151313152, "total_pieces_content_size": 1229362603776, "total_pieces_count": 3493573, "duration": "2.450409583s"}
2026-05-23T21:46:15-07:00	INFO	pieces	pieces/store.go:777	used-space-filewalker started	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2026-05-23T21:46:15-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:50	starting subprocess	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2026-05-23T21:46:15-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:76	subprocess started	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2026-05-23T21:46:16-07:00	INFO	lazyfilewalker.used-space-filewalker.subprocess	internalcmd/used_space_filewalker.go:81	Database started	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "process": "storagenode"}
2026-05-23T21:46:18-07:00	INFO	lazyfilewalker.used-space-filewalker	lazyfilewalker/process.go:88	subprocess finished successfully	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2026-05-23T21:46:18-07:00	INFO	pieces	pieces/store.go:800	used-space-filewalker completed	{"process": "storagenode", "satellite_id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "lazy_file_walker": true, "total_pieces_size": 71946915584, "total_pieces_content_size": 71866725632, "total_pieces_count": 156621, "duration": "2.378478583s"}

arrogantrabbit · May 24, 2026, 5:01am

Look at logs at node startup. See that satellite registration succeeds and it can ping the node.

Alexey · May 24, 2026, 5:30am

You need to use only straight quotes like ' and ", instead of curly ones like ‘ and ’ or “ and ”, the quoted message doesn’t contain code-block formatting, thus they are “curlyfied”.

hchung · May 24, 2026, 8:27am

I don’t see any log message nor errors about registration. The most related one I see is the trust refresh in 6h25m. I’ve enabled debug logging too.

Port forwarding should be working; I ran curl against my external address and got back { "Statuses": null, "Help": "To access Storagenode services, please use DRPC protocol!", "AllHealthy": true }

hchung · May 24, 2026, 11:33pm

Is there anything that would show up in a log if somehow storagenode doesn’t try to contact the satellites? Does a config even exist for that? Found the trust-cache.json and it says authoritative:true for all the entries.

Toyoo · May 24, 2026, 11:55pm

If a node acts as if there were no satellites to contact, there’s an error message of:

"errorVerbose": "system clock is out of sync: system clock is out of sync with all trusted satellites\n\tstorj.io/storj/storagenode/preflight.(*LocalTime).Check:96\n\tstorj.io/storj/storagenode.(*Peer).Run:1100\n\tmain.cmdRun:127\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\truntime.main:283"

(example: Wireguard + VPS: need help for QUIC - #26 by smokemodel; note: line numbers change from version to version)

Which is effectively a statement that “there were no satellites with which a clock would be in sync”.

hchung · May 25, 2026, 12:34am

Interesting, I didn’t get that, and started digging and found that I had preflight.local-time-check:false set from long ago when there was some weird issue on FreeBSD. (Though now I’m running this from macOS years later)

Enabling it gets the message you mentioned. But it seems I get none of the “unable to get satellite system time” or “system clock is out of sync with satellite” messages. Just straight to all no sync with all trusted satellites.

I’m not a Go programmer, but reading the code suggests the problem isn’t connecting to the satellite but that somehow it thinks they’re all untrusted?

The trust-cache.json seems to suggest they’re all trusted. But if I rename the file and restart, I end up with just “{}”.

Here’s the trust-cache.json I had earlier: { "entries": { "https://static.storj.io/dcs-satellites": [ { "SatelliteURL": { "id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "host": "us1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "host": "eu1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "host": "ap1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "host": "saltlake.tardigrade.io", "port": 7777 }, "authoritative": true } ], "https://tardigrade.io/trusted-satellites": [ { "SatelliteURL": { "id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "host": "us1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "host": "eu1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "host": "ap1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "host": "saltlake.tardigrade.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "host": "europe-north-1.tardigrade.io", "port": 7777 }, "authoritative": false }, { "SatelliteURL": { "id": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "host": "us2.storj.io", "port": 7777 }, "authoritative": false } ], "https://www.storj.io/dcs-satellites": [ { "SatelliteURL": { "id": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "host": "us1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "host": "eu1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "host": "ap1.storj.io", "port": 7777 }, "authoritative": true }, { "SatelliteURL": { "id": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "host": "saltlake.tardigrade.io", "port": 7777 }, "authoritative": true } ] } }

hchung · May 25, 2026, 12:57am

Okay mystery solved, the cache file doesn’t seem to work on its own. Refresh the trust list was broken until I set storage2.trust.sources: “https://static.storj.io/dcs-satellites”, changed the refresh-interval to 1m0s (I’ll change this back now), and restarted.

kocoten1992 · May 25, 2026, 1:27am

Seen that bug before, trust-cache.json content become {}, it a rare bug, just delete the file (trust-cache.json) and restart, it will auto repopulate.

Or manually copy that file from other node, that work too.