Error: missing trie node on startup

[offerm]

With latest master, after erasing the datadir, I'm getting this:

/Users/admin/.virtualenvs/raiden/bin/python "/Applications/PyCharm CE.app/Contents/helpers/pydev/pydevd.py" --multiproc --qt-support=auto --client 127.0.0.1 --port 61936 --file /Users/admin/.virtualenvs/raiden/bin/raiden --datadir exchange-a --keystore-path /Users/admin/xud-eth/blkchain1/keystore/ --network-id 4321 --accept-disclaimer --address 0x4F6799E2341379eA52213919622B9bEc80a1b655 --rpc --api-address 0.0.0.0:5001 --web-ui --environment-type development --password-file passwd_file --console --no-sync-check --accept-disclaimer --tokennetwork-registry-contract-address 0x5d197A820cE02119b49E736a932E2FE85945F2B1 --secret-registry-contract-address 0xE8819BeaB19dd62553A9f9765DAA509a4f97A3a6 --endpoint-registry-contract-address 0xb523bcB28ddF7a7DadF77F98ad43c47D38dBDdce --gas-price 10000000000
pydev debugger: process 14661 is connecting

Connected to pydev debugger (build 183.5153.39)
Welcome to Raiden, version 0.100.2rc5.dev275+g6de4082d!
----------------------------------------------------------------------
| This is an Alpha version of experimental open source software      |
| released as a test version under an MIT license and may contain    |
| errors and/or bugs. No guarantee or representations whatsoever is  |
| made regarding its suitability (or its use) for any purpose or     |
| regarding its compliance with any applicable laws and regulations. |
| Use of the software is at your own risk and discretion and by      |
| using the software you acknowledge that you have read this         |
| disclaimer, understand its contents, assume all risk related       |
| thereto and hereby release, waive, discharge and covenant not to   |
| sue Brainbot Labs Establishment or any officers, employees or      |
| affiliates from and for any direct or indirect liability resulting |
| from the use of the software as permissible by applicable laws and |
| regulations.                                                       |
|                                                                    |
| Privacy Warning: Please be aware, that by using the Raiden Client, |
| among others, your Ethereum address, channels, channel deposits,   |
| settlements and the Ethereum address of your channel counterparty  |
| will be stored on the Ethereum chain, i.e. on servers of Ethereum  |
| node operators and ergo are to a certain extent publicly available.|
| The same might also be stored on systems of parties running Raiden |
| nodes connected to the same token network. Data present in the     |
| Ethereum chain is very unlikely to be able to be changed, removed  |
| or deleted from the public arena.                                  |
|                                                                    |
| Also be aware, that data on individual Raiden token transfers will |
| be made available via the Matrix protocol to the recipient,        |
| intermediating nodes of a specific transfer as well as to the      |
| Matrix server operators.                                           |
----------------------------------------------------------------------
2019-02-26 19:43:23.147046 [info     ] Starting Raiden                [raiden.ui.runners] distribution=source python_implementation=CPython python_version=3.7.2 raiden=0.100.2rc5.dev275+g6de4082d system=macOS 10.14 64bit
There is no pathfinding service defined, basic routing will be used
Raiden is running in development mode

