"GET_REPAIR”, “error”: “used serial already exists in store”

[mus6677]

Not just one occurence. Multiple log from this error, I checked log from last 3 4 days i think got hundreds of this error

[thepaul]

This should be fixed. If anyone is still seeing this error after this point, please let us know.

[deathlessdd]

Fixed you say is this the same error or a different issue?

> 2022-04-20T10:09:59.378Z        ERROR   piecestore      download failed {"Piece ID": "XMCZQAUZKTQ566U6OR4BUYQBXSDVDFHWFJ4QGAPVVGJ4M5O3SJPQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "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:546\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
> 2022-04-20T10:09:59.856Z        INFO    piecestore      download started        {"Piece ID": "XMCZQAUZKTQ566U6OR4BUYQBXSDVDFHWFJ4QGAPVVGJ4M5O3SJPQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
> 2022-04-20T10:09:59.857Z        ERROR   piecestore      download failed {"Piece ID": "XMCZQAUZKTQ566U6OR4BUYQBXSDVDFHWFJ4QGAPVVGJ4M5O3SJPQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

[nerdatwork]

GET REPAIR errors showing up on storage nodes

Fix should be in the satellite v1.53 release.

We are still in 1.52.2

[deathlessdd]

Ok then I miss understood cause it sounded like it was a satellite issue not a storagenode issue.

[RJGSpace]

my node get same issue …

[thepaul]

That looks like the same issue to me. Darn, there must be another potential cause we haven’t found yet.

@nerdatwork

We are still in 1.52.2

I’ve been told all the satellites are upgraded to 1.53.1. I don’t know enough of our ops setup to know how to tell for sure, but I think it’s accurate.

@deathlessdd

Ok then I miss understood cause it sounded like it was a satellite issue not a storagenode issue.

The bug we found and the fix we applied were on the satellite side, yeah. But I suppose there’s still room for something to be wrong on the node side as well.

It may be helpful to see logs from everyone who still sees this error (please include any other lines dealing with the same pieceID as the one on the error line).

[baker]

I’ve got a few here for you:

From my first node

2022-04-20T18:16:49.141Z        INFO    piecestore      download started        {"Piece ID": "YH4XQJ7ZRGTMQ4JFUJ6VRQX4YM3VDOUDKSF6QLBM446HLPAROX3A", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-20T18:18:12.265Z        ERROR   piecestore      download failed {"Piece ID": "YH4XQJ7ZRGTMQ4JFUJ6VRQX4YM3VDOUDKSF6QLBM446HLPAROX3A", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "write tcp 172.17.0.4:28967->116.203.195.108:48004: write: connection timed out", "errorVerbose": "write tcp 172.17.0.4:28967->116.203.195.108:48004: write: connection timed out\n\tstorj.io/drpc/drpcstream.(*Stream).rawWriteLocked:322\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:400\n\tstorj.io/common/pb.(*drpcPiecestore_DownloadStream).Send:317\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func5.1:620\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22"}
2022-04-20T18:18:16.962Z        INFO    piecestore      download started        {"Piece ID": "YH4XQJ7ZRGTMQ4JFUJ6VRQX4YM3VDOUDKSF6QLBM446HLPAROX3A", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-20T18:18:16.963Z        ERROR   piecestore      download failed {"Piece ID": "YH4XQJ7ZRGTMQ4JFUJ6VRQX4YM3VDOUDKSF6QLBM446HLPAROX3A", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

2022-04-21T04:40:35.326Z        INFO    piecestore      download started        {"Piece ID": "I4AEZRDLE3DYMYFZUS6N3ZVY53YSJAHGMXXGS3KJ72MDPTU2UMZQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR"}
2022-04-21T04:41:55.498Z        INFO    piecestore      downloaded      {"Piece ID": "I4AEZRDLE3DYMYFZUS6N3ZVY53YSJAHGMXXGS3KJ72MDPTU2UMZQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR"}
2022-04-21T04:41:58.174Z        INFO    piecestore      download started        {"Piece ID": "I4AEZRDLE3DYMYFZUS6N3ZVY53YSJAHGMXXGS3KJ72MDPTU2UMZQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR"}
2022-04-21T04:41:58.176Z        ERROR   piecestore      download failed {"Piece ID": "I4AEZRDLE3DYMYFZUS6N3ZVY53YSJAHGMXXGS3KJ72MDPTU2UMZQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

2022-04-21T04:57:56.335Z        INFO    piecestore      download started        {"Piece ID": "ZLOQZCJO2B3SLGGDBP26WX7KTGN3NPE7GBBZSCJUGSCJCAVFXH6A", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET_REPAIR"}
2022-04-21T04:58:58.859Z        ERROR   piecestore      download failed {"Piece ID": "ZLOQZCJO2B3SLGGDBP26WX7KTGN3NPE7GBBZSCJUGSCJCAVFXH6A", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET_REPAIR", "error": "write tcp 172.17.0.4:28967->5.161.74.40:37596: write: connection timed out", "errorVerbose": "write tcp 172.17.0.4:28967->5.161.74.40:37596: write: connection timed out\n\tstorj.io/drpc/drpcstream.(*Stream).rawWriteLocked:322\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:400\n\tstorj.io/common/pb.(*drpcPiecestore_DownloadStream).Send:317\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func5.1:620\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22"}
2022-04-21T04:59:55.686Z        INFO    piecestore      download started        {"Piece ID": "ZLOQZCJO2B3SLGGDBP26WX7KTGN3NPE7GBBZSCJUGSCJCAVFXH6A", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET_REPAIR"}
2022-04-21T04:59:55.688Z        ERROR   piecestore      download failed {"Piece ID": "ZLOQZCJO2B3SLGGDBP26WX7KTGN3NPE7GBBZSCJUGSCJCAVFXH6A", "Satellite ID": "12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

2022-04-21T05:28:47.828Z        INFO    piecestore      download started        {"Piece ID": "ZT4IYRNI44RJRAQQRETIDCUERH65V5KMG7PQAEGHRF25GGMUSZJA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR"}
2022-04-21T05:30:11.496Z        ERROR   piecestore      download failed {"Piece ID": "ZT4IYRNI44RJRAQQRETIDCUERH65V5KMG7PQAEGHRF25GGMUSZJA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "write tcp 172.17.0.4:28967->157.90.17.108:51236: write: connection timed out", "errorVerbose": "write tcp 172.17.0.4:28967->157.90.17.108:51236: write: connection timed out\n\tstorj.io/drpc/drpcstream.(*Stream).rawWriteLocked:322\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:400\n\tstorj.io/common/pb.(*drpcPiecestore_DownloadStream).Send:317\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func5.1:620\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22"}
2022-04-21T05:30:13.747Z        INFO    piecestore      download started        {"Piece ID": "ZT4IYRNI44RJRAQQRETIDCUERH65V5KMG7PQAEGHRF25GGMUSZJA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR"}
2022-04-21T05:30:13.748Z        ERROR   piecestore      download failed {"Piece ID": "ZT4IYRNI44RJRAQQRETIDCUERH65V5KMG7PQAEGHRF25GGMUSZJA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

From my second node

2022-04-20T19:27:23.385Z        INFO    piecestore      download started        {"Piece ID": "FBMYHTM5XVNRUKZQVROVIQWTLEZG5CNG7PF7BRXIXL625QTPZK4A", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-04-20T19:29:18.507Z        INFO    piecestore      download canceled       {"Piece ID": "FBMYHTM5XVNRUKZQVROVIQWTLEZG5CNG7PF7BRXIXL625QTPZK4A", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-04-20T19:29:21.403Z        INFO    piecestore      download started        {"Piece ID": "FBMYHTM5XVNRUKZQVROVIQWTLEZG5CNG7PF7BRXIXL625QTPZK4A", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-04-20T19:29:21.404Z        ERROR   piecestore      download failed {"Piece ID": "FBMYHTM5XVNRUKZQVROVIQWTLEZG5CNG7PF7BRXIXL625QTPZK4A", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

2022-04-20T22:30:08.202Z        INFO    piecestore      download started        {"Piece ID": "5YOUGAHFXQCSX27YRGPI25SAQCJC2XKE3MMROISOMB6W7A7CGRIA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-20T22:31:37.513Z        ERROR   piecestore      download failed {"Piece ID": "5YOUGAHFXQCSX27YRGPI25SAQCJC2XKE3MMROISOMB6W7A7CGRIA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "write tcp 172.17.0.3:28967->88.99.191.212:42180: write: connection timed out", "errorVerbose": "write tcp 172.17.0.3:28967->88.99.191.212:42180: write: connection timed out\n\tstorj.io/drpc/drpcstream.(*Stream).rawWriteLocked:322\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:400\n\tstorj.io/common/pb.(*drpcPiecestore_DownloadStream).Send:317\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func5.1:620\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22"}
2022-04-20T22:32:53.247Z        INFO    piecestore      download started        {"Piece ID": "5YOUGAHFXQCSX27YRGPI25SAQCJC2XKE3MMROISOMB6W7A7CGRIA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-20T22:32:53.249Z        ERROR   piecestore      download failed {"Piece ID": "5YOUGAHFXQCSX27YRGPI25SAQCJC2XKE3MMROISOMB6W7A7CGRIA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

2022-04-21T02:28:53.377Z        INFO    piecestore      download started        {"Piece ID": "NWF2GQOGEYLLJEHWDZMW6GXAIWXLOPSTXOJJ54DO7ISNO3W4GKRA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-21T02:30:16.618Z        ERROR   piecestore      download failed {"Piece ID": "NWF2GQOGEYLLJEHWDZMW6GXAIWXLOPSTXOJJ54DO7ISNO3W4GKRA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "write tcp 172.17.0.3:28967->94.130.179.74:34642: write: connection timed out", "errorVerbose": "write tcp 172.17.0.3:28967->94.130.179.74:34642: write: connection timed out\n\tstorj.io/drpc/drpcstream.(*Stream).rawWriteLocked:322\n\tstorj.io/drpc/drpcstream.(*Stream).MsgSend:400\n\tstorj.io/common/pb.(*drpcPiecestore_DownloadStream).Send:317\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func5.1:620\n\tstorj.io/common/rpc/rpctimeout.Run.func1:22"}
2022-04-21T02:30:20.528Z        INFO    piecestore      download started        {"Piece ID": "NWF2GQOGEYLLJEHWDZMW6GXAIWXLOPSTXOJJ54DO7ISNO3W4GKRA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR"}
2022-04-21T02:30:20.532Z        ERROR   piecestore      download failed {"Piece ID": "NWF2GQOGEYLLJEHWDZMW6GXAIWXLOPSTXOJJ54DO7ISNO3W4GKRA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

—edit—
Added three more errors from my first node

[SGC]

@thepaul

I’ve been told all the satellites are upgraded to 1.53.1. I don’t know enough of our ops setup to know how to tell for sure, but I think it’s accurate.

the first of my nodes also updated to 1.53.1 so yeah i would very much assume the satellites update their software before the nodes.

[Chris21788]

So this is still an issue. I have 5 nodes all on 1.53.1, and two of my nodes (both in different locations) are having suspensions.
The below is focused on my main node: 1765RRSLTetCWq9omHzemihN3GzAgXhgbNNxDJ77t6tj6ejxLF,

This node is suspended on 3 satellites:

• 121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6
• 12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs
• 12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB

Looking in the logs, I’m still seeing errors related to this issue:

Satellite 121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6:

2022-04-28T15:05:11.549-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "U5PTPG6PVU7ZX53OUI6ETCJUG2NP4UHTLXG6U5ZPINOWELJY72GQ", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T15:07:01.508-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "S4X3CFM6LKJIX4DJ7YDSK45M2OBAFLH2Q3JC35GUMBVYNBIT3BLA", "Satellite ID": "121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

Satellite 12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs:

2022-04-28T16:08:20.002-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "AH42O3T5FHCQ4Q5LD7SDTTFONUWNFWZJ2OY3HGSZTP4OL7J2P6XQ", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T16:08:35.299-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "HO5KVYHPFFW2HYJH2O64JHTKCMJEJ2UHN2SKI6NOGK4XYJBS6U4Q", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T16:08:42.946-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "DWGTZBXAWNEOZE2JMRFPUI6F7C3Y37XF7URONCIYKNBIRCDSNEGA", "Satellite ID": "12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

Satellite 12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB:

2022-04-28T16:06:26.044-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "QK6XTWVYTY7MDEN62U4GJS5PUFPMR6ZGDO3I6TCQ6THDAAMKGBIQ", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T16:06:26.692-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "Q3XCJPLTVH3ITBTJL5JPQFBFQLR6HN6JBS7HNFWHBWI3FMQLHDGQ", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T16:07:01.705-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "ZUXDOG6RYHZGJKZWSGSMTZ3LCRMKQYMWE6YHUXJJQ4JBI3UEFNHA", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}
2022-04-28T16:07:23.193-0400    ERROR   piecestore      download failed {"Process": "storagenode", "Piece ID": "OG6IMSNWHSQOYI76DRAJHQQLSJLCYY6ZPFRUV7YH2CL7JZ55K6HQ", "Satellite ID": "12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

Above are just to name a few of them. This particular node has been running 1.53.1 for ~57 hours.

Any help on this? I haven’t received any suspension emails this time around, and I don’t like having to keep checking the dashboards to see if I’m suspended.

This also isn’t an I/O issue or network issue for me. I’ve got 1GBps internet (and a 5% utilization), along with a multi-disk array with low I/O (and dedicated disks just to Storj).

[thepaul]

Yeah, it’s still an issue. Thanks for the extra logs, that may help. Right now I’m dealing with a somewhat urgent database performance problem that has popped up, but after that I can try to investigate this again, if no one else gets to it before me.

[Luis]

I have 9 nodes on different networks, 5 nodes with this problem.

All in the last 24 hours

2022-04-30T14:40:30.726+0100 ERROR piecestore download failed {“Piece ID”: “VM5JOJIINPNWTURZYTDG5WTEO63S4BCCNVTQAKD5N5VBMDHSSX2Q”, “Satellite ID”: “121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6”, “Action”: “GET_REPAIR”, “error”: “used serial already exists in store”, “errorVerbose”: “used serial already exists in store\n[tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table](http://tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table)).Add:117\n[tstorj.io/storj/storagenode/piecestore.(*Endpoint](http://tstorj.io/storj/storagenode/piecestore.(*Endpoint)).verifyOrderLimit:76\n[tstorj.io/storj/storagenode/piecestore.(*Endpoint](http://tstorj.io/storj/storagenode/piecestore.(*Endpoint)).Download:498\n[tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux](http://tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:228\n\tstorj.io/drpc/drpcmux.(*Mux)).HandleRPC:33\n[tstorj.io/common/rpc/rpctracing.(*Handler](http://tstorj.io/common/rpc/rpctracing.(*Handler)).HandleRPC:58\n[tstorj.io/drpc/drpcserver.(*Server](http://tstorj.io/drpc/drpcserver.(*Server)).handleRPC:122\n[tstorj.io/drpc/drpcserver.(*Server](http://tstorj.io/drpc/drpcserver.(*Server)).ServeOne:66\n[tstorj.io/drpc/drpcserver.(*Server](http://tstorj.io/drpc/drpcserver.(*Server)).Serve.func2:112\n[tstorj.io/drpc/drpcctx.(*Tracker](http://tstorj.io/drpc/drpcctx.(*Tracker)).track:52”}

​ ​ ​ ​

[Craig]

An earlier thread pointed to this one as where to report if we were seeing these “used serial already exists” error. I’ve had these show up on my 3 nodes, it has already suspended me on europe-north for my first node. This happened within the last 8 hours. Please advise what logs would help, currently I’m spooling them off for all nodes with the following command (adjusted for node #):

docker logs storagenode1 2>&1 | grep -E "GET_AUDIT|GET_REPAIR" | grep failed | grep 2022-05-26 > /tmp/logfailed$(date +%F).txt

Quick summary of log entries for today (EDT) on my first node:

pi@storjpi:~ $ grep "closed network connection" /tmp/logfailedn1-2022-05-26.txt | wc -l
2
pi@storjpi:~ $ grep "broken pipe" /tmp/logfailedn1-2022-05-26.txt | wc -l
3
pi@storjpi:~ $ grep "timed out" /tmp/logfailedn1-2022-05-26.txt | wc -l
78
pi@storjpi:~ $ grep "serial already exists" /tmp/logfailedn1-2022-05-26.txt | wc -l
103
pi@storjpi:~ $ cat /tmp/logfailedn1-2022-05-26.txt | wc -l
186

[Alexey]

What is node’s version?

[Bivvo]

Same here, still occuring @thepaul :

docker logs sn1 2>&1 | grep 'LMZ25OLOVGVBOM4VKQMUPJ4H64QMNWF6RVEKI37BI62OMJZ5F3IQ'
2022-05-28T10:04:50.282Z	INFO	piecestore	download started	{"Process": "storagenode", "Piece ID": "LMZ25OLOVGVBOM4VKQMUPJ4H64QMNWF6RVEKI37BI62OMJZ5F3IQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-05-28T10:05:54.047Z	INFO	piecestore	downloaded	{"Process": "storagenode", "Piece ID": "LMZ25OLOVGVBOM4VKQMUPJ4H64QMNWF6RVEKI37BI62OMJZ5F3IQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-05-28T10:09:50.309Z	INFO	piecestore	download started	{"Process": "storagenode", "Piece ID": "LMZ25OLOVGVBOM4VKQMUPJ4H64QMNWF6RVEKI37BI62OMJZ5F3IQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR"}
2022-05-28T10:09:50.310Z	ERROR	piecestore	download failed	{"Process": "storagenode", "Piece ID": "LMZ25OLOVGVBOM4VKQMUPJ4H64QMNWF6RVEKI37BI62OMJZ5F3IQ", "Satellite ID": "1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE", "Action": "GET_REPAIR", "error": "used serial already exists in store", "errorVerbose": "used serial already exists in store\n\tstorj.io/storj/storagenode/piecestore/usedserials.insertSerial:263\n\tstorj.io/storj/storagenode/piecestore/usedserials.(*Table).Add:117\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).verifyOrderLimit:76\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:498\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:122\n\tstorj.io/drpc/drpcserver.(*Server).ServeOne:66\n\tstorj.io/drpc/drpcserver.(*Server).Serve.func2:112\n\tstorj.io/drpc/drpcctx.(*Tracker).track:52"}

[Craig]

My nodes are all on 1.55.1. For me the errors only seem to be happening on europe-north (worst offender) and a bit on ap1 and eu1. us1/us2/saltlake seem unphased as so far as I recall have been a steady 100%. I am located in the USA though, coincidence?

[computerMonk]

I’ve been getting this error too.

Node Suspension - serial already exists in store

[suspension] Hello all, My node has been running for a little over a year now, but lately I’ve noticed that the suspension score from the satellites across the Atlantic have been sliding down. I really can’t figure out what is causing this. The US based satellites haven’t been affected. This seems to be the typical error message: 2022-05-26T17:42:20.107Z ERROR piecestore download failed {“Process”: “storagenode”, “Piece ID”: “EQYRH2RNA6XROSM2OFUB2W4CJWLDRP5SAFDIFGTKAES22GZPWY4Q”, “Satellite…

[thepaul]

I’m finally back to investigating this.

Can anyone else (thank you, @Craig) provide me with rates of how often this is happening for you? The query command might look like:

docker logs storagenode 2>&1 | \
awk '$0~/used serial already exists in store/ {sub(/T.*/,"");a[$0]++} END {for(d in a){print d,a[d]}}' | sort

That will provide a per-day count. If Craig’s results are typical, this is happening a lot more than I thought.

Secondly, the latest logs from @baker and @Bivvo are very interesting, because they show the first cases I’ve noticed where the download succeeds the first time. That throws a whole different spin on things and leaves me particularly confused. I hope to get to the bottom of this soon.

[BrightSilence]

Ran it on my log file which started april 15th.

2022-05-05 18

That’s it. Seems like one specific day only.

[thepaul]

@BrightSilence

That’s it. Seems like one specific day only.

But wow, 18 times on that one day. How strange. Did you get more traffic in general that day?