Tonight was a Daylight Saving Time switch. I got a E-Mail about an hour ago that my node got suspended on asia-east-1. Since I just checked the dashboard yesterday I was wondering how so much audits could suddenly be failing.
What caught my eye was that the last contact is reported as being 60 minutes in the future. (Displays -60m ago)
Could my audits be failing due to incorrect time handling by storj?
Audits only seem to be failing on non EU servers - which further indicates that this is a DST issue?
Hi @robske110 and welcome to the forum!
The first thing to check would be your nodeās logs: error entries should give us an idea why scores are dropping.
Could you have a look and report back?
You can use triple backticks to paste your suspicious log entries in here (if any) so theyāre readable.
Example:
Running docker logs storagenode 2>&1 | grep -E "GET_AUDIT|GET_REPAIR" | grep failed yields ton of these:
2021-10-31T17:22:03.785Z ERROR piecestore download failed {"Piece ID": "Y63AO6TJVAW7OKTHKOHBJCIS3RYGR67EL4YGMPPN4YQSSN762JGA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_REPAIR", "error": "order created too long ago: OrderCreation 2021-10-31 16:22:03.633145513 +0000 UTC < SystemClock 2021-10-31 17:22:03.78556177 +0000 UTC m=+165445.791976920", "errorVerbose": "order created too long ago: OrderCreation 2021-10-31 16:22:03.633145513 +0000 UTC < SystemClock 2021-10-31 17:22:03.78556177 +0000 UTC m=+165445.791976920\n\tstorj.io/common/rpc/rpcstatus.Errorf:87\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:45\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:490\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:104\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:97\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2021-10-31T17:37:04.006Z ERROR piecestore download failed {"Piece ID": "H5IFJFOFLYEMIEFMUENWTJKQUYQY6FKKZNITMCI5EGN6QINRBULQ", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_REPAIR", "error": "order created too long ago: OrderCreation 2021-10-31 16:37:03.82264757 +0000 UTC < SystemClock 2021-10-31 17:37:04.006868936 +0000 UTC m=+166346.013284087", "errorVerbose": "order created too long ago: OrderCreation 2021-10-31 16:37:03.82264757 +0000 UTC < SystemClock 2021-10-31 17:37:04.006868936 +0000 UTC m=+166346.013284087\n\tstorj.io/common/rpc/rpcstatus.Errorf:87\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:45\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:490\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:104\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:97\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2021-10-31T18:13:16.735Z ERROR piecestore download failed {"Piece ID": "3YJQDETWGXNYKN63FSQ34XTNIBZOZ4GSALZWT4R3GJHV5WVTN5HA", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "error": "order created too long ago: OrderCreation 2021-10-31 17:13:15.764550026 +0000 UTC < SystemClock 2021-10-31 18:13:16.735026369 +0000 UTC m=+168518.741441511", "errorVerbose": "order created too long ago: OrderCreation 2021-10-31 17:13:15.764550026 +0000 UTC < SystemClock 2021-10-31 18:13:16.735026369 +0000 UTC m=+168518.741441511\n\tstorj.io/common/rpc/rpcstatus.Errorf:87\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:45\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:490\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:104\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:97\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2021-10-31T18:27:04.034Z ERROR piecestore download failed {"Piece ID": "WAADBJ7YCZISEALGDLKQRERJUAIOY5JSFRKPMEE47ODYGVIQJKMQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "error": "order created too long ago: OrderCreation 2021-10-31 17:27:03.350922039 +0000 UTC < SystemClock 2021-10-31 18:27:04.034182423 +0000 UTC m=+169346.040597572", "errorVerbose": "order created too long ago: OrderCreation 2021-10-31 17:27:03.350922039 +0000 UTC < SystemClock 2021-10-31 18:27:04.034182423 +0000 UTC m=+169346.040597572\n\tstorj.io/common/rpc/rpcstatus.Errorf:87\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:45\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:490\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:104\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:97\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
Since I restarted the server these errors do not pop up anymore. System clock was also correct before the restart though.
the storagenodes run on UTC this is a timezone and summer winter time agnostic, however i suppose it is possible for your local clock to affect your node.
the offset on the webdash board also happens when one sets a computer in standby and wakes it up later, this has nothing to do with the actual node time, but only when the webdash running on your website viewing device last had contact with the node, and some things offsets it.
not sure how fast one can earn a suspension, but its rarely instant if everā¦
if your suspension scores are going up again, i would suppose the problem is goneā¦
what exactly happened is difficult to sayā¦
sure it could be time adjustment from the summer winter switch, but i donāt think that actually changes anythingā¦ you will be on DST and then move to the DSTS (summer timezone) or such thus your clock will not be changed, only the modifier which is applied to it for your usages.
i would say the recent solar flare, a bad hdd cable or just random weirdness that computers sometimes have from running 24/7
but i seriously doubt that its related to time, also keep in mind time keeping has been a critical feature since the dawn of computing, so its pretty rock solid.
Is it a docker node? The docker node might not be aware of your timezone and when the host system screws up the clock than docker might get confused by that. Maybe check if there are any docker + timezone issues for your setup.
This happened to me today. My QNAP server was set to an ntp server but testing interval was set to 1-day instead of 1-hour. So when DST was reverted today the time on server didnāt get changed automatically soon enough resulting in account suspension. Iāve now corrected the time, restarted the whole server just in case and restarted docker. Half an hour later iāve got the email from storj that from one of the satellelites iāve been unsuspended (although it will take some time to imporve my red %s). Yay!
Hi Alexey,
Thank you!
It was the suspention score. Woke up to see couple of automated emails from satellites that the node has been suspended due to audit errors. Found this thread, realised the server time is different to PC/mobile time. Now all good, both suspensions were removed about an hour later and my scores are steadily improving!
Just to add, I had the same time issue here in New Zealandā¦
Daylight Savings changed over the weekend and for some odd reason the server did not automatically update the time. I woke up this morning to a pile of suspension āsuspended for returning errors in response to auditsā emails . Within 10 minutes of fixing the time, started getting āunsuspendedā emails.
MIght I suggest the Storj dashboard pops up a less scary error message if it detect the time is incorrect and can lead to suspension, I canāt imagine it is that difficult for Storj to detect.
One other thing to address is the log file size, over 2.5GB at the moment, and notepad++ canāt open itā¦ probably needs to be truncated on a weekly/ monthly basis
