Storj v3 Storage Node service not starting

server listening on 127.0.0.1:32011

im guess that is what i got as

2020-06-25T13:04:26.414Z INFO Telemetry enabled

which seems to indicate it might be a connection issue…
that port number is also custom

is a bit wierd that the windows logs and docker logs doesn’t go through the same steps in the same order during boot… or just logs them different…

Hi!! Much more info!!

PS C:\Program Files\Storj\Storage Node> ./storagenode run --config-dir “$env:ProgramFiles\Storj\Storage Node” --log.level debug --log.output stdout
2020-06-26T15:39:17.541+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-06-26T15:39:17.629+0200 DEBUG Anonymized tracing disabled
2020-06-26T15:39:17.639+0200 INFO Operator email {“Address”: “mail@gmail.com”}
2020-06-26T15:39:17.639+0200 INFO Operator wallet {“Address”: “payout_addr”}
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x28 pc=0xd6b904]

goroutine 1 [running]:
github.com/spacemonkeygo/monkit/v3.newSpan.func1(0xc0003f4f20)
/go/pkg/mod/github.com/spacemonkeygo/monkit/v3@v3.0.7-0.20200515175308-072401d8c752/ctx.go:147 +0x3af
panic(0x116a9a0, 0x103c200)
/usr/local/go/src/runtime/panic.go:679 +0x1c0
storj.io/storj/storagenode/storagenodedb.(*DB).closeDatabase(0xc0004600f0, 0x12e7084, 0xa, 0x103c7e0, 0x3)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:395 +0x84
storj.io/storj/storagenode/storagenodedb.(*DB).closeDatabases(0xc0004600f0, 0x12e7084, 0xa)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:384 +0xb5
storj.io/storj/storagenode/storagenodedb.(*DB).openDatabases(0xc0004600f0, 0xc0004600f0, 0x12e43d3)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:242 +0x39b
storj.io/storj/storagenode/storagenodedb.New(0xc0004ae4e0, 0xc000458570, 0xe, 0xc000133160, 0x1b, 0xc0001331c0, 0x15, 0x0, 0x0, 0xc000458570, …)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:172 +0x860
main.cmdRun(0x1048260, 0xc000159980, 0x0, 0x6, 0x0, 0x0)
/go/src/storj.io/storj/cmd/storagenode/main.go:147 +0x5cd
storj.io/private/process.cleanup.func1.4(0x1485b00, 0xc00045d220)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:359 +0x142
storj.io/private/process.cleanup.func1(0x1048260, 0xc000159980, 0x0, 0x6, 0x0, 0x0)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:377 +0x21c9
github.com/spf13/cobra.(*Command).execute(0x1048260, 0xc0001598c0, 0x6, 0x6, 0x1048260, 0xc0001598c0)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:840 +0x467
github.com/spf13/cobra.(*Command).ExecuteC(0x1047fc0, 0xc000062000, 0x1336268, 0x0)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:945 +0x31e
github.com/spf13/cobra.(*Command).Execute(…)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:885
storj.io/private/process.ExecWithCustomConfig(0x1047fc0, 0x0, 0x1336268)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:88 +0x196
storj.io/private/process.ExecCustomDebug(...)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:70
main.main()
/go/src/storj.io/storj/cmd/storagenode/main.go:320 +0x45
PS C:\Program Files\Storj\Storage Node>

We have created an internal ticket for that issue

1 Like

Thank you!! Please contact me if you need more info.

have you tried a reboot of the computer and a reinstall of the node… ofc using the existing identity and data folders if any data on the node…

else makes sure the software like “docker” or whatever is the recommended version
also running a windows update sometimes can help with general weirdness.

maybe checking that your antivirus did mess with the install

and ofc start from the easiest solutions to test first

Yeah, I have been doing all our recommendations. The node has 7TB of data and it’s full. It has been running very well since I installed it in january.
I fear it’s some type of weird permissions problem, but I can’t find what is.

you migrated it recently? or why would you think it’s permissions… ?

I has not been migrated. Was “born” in Windows GUI. I think that’s permissions because I don’t have any other explanation.

6 posts were split to a new topic: Windows GUI Service doesn’t start (1067 error)

I am getting

Error 1067: The Process terminated unexpectedly

(I’ve replaced my real wallet addres and email with ‘…’)

PS C:\Program Files\Storj\Storage Node> Get-Content “$env:ProgramFiles/Storj/Storage Node/storagenode-2020-07.log” -Tail 20 -Wait
2020-07-10T23:47:52.699+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:47:52.699+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:47:56.715+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:47:56.721+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:47:56.722+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:48:07.071+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:48:07.078+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:48:07.078+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:48:30.554+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:48:30.562+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:48:30.562+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:51:55.872+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:51:55.880+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:51:55.880+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:56:12.973+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:56:12.979+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:56:12.979+0200 INFO Operator wallet {“Address”: “…”}
2020-07-10T23:58:12.631+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-10T23:58:12.638+0200 INFO Operator email {“Address”: “…”}
2020-07-10T23:58:12.639+0200 INFO Operator wallet {“Address”: “…”}

As there was nothing interesting in storagenode.log, I tried this way:

PS C:\Program Files\Storj\Storage Node> .\storagenode.exe run
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x28 pc=0xd6b904]

goroutine 1 [running]:
github.com/spacemonkeygo/monkit/v3.newSpan.func1(0xc000369ac0)
/go/pkg/mod/github.com/spacemonkeygo/monkit/v3@v3.0.7-0.20200515175308-072401d8c752/ctx.go:147 +0x3af
panic(0x116a9a0, 0x103c200)
/usr/local/go/src/runtime/panic.go:679 +0x1c0
storj.io/storj/storagenode/storagenodedb.(*DB).closeDatabase(0xc0004000f0, 0x12e7278, 0xa, 0x103c7e0, 0x3)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:395 +0x84
storj.io/storj/storagenode/storagenodedb.(*DB).closeDatabases(0xc0004000f0, 0x12e2df3, 0x6)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:384 +0xb5
storj.io/storj/storagenode/storagenodedb.(*DB).openDatabases(0xc0004000f0, 0xc0004000f0, 0x12e43d3)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:197 +0x87e
storj.io/storj/storagenode/storagenodedb.New(0xc00046a060, 0xc0003eed80, 0x9, 0xc0003d8040, 0x16, 0xc00047c040, 0x10, 0x0, 0x0, 0xc0003eed80, …)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:172 +0x860
main.cmdRun(0x1048260, 0x1bbfbd0, 0x0, 0x0, 0x0, 0x0)
/go/src/storj.io/storj/cmd/storagenode/main.go:147 +0x5cd
storj.io/private/process.cleanup.func1.4(0x1485b00, 0xc0003fa960)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:359 +0x142
storj.io/private/process.cleanup.func1(0x1048260, 0x1bbfbd0, 0x0, 0x0, 0x0, 0x0)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:377 +0x21c9
github.com/spf13/cobra.(*Command).execute(0x1048260, 0x1bbfbd0, 0x0, 0x0, 0x1048260, 0x1bbfbd0)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:840 +0x467
github.com/spf13/cobra.(*Command).ExecuteC(0x1047fc0, 0xc00007e000, 0x1336268, 0x0)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:945 +0x31e
github.com/spf13/cobra.(*Command).Execute(…)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:885
storj.io/private/process.ExecWithCustomConfig(0x1047fc0, 0x0, 0x1336268)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:88 +0x196
storj.io/private/process.ExecCustomDebug(...)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:70
main.main()
/go/src/storj.io/storj/cmd/storagenode/main.go:320 +0x45

I have reinstalled the machine but I keep getting the 1067 error, so I thing the node installation is ok. If I change the route for the storage the node starts ok. It’s something related to the database perhaps?? The log in debug node doesn’t give any info.

might as well post what the log does say… remember to remove what you consider private information…

usually tho if the node keeps restarting, then it’s a router port issues or a firewall issue… usually router port redirection to your storagenode. it’s kinda well covered in the storagenode documentation, but sometimes you will need ISP information…

another option is that your ISP or the current service you are subscribed to at your ISP doesn’t do port redirection…

thats afaik the most common issue when setting up a new storagenode.

sorry i cannot be of more help… i’m sure somebody will go through it all in great detail if you wait around a bit…

the route for the storage… most network storage protocols won’t work well… such a NFS or SMB/samba, iscsi i believe is the solution people have had the best results with… but network storage for your storagenode is not a great idea…

if you by changed route means you changes the port numbers or the storagenode data location… then ofc double and triple check your ports and locations… sometimes deleting them and typing them back in can help, because one can sort of get blind to a miss configuration of a port number of a slight deviation in the location address…

No, the node tries to start gives the 1067 error and stops. The log says that:

2020-07-17T23:40:44.490+0200 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-17T23:40:44.510+0200 DEBUG Anonymized tracing disabled
2020-07-17T23:40:44.511+0200 DEBUG debug server listening on 127.0.0.1:51201
2020-07-17T23:40:44.523+0200 INFO Operator email {“Address”: “xxxxxxxx@gmail.com”}
2020-07-17T23:40:44.523+0200 INFO Operator wallet {“Address”: “0xxxxxxxxx”}

yeah doesn’t look like it connects online correctly…
this is mine in docker on linux… sadly the logs are not the same exactly and doesn’t give us any easy to read indication of what is wrong… but as you can see it will very early on… try to connect online… so either ports or ip’s the ports are routed to are wrong… or something in that regard… its either that or storage location.

but mine seems to check the version number almost as the first thing… which yours seems to timeout or fail at…
sorry the logs in this are kinda terrible… if one isn’t very familiar with them… i mean it wouldn’t take much for it to tell us what failed… instead of just being silent…

anyways… my bet it on that it doesn’t connect correctly to the internet…

but you might have better luck with somebody like @nerdatwork @Alexey @BrightSilence
they are very well versed in the details of the node… but do double check your routing, it’s the most common configuration failure…

2020-07-02T20:01:45.552Z INFO Configuration loaded {“Location”: “/app/config/config.yaml”}
2020-07-02T20:01:45.553Z DEBUG Anonymized tracing disabled
2020-07-02T20:01:45.585Z INFO Operator email {“Address”: “myemail@gmail.com”}
2020-07-02T20:01:45.585Z INFO Operator wallet {“Address”: “0x…”}
2020-07-02T20:01:45.683Z DEBUG Version info {“Version”: “1.6.4”, “Commit Hash”: "5e495f4b3bee91d6e6ac2fa43fc50341921$
2020-07-02T20:01:46.336Z DEBUG version Allowed minimum version from control server. {“Minimum Version”: “1.3.0”}
2020-07-02T20:01:46.336Z DEBUG version Running on allowed version. {“Version”: “1.6.4”}
2020-07-02T20:01:46.337Z INFO Telemetry enabled
2020-07-02T20:01:46.337Z DEBUG Initialized batcher {“ID”: “…”}
2020-07-02T20:01:46.346Z INFO db.migration.40 Add unknown_audit_reputation_score field to satellites db
2020-07-02T20:01:46.357Z INFO db.migration.41 Make satellite_id foreign key in satellite_exit_progress table
2020-07-02T20:01:46.368Z INFO db.migration.42 Drop used serials table
2020-07-02T20:01:48.458Z INFO db.migration Database Version {“version”: 42}
2020-07-02T20:01:49.091Z DEBUG trust Fetched URLs from source; updating cache {“source”: "https://tardigrade.i$
2020-07-02T20:01:49.094Z DEBUG trust Satellite is trusted {“id”: "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdp$
2020-07-02T20:01:49.094Z DEBUG trust Satellite is trusted {“id”: "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcN$
2020-07-02T20:01:49.095Z DEBUG trust Satellite is trusted {“id”: "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vz$
2020-07-02T20:01:49.095Z DEBUG trust Satellite is trusted {“id”: "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvv$
2020-07-02T20:01:49.095Z DEBUG trust Satellite is trusted {“id”: "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69t$
2020-07-02T20:01:49.095Z DEBUG trust Satellite is trusted {“id”: "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuaw$
2020-07-02T20:01:49.095Z INFO preflight:localtime start checking local system clock with trusted satellites’ syste$
2020-07-02T20:01:50.970Z INFO preflight:localtime local system clock is in sync with trusted satellites’ system cl$
2020-07-02T20:01:50.970Z DEBUG servers started {“items”: [“debug”, “server”]}
2020-07-02T20:01:50.970Z DEBUG services started {“items”: [“version”, “trust”, “contact:chore”, “PieceDeleter”, 2020-07-02T20:01:50.970Z INFO bandwidth Performing bandwidth usage rollups 2020-07-02T20:01:50.970Z INFO trust Scheduling next refresh {"after": "4h58m8.200695359s"} 2020-07-02T20:01:50.970Z INFO Node started 2020-07-02T20:01:50.971Z WARN piecestore:monitor Disk space is less than requested. Allocating space {"bytes"
2020-07-02T20:01:50.971Z INFO Public server started on [::]:28967
2020-07-02T20:01:50.973Z INFO Private server started on 127.0.0.1:7778
2020-07-02T20:01:50.972Z DEBUG contact:chore Starting cycle {“Satellite ID”: "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJe$
2020-07-02T20:01:50.973Z DEBUG contact:chore Starting cycle {“Satellite ID”: "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpS$
2020-07-02T20:01:50.973Z DEBUG pieces:trash starting emptying trash

Very rare. The service/container is usually restarting if it have problems with storage - either wrong path or corrupted structure.
In rare cases (antivirus or some aggressive firewall) the network infrastructure could block the needed traffic to contact satellites and node will fail on preflight check.

If you have a port problem your node will just simply being offline. The service will not restart.

So, since there is no evidence to have an aggressive firewall and node crash even before the preflight check, then I can assume that this node have a problem with storage.

Please, stop your storagenode and check your filesystem for errors with checkdisk
Then, check all sqlite databases and fix them, if they are corrupted:

After that try to start the storagenode.

2 Likes

I am having the same issues.

Did a chkdsk and found nothing worng.

Any help will be appreciated.

Please run storagenode run --config-dir "<your config dir>" --log.level debug --log.output stdout and post the output.

Depending on where it fails, it will help show which DB it is failing to open (if your issue is the same as the original post).

The theory is one of the sqlite DBs are corrupt or has permission issues.

Your command had curly quotes. Should be

storagenode run --config-dir "<your config dir>" --log.level debug --log.output stdout

2020-07-24T20:48:41.442+0800 INFO Configuration loaded {“Location”: “C:\Program Files\Storj\Storage Node\config.yaml”}
2020-07-24T20:48:41.487+0800 DEBUG Anonymized tracing disabled
2020-07-24T20:48:41.499+0800 INFO Operator email {“Address”: “”}
2020-07-24T20:48:41.499+0800 INFO Operator wallet {“Address”: “”}
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xc0000005 code=0x0 addr=0x28 pc=0xd6b904]

goroutine 1 [running]:
github com/spacemonkeygo/monkit/v3.newSpan.func1(0xc0003df110)
/go/pkg/mod/github.com/spacemonkeygo/monkit/v3@v3.0.7-0.20200515175308-072401d8c752/ctx.go:147 +0x3af
panic(0x116a9a0, 0x103c200)
/usr/local/go/src/runtime/panic.go:679 +0x1c0
storj io/storj/storagenode/storagenodedb.(*DB).closeDatabase(0xc00044a0f0, 0x12e7084, 0xa, 0x103c7e0, 0x3)
/go/src/storj io/storj/storagenode/storagenodedb/database.go:395 +0x84
storj io/storj/storagenode/storagenodedb.(*DB).closeDatabases(0xc00044a0f0, 0x12e2df3, 0x6)
/go/src/storj io/storj/storagenode/storagenodedb/database.go:384 +0xb5
storj io/storj/storagenode/storagenodedb.(*DB).openDatabases(0xc00044a0f0, 0xc00044a0f0, 0x12e43d3)
/go/src/storj io/storj/storagenode/storagenodedb/database.go:197 +0x87e
storj io/storj/storagenode/storagenodedb.New(0xc00011c540, 0xc00043d740, 0x16, 0xc00052e180, 0x23, 0xc0005582e0, 0x1d, 0x0, 0x0, 0xc00043d740, …)
/go/src/storj.io/storj/storagenode/storagenodedb/database.go:172 +0x860
main.cmdRun(0x1048260, 0xc000161b00, 0x0, 0x6, 0x0, 0x0)
/go/src/storj io/storj/cmd/storagenode/main.go:147 +0x5cd
storj io/private/process.cleanup.func1.4(0x1485b00, 0xc0004490e0)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:359 +0x142
storj io/private/process.cleanup.func1(0x1048260, 0xc000161b00, 0x0, 0x6, 0x0, 0x0)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:377 +0x21c9
github com/spf13/cobra.(*Command).execute(0x1048260, 0xc000161a40, 0x6, 0x6, 0x1048260, 0xc000161a40)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:840 +0x467
github com/spf13/cobra.(*Command).ExecuteC(0x1047fc0, 0xc00006c000, 0x1336268, 0x0)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:945 +0x31e
github com/spf13/cobra.(*Command).Execute(…)
/go/pkg/mod/github.com/spf13/cobra@v0.0.6/command.go:885
storj io/private/process.ExecWithCustomConfig(0x1047fc0, 0x0, 0x1336268)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:88 +0x196
storj io/private/process.ExecCustomDebug(…)
/go/pkg/mod/storj.io/private@v0.0.0-20200504130741-565a173f6d33/process/exec_conf.go:70
main.main()
/go/src/storj.io/storj/cmd/storagenode/main.go:320 +0x45

Can you check the permissions on C:\Program Files\Storj\Storage Node\storage\orders.db to make sure the file is writable for the storage node process user.

Next you can run the following to verify the DB is not corrupt.
sqlite3 pieceinfo.db "PRAGMA integrity_check;"
If it is, please see https://support.storj.io/hc/en-us/articles/360029309111-How-to-fix-a-database-disk-image-is-malformed-?_ga=2.246141572.1035966471.1595438903-1386301597.1583787199