DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start

Node Operators troubleshooting
21

Then proceed the next one. Every deleted line is a lost stat…

22

Alright, so basically just work through in order until it comes good?

23

Yes, until it starts working

24

Scripted this to do the following:

  1. stop storagenode
  2. delete matching the first row in the query (ie. the oldest time) and exit sqlite
  3. run storagenode without auto restart
  4. loop, ie. it keeps deleting until the node doesn’t crash

Well I’m going, but not without removing every record in that list.

Reverting to backup and running it in reverse order, ie. deleting the newest time, had the same result in a functioning node but an empty query.

A win, if perhaps a pyrrhic one.

1 Like
25

2 posts were merged into an existing topic: Docker 0.15.3 won’t start anymore

28

My recent node started yesterday won’t start anymore with the error voucher: unable to find satellite on the network: context canceled.

Here are more logs:

2019-07-25T00:24:17.782Z e[34mINFOe[0m Node 12HXxBwdYLjjt8BcZGTRtKGG8N7MKDa9W38kpde9FMsGpmq2ygb started
2019-07-25T00:24:17.782Z e[34mINFOe[0m Public server started on [::]:28967
2019-07-25T00:24:17.782Z e[34mINFOe[0m Private server started on 127.0.0.1:7778
2019-07-25T00:24:17.782Z e[34mINFOe[0m vouchers Checking vouchers

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

2019-07-25T00:24:17.805Z e[34mINFOe[0m vouchers Requesting voucher {“satellite”: “118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW”}
2019-07-25T00:24:17.805Z e[34mINFOe[0m vouchers Requesting voucher {“satellite”: “121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6”}
2019-07-25T00:24:17.805Z e[34mINFOe[0m vouchers Requesting voucher {“satellite”: “12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S”}
2019-07-25T00:24:17.805Z e[34mINFOe[0m vouchers Requesting voucher {“satellite”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”}
ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

2019-07-25T00:24:17.805Z e[31mERRORe[0m vouchers Error requesting voucher {“satellite”: “118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW”, “error”: “voucher: unable to find satellite on the network: context canceled”, “errorVerbose”: "voucher: unable to find satellite on the network: context canceled\n\storj/storagenode/vouchers.(*Service).request:127\n/storj/storagenode/vouchers.(*Service).Request:116\n/storj/storagenode/vouchers.

2019-07-25T00:24:17.806Z e[31mERRORe[0m vouchers Error requesting voucher {“satellite”: “121RTSDpyNZVcEU84Ticf2L1ntiuUimbWgfATz21tuvgk3vzoA6”, “error”: “voucher: unable to find satellite on the network: context canceled”, “errorVerbose”: "voucher: unable to find satellite on the (*Service).RunOnce.func1:103\

2019-07-25T00:24:17.806Z e[31mERRORe[0m vouchers Error requesting voucher {“satellite”: “12EayRS2V1kEsWESU9QMRseFhdxYxKicsiFmxrsLZHeLUtdps3S”, “error”: “voucher: unable to find satellite on the network: context canceled”, “errorVerbose”: "voucher: unable to find satellite on t(*Service).RunOnce.func1:103\n

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

ERROR: 2019/07/25 00:24:17 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing

2019-07-25T00:24:17.806Z e[31mERRORe[0m vouchers Error requesting voucher {“satellite”: “12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs”, “error”: “voucher: unable to find satellite on the network: context canceled”, “errorVerbose”: "voucher: unable to find

2019-07-25T00:24:17.807Z e[34mINFOe[0m piecestore:monitor Remaining Bandwidth {“bytes”: 5936007816960}
2019-07-25T00:24:17.818Z e[34mINFOe[0m piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs sending {“count”: 357}
2019-07-25T00:24:17.818Z e[34mINFOe[0m piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW sending {“count”: 1642}
2019-07-25T00:24:17.819Z e[34mINFOe[0m piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW finished
2019-07-25T00:24:17.819Z e[34mINFOe[0m piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs finished
2019-07-25T00:24:17.819Z e[31mERRORe[0m piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”:

2019-07-25T00:24:17.819Z e[31mERRORe[0m piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”:

29

Hello @aeleos,
Welcome to the forum!

Please, replace the info logging level to the debug in the config.yaml, save it and restart the node: docker restart -t 300 storagenode
Then take a log (for Linux):

docker logs storagenode 2>&1 | grep -B 3 -i fatal

Or for Windows PowerShell:

docker logs storagenode 2>&1 | sls -context 3,0 fatal
31

Hi but it seems I can’t reply to the post anymore, but here are the logs you asked for

2019-07-25T00:40:23.811Z INFO piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW finished
2019-07-25T00:40:23.811Z ERROR piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\t/storj/storagenode/orders.(*Sender).settle:156\n\t/storj/storagenode/orders.(*Sender).Settle:142\n\t/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\t/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T00:40:23.812Z INFO piecestore:monitor Remaining Bandwidth {“bytes”: 9936007816960}
2019-07-25T00:40:24.801Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

2019-07-25T00:42:42.459Z ERROR piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\t/storj/storagenode/orders.(*Sender).settle:156\n\t/storj/storagenode/orders.(*Sender).Settle:142\n\t/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\t/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T00:42:42.459Z INFO piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs finished
2019-07-25T00:42:42.459Z ERROR piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\t/storj/storagenode/orders.(*Sender).settle:156\n\t/storj/storagenode/orders.(*Sender).Settle:142\n\t/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\t/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T00:42:43.448Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

ERROR: 2019/07/25 00:43:20 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing
2019-07-25T00:43:20.875Z INFO piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs finished
2019-07-25T00:43:20.875Z ERROR piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\t/storj/storagenode/orders.(*Sender).settle:156\n\t/storj/storagenode/orders.(*Sender).Settle:142\n\t/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\t/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T00:43:21.863Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

32

I need a result of this query: DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start

33

https://forum.storj.io/t/debug-fatal-error-infodb-unique-constraint-failed-bandwidth-usage-rollups-interval-start/698/32

Here is the output

SQLite version 3.18.0 2017-03-28 18:48:43
Enter “.help” for usage hints.
sqlite> SELECT datetime(strftime(’%Y-%m-%dT%H:00:00’, created_at)) created, bu.satellite_id sat_id, bu.action act , SUM(bu.amount) amt
…> FROM bandwidth_usage bu, bandwidth_usage_rollups bur
…> WHERE datetime(created_at) < datetime(CURRENT_TIMESTAMP)
…> AND bur.interval_start = created
…> AND bur.satellite_id = sat_id
…> AND bur.action = act
…> GROUP BY created, sat_id, act;
2019-07-24 15:00:00||1|2603300096
2019-07-24 15:00:00||2|1364762624
2019-07-24 15:00:00|�,B|3|768
sqlite>

34

Replace the path to yours.

  1. docker stop -t 300 storagenode
  2. docker run --rm -it -v /disk2/storj/storage/info.db:/data/info.db sstc/sqlite3 sqlite3 ./info.db
delete from bandwidth_usage_rollups where interval_start = '2019-07-24 15:00:00';
  1. .exit
  2. docker start storagenode
35

https://forum.storj.io/t/debug-fatal-error-infodb-unique-constraint-failed-bandwidth-usage-rollups-interval-start/698/34

ERROR: 2019/07/25 01:06:19 pickfirstBalancer: failed to NewSubConn: rpc error: code = Canceled desc = grpc: the client connection is closing
2019-07-25T01:06:19.390Z INFO piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs finished
2019-07-25T01:06:19.390Z ERROR piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\tstorj.io/storj/storagenode/orders.(*Sender).settle:156\n\tstorj.io/storj/storagenode/orders.(*Sender).Settle:142\n\tstorj.io/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T01:06:20.378Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

2019-07-25T01:07:57.964Z INFO piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW finished
2019-07-25T01:07:57.964Z ERROR piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\tstorj.io/storj/storagenode/orders.(*Sender).settle:156\n\tstorj.io/storj/storagenode/orders.(*Sender).Settle:142\n\tstorj.io/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T01:07:57.982Z INFO piecestore:monitor Remaining Bandwidth {“bytes”: 9936007816960}
2019-07-25T01:07:58.954Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

2019-07-25T01:16:17.549Z ERROR piecestore:orderssender.118UWpMCHzs6CvSgWd9BfFVjw5K9pZbJjkfZJexMtSkmKxvvAW failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\tstorj.io/storj/storagenode/orders.(*Sender).settle:156\n\tstorj.io/storj/storagenode/orders.(*Sender).Settle:142\n\tstorj.io/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T01:16:17.549Z INFO piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs finished
2019-07-25T01:16:17.549Z ERROR piecestore:orderssender.12L9ZFwhzVpuEKMUNUqkaTLGzwY9G24tbiigLiXpmZWKwmcNDDs failed to settle orders {“error”: “order: unable to find satellite on the network: context canceled”, “errorVerbose”: “order: unable to find satellite on the network: context canceled\n\tstorj.io/storj/storagenode/orders.(*Sender).settle:156\n\tstorj.io/storj/storagenode/orders.(*Sender).Settle:142\n\tstorj.io/storj/storagenode/orders.(*Sender).runOnce.func1:127\n\tgolang.org/x/sync/errgroup.(*Group).Go.func1:57”}
2019-07-25T01:16:18.537Z DEBUG Fatal error: infodb: UNIQUE constraint failed: bandwidth_usage_rollups.interval_start, bandwidth_usage_rollups.satellite_id, bandwidth_usage_rollups.action

36

Still can’t reply and got blocked for 24 hours because i hit a limit on my first day but here are the logs, the issue is still apparent

37

Please, run the SQL again and delete the next duplicate.