Regular sync throws error

[cburgdorf]

What is wrong?

This happens on a fresh empty data dir when I enforce regular sync.

    INFO  11-22 15:55:42    RegularChainSyncer  Header Sync with ETHPeer <Node([email protected])> ended
   ERROR  11-22 15:55:47               asyncio  Task was destroyed but it is pending!
task: <Task pending coro=<BaseService.run() running at /home/cburgdorf/Documents/hacking/ef/py-evm/p2p/service.py:141> wait_for=<Future pending cb=[<TaskWakeupMethWrapper object at 0x7fec444b1168>()]>>
   ERROR  11-22 15:55:47               asyncio  Task was destroyed but it is pending!
task: <Task pending coro=<BaseService.run() running at /home/cburgdorf/Documents/hacking/ef/py-evm/p2p/service.py:103> wait_for=<_GatheringFuture pending cb=[<TaskWakeupMethWrapper object at 0x7fec441fe7c8>()]>>
Exception ignored in: <coroutine object BaseService.run at 0x7fec452a85c8>
RuntimeError: coroutine ignored GeneratorExit
   ERROR  11-22 15:55:47              FullNode  Unexpected error in <trinity.nodes.full.FullNode object at 0x7fec4a0ea780>, exiting
Traceback (most recent call last):
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/p2p/service.py", line 103, in run
    await self._run()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/trinity/nodes/base.py", line 139, in _run
    await self.get_p2p_server().run()
RuntimeError: coroutine ignored GeneratorExit

How can it be fixed

🙈 🙉

[cburgdorf]

False alarm. I was on a branch with weird hackings.

[cburgdorf]

More confusion. It does happen on latest master (maybe not always?). Investigating.

[cburgdorf]

Seems related.

  DEBUG  11-22 16:44:19    RegularChainSyncer  <coroutine object RegularChainSyncer._import_ready_blocks at 0x7fcfec1ed0a0> finished while <trinity.sync.full.chain.RegularChainSyncer object at 0x7fcfef6e8048> is still running, terminating as well
 WARNING  11-22 16:44:19    RegularChainSyncer  Task <coroutine object RegularChainSyncer._import_ready_blocks at 0x7fcfec1ed048> finished unexpectedly: b'\xd7\xf8\x97O\xb5\xacx\xd9\xac\t\x9b\x9a\xd5\x01\x8b\xed\xc2\xce\nr\xda\xd1\x82z\x17\t\xda0X\x0f\x05D'
   DEBUG  11-22 16:44:19    RegularChainSyncer  Task failure traceback
trinity.utils.mp.RemoteTraceback: 
"""
Traceback (most recent call last):
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/batch.py", line 57, in __getitem__
    value = self._track_diff[key]
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/diff.py", line 78, in __getitem__
    raise DiffMissingError(key, result)  # type: ignore # ignore over cast for perf reasons
eth.db.diff.DiffMissingError: (b'\xd7\xf8\x97O\xb5\xacx\xd9\xac\t\x9b\x9a\xd5\x01\x8b\xed\xc2\xce\nr\xda\xd1\x82z\x17\t\xda0X\x0f\x05D', <eth.db.diff.MissingReason object at 0x7fbfaa8ba668>)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/trinity/utils/mp.py", line 66, in wrapper
    return attr(*args, **kwargs)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/chains/base.py", line 678, in import_block
    imported_block = self.get_vm(base_header_for_import).import_block(block)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/vm/base.py", line 549, in import_block
    return self.mine_block()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/vm/base.py", line 560, in mine_block
    final_block = self.finalize_block(packed_block)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/vm/base.py", line 616, in finalize_block
    self.state.account_db.persist()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/account.py", line 416, in persist
    self.make_state_root()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/account.py", line 412, in make_state_root
    self._journaltrie.persist()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/journal.py", line 257, in persist
    self.commit(self.journal.root_changeset_id)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/journal.py", line 242, in commit
    self.wrapped_db[key] = value
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/cache.py", line 26, in __setitem__
    self._db[key] = value
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/keymap.py", line 31, in __setitem__
    self._db[mapped_key] = val
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/venv/lib/python3.6/site-packages/trie/hexary.py", line 436, in __setitem__
    return self.set(key, value)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/venv/lib/python3.6/site-packages/trie/hexary.py", line 94, in set
    root_node = self.get_node(self.root_hash)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/venv/lib/python3.6/site-packages/trie/hexary.py", line 198, in get_node
    encoded_node = self.db[node_hash]
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/batch.py", line 62, in __getitem__
    return self.wrapped_db[key]
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/eth/db/backends/level.py", line 54, in __getitem__
    raise KeyError(key)
KeyError: b'\xd7\xf8\x97O\xb5\xacx\xd9\xac\t\x9b\x9a\xd5\x01\x8b\xed\xc2\xce\nr\xda\xd1\x82z\x17\t\xda0X\x0f\x05D'
"""

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/p2p/service.py", line 141, in _run_task_wrapper
    await awaitable
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/p2p/service.py", line 160, in _run_daemon_task_wrapper
    await awaitable
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/trinity/sync/full/chain.py", line 877, in _import_ready_blocks
    await self._import_blocks(completed_headers)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/trinity/sync/full/chain.py", line 910, in _import_blocks
    self.chain.coro_import_block(block, perform_validation=True)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/p2p/cancellable.py", line 19, in wait
    return await self.wait_first(awaitable, token=token, timeout=timeout)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/p2p/cancellable.py", line 41, in wait_first
    return await token_chain.cancellable_wait(*awaitables, timeout=timeout)
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/venv/lib/python3.6/site-packages/cancel_token/token.py", line 152, in cancellable_wait
    return done.pop().result()
  File "/home/cburgdorf/Documents/hacking/ef/py-evm/trinity/utils/mp.py", line 31, in method
    args,
  File "/usr/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/lib/python3.6/multiprocessing/managers.py", line 772, in _callmethod
    raise convert_to_error(kind, result)
KeyError: b'\xd7\xf8\x97O\xb5\xacx\xd9\xac\t\x9b\x9a\xd5\x01\x8b\xed\xc2\xce\nr\xda\xd1\x82z\x17\t\xda0X\x0f\x05D'

[cburgdorf]

@carver @pipermerriam it seems that #1299 (rebased on latest master because it needs the DBProxy fix) is the only version that still seems able to perform a regular sync.

I tried master, and several commits behind master but none of them worked. I don't know why that is. Could run a git bisect to identify the breakage better but it's a slow progress. If we merge #1299 soon I'll rather focus on moving #1497 forward and just base it on #1299 for the time being.

[cburgdorf]

This now fixed as #1299 is merged