checked again this morning. 94 deleted failed
1 Like
Devs are looking in to this bug and a fix would be on the way soon ™
Do check if your have failed audits for pieces that were already deleted as @Pentium100 posted. If you do, do post a screenshot of the log so devs can look in to it too.
I have 3 failed audits but no proof of pieces being deleted since my logs don’t go far. I am thinking of filing a ticket.
Thanks for the tip. I Will do that
1 Like
subwolf@localhost:~/storjnet-info$ sudo docker logs storagenode 2>&1 | grep "delete failed" -c
79
subwolf@localhost:~/storjnet-info$ sudo docker logs storagenode 2>&1 | grep "file does not exist" | grep "GET_AUDIT" -c
2
Examples after running sudo docker logs storagenode 2>&1 | grep "delete failed" and picking some random piece id’s:
subwolf@localhost:~$ sudo docker logs storagenode 2>&1 | grep "Q5DD3HXRF3XTU5YX3AACXO5NQAFKXLME7PAO2XTP7GBJ4D4CA2ZA"
2019-09-21T06:45:37.410Z INFO piecestore deleted {"Piece ID": "Q5DD3HXRF3XTU5YX3AACXO5NQAFKXLME7PAO2XTP7GBJ4D4CA2ZA"}
2019-09-21T07:35:10.171Z ERROR piecestore delete failed {"Piece ID": "Q5DD3HXRF3XTU5YX3AACXO5NQAFKXLME7PAO2XTP7GBJ4D4CA2ZA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storage/filestore.(*Store).Stat:80\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).Delete:170\n\tstorj.io/storj/storagenode/pieces.(*Store).Delete:257\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Delete:136\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler.func1:1134\n\tstorj.io/storj/pkg/server.(*Server).logOnErrorUnaryInterceptor:38\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler:1136\n\tgoogle.golang.org/grpc.(*Server).processUnaryRPC:940\n\tgoogle.golang.org/grpc.(*Server).handleStream:1174\n\tgoogle.golang.org/grpc.(*Server).serveStreams.func1.1:696"}
subwolf@localhost:~$ sudo docker logs storagenode 2>&1 | grep "4MBRBOJRWOMHCRQNUCORPM5BZ5HAPWN35KO3YUXAH65IL4PNKEUA"
2019-09-21T06:38:57.866Z INFO piecestore deleted {"Piece ID": "4MBRBOJRWOMHCRQNUCORPM5BZ5HAPWN35KO3YUXAH65IL4PNKEUA"}
2019-09-21T07:34:56.395Z ERROR piecestore delete failed {"Piece ID": "4MBRBOJRWOMHCRQNUCORPM5BZ5HAPWN35KO3YUXAH65IL4PNKEUA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storage/filestore.(*Store).Stat:80\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).Delete:170\n\tstorj.io/storj/storagenode/pieces.(*Store).Delete:257\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Delete:136\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler.func1:1134\n\tstorj.io/storj/pkg/server.(*Server).logOnErrorUnaryInterceptor:38\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler:1136\n\tgoogle.golang.org/grpc.(*Server).processUnaryRPC:940\n\tgoogle.golang.org/grpc.(*Server).handleStream:1174\n\tgoogle.golang.org/grpc.(*Server).serveStreams.func1.1:696"}
2019-09-21T07:54:52.283Z ERROR piecestore delete failed {"Piece ID": "4MBRBOJRWOMHCRQNUCORPM5BZ5HAPWN35KO3YUXAH65IL4PNKEUA", "error": "pieces error: filestore error: file does not exist", "errorVerbose": "pieces error: filestore error: file does not exist\n\tstorj.io/storj/storage/filestore.(*Store).Stat:80\n\tstorj.io/storj/storagenode/pieces.(*BlobsUsageCache).Delete:170\n\tstorj.io/storj/storagenode/pieces.(*Store).Delete:257\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Delete:136\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler.func1:1134\n\tstorj.io/storj/pkg/server.(*Server).logOnErrorUnaryInterceptor:38\n\tstorj.io/storj/pkg/pb._Piecestore_Delete_Handler:1136\n\tgoogle.golang.org/grpc.(*Server).processUnaryRPC:940\n\tgoogle.golang.org/grpc.(*Server).handleStream:1174\n\tgoogle.golang.org/grpc.(*Server).serveStreams.func1.1:696"}
Maybe deletions need to include the satellite ID in case multiple satellites are attempting to delete pieces.
subwolf@localhost:~$ sudo docker logs storagenode 2>&1 | grep "file does not exist" | grep "GET_AUDIT"
2019-09-21T12:40:42.067Z INFO piecestore download failed {"Piece ID": "X6YWBSNU4PWF4GDDIOS2LNLUXDT34LCJ3LGW2TXNHROIN2PRS2EQ", "SatelliteID": "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW", "Action": "GET_AUDIT", "error": "rpc error: code = NotFound desc = file does not exist"}
2019-09-22T08:06:51.928Z INFO piecestore download failed {"Piece ID": "CLXWK55G2YDP5XDBOZXBUFDDCDLKEZQ6D7HR7HQEQPM7VZIOAHQA", "SatelliteID": "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW", "Action": "GET_AUDIT", "error": "rpc error: code = NotFound desc = file does not exist"}
subwolf@localhost:~$ sudo docker logs storagenode 2>&1 | grep "X6YWBSNU4PWF4GDDIOS2LNLUXDT34LCJ3LGW2TXNHROIN2PRS2EQ"
2019-09-21T09:47:25.228Z INFO piecestore deleted {"Piece ID": "X6YWBSNU4PWF4GDDIOS2LNLUXDT34LCJ3LGW2TXNHROIN2PRS2EQ"}
2019-09-21T12:40:42.039Z INFO piecestore download started {"Piece ID": "X6YWBSNU4PWF4GDDIOS2LNLUXDT34LCJ3LGW2TXNHROIN2PRS2EQ", "SatelliteID": "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW", "Action": "GET_AUDIT"}
2019-09-21T12:40:42.067Z INFO piecestore download failed {"Piece ID": "X6YWBSNU4PWF4GDDIOS2LNLUXDT34LCJ3LGW2TXNHROIN2PRS2EQ", "SatelliteID": "118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW", "Action": "GET_AUDIT", "error": "rpc error: code = NotFound desc = file does not exist"}
1 Like
Good news:
I was able to reproduce it in storj-sim. My local test storage nodes are producing failed audits now. We are working on a fix and meanwhile have stopped our delete scripts. I am not sure how fast we can roll out the fix because most of the team is in flight at the moment.
5 Likes
Hopefully flying back and not away!
Same issue:
1 Like
…