"failed to add bandwidth usage" and "orders cleaning filestore archive" errors

Node Operators troubleshooting
1

With the new month I don’t see traffic from the dashboard and after a few days looking at the log I discovered why, the bandwidthdb was malformed. Now I fixed the db and everything works but I’m curious, what has corrupted the database with the end of the month? And in this period the reputation of the node has decreased or from the satellite side everything seems ok? Do I get paid for the traffic of these days?

Logs

2020-12-07T16:49:00.975Z ERROR piecestore failed to add bandwidth usage {“error”: “bandwidthdb error: database disk image is malformed”, “errorVerbose”: “bandwidthdb error: database disk image is malformed\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:683\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func6:625\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:646\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:29\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”}
2020-12-07T16:49:00.975Z INFO piecestore downloaded {“Piece ID”: “3YBRF3CJX7HROEABNK2DTNUGAESZGHVCLQOFN2LJH2YFLOTRGVQQ”, “Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Action”: “GET”}
2020-12-07T16:49:02.792Z ERROR piecestore failed to add bandwidth usage {“error”: “bandwidthdb error: database disk image is malformed”, “errorVerbose”: “bandwidthdb error: database disk image is malformed\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:683\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func6:625\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:646\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:29\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”}
2020-12-07T16:49:02.792Z INFO piecestore downloaded {“Piece ID”: “KAB35FZPVVOWYVYZN7WHWL5ZRUXU4ERDGZ4D34HWQ4S22KPJWMAQ”, “Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Action”: “GET”}
2020-12-07T16:49:04.959Z INFO piecestore download started {“Piece ID”: “BUDBQFLI2MXMY5SKJS35YADTLR6XLQHS5CTUFZ7HRI4LP3KSVKVQ”, “Satellite ID”: “1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE”, “Action”: “GET”}
2020-12-07T16:49:06.259Z INFO piecestore download started {“Piece ID”: “HTKLPOK2GXKY52JDFAGTNKBQENFOTVG7PZLZV66UBC6ANZSYEPPQ”, “Satellite ID”: “12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB”, “Action”: “GET_REPAIR”}
2020-12-07T16:49:08.352Z ERROR piecestore failed to add bandwidth usage {“error”: “bandwidthdb error: database disk image is malformed”, “errorVerbose”: “bandwidthdb error: database disk image is malformed\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:683\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func6:622\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:646\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:29\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”}
2020-12-07T16:49:08.352Z INFO piecestore downloaded {“Piece ID”: “HTKLPOK2GXKY52JDFAGTNKBQENFOTVG7PZLZV66UBC6ANZSYEPPQ”, “Satellite ID”: “12rfG3sh9NCWiX3ivPjq2HtdLmbqCrvHVEzJubnzFzosMuawymB”, “Action”: “GET_REPAIR”}
2020-12-07T16:49:09.220Z ERROR piecestore failed to add bandwidth usage {“error”: “bandwidthdb error: database disk image is malformed”, “errorVerbose”: “bandwidthdb error: database disk image is malformed\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:683\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func6:625\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:646\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:29\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”}
2020-12-07T16:49:09.221Z INFO piecestore downloaded {“Piece ID”: “BUDBQFLI2MXMY5SKJS35YADTLR6XLQHS5CTUFZ7HRI4LP3KSVKVQ”, “Satellite ID”: “1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE”, “Action”: “GET”}
2020-12-07T16:49:12.598Z INFO piecestore download started {“Piece ID”: “PG3LWT56UVM56NDCNP3T5QEDC44CNPNKJ4SDLYPF6ISUALZFW5EA”, “Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Action”: “GET”}
2020-12-07T16:49:12.989Z ERROR orders cleaning filestore archive {“error”: “order: lstat config/orders/archive/archived-orders-12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S-1606741200000000000-1606760995898997164-ACCEPTED.v1: structure needs cleaning; order: lstat config/orders/archive/archived-orders-12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs-1606741200000000000-1606760995527829035-ACCEPTED.v1: structure needs cleaning; order: lstat config/orders/archive/archived-orders-12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs-1606744800000000000-1606760997454168867-ACCEPTED.v1: structure needs cleaning”, “errorVerbose”: “group:\n— group:\n— order: lstat config/orders/archive/archived-orders-12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S-1606741200000000000-1606760995898997164-ACCEPTED.v1: structure needs cleaning\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive.func1:366\n\tpath/filepath.walk:380\n\tpath/filepath.Walk:406\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive:364\n\tstorj.io/storj/storagenode/orders.(*Service).CleanArchive:165\n\tstorj.io/storj/storagenode/orders.(*Service).Run.func2:143\n\tstorj.io/common/sync2.(*Cycle).Run:152\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57\n— order: lstat config/orders/archive/archived-orders-12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs-1606741200000000000-1606760995527829035-ACCEPTED.v1: structure needs cleaning\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive.func1:366\n\tpath/filepath.walk:380\n\tpath/filepath.Walk:406\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive:364\n\tstorj.io/storj/storagenode/orders.(*Service).CleanArchive:165\n\tstorj.io/storj/storagenode/orders.(*Service).Run.func2:143\n\tstorj.io/common/sync2.(*Cycle).Run:152\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57\n— order: lstat config/orders/archive/archived-orders-12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs-1606744800000000000-1606760997454168867-ACCEPTED.v1: structure needs cleaning\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive.func1:366\n\tpath/filepath.walk:380\n\tpath/filepath.Walk:406\n\tstorj.io/storj/storagenode/orders.(*FileStore).CleanArchive:364\n\tstorj.io/storj/storagenode/orders.(*Service).CleanArchive:165\n\tstorj.io/storj/storagenode/orders.(*Service).Run.func2:143\n\tstorj.io/common/sync2.(*Cycle).Run:152\n\tstorj.io/common/sync2.(*Cycle).Start.func1:71\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2020-12-07T16:49:13.235Z ERROR piecestore failed to add bandwidth usage {“error”: “bandwidthdb error: database disk image is malformed”, “errorVerbose”: “bandwidthdb error: database disk image is malformed\n\tstorj.io/storj/storagenode/storagenodedb.(*bandwidthDB).Add:60\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).beginSaveOrder.func1:683\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download.func6:625\n\tstorj.io/storj/storagenode/piecestore.(*Endpoint).Download:646\n\tstorj.io/common/pb.DRPCPiecestoreDescription.Method.func2:1004\n\tstorj.io/drpc/drpcmux.(*Mux).HandleRPC:29\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”}
2020-12-07T16:49:13.235Z INFO piecestore downloaded {“Piece ID”: “PG3LWT56UVM56NDCNP3T5QEDC44CNPNKJ4SDLYPF6ISUALZFW5EA”, “Satellite ID”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “Action”: “GET”}
2020-12-07T16:49:18.171Z INFO piecestore download started {“Piece ID”: “2RLL3LPY7G7JOOU7U73GBYVSTTAPVDEKYRDQU5USLLHYIZ5WB36A”, “Satellite ID”: “1wFTAgs9DP5RSnCqKV1eLf6N9wtk4EAtmN5DpSxcs8EjT69tGE”, “Action”: “GET_REPAIR”}

2

Please, check your dashboard.

3

Hi Alexey,

what I have to check?
Can I suggest to show in the dashbord the last error with a timestamp to make easer to know that there is a problem?

image
image924×604 31.1 KB

image
image814×705 41.1 KB

image
image764×436 24.8 KB

4

You can see a reputation on each satellite in the “Suspension & Audit” section:

You will be paid for all submitted orders. If some orders were not submitted - they will not be paid.
And you will see a difference between an estimation in the “Payout information” screen in the “Info & Estimation” for November and the real payout information for November (it will be pushed back to the nodes and will be displayed instead of estimation), when all storagenodes will be paid.

Perhaps you did not update the docker run command with the --stop-timeout 300 option, or your node were killed by the system for slow response or OOM, or simple unexpected power loss.

If you use Windows, then your disk could have a write cache enabled and if you had a power loss, the result may be the same.

5

So it seems that on the satellite side everything is normal

And with a “failed to add bandwidth usage” error the order is submitted?

I am under linux and power loss is an option, the UPS is not working well lately.

What about adding in the dashboard that something is not working good?

6

You can check your orders/unsent folder - is there orders older than 48h?
You also can check your orders/archive for rejected orders.