QUIC misconfigured, node offline

Hey, old node operator trying to get back in the game but having issues with QUIC misconfiguration and node offline.

With hours of debugging my network at a new location via netcat and whatnot, came to the conclusion that I was behind the ISPs NAT.
Did however manage to get a public IP from them, so that’s good - port 28967 is now indeed open when checked via IP and hostname (Using NoIP via DDNS).
Picture below tested with hostname, not IP however both work.
portTest

WAN IP is the same as what I get from whatismyipaddress.com

Now what I’m facing is the topic’s issue.
From what I can tell, since the port is indeed open I’ve correctly forwarded the TCP+UDP ports on my router but my node dashboard is still telling me “Misconfigured” and pointing that QUIC isn’t working. Below a picture of the forward rule on the router.

Incoming Windows firewall rules have also been of course added for both TCP and UDP for the port in question.


What I find hilarious though is the 17740200 hours from last contact, that’d take us around 1 AD. That’s uhh… Probably not true :slight_smile:

One thing to note, I am using my old identity from 2019 - would that have any effect? Doesn’t sound like a network issue though.
But regarding that, is it advisable to use a newly created identity since I doubt my exit was graceful by any means. Any implications to using the old identity?
Another thing that this test is done for now on wifi, not ethernet. Wifi connected local machine has a static internal IP attached.

Ncat however is still baffling me, as it’s not showing UDP traffic even if i send some to it.
No output whatsoever.

After being tired from hours of debugging, I’m running out of ideas where the issue could be now.
Am running the docker version on Windows 11. Fresh install, fresh hard drive, no migration.
Any assistance on how to further debug / straight pointers on what’s the issue now?

Thanks in advance.

Why? create a new one.

This does not matter. Your node is offline. You need to look into logs.

Node will get disqualified almost instantly.

UDP traffic does not matter.

Before you start debugging you need to triage. And answers are in the first 20 lines of node log.

1 Like

Why the old identity? Seemed convenient…? Didn’t feel like waiting for creating a new one.
Alright well I’ll get back to this when a new identity is created and have a look at the logs.
Will create a new docker container with new info once that’s done.
Thanks.
About UDP - I was under the impression QUIC needs UDP.

Errors I’m seeing in logs currently are:
ERROR contact:service ping satellite failed {“Process”: “storagenode”, “Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “attempts”: 1, “error”: “ping satellite: failed to ping storage node, your node indicated error code: 0, rpc: tcp connector failed: rpc: tls peer certificate verification: not signed by any CA in the whitelist: CA cert”, “errorVerbose”: “ping satellite: failed to ping storage node, your node indicated error code: 0, rpc: tcp connector failed: rpc: tls peer certificate verification: not signed by any CA in the whitelist: CA cert\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:208\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:156\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/common/sync2.(*Cycle).Start.func1:77\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78”}

And
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Configuration loaded {“Process”: “storagenode-updater”, “Location”: “/app/config/config.yaml”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “operator.wallet-features”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “healthcheck.details”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “storage.allocated-bandwidth”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “console.address”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “contact.external-address”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “server.address”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “server.private-address”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “storage.allocated-disk-space”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “operator.wallet”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “operator.email”}
2024-10-17 07:52:42 2024-10-17T04:52:42Z INFO Invalid configuration file key {“Process”: “storagenode-updater”, “Key”: “healthcheck.enabled”}

Your identity is not signed.

That identity has been offline for over a month, did not it? It’s disqualified already on all satellites. You can also read it on the screenshot you posted.

side note:

Please place logs between ``` and ```. Like this:

```
logs go here
```

to get

logs go here

Otherwise it’s unreadable. And post full logs until the first error.

1 Like

Right ok, here’s the logs with newly created and signed identity.