You are connected to the '4321' network and the DB path is: /Users/admin/xud-eth/exchange-a/node_4f6799e2/netid_4321/network_5d197a82/v18_log.db
2019-02-26 19:43:28.554337 [info     ] Automatically selecting matrix homeserver based on RTT [raiden.network.transport.matrix.utils] sorted_servers=['https://transport01.raiden.network', 'https://transport03.raiden.network', 'https://transport02.raiden.network']
Traceback (most recent call last):
  File "/Applications/PyCharm CE.app/Contents/helpers/pydev/pydevd.py", line 1741, in <module>
    main()
  File "/Applications/PyCharm CE.app/Contents/helpers/pydev/pydevd.py", line 1735, in main
    globals = debugger.run(setup['file'], None, None, is_module)
  File "/Applications/PyCharm CE.app/Contents/helpers/pydev/pydevd.py", line 1135, in run
    pydev_imports.execfile(file, globals, locals)  # execute the script
  File "/Applications/PyCharm CE.app/Contents/helpers/pydev/_pydev_imps/_pydev_execfile.py", line 18, in execfile
    exec(compile(contents+"\n", file, 'exec'), glob, loc)
  File "/Users/admin/.virtualenvs/raiden/bin/raiden", line 11, in <module>
    load_entry_point('raiden', 'console_scripts', 'raiden')()
  File "/Users/admin/raiden/raiden/__main__.py", line 11, in main
    run(auto_envvar_prefix='RAIDEN')  # pylint: disable=no-value-for-parameter
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/core.py", line 722, in __call__
    return self.main(*args, **kwargs)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/core.py", line 697, in main
    rv = self.invoke(ctx)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/core.py", line 1043, in invoke
    return Command.invoke(self, ctx)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/core.py", line 895, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/core.py", line 535, in invoke
    return callback(*args, **kwargs)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/click/decorators.py", line 17, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/Users/admin/raiden/raiden/ui/cli.py", line 469, in run
    app = runner.run()
  File "/Users/admin/raiden/raiden/ui/runners.py", line 261, in run
    return self._start_services()
  File "/Users/admin/raiden/raiden/ui/runners.py", line 95, in _start_services
    app_ = run_app(**self._options)
  File "/Users/admin/raiden/raiden/ui/app.py", line 452, in run_app
    raiden_app.start()
  File "/Users/admin/raiden/raiden/app.py", line 135, in start
    self.raiden.start()
  File "/Users/admin/raiden/raiden/raiden_service.py", line 394, in start
    self.alarm.first_run(last_log_block_number)
  File "/Users/admin/raiden/raiden/tasks.py", line 193, in first_run
    self._maybe_run_callbacks(latest_block)
  File "/Users/admin/raiden/raiden/tasks.py", line 233, in _maybe_run_callbacks
    result = callback(latest_block)
  File "/Users/admin/raiden/raiden/raiden_service.py", line 651, in _callback_new_block
    on_blockchain_event(self, event)
  File "/Users/admin/raiden/raiden/blockchain_events_handler.py", line 334, in on_blockchain_event
    handle_channel_new(raiden, event)
  File "/Users/admin/raiden/raiden/blockchain_events_handler.py", line 97, in handle_channel_new
    opened_block_hash=block_hash,
  File "/Users/admin/raiden/raiden/blockchain/state.py", line 26, in get_channel_state
    channel_details = payment_channel_proxy.detail(opened_block_hash)
  File "/Users/admin/raiden/raiden/network/proxies/payment_channel.py", line 77, in detail
    channel_identifier=self.channel_identifier,
  File "/Users/admin/raiden/raiden/network/proxies/token_network.py", line 468, in detail
    channel_identifier=channel_identifier,
  File "/Users/admin/raiden/raiden/network/proxies/token_network.py", line 395, in detail_channel
    to_checksum_address(participant2),
  File "/Users/admin/raiden/raiden/network/proxies/token_network.py", line 145, in _call_and_check_result
    call_result = fn(*args).call(block_identifier=block_identifier)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/web3/contract.py", line 1120, in call
    **self.kwargs
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/web3/contract.py", line 1369, in call_contract_function
    return_data = web3.eth.call(call_transaction, block_identifier=block_id)
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/eth_utils/functional.py", line 22, in inner
    return callback(fn(*args, **kwargs))
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/web3/eth.py", line 294, in call
    [transaction, block_identifier],
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/web3/manager.py", line 112, in request_blocking
    raise ValueError(response["error"])
ValueError: {'code': -32000, 'message': 'missing trie node d74423b54378a6d49546847401bb01798f2ac01f8f0a9ba47ed8a5b26c20ef4c (path )'}
--- Logging error ---
Exception ignored in: <function BaseFileLock.__del__ at 0x10c6fc510>
Traceback (most recent call last):
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/filelock.py", line 333, in __del__
  File "/Users/admin/.virtualenvs/raiden/lib/python3.7/site-packages/filelock.py", line 320, in release
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 1383, in info
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 1519, in _log
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 1529, in handle
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 1591, in callHandlers
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 905, in handle
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/handlers.py", line 72, in emit
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/logging/__init__.py", line 958, in handleError
  File "/usr/local/Cellar/python/3.7.2_1/Frameworks/Python.framework/Versions/3.7/lib/python3.7/traceback.py", line 104, in print_exception
  File "/Users/admin/raiden/raiden/log_config.py", line 143, in tracebackexception_format
  File "/Users/admin/raiden/raiden/log_config.py", line 124, in processor_wrapper
ImportError: sys.meta_path is None, Python is likely shutting down

[ulope]

Hi @offerm, that isn't actually a Raiden error. The actual error message

{'code': -32000, 'message': 'missing trie node d74423b54378a6d49546847401bb01798f2ac01f8f0a9ba47ed8a5b26c20ef4c (path )'}

is produced by your Ethereum node.

From a bit of googling this is most likely caused by fast-syncing your Eth node: https://github.com/ethereum/go-ethereum/issues/16123

[offerm]

@ulope thanks. I'm using a private ETH chain running locally. The geth process is not mining so there are not additional blocks. When I start the master I constantly get this error. However, when I start an older branch there is no error.

How can this be related to Eth node if I'm using the same node for both branches?

[offerm]

@ulope more information:

If I change raiden/blockchain/state.py:26 from

channel_details = payment_channel_proxy.detail(opened_block_hash)

to

channel_details = payment_channel_proxy.detail('latest')

everything works.

This line was changed (from latest to opened_block_hash) by @LefterisJP on 2019-02-18.

My concern is that the open_block_hash is wrong.

Let me know if you need any other information.

[offerm]

Note that now, after I started raiden with channel_details = payment_channel_proxy.detail('latest') I don't see the problem any more even after changing the line back to channel_details = payment_channel_proxy.detail(opened_block_hash)

I guess that once the blockchain event was handled there is no need to handle it again.

To recreate the problem I remove the datadir and restart.

[LefterisJP]

My concern is that the open_block_hash is wrong.

Can you add a breakpoint to /Users/admin/raiden/raiden/blockchain_events_handler.py:89 before the call of get_channel_state() and inspect the value of the blockhash? The data is retrieved from the ethereum event.

[offerm]

Sure.

I see there blockNumber : 6414 and block_hash: '0xb3e09a099579b2ea8b5fa8f872e2c559514b787ec8f53650ded440ab6f89611b'

Information looks consistent. Not sure that the channel created in that block.

> eth.getBlock(6414)
{
  difficulty: 1665051,
  extraData: "0xd983010814846765746888676f312e31312e328664617277696e",
  gasLimit: 8000000,
  gasUsed: 109923,
  hash: "0xb3e09a099579b2ea8b5fa8f872e2c559514b787ec8f53650ded440ab6f89611b",
  logsBloom: "0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000200000000000000000c000000000000040000000000000000000000000000000000000000000000040000000000000000000000000000000000000000000000000500000000000000100000000000008000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000400000000040000000001000000000000000000000010000000000002000000000000000000000000000000000000040000000000000000000000000000000000000000000000000000000000000000000",
  miner: "0x4f6799e2341379ea52213919622b9bec80a1b655",
  mixHash: "0x9291f3b0b571498d47d434ac21fbe43ebafbca5013c5e7e183e41d5375ba05dc",
  nonce: "0x01dd2067f6ff45dc",
  number: 6414,
  parentHash: "0x7fbf4552baa61e5ad7edfe4e6914b7a4f0d4cfc6024a1495306363cb62266441",
  receiptsRoot: "0xfade99ec95d46a72f5b67518d9de131641b8726577d4a7f0497e4e03bef3817f",
  sha3Uncles: "0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347",
  size: 747,
  stateRoot: "0xd74423b54378a6d49546847401bb01798f2ac01f8f0a9ba47ed8a5b26c20ef4c",
  timestamp: 1550160798,
  totalDifficulty: 4543987762,
  transactions: ["0x3ec4eb59f2f10159a50196b7105fe67f1d0a4560f5ceaff4746914f242cd686e"],
  transactionsRoot: "0x9c0a323f65ae148215d025915c72b952a27acc7469a90c8a090df8a0b5f1f371",
  uncles: []
}

[LefterisJP]

Hmm okay this looks wrong. Is the block_hash a hexadecimal string at the point I asked you to put the breakpoint? It should be bytes after this change. Are you sure you are properly rebased on master?

I tried it on Kovan by putting a breakpoint on latest master while it processes blockchain events and the blockhash there is indeed bytes.

[offerm]

Sorry. Yes, it is bytes there. I used event.event_data['block_hash'].hex()

@LefterisJP note that the error is

`{'code': -32000, 'message': 'missing trie node d74423b54378a6d49546847401bb01798f2ac01f8f0a9ba47ed8a5b26c20ef4c (path )'}`

the hex string d74423b54378a6d49546847401bb01798f2ac01f8f0a9ba47ed8a5b26c20ef4c is probably taken from stateRoot of block 6414. (see above)

[offerm]

From what I read, geth 1.8.0 is using state pruning and only keeping the last 128 states. This is probably the reason why we see this error when asking for block 6416 and the chain is at 7542.

Is it safe to use the historical block without checking that the state is available? Maybe use 'latest' in case of a too old block?

[LefterisJP]

@offerm indeed that must be it. I ran some tests. Made an issue for this: https://github.com/raiden-network/raiden/issues/3566