After dfuseeos is suspended and restarted, synchronization cannot be continued for a long time #216
Description
The following log has been output
found a hole in a oneblock files (merger/bundle.go:101){"bundle_lower_block": 2257100, "missing_block_num": 2257182, "missing_block_id": "2206ae27"}
dfuse.log.json
{"level":"info","ts":1613974873.342177,"logger":"trxdb-loader.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974873.3667006,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:13.366 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block b9a209f6ce08c9dd... #2704511 @ 2021-02-22T06:21:13.500 signed by 3grxzx42cwog [trxs: 2, lib: 2704279, conf: 0, latency: -133 ms]"}
{"level":"info","ts":1613974873.4008152,"logger":"tokenmeta.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974873.461151,"logger":"eosws.hub.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002688300.dbin.zst","base_filename":"0002688300","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974873.7214723,"logger":"search-indexer.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974873.8656628,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:13.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block be78d503eff0dd72... #2704512 @ 2021-02-22T06:21:14.000 signed by 3grxzx42cwog [trxs: 0, lib: 2704279, conf: 0, latency: -134 ms]"}
{"level":"info","ts":1613974873.867669,"logger":"eosws.hub.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":0,"last_file_block":0,"last_live_block":0,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974873.8721843,"logger":"search-archive","caller":"archive/archivequery.go:258","msg":"run query: all shards processed","trace_id":"37a419e676213e92ff4eed9eea01129b","last_read":2256799}
{"level":"info","ts":1613974874.3661432,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:14.366 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block 0ea7495a759be9d3... #2704513 @ 2021-02-22T06:21:14.500 signed by 3grxzx42cwog [trxs: 2, lib: 2704279, conf: 0, latency: -133 ms]"}
{"level":"info","ts":1613974874.471393,"logger":"statedb.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974874.802782,"logger":"search-live","caller":"live/app.go:220","msg":"not near, will retry","archive_lib":{}}
{"level":"info","ts":1613974874.8652763,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:14.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block 382e8d4e306d04bb... #2704514 @ 2021-02-22T06:21:15.000 signed by 3grxzx42cwog [trxs: 0, lib: 2704279, conf: 0, latency: -134 ms]"}
{"level":"info","ts":1613974874.8724325,"logger":"search-archive","caller":"search/metric.go:118","msg":"query metrics","trace_id":"37a419e676213e92ff4eed9eea01129b","query":"receiver:fscio action:setabi notif:false","duration":0.889087124,"descending":false,"low_block_num":59,"high_block_num":2256799,"time_to_first_result":0.000800301,"transaction_seen_count":1,"potential_indexes_count":11284,"searched_indexes_count":11284,"utilized_indexes_count":11284,"searched_trx_count":1,"utilized_trx_count":1,"searched_total_duration":2.651835497,"utilized_total_duration":2.708875424}
{"level":"info","ts":1613974875.2410948,"logger":"tokenmeta.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":-2257099,"last_file_block":2257099,"last_live_block":0,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974875.3002598,"logger":"accounthist","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974875.3319783,"logger":"trxdb-loader.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":431246,"last_file_block":2257099,"last_live_block":2688345,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974875.3664143,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:15.366 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block da88be54bab70014... #2704515 @ 2021-02-22T06:21:15.500 signed by 3grxzx42cwog [trxs: 2, lib: 2704279, conf: 0, latency: -133 ms]"}
{"level":"info","ts":1613974875.5584867,"logger":"search-indexer.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":431246,"last_file_block":2257099,"last_live_block":2688345,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974875.6542163,"logger":"relayer.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002688100.dbin.zst","base_filename":"0002688100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974875.6542857,"logger":"relayer.js.file","caller":"bstream/filesource.go:183","msg":"asking merger for missing files","base_block_num":2688100}
{"level":"info","ts":1613974875.8504183,"logger":"merger","caller":"merger/merger.go:431","msg":"retrieved list of files","seenblock_low_boundary":2247099,"bundle_lower_block":2257100,"seen_files_count":0,"too_old_files_count":0,"good_files_count":108072,"canonical_good_files_count":108072}
{"level":"info","ts":1613974875.8653615,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:15.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block cde8c5901d97b7cb... #2704516 @ 2021-02-22T06:21:16.000 signed by 3grxzx42cwog [trxs: 0, lib: 2704279, conf: 0, latency: -134 ms]"}
{"level":"warn","ts":1613974875.9405856,"logger":"merger","caller":"merger/bundle.go:101","msg":"found a hole in a oneblock files","bundle_lower_block":2257100,"missing_block_num":2257182,"missing_block_id":"2206ae27"}
{"level":"info","ts":1613974875.9406965,"logger":"merger","caller":"merger/merger.go:365","msg":"waiting for more files to complete bundle","bundle_lowerblock":2257100,"bundle_length":99,"bundle_upper_block_id":"b5c4d0d7"}
{"level":"info","ts":1613974876.3660555,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:16.365 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block d6ea39359c173a71... #2704517 @ 2021-02-22T06:21:16.500 signed by 3grxzx42cwog [trxs: 2, lib: 2704279, conf: 0, latency: -134 ms]"}
{"level":"info","ts":1613974876.497851,"logger":"blockmeta.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002688200.dbin.zst","base_filename":"0002688200","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974876.8652704,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:16.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block ee10e01f041b342e... #2704518 @ 2021-02-22T06:21:17.000 signed by 3grxzx42cwog [trxs: 0, lib: 2704279, conf: 0, latency: -134 ms]"}
{"level":"info","ts":1613974877.1231117,"logger":"search-router","caller":"router/queryexecutor.go:85","msg":"cannot get next target peer from planner","trace_id":"37a419e676213e92ff4eed9eea01129b","low_block_num":2256800,"high_block_num":9000000000000000000,"decending":false,"with_reversible":true}
{"level":"info","ts":1613974877.1235762,"logger":"abicodec","caller":"abicodec/syncer.go:83","msg":"abi codec stream abi changes","error":"search stream terminated with error: rpc error: code = Unknown desc = Internal server error"}
{"level":"info","ts":1613974877.1236148,"logger":"abicodec","caller":"abicodec/syncer.go:86","msg":"the search stream ended with error","error":"search stream terminated with error: rpc error: code = Unknown desc = Internal server error"}
{"level":"info","ts":1613974877.2658145,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:17.265 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block 2de56549456b584b... #2704519 @ 2021-02-22T06:21:17.500 signed by 3grxzx42cwog [trxs: 2, lib: 2704279, conf: 0, latency: -234 ms]"}
{"level":"info","ts":1613974877.3438373,"logger":"trxdb-loader.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974877.401033,"logger":"tokenmeta.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974877.4613962,"logger":"eosws.hub.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002688300.dbin.zst","base_filename":"0002688300","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974877.7217262,"logger":"search-indexer.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974877.8055303,"logger":"search-live","caller":"live/app.go:220","msg":"not near, will retry","archive_lib":{}}
{"level":"info","ts":1613974877.866014,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:17.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block d1014b251f4a998e... #2704520 @ 2021-02-22T06:21:18.000 signed by 5fnrk4ozmfgg [trxs: 0, lib: 2704291, conf: 168, latency: -134 ms]"}
{"level":"info","ts":1613974878.1237366,"logger":"abicodec","caller":"abicodec/syncer.go:81","msg":"starting ABI syncer"}
{"level":"info","ts":1613974878.1243384,"logger":"search-router","caller":"router/router.go:93","msg":"routing active query","trace_id":"a8180536daae1e4b564f041f592d5358","request":{"query":"receiver:fscio action:setabi notif:false","lowBlockNum":1,"highBlockUnbounded":true,"cursor":"1:59::f3d3bb6589ff","withReversible":true,"liveMarkerInterval":1},"head_delay_tolerance":0,"lib_delay_tolerance":0}
{"level":"info","ts":1613974878.1246057,"logger":"search-router","caller":"router/router.go:166","msg":"adjusted query range","trace_id":"a8180536daae1e4b564f041f592d5358","low_block_num":59,"high_block_num":9000000000000000000,"mode":"STREAMING"}
{"level":"info","ts":1613974878.1246736,"logger":"search-router","caller":"router/queryexecutor.go:105","msg":"running backend query request","trace_id":"a8180536daae1e4b564f041f592d5358","backend_addr":"172.17.116.159:13015","low_block_num":59,"high_block_num":2256799,"serves_reversible":false,"backend_request":"query:\"receiver:fscio action:setabi notif:false\" lowBlockNum:59 highBlockNum:2256799 "}
{"level":"info","ts":1613974878.125236,"logger":"search-archive","caller":"archive/backend.go:182","msg":"starting streaming search query processing","trace_id":"a8180536daae1e4b564f041f592d5358"}
{"level":"info","ts":1613974878.125501,"logger":"search-archive","caller":"archive/archivequery.go:107","msg":"run archive query","trace_id":"a8180536daae1e4b564f041f592d5358","bquery":{"Raw":"receiver:fscio action:setabi notif:false","FieldTransformer":{},"FieldNames":["action","notif","receiver"],"Validator":{}},"low_block_num":59,"high_block_num":2256799}
{"level":"info","ts":1613974878.2083225,"logger":"statedb.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":-2257099,"last_file_block":2257099,"last_live_block":0,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974878.2112997,"logger":"relayer.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":2704520,"last_file_block":0,"last_live_block":2704520,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974878.2113698,"logger":"blockmeta.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":0,"last_file_block":0,"last_live_block":0,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974878.3699305,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:18.366 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block 58559391ef9a35a0... #2704521 @ 2021-02-22T06:21:18.500 signed by 5fnrk4ozmfgg [trxs: 2, lib: 2704291, conf: 0, latency: -133 ms]"}
{"level":"info","ts":1613974878.4715455,"logger":"statedb.js.file","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974878.8662288,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:18.865 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block 1669118b896189fa... #2704522 @ 2021-02-22T06:21:19.000 signed by 5fnrk4ozmfgg [trxs: 0, lib: 2704291, conf: 0, latency: -134 ms]"}
{"level":"info","ts":1613974878.8677676,"logger":"eosws.hub.js","caller":"bstream/joiningsource.go:551","msg":"joining state JOINING","block_behind_live":0,"last_file_block":0,"last_live_block":0,"last_merger_block":0,"buffer_lower_block":0,"buffer_higher_block":0}
{"level":"info","ts":1613974879.23096,"logger":"search-archive","caller":"archive/archivequery.go:258","msg":"run query: all shards processed","trace_id":"a8180536daae1e4b564f041f592d5358","last_read":2256799}
{"level":"info","ts":1613974879.3005145,"logger":"accounthist","caller":"bstream/filesource.go:179","msg":"reading from blocks store: file does not (yet?) exist, retrying in","filename":"/data/dfuseeos/dfuse-data/storage/merged-blocks/0002257100.dbin.zst","base_filename":"0002257100","retry_delay":4,"secondary_blocks_stores_count":0}
{"level":"info","ts":1613974879.366313,"logger":"mindreader","caller":"log_plugin/to_zap_log_plugin.go:119","msg":"info 2021-02-22T06:21:19.366 nodeos producer_plugin.cpp:405 on_incoming_block ] Received block d457acfbf29e84e9... #2704523 @ 2021-02-22T06:21:19.500 signed by 5fnrk4ozmfgg [trxs: 2, lib: 2704291, conf: 0, latency: -133 ms]"}