Warning and error logs since updating to latest releasse

Hello all. I’ve gotten the following errors since updating to the latest Storj release about an hour ago.

2021-05-05T03:02:50.454Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:02:50.779Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:02:50.863Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:02:51.082Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:02:51.184Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:03:04.000Z        ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 1, "error": "ping satellite error: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838: rpc: context deadline exceeded", "errorVerbose": "ping satellite error: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838: rpc: context deadline exceeded\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:141\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:03:15.792Z        ERROR   nodestats:cache Get pricing-model/join date failed     {"error": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).dial:231\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).GetAllPaystubs:106\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run.func1:81\n\tstorj.io/storj/storagenode/nodestats.(*Cache).satelliteLoop:261\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run:80\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2.1:81\n\truntime/pprof.Do:40\n\tstorj.io/storj/private/lifecycle.(*Group).Run.func2:80\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:03:25.002Z        ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 2, "error": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/common/rpc.TCPConnector.DialContextUnencrypted:107\n\tstorj.io/common/rpc.TCPConnector.DialContext:71\n\tstorj.io/common/rpc.Dialer.dialEncryptedConn:186\n\tstorj.io/common/rpc.Dialer.DialNodeURL.func1:107\n\tstorj.io/common/rpc/rpcpool.(*Pool).get:90\n\tstorj.io/common/rpc/rpcpool.(*Pool).Get:110\n\tstorj.io/common/rpc.Dialer.dialPool:152\n\tstorj.io/common/rpc.Dialer.DialNodeURL:106\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:124\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:03:47.003Z        ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 3, "error": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/common/rpc.TCPConnector.DialContextUnencrypted:107\n\tstorj.io/common/rpc.TCPConnector.DialContext:71\n\tstorj.io/common/rpc.Dialer.dialEncryptedConn:186\n\tstorj.io/common/rpc.Dialer.DialNodeURL.func1:107\n\tstorj.io/common/rpc/rpcpool.(*Pool).get:90\n\tstorj.io/common/rpc/rpcpool.(*Pool).Get:110\n\tstorj.io/common/rpc.Dialer.dialPool:152\n\tstorj.io/common/rpc.Dialer.DialNodeURL:106\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:124\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:04:11.004Z        ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 4, "error": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/common/rpc.TCPConnector.DialContextUnencrypted:107\n\tstorj.io/common/rpc.TCPConnector.DialContext:71\n\tstorj.io/common/rpc.Dialer.dialEncryptedConn:186\n\tstorj.io/common/rpc.Dialer.DialNodeURL.func1:107\n\tstorj.io/common/rpc/rpcpool.(*Pool).get:90\n\tstorj.io/common/rpc/rpcpool.(*Pool).Get:110\n\tstorj.io/common/rpc.Dialer.dialPool:152\n\tstorj.io/common/rpc.Dialer.DialNodeURL:106\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:124\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:04:39.006Z        ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 5, "error": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "ping satellite error: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/common/rpc.TCPConnector.DialContextUnencrypted:107\n\tstorj.io/common/rpc.TCPConnector.DialContext:71\n\tstorj.io/common/rpc.Dialer.dialEncryptedConn:186\n\tstorj.io/common/rpc.Dialer.DialNodeURL.func1:107\n\tstorj.io/common/rpc/rpcpool.(*Pool).get:90\n\tstorj.io/common/rpc/rpcpool.(*Pool).Get:110\n\tstorj.io/common/rpc.Dialer.dialPool:152\n\tstorj.io/common/rpc.Dialer.DialNodeURL:106\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:124\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:05:02.358Z        WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity"}
2021-05-05T03:06:36.889Z        ERROR   nodestats:cache payouts err     {"satellite": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2021-05-05T03:06:39.597Z        ERROR   nodestats:cache Get held amount query failed    {"error": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).dial:231\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).GetPaystub:56\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheHeldAmount.func1:204\n\tstorj.io/storj/storagenode/nodestats.(*Cache).satelliteLoop:261\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheHeldAmount:196\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run.func3:137\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:07:27.714Z        ERROR   nodestats:cache Get stats query failed  {"error": "node stats service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "node stats service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/storj/storagenode/nodestats.(*Service).dial:155\n\tstorj.io/storj/storagenode/nodestats.(*Service).GetReputationStats:66\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheReputationStats.func1:154\n\tstorj.io/storj/storagenode/nodestats.(*Cache).satelliteLoop:261\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheReputationStats:153\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run.func2:120\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

I’m still getting traffic to my node though majority of it is coming from the Saltlake satellite. Is the warning and error logs something I should address? Or are those logs normal and there’s nothing I should be worried about?

1 Like

Breaking down the errors:

WARN    contact:service Your node is still considered to be online but encountered an error.    {"Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Error": "contact: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838 using QUIC: rpc: quic error: Timeout: No recent network activity

These relate to UDP port forwarding testing - Experimenting with UDP based protocols. There’s no need to ‘fix’ yet as this is just for testing but may be requested in the future.


ERROR   contact:service ping satellite failed   {"Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "attempts": 1, "error": "ping satellite error: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838: rpc: context deadline exceeded", "errorVerbose": "ping satellite error: failed to dial storage node (ID: 1XtserY2gWe4q8TafVMsa5bLSnZcncY4EDMqBagqpYigRy4FEF) at address carovonoliver-49838.portmap.host:49838: rpc: context deadline exceeded\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatelliteOnce:141\n\tstorj.io/storj/storagenode/contact.(*Service).pingSatellite:95\n\tstorj.io/storj/storagenode/contact.(*Chore).updateCycles.func1:87\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

This suggests the DDNS/portmap name resolution had a blip. It was only the first attempt, so nothing to be too worried about. It could also be related the satellite outage mentioned below.


2021-05-05T03:06:36.889Z        ERROR   nodestats:cache payouts err     {"satellite": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE"}
2021-05-05T03:06:39.597Z        ERROR   nodestats:cache Get held amount query failed    {"error": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "payouts service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).dial:231\n\tstorj.io/storj/storagenode/payouts.(*Endpoint).GetPaystub:56\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheHeldAmount.func1:204\n\tstorj.io/storj/storagenode/nodestats.(*Cache).satelliteLoop:261\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheHeldAmount:196\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run.func3:137\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}
2021-05-05T03:07:27.714Z        ERROR   nodestats:cache Get stats query failed  {"error": "node stats service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout", "errorVerbose": "node stats service error: unable to connect to the satellite 1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE: rpc: dial tcp 35.236.51.151:7777: i/o timeout\n\tstorj.io/storj/storagenode/nodestats.(*Service).dial:155\n\tstorj.io/storj/storagenode/nodestats.(*Service).GetReputationStats:66\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheReputationStats.func1:154\n\tstorj.io/storj/storagenode/nodestats.(*Cache).satelliteLoop:261\n\tstorj.io/storj/storagenode/nodestats.(*Cache).CacheReputationStats:153\n\tstorj.io/storj/storagenode/nodestats.(*Cache).Run.func2:120\n\tstorj.io/common/sync2.(*Cycle).Run:92\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57"}

I haven’t seen these errors before but it looks to coincide with an outage for the saltlake satellite (http://storjnet.info/):

image

3 Likes

Thanks! Since it’s been a full 24 hours and my node is still working fine I think it’s safe to assume that the node doesn’t have any issues.