2024-10-17 08:20:00 2024-10-17 05:20:00,030 INFO Set uid to user 0 succeeded
2024-10-17 08:20:00 2024-10-17 05:20:00,034 INFO RPC interface 'supervisor' initialized
2024-10-17 08:20:00 2024-10-17 05:20:00,034 INFO supervisord started with pid 1
2024-10-17 08:20:01 2024-10-17 05:20:01,036 INFO spawned: 'processes-exit-eventlistener' with pid 56
2024-10-17 08:20:01 2024-10-17 05:20:01,037 INFO spawned: 'storagenode' with pid 57
2024-10-17 08:20:01 2024-10-17 05:20:01,039 INFO spawned: 'storagenode-updater' with pid 58
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOConfiguration loaded{"Process": "storagenode-updater", "Location": "/app/config/config.yaml"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "storage.allocated-bandwidth"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "server.address"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.email"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.wallet-features"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "console.address"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOAnonymized tracing enabled{"Process": "storagenode-updater"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFORunning on version{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFODownloading versions.{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOConfiguration loaded{"Process": "storagenode", "Location": "/app/config/config.yaml"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOAnonymized tracing enabled{"Process": "storagenode"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOOperator email{"Process": "storagenode", "Address": "@gmail.com"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOOperator wallet{"Process": "storagenode", "Address": "0x"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOCurrent binary version{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.113.2"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFONew version is being rolled out but hasn't made it to this node yet{"Process": "storagenode-updater", "Service": "storagenode"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOCurrent binary version{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFONew version is being rolled out but hasn't made it to this node yet{"Process": "storagenode-updater", "Service": "storagenode-updater"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOserverkernel support for server-side tcp fast open remains disabled.{"Process": "storagenode"}
2024-10-17 08:20:01 2024-10-17T05:20:01ZINFOserverenable with: sysctl -w net.ipv4.tcp_fastopen=3{"Process": "storagenode"}
2024-10-17 08:20:02 2024-10-17T05:20:02ZINFOTelemetry enabled{"Process": "storagenode", "instance ID": "12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5"}
2024-10-17 08:20:02 2024-10-17T05:20:02ZINFOEvent collection enabled{"Process": "storagenode", "instance ID": "12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5"}
2024-10-17 08:20:02 2024-10-17 05:20:02,369 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:02 2024-10-17 05:20:02,369 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:02 2024-10-17 05:20:02,369 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:03 2024-10-17T05:20:03ZINFOdb.migrationDatabase Version{"Process": "storagenode", "version": 61}
2024-10-17 08:20:04 2024-10-17T05:20:04ZINFOpreflight:localtimestart checking local system clock with trusted satellites' system clock.{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOpreflight:localtimelocal system clock is in sync with trusted satellites' system clock.{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcollectorexpired pieces collection started{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFONode 12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5 started{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOPublic server started on [::]:28967{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOPrivate server started on 127.0.0.1:7778{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOfailed to sufficiently increase receive buffer size (was: 208 kiB, wanted: 2048 kiB, got: 416 kiB). See https://github.com/quic-go/quic-go/wiki/UDP-Buffer-Sizes for details.{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOpieces:trashemptying trash started{"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOlazyfilewalker.trash-cleanup-filewalkerstarting subprocess{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFObandwidthPersisting bandwidth usage cache to db{"Process": "storagenode"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOtrustScheduling next refresh{"Process": "storagenode", "after": "5h17m2.198369704s"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcollectorexpired pieces collection completed{"Process": "storagenode", "count": 0}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORservicesunexpected shutdown of a runner{"Process": "storagenode", "name": "piecestore:monitor", "error": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)", "errorVerbose": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1.1:159\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1:140\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.94.153.46:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.94.153.46:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORnodestats:cacheGet pricing-model/join date failed{"Process": "storagenode", "error": "context canceled"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORversionfailed 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\tstorj.io/storj/storagenode/version.(*Chore).checkVersion:115\n\tstorj.io/storj/storagenode/version.(*Chore).RunOnce:71\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/version.(*Chore).Run:64\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2.1:87\n\truntime/pprof.Do:51\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2:86\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.159.134.91:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.159.134.91:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.126.92.94:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.126.92.94:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.150.199.48:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.150.199.48:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOlazyfilewalker.trash-cleanup-filewalkersubprocess started{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZINFOlazyfilewalker.trash-cleanup-filewalkersubprocess exited with status{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "status": -1, "error": "signal: killed"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORpieces:trashemptying trash failed{"Process": "storagenode", "error": "pieces error: lazyfilewalker: signal: killed", "errorVerbose": "pieces error: lazyfilewalker: signal: killed\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*process).run:85\n\tstorj.io/storj/storagenode/pieces/lazyfilewalker.(*Supervisor).WalkCleanupTrash:196\n\tstorj.io/storj/storagenode/pieces.(*Store).EmptyTrash:447\n\tstorj.io/storj/storagenode/pieces.(*TrashChore).Run.func1.1:84\n\tstorj.io/common/sync2.(*Workplace).Start.func1:89"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORpiecestore:cacheerror persisting cache totals to the database: {"Process": "storagenode", "error": "piece space used: context canceled", "errorVerbose": "piece space used: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*pieceSpaceUsedDB).UpdatePieceTotalsForSatellite:174\n\tstorj.io/storj/storagenode/storagenodedb.(*pieceSpaceUsedDB).UpdatePieceTotalsForAllSatellites:159\n\tstorj.io/storj/storagenode/pieces.(*CacheService).PersistCacheTotals:140\n\tstorj.io/storj/storagenode/pieces.(*CacheService).Run.func1:108\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:05 2024-10-17T05:20:05ZERRORgracefulexit:choreerror retrieving satellites.{"Process": "storagenode", "error": "satellitesdb: context canceled", "errorVerbose": "satellitesdb: context canceled\n\tstorj.io/storj/storagenode/storagenodedb.(*satellitesDB).ListGracefulExits.func1:200\n\tstorj.io/storj/storagenode/storagenodedb.(*satellitesDB).ListGracefulExits:212\n\tstorj.io/storj/storagenode/gracefulexit.(*Service).ListPendingExits:59\n\tstorj.io/storj/storagenode/gracefulexit.(*Chore).AddMissing:55\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/gracefulexit.(*Chore).Run:48\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2.1:87\n\truntime/pprof.Do:51\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2:86\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:07 2024-10-17T05:20:07ZERRORfailure during run{"Process": "storagenode", "error": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)", "errorVerbose": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1.1:159\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1:140\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:07 Error: piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)
2024-10-17 08:20:07 2024-10-17 05:20:07,195 WARN exited: storagenode (exit status 1; not expected)
2024-10-17 08:20:08 2024-10-17 05:20:08,198 INFO spawned: 'storagenode' with pid 108
2024-10-17 08:20:08 2024-10-17 05:20:08,198 WARN received SIGQUIT indicating exit request
2024-10-17 08:20:08 2024-10-17 05:20:08,198 INFO waiting for processes-exit-eventlistener, storagenode, storagenode-updater to die
2024-10-17 08:20:08 2024-10-17T05:20:08ZINFOGot a signal from the OS: "terminated"{"Process": "storagenode-updater"}
2024-10-17 08:20:08 2024-10-17 05:20:08,200 INFO stopped: storagenode-updater (exit status 0)
2024-10-17 08:20:08 2024-10-17 05:20:08,200 WARN stopped: storagenode (terminated by SIGTERM)
2024-10-17 08:20:08 2024-10-17 05:20:08,200 WARN stopped: processes-exit-eventlistener (terminated by SIGTERM)
2024-10-17 08:20:10 2024-10-17 05:20:10,351 INFO Set uid to user 0 succeeded
2024-10-17 08:20:10 2024-10-17 05:20:10,353 INFO RPC interface 'supervisor' initialized
2024-10-17 08:20:10 2024-10-17 05:20:10,353 INFO supervisord started with pid 1
2024-10-17 08:20:11 2024-10-17 05:20:11,355 INFO spawned: 'processes-exit-eventlistener' with pid 53
2024-10-17 08:20:11 2024-10-17 05:20:11,357 INFO spawned: 'storagenode' with pid 54
2024-10-17 08:20:11 2024-10-17 05:20:11,358 INFO spawned: 'storagenode-updater' with pid 55
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOConfiguration loaded{"Process": "storagenode-updater", "Location": "/app/config/config.yaml"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "storage.allocated-bandwidth"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.wallet"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "contact.external-address"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.email"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "storage.allocated-disk-space"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "operator.wallet-features"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "console.address"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "healthcheck.details"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "healthcheck.enabled"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "server.private-address"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOInvalid configuration file key{"Process": "storagenode-updater", "Key": "server.address"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOAnonymized tracing enabled{"Process": "storagenode-updater"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFORunning on version{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFODownloading versions.{"Process": "storagenode-updater", "Server Address": "https://version.storj.io"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOConfiguration loaded{"Process": "storagenode", "Location": "/app/config/config.yaml"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOAnonymized tracing enabled{"Process": "storagenode"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOOperator email{"Process": "storagenode", "Address": "x@gmail.com"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOOperator wallet{"Process": "storagenode", "Address": "0x"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOserverkernel support for server-side tcp fast open remains disabled.{"Process": "storagenode"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOserverenable with: sysctl -w net.ipv4.tcp_fastopen=3{"Process": "storagenode"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOCurrent binary version{"Process": "storagenode-updater", "Service": "storagenode", "Version": "v1.113.2"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFONew version is being rolled out but hasn't made it to this node yet{"Process": "storagenode-updater", "Service": "storagenode"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFOCurrent binary version{"Process": "storagenode-updater", "Service": "storagenode-updater", "Version": "v1.113.2"}
2024-10-17 08:20:11 2024-10-17T05:20:11ZINFONew version is being rolled out but hasn't made it to this node yet{"Process": "storagenode-updater", "Service": "storagenode-updater"}
2024-10-17 08:20:12 2024-10-17T05:20:12ZINFOTelemetry enabled{"Process": "storagenode", "instance ID": "12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5"}
2024-10-17 08:20:12 2024-10-17T05:20:12ZINFOEvent collection enabled{"Process": "storagenode", "instance ID": "12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5"}
2024-10-17 08:20:13 2024-10-17T05:20:13ZINFOdb.migrationDatabase Version{"Process": "storagenode", "version": 61}
2024-10-17 08:20:13 2024-10-17 05:20:13,083 INFO success: processes-exit-eventlistener entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:13 2024-10-17 05:20:13,083 INFO success: storagenode entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:13 2024-10-17 05:20:13,083 INFO success: storagenode-updater entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2024-10-17 08:20:14 2024-10-17T05:20:14ZINFOpreflight:localtimestart checking local system clock with trusted satellites' system clock.{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOpreflight:localtimelocal system clock is in sync with trusted satellites' system clock.{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFONode 12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5 started{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOcollectorexpired pieces collection started{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOPublic server started on [::]:28967{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOPrivate server started on 127.0.0.1:7778{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOfailed to sufficiently increase receive buffer size (was: 208 kiB, wanted: 2048 kiB, got: 416 kiB). See https://github.com/quic-go/quic-go/wiki/UDP-Buffer-Sizes for details.{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOtrustScheduling next refresh{"Process": "storagenode", "after": "6h33m44.690958189s"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFObandwidthPersisting bandwidth usage cache to db{"Process": "storagenode"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOpieces:trashemptying trash started{"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOlazyfilewalker.trash-cleanup-filewalkerstarting subprocess{"Process": "storagenode", "satelliteID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORservicesunexpected shutdown of a runner{"Process": "storagenode", "name": "piecestore:monitor", "error": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)", "errorVerbose": "piecestore monitor: error verifying location and/or readability of storage directory: node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node's ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1.1:159\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/monitor.(*Service).Run.func1:140\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORnodestats:cacheGet pricing-model/join date failed{"Process": "storagenode", "error": "context canceled"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.126.92.94:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.126.92.94:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.159.134.91:7777: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp 34.159.134.91:7777: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORversionfailed 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\tstorj.io/storj/storagenode/version.(*Chore).checkVersion:115\n\tstorj.io/storj/storagenode/version.(*Chore).RunOnce:71\n\tstorj.io/common/sync2.(*Cycle).Run:99\n\tstorj.io/storj/storagenode/version.(*Chore).Run:64\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2.1:87\n\truntime/pprof.Do:51\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2:86\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:78"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZERRORcontact:serviceping satellite failed {"Process": "storagenode", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 1, "error": "ping satellite: rpc: tcp connector failed: rpc: dial tcp: lookup saltlake.tardigrade.io: operation was canceled", "errorVerbose": "ping satellite: rpc: tcp connector failed: rpc: dial tcp: lookup saltlake.tardigrade.io: operation was canceled\n\tstorj.io/common/rpc.HybridConnector.DialContext.func1:190"}
2024-10-17 08:20:15 2024-10-17T05:20:15ZINFOcontact:servicecontext cancelled{"Process": "storagenode", "Satellite ID": 

your logs are mangled. can you post them unmodified?

But you can read the logs yourself too, you don’t really need me to copy paste stuff from your logs.

You are using old data with new node.

node ID in file (14B2kuyrk6jv6d2yCq1hYcgFRDazjbZ7w3eUiNdXoLWq1mgzZr) does not match running node’s ID (12eg9zaUHQCC4FsMjg42Z1G6rL1L8GJ8rptruaPSZGfVrJZj4v5)",

Delete all data, delete all identities, nuke everything, and then follow Sign up and host a Node on Storj - Storj Docs verbatim, to setup node from scratch. Don’t re-use anything.

2 Likes

Oh fudge, yeah I didn’t clean the dirs. Will do all that. “BRB”…

There we go…
status_ok

And about the “But you can read the logs yourself too, you don’t really need me to copy paste stuff from your logs.”
U know, not everyone even though capable of reading - are aware of the innards of what’s happening here.

Plus. Having the node disqualified on all satellites - how am I supposed to know that’s indefinitely? Your nick, arrogantcat indeed compliments your style of communicating.

“Your identity is not signed”
->tls peer certificate verification: not signed by any CA in the whitelist
How am I supposed to know that refers to the identity, huh?

“You are using old data with new node.”
The error indeed is somewhat clear but definitely very unclear on what the mismatch is.

You being familiar with the project nowadays does not give you the right to feel superior for understanding the error messages you’ve been scouring through for a year or two now.

Thanks to you none the less! Much appreciated!

2 Likes

Hello @inity,
Welcome back!

The disqualification is permanent and not reversible. You may check the support portal for that:

It’s also possible to find here, on the forum about disqualification.
When the node is disqualified, there is no way back, the satellites will not trust this identity anymore. Thus it’s required to generate a new identity, sign it with a new authorization token and start with a clean storage.

When you generated a new identity, it’s mentioned in the documentation, you seems just skipped this step before. But again, you may search on the forum: Search results for 'tls peer certificate verification: not signed by any CA in the whitelist' - Storj Community Forum (official)
There are solutions almost for any case.

Good that you finally setup the node!

1 Like

Valid questions, point taken, but let me still address concerns one by one.

I’m not aware of innards either. I’m just another dude/gal like yourself.

When I embarked on a journey of trying to figure out the issue for you, I also had no clue what is wrong. I have never seen that failure before in my life. But I was convinced you cannot be the very first one who hits that bug, so I asked you for more full logs, then read them (with eyes) line by line until the first warnig/error. The same thing I would have done if I was solving any of my issues. (I have none, everything works, so to scratch the itch of solving puzzles I hang out here)

I found “not signed by any CA in the whitelist” in the blob of first failure log. I had no clue what that meant either. But I assumed you can’t be the first one who encountered it, so So I searched the forum, and found this comment by @Alexey

I copy-pasted the answer.

What if there was no forum post? I would have searched source on GitHub for that sentence. It would have been quite easy to figure out what failure results in that log message.

I’m using the same approach for everything. I like debugging and triaging (it’s my day job) but I"m also phenomenally lazy, and I don’t want to do the work that someone else has already done before. So I search error messages in forums, chats, slack, GitHub, etc. 99.34% of the time this yields the solution or significant progress. The remaining 0.66% are the new puzzles that I end up solving myself and loving every second of doing so.

A big part of it is, in fact, humility, nor arrogance: not thinking that I’m the first one to encounter a specific issue, or that behavior I’m seeing is a bug in the software, etc. Because in 99.34% of time it is not the case. And therefore solution is almost certainly a search away.

Just like with the previous question – forum search for “Is disqualification permanent?” yields:

It was not chosen arbitrarily :slight_smile: But I’m aware that in western world a lot of sugarcoating is required in normal communication, I’m working on making my rants more palatable, not everyone operates straight on facts, but I’m not putting too much effort into it. It’s a technical forum, I would have also preferred brief answers that show direction to handholding and sugarcoating myself.

That data is encrypted/sigend with node identity? It’s described in the whitepaper. So of course it’s obvious, but it requires reading the whitepaper in the first place.

I don’t feel superior, and I learn something new every day. I’m far from being familiar with storagenode software. What you sensed in my comments as superiority and arrogance is in fact mild annoyance that all of your questions could have been answered by forum searches. And answered much faster than typing the post and waiting for responses. To be clear – this is mild annoyance, and I did not have to repond “if it bothered me so much”, but I’m here to help, and I hope I did not just help but maybe showed a bit of approach.

This is not specific to storj or this forum. It’s a general attitudes towards asking questions.There is a good old writeup floating on the interwebs https://www.catb.org/esr/faqs/smart-questions.html on precisely that.

I have adopted that approach (before stumbling on that writeup) myself. It’s very powerful.

The idea is you start writing an email/post with questions about the problem you encountered. If you described the problem well, steps you took to solve it, what went wrong, and were you are stuck, your brain will be forced to arrange the thoughts in a coherent form to put them in writing, and while doing that you will have a lot of “hmm” and “aha” moments. Ultimately in 94% of cases you would end up not sending that e-mail, because you would have found a solution while writing it.

If you adopt this approach – you’ll find you almost never truly stuck – by the time you are finished typing that email/forum post/etc, you have understood the problem and found a solution, and the satisfaction of having solved the puzzle.

How could have this topic gone instead:
Start writing new post: “I see this error message” … hmmm what was the error message?.. found it! " something something ‘Not signed by any CA’“. “I have no idea what it means” …hmm… maybe I can find out. let me search that… Oh, it is probably because identity is not signed.
Delete last paragraph, write instead – I have signed identity and now see this issue about node id not matching data”… wait… Node id not matching data? Data must be from old node, dang it! Delete the data. Restart. all works. Delete the draft of the post without sending.

I hold myself to that standard, I feel embarrassed if I asked question that I could have found an answer on myself. And I expect the same standard from all participants in any technical discussions, be that here or at work. And if someone does not play by the same rules I feel that I have to do something to help that person become more effective and improve community – so that posts that do end up posted are actually interesting new problems. I want to solve problems, not google on fellow forum user’s behalf. At least this is my perspective.

Anyway, sorry for arrogance, long rants, and I’m glad we figured it out.

5 Likes

One of the biggest replys of @arrogantrabbit I’ve seen so far, maybe the biggest? :sweat_smile:
3 fingers scroll, wow! :grin:

And here I thought football fields is already a weird unit.

2 Likes

I did follow that approach, and got fairly far with it.
Scouring through related error messages on the forum feels like a waste of my time when there’s someone like you that was able to point the ERRORs of interest straight away again hastened my process of fixing the issue.
Not everything needs to be done on your own, when there’s more knowledgeable people around. That’s what forums are for.
I did my triaging, though neglected to go through the logs, that’s on me.
From my narrow view, I was not that far that it was necessary as my previous issues pointed to a network/firewall misconfiguration, not the node itself.

When I’m able to ask from a “specialist” straight away I don’t feel like it’s a good use of my time to scour through all related posts - I did do some, just not the log related errors.

But great points and well put together - appreciated.

2 Likes