Audit weirdness (us2 satellite). (Team aware. No additional information is needed)

Looks like I actually had a similar audit failure. There goes my clean record…

2021-03-16T17:36:26.016Z       INFO    piecestore      upload started  {"Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "PUT", "Available Space": 7858822696960}
2021-03-16T17:36:55.034Z       INFO    piecestore      uploaded        {"Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "PUT", "Size": 2319360}
2021-03-17T18:55:02.214Z       DEBUG   pieces  deleted piece   {"Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA"}
2021-03-17T18:55:02.214Z       INFO    collector       delete expired  {"Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA"}
2021-07-13T14:33:06.479Z       INFO    piecestore      download started        {"Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_AUDIT"}
2021-07-13T14:33:06.486Z       ERROR   piecestore      download failed {"Piece ID": "5TIL6XHVZDDBWQ34UHC72GQNO56BC4ZBS7EKTMLGAAE5X4ZV5EWA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_AUDIT", "error": "file does not exist", "errorVerbose": "file does not exist\n\tstorj.io/common/rpc/rpcstatus.Wrap:74\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:508\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:217\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:111\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:62\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:99\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51"}

Indeed as @Alexey mentioned it was an expired piece. Surprisingly, it was a LOOONG expired piece. Good thing I still have all my logs.

The failure happened a while ago and I guess I didn’t spot it at the time. My score already shows 100% again in the dashboard. But I noticed the API said "auditScore":0.9999995.

I wonder how this happened though, it must be something specific to this satellite or else it would have happened much more often. It is a testing satellite after all.

Same for my node. I was also able to retrace the audit failure to an expired piece in my logs. I am at 99.5% audit score right now. Let’s hope this was a one time occurrence.

if i was to hazard a guess… it almost looks like a test i mean why just one…
whatever happened here might be used maliciously… if one could DQ nodes for data that is long deleted.

also the error seems to still be permeating through the network… got another node that has just failed an audit since this morning… might look like it will end up going through all nodes beyond a certain age…

or i got two, but the one is the one i accidentally ran a rsync --delete on after running it for a minut… so might not be relevant.

Exactly same happened to me. I figured its the sattelite. Because i just installed a brand new HDD and transferred with 3 robocopies with /MIR the contents.

8 posts were merged into an existing topic: Audit scores dropping on ap1; Storj is working on a fix, SNO’s don’t need to do anything. ERROR piecedeleter could not send delete piece to trash >> Pieces error: v0pieceinfodb: sql: no rows in result set

A post was merged into an existing topic: Audit scores dropping on ap1; Storj is working on a fix, SNO’s don’t need to do anything. ERROR piecedeleter could not send delete piece to trash >> Pieces error: v0pieceinfodb: sql: no rows in result set

5 posts were merged into an existing topic: Audit scores dropping on ap1; Storj is working on a fix, SNO’s don’t need to do anything. ERROR piecedeleter could not send delete piece to trash >> Pieces error: v0pieceinfodb: sql: no rows in result set

same here yesterday for us1 and ap1

But is growing again.

1 Like

whatever the causes, this is bad… very bad…
seems to affect nodes around the 7-8 month mark the worst…
atleast with never having a failed audit before then, my nodes are pretty well positioned to survive.
this might get worse before it gets better

I am now seriously wondering what happens if Nodes is disqualified because of this error?

How does Storj intend to compensate the node operator? We SNOs are obviously not responsible for this…

My audit grew again overnight, but is now falling further.
This happens on several nodes, so I can rule out problems on the node side.

This a storj network software issue, most likely related to the latest update…
so if anyone is on the old version lets hear if you are seeing this…

also tried apt upgrade my container and a cold reboot of the container… but no joy.

@LinuxNet i will most likely shutdown my nodes if it comes to that, the 80% one is a prime candidate for it…
but i rather want to avoid that… but it should keep the node safe… since we have 12 days of allowed downtime until suspension… not great for the network…

but i can only assume that DQ means DQ since it has done so in the past… sure this is a wider issue, but people have lost nodes for no reason of their own… so cannot really assume a DQ will just get fixed.

Let’s also try to keep misleading info to a minimum. I believe you said elsewhere that the audit score drops on other satellites had to do with a migration you did. As of now I don’t have any reason to think the delete issue is wider spread than ap1. Please look up logs for other satellites if you think they’re having the same issue. Also, this topic was originally about a different issue on us2. For the issues with ap1 deletes, best to stick to this topic to keep everything in one place.

1 Like

yeah thats right, i haven’t gotten around to correcting it… remembered after i had written it here.
deleted it for simplicity sake.

1 Like

Started approx 7/22 15:40

A post was merged into an existing topic: Audit falling on eu1

Have this issue on some of my nodes. AP1 and US2 are affected. Saving log files on all nodes now.
In some cases I wasn’t able to see any deletes in logs, but I refuse to believe it’s a coincidence.

1 Like

A post was merged into an existing topic: Audit falling on eu1

I might have a related problem on us2 also.

hehe i think we can call this confirmed lol pretty spot on for this node…

one piece seems to be this one

2021-07-24T09:02:48.922Z INFO piecestore download started {"Piece ID": "TMH2O4Q2YG7CQFWFTWDY7C5SMZCVUCKEICW53XI47XXIO2RKH5LA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_AUDIT"}

can’t find anything else in my logs about this piece, but they only go back to the 16th and my logging export got overloaded when we got the massive delete failures the last little while.
so they are also full of holes

2021-07-24T09:02:48.937Z ERROR piecestore download failed {"Piece ID": "TMH2O4Q2YG7CQFWFTWDY7C5SMZCVUCKEICW53XI47XXIO2RKH5LA", "Satellite ID": "12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo", "Action": "GET_AUDIT", "error": "file does not exist", "errorVerbose": "file does not exist\n\tstorj.io/common/rpc/rpcstatus.Wrap:73\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:534\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:217\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:102\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:95\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51"}

this is weird tho… i cannot seem to find the log entry about the recent audit failure on ap1…

still seeing unexpected audit failures today on us2, but still quite rare…
just wanted to mention it, as i’m unaware if this issue was assumed fixed…

2021-07-26T11:17:54.655Z ERROR piecestore download failed {“Piece ID”: “YHPWJD5XNXXMYLCSIKSE557UOZT5PNMVMRMVKZYFNWGGQQJG7MXA”, “Satellite ID”: “12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo”, “Action”: “GET_AUDIT”, “error”: “file does not exist”, “errorVerbose”: “file does not exist\n\tstorj.io/common/rpc/rpcstatus.Wrap:73\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:534\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:217\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:102\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:95\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51”}

and

2021-07-26T11:17:54.818Z ERROR piecestore download failed {“Piece ID”: “CY5Z3ID3VLJ4U6ANAWO336ZHXJAPFKIE4H2JCDUXGR6B3SSG3OZQ”, “Satellite ID”: “12tRQrMTWUWwzwGh18i7Fqs67kmdhH9t6aToeiwbo5mfS2rUmo”, “Action”: “GET_AUDIT”, “error”: “file does not exist”, “errorVerbose”: “file does not exist\n\tstorj.io/common/rpc/rpcstatus.Wrap:73\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:534\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:217\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:33\n\tstorj.io/common/rpc/rpctracing.(*Handler).HandleRPC:58\n\tstorj.io/drpc/drpcserver.(*Server).handleRPC:102\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:60\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:95\n\tstorj.io/drpc/drpcctx.(*Tracker).track:51”}

incase of timestamps would help…