New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

ContractReceiveRouteClosed key error #2449

Closed
pcppcp opened this Issue Sep 12, 2018 · 3 comments

Comments

Projects
None yet
4 participants
@pcppcp
Contributor

pcppcp commented Sep 12, 2018

complete log

traceback

2018-09-11 19:35:56 [debug    ] STATE CHANGE                   [raiden.raiden_service] node=92746ece state_change=<ContractReceiveRouteClosed token_network:9dded03e id:5>
Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/tasks.py", line 98, in _run
    self.loop_until_stop()
  File "/srv/data/src/raiden/raiden/tasks.py", line 155, in loop_until_stop
    self._run_callbacks(current_block)
  File "/srv/data/src/raiden/raiden/tasks.py", line 172, in _run_callbacks
    result = callback(current_block)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 468, in _callback_new_block
    on_blockchain_event(self, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 305, in on_blockchain_event
    handle_channel_closed(raiden, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 195, in handle_channel_closed
    raiden.handle_state_change(channel_closed)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 405, in handle_state_change
    event_list = self.wal.log_and_dispatch(state_change)
  File "/srv/data/src/raiden/raiden/storage/wal.py", line 53, in log_and_dispatch
    events = self.state_manager.dispatch(state_change)
  File "/srv/data/src/raiden/raiden/transfer/architecture.py", line 209, in dispatch
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 1117, in state_transition
    iteration = handle_state_change(chain_state, state_change)
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 811, in handle_state_change
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 457, in handle_token_network_action
    chain_state.block_number,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 387, in state_transition
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 231, in handle_closeroute
    state_change.channel_identifier
KeyError: 5
2018-09-11T19:35:56Z <Greenlet "AlarmTask|Greenlet-2" at 0x7f19de0f2048: <bound method AlarmTask._run of <raiden.tasks.AlarmTask object at 0x7f19de0e9e80>>> failed with KeyError

Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 359, in _run
    self.stop()
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 381, in stop
    self.alarm.get()
  File "src/gevent/greenlet.py", line 633, in gevent._greenlet.Greenlet.get
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/tasks.py", line 98, in _run
    self.loop_until_stop()
  File "/srv/data/src/raiden/raiden/tasks.py", line 155, in loop_until_stop
    self._run_callbacks(current_block)
  File "/srv/data/src/raiden/raiden/tasks.py", line 172, in _run_callbacks
    result = callback(current_block)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 468, in _callback_new_block
    on_blockchain_event(self, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 305, in on_blockchain_event
    handle_channel_closed(raiden, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 195, in handle_channel_closed
    raiden.handle_state_change(channel_closed)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 405, in handle_state_change
    event_list = self.wal.log_and_dispatch(state_change)
  File "/srv/data/src/raiden/raiden/storage/wal.py", line 53, in log_and_dispatch
    events = self.state_manager.dispatch(state_change)
  File "/srv/data/src/raiden/raiden/transfer/architecture.py", line 209, in dispatch
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 1117, in state_transition
    iteration = handle_state_change(chain_state, state_change)
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 811, in handle_state_change
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 457, in handle_token_network_action
    chain_state.block_number,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 387, in state_transition
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 231, in handle_closeroute
    state_change.channel_identifier
KeyError: 5
2018-09-11T19:35:57Z <Greenlet "RaidenService|Greenlet-1" at 0x7f19df8b3e48: <bound method RaidenService._run of <RaidenService 92746ece>>> failed with KeyError

FATAL: An unexpected exception occured. A traceback has been written to /tmp/raiden-exception-2018-09-11T19-35e6ei7g56.txt
5
Traceback (most recent call last):
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/ui/cli.py", line 1067, in stop_task
    task.get()  # re-raise
  File "src/gevent/greenlet.py", line 633, in gevent._greenlet.Greenlet.get
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 359, in _run
    self.stop()
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 381, in stop
    self.alarm.get()
  File "src/gevent/greenlet.py", line 633, in gevent._greenlet.Greenlet.get
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/tasks.py", line 98, in _run
    self.loop_until_stop()
  File "/srv/data/src/raiden/raiden/tasks.py", line 155, in loop_until_stop
    self._run_callbacks(current_block)
  File "/srv/data/src/raiden/raiden/tasks.py", line 172, in _run_callbacks
    result = callback(current_block)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 468, in _callback_new_block
    on_blockchain_event(self, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 305, in on_blockchain_event
    handle_channel_closed(raiden, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 195, in handle_channel_closed
    raiden.handle_state_change(channel_closed)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 405, in handle_state_change
    event_list = self.wal.log_and_dispatch(state_change)
  File "/srv/data/src/raiden/raiden/storage/wal.py", line 53, in log_and_dispatch
    events = self.state_manager.dispatch(state_change)
  File "/srv/data/src/raiden/raiden/transfer/architecture.py", line 209, in dispatch
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 1117, in state_transition
    iteration = handle_state_change(chain_state, state_change)
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 811, in handle_state_change
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 457, in handle_token_network_action
    chain_state.block_number,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 387, in state_transition
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 231, in handle_closeroute
    state_change.channel_identifier
KeyError: 5
2018-09-11T19:35:57Z <Greenlet "Greenlet-4" at 0x7f19de0f2748: stop_task(<RaidenService 92746ece>)> failed with KeyError

Traceback (most recent call last):
  File "/home/xoza/.pyenv/versions/3.6.0/lib/python3.6/runpy.py", line 193, in _run_module_as_main
    "__main__", mod_spec)
  File "/home/xoza/.pyenv/versions/3.6.0/lib/python3.6/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/srv/data/src/raiden/raiden/__main__.py", line 15, in <module>
    main()
  File "/srv/data/src/raiden/raiden/__main__.py", line 11, in main
    run(auto_envvar_prefix='RAIDEN')  # pylint: disable=no-value-for-parameter
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/core.py", line 722, in __call__
    return self.main(*args, **kwargs)
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/core.py", line 697, in main
    rv = self.invoke(ctx)
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/core.py", line 1043, in invoke
    return Command.invoke(self, ctx)
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/core.py", line 895, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/core.py", line 535, in invoke
    return callback(*args, **kwargs)
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/click/decorators.py", line 17, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/srv/data/src/raiden/raiden/ui/cli.py", line 1110, in run
    NodeRunner(kwargs, ctx).run()
  File "/srv/data/src/raiden/raiden/ui/cli.py", line 943, in run
    app = self._run_app()
  File "/srv/data/src/raiden/raiden/ui/cli.py", line 1073, in _run_app
    raise_error=True,
  File "src/gevent/greenlet.py", line 849, in gevent._greenlet.joinall
  File "src/gevent/greenlet.py", line 865, in gevent._greenlet.joinall
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/ui/cli.py", line 1067, in stop_task
    task.get()  # re-raise
  File "src/gevent/greenlet.py", line 633, in gevent._greenlet.Greenlet.get
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 359, in _run
    self.stop()
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 381, in stop
    self.alarm.get()
  File "src/gevent/greenlet.py", line 633, in gevent._greenlet.Greenlet.get
  File "src/gevent/greenlet.py", line 312, in gevent._greenlet.Greenlet._raise_exception
  File "/home/xoza/.pyenv/versions/360_raiden/lib/python3.6/site-packages/gevent/_compat.py", line 47, in reraise
    raise value.with_traceback(tb)
  File "src/gevent/greenlet.py", line 716, in gevent._greenlet.Greenlet.run
  File "/srv/data/src/raiden/raiden/tasks.py", line 98, in _run
    self.loop_until_stop()
  File "/srv/data/src/raiden/raiden/tasks.py", line 155, in loop_until_stop
    self._run_callbacks(current_block)
  File "/srv/data/src/raiden/raiden/tasks.py", line 172, in _run_callbacks
    result = callback(current_block)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 468, in _callback_new_block
    on_blockchain_event(self, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 305, in on_blockchain_event
    handle_channel_closed(raiden, event)
  File "/srv/data/src/raiden/raiden/blockchain_events_handler.py", line 195, in handle_channel_closed
    raiden.handle_state_change(channel_closed)
  File "/srv/data/src/raiden/raiden/raiden_service.py", line 405, in handle_state_change
    event_list = self.wal.log_and_dispatch(state_change)
  File "/srv/data/src/raiden/raiden/storage/wal.py", line 53, in log_and_dispatch
    events = self.state_manager.dispatch(state_change)
  File "/srv/data/src/raiden/raiden/transfer/architecture.py", line 209, in dispatch
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 1117, in state_transition
    iteration = handle_state_change(chain_state, state_change)
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 811, in handle_state_change
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/node.py", line 457, in handle_token_network_action
    chain_state.block_number,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 387, in state_transition
    state_change,
  File "/srv/data/src/raiden/raiden/transfer/token_network.py", line 231, in handle_closeroute
    state_change.channel_identifier
KeyError: 5

@palango palango self-assigned this Sep 17, 2018

@palango palango added this to the Red Eyes Testnet 10 milestone Sep 17, 2018

@palango

This comment has been minimized.

Collaborator

palango commented Sep 17, 2018

The problem is that the node sent two closing transactions:
Line 11868:

2018-09-11 19:35:31 [debug    ] BLOCKCHAIN EVENT               [raiden.blockchain_events_handler] chain_event=<Event contract: 9dded03e event: {'args': AttributeDict({'channel_identifier': 5, 'closing_participant': '0x78c13BBeE31135a2cBaFd09DE1C4f26371536400', 'nonce': 0}), 'event': 'ChannelClosed', 'logIndex': 2, 'transactionIndex': 10, 'transactionHash': HexBytes('0x4b20deb5c5c12bea923882d92f0176e2ea42a543ab88bab50cd9e2ce0f549f8c'), 'address': '0x9dDED03ED3752A1289B5dF71680179aA71Ba19dC', 'blockHash': HexBytes('0x42a0f0211d761602a9365baa2d76df4194fcc8a5d0e442baef94161ed213376f'), 'blockNumber': 4020484, 'block_number': 4020484, 'channel_identifier': 5, 'closing_participant': b'x\xc1;\xbe\xe3\x115\xa2\xcb\xaf\xd0\x9d\xe1\xc4\xf2cqSd\x00'}> node=92746ece

Line 11882:

2018-09-11 19:35:56 [debug    ] BLOCKCHAIN EVENT               [raiden.blockchain_events_handler] chain_event=<Event contract: 9dded03e event: {'args': AttributeDict({'channel_identifier': 5, 'closing_participant': '0x78c13BBeE31135a2cBaFd09DE1C4f26371536400', 'nonce': 0}), 'event': 'ChannelClosed', 'logIndex': 0, 'transactionIndex': 4, 'transactionHash': HexBytes('0x4b20deb5c5c12bea923882d92f0176e2ea42a543ab88bab50cd9e2ce0f549f8c'), 'address': '0x9dDED03ED3752A1289B5dF71680179aA71Ba19dC', 'blockHash': HexBytes('0xc73c2c1f0c8572c65ae4e8486b38ab0c275847029866a56672f10ab963a62675'), 'blockNumber': 4020485, 'block_number': 4020485, 'channel_identifier': 5, 'closing_participant': b'x\xc1;\xbe\xe3\x115\xa2\xcb\xaf\xd0\x9d\xe1\xc4\xf2cqSd\x00'}> node=92746ece

I'm not exactly sure how to trigger this yet, but I'll try with Jozef. Fix is easy to do.

palango added a commit to palango/raiden that referenced this issue Sep 17, 2018

palango added a commit to palango/raiden that referenced this issue Sep 17, 2018

palango added a commit to palango/raiden that referenced this issue Sep 17, 2018

LefterisJP added a commit that referenced this issue Sep 18, 2018

LefterisJP added a commit that referenced this issue Sep 18, 2018

@hackaugusto

This comment has been minimized.

Collaborator

hackaugusto commented Sep 18, 2018

@palango BLOCKCHAIN EVENT are log lines for events polled by the alarm task, this does not mean the node sent the transactions twice, in fact, in the linked log there is no ContractSend* lines, which means the node never sent a transaction (at least through the state machine code).

Probably what we have here is a chain reorg (block hash corresponding to the events above):

'blockHash': HexBytes('0x42a0f0211d761602a9365baa2d76df4194fcc8a5d0e442baef94161ed213376f')
'blockHash': HexBytes('0xc73c2c1f0c8572c65ae4e8486b38ab0c275847029866a56672f10ab963a62675')

@palango

This comment has been minimized.

Collaborator

palango commented Sep 18, 2018

I agree, see #2498 (comment)
So the transaction was sent properly, but we still need to be able to handle the event multiple times.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment