Page MenuHomePhabricator

[chronik] Improve error handling of the electrum interface
ClosedPublic

Authored by Fabien on Thu, Apr 9, 07:30.

Details

Reviewers
PiRK
Group Reviewers
Restricted Project
Commits
rABC8acc20dc06c6: [chronik] Improve error handling of the electrum interface
Summary

The current solution will wait forever when a future is failing which is not the expected behavior. Use start_block() instead to properly catch the errors.

Depends on D19810.

Test Plan
ninja all check-all

Diff Detail

Repository
rABC Bitcoin ABC
Lint
Lint Not Applicable
Unit
Tests Not Applicable

Event Timeline

Fabien requested review of this revision.Thu, Apr 9, 07:30

Tail of the build log:

    Checking chronik-plugin v0.1.0 (/work/chronik/chronik-plugin)
    Checking tungstenite v0.24.0
    Checking url v2.5.7
    Checking event-listener-strategy v0.5.4
    Checking futures-executor v0.3.31
   Compiling pyo3 v0.23.5
    Checking toml_datetime v0.6.11
    Checking serde_spanned v0.6.9
    Checking topo_sort v0.4.0
    Checking mime v0.3.17
    Checking seahash v4.1.0
    Checking winnow v0.7.13
    Checking toml_write v0.1.2
    Checking axum-core v0.4.5
    Checking futures v0.3.31
    Checking tokio-tungstenite v0.24.0
    Checking hyper-util v0.1.17
    Checking async-channel v2.5.0
    Checking memoffset v0.9.1
    Checking tower v0.5.2
    Checking serde_urlencoded v0.7.1
   Compiling karyon_jsonrpc_macro v0.6.1
    Checking serde_path_to_error v0.1.20
   Compiling chronik-bridge v0.1.0 (/work/chronik/chronik-bridge)
    Checking matchit v0.7.3
    Checking unindent v0.2.4
    Checking unicode-segmentation v1.12.0
    Checking base64 v0.22.1
    Checking tower-http v0.5.2
    Checking webpki-roots v1.0.3
    Checking convert_case v0.6.0
    Checking toml_edit v0.22.27
   Compiling librocksdb-sys v0.17.3+10.4.2
    Checking axum v0.7.9
   Compiling pyo3-macros v0.23.5
    Checking toml v0.8.23
    Checking chronik-plugin-impl v0.1.0 (/work/chronik/chronik-plugin-impl)
   Compiling aws-lc-rs v1.14.1
   Compiling rustls v0.23.32
    Checking rustls-webpki v0.103.7
    Checking tokio-rustls v0.26.4
    Checking karyon_async_rustls v0.6.1
    Checking karyon_net v0.6.1
    Checking karyon_jsonrpc v0.6.1
    Checking rocksdb v0.24.0
    Checking chronik-db v0.1.0 (/work/chronik/chronik-db)
    Checking chronik-indexer v0.1.0 (/work/chronik/chronik-indexer)
    Checking chronik-http v0.1.0 (/work/chronik/chronik-http)
error: unused import: `futures::future`
  --> chronik/chronik-http/src/electrum.rs:31:5
   |
31 | use futures::future;
   |     ^^^^^^^^^^^^^^^
   |
   = note: `-D unused-imports` implied by `-D warnings`
   = help: to override `-D warnings` add `#[allow(unused_imports)]`

error: could not compile `chronik-http` (lib) due to 1 previous error
ninja: build stopped: cannot make progress due to previous errors.
Build build-chronik failed with exit code 1

Tail of the build log:

    Checking karyon_core v0.6.1
    Checking tungstenite v0.24.0
    Checking url v2.5.7
    Checking event-listener-strategy v0.5.4
    Checking futures-executor v0.3.31
   Compiling pyo3 v0.23.5
    Checking toml_datetime v0.6.11
    Checking serde_spanned v0.6.9
    Checking mime v0.3.17
    Checking toml_write v0.1.2
    Checking topo_sort v0.4.0
    Checking winnow v0.7.13
    Checking seahash v4.1.0
    Checking tokio-tungstenite v0.24.0
    Checking futures v0.3.31
    Checking axum-core v0.4.5
    Checking hyper-util v0.1.17
    Checking async-channel v2.5.0
    Checking memoffset v0.9.1
    Checking tower v0.5.2
    Checking serde_urlencoded v0.7.1
   Compiling karyon_jsonrpc_macro v0.6.1
    Checking serde_path_to_error v0.1.20
   Compiling chronik-bridge v0.1.0 (/work/chronik/chronik-bridge)
    Checking matchit v0.7.3
    Checking unicode-segmentation v1.12.0
    Checking base64 v0.22.1
    Checking unindent v0.2.4
    Checking webpki-roots v1.0.3
    Checking tower-http v0.5.2
    Checking convert_case v0.6.0
    Checking toml_edit v0.22.27
   Compiling librocksdb-sys v0.17.3+10.4.2
    Checking axum v0.7.9
   Compiling pyo3-macros v0.23.5
    Checking toml v0.8.23
    Checking chronik-plugin-impl v0.1.0 (/work/chronik/chronik-plugin-impl)
   Compiling aws-lc-rs v1.14.1
   Compiling rustls v0.23.32
    Checking rustls-webpki v0.103.7
    Checking tokio-rustls v0.26.4
    Checking karyon_async_rustls v0.6.1
    Checking karyon_net v0.6.1
    Checking karyon_jsonrpc v0.6.1
    Checking rocksdb v0.24.0
    Checking chronik-db v0.1.0 (/work/chronik/chronik-db)
    Checking chronik-indexer v0.1.0 (/work/chronik/chronik-indexer)
    Checking chronik-http v0.1.0 (/work/chronik/chronik-http)
error: unused import: `futures::future`
  --> chronik/chronik-http/src/electrum.rs:31:5
   |
31 | use futures::future;
   |     ^^^^^^^^^^^^^^^
   |
   = note: `-D unused-imports` implied by `-D warnings`
   = help: to override `-D warnings` add `#[allow(unused_imports)]`

error: could not compile `chronik-http` (lib) due to 1 previous error
ninja: build stopped: cannot make progress due to previous errors.
Build build-chronik-plugins failed with exit code 1
Fabien planned changes to this revision.Thu, Apr 9, 08:21

Failed tests logs:

====== Bitcoin ABC functional tests: chronik_electrum_blockchain.py ======

------- Stdout: -------
2026-04-09T08:53:46.357000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_085250_14539/chronik_electrum_blockchain_23
2026-04-09T08:53:51.389000Z TestFramework (INFO): Test the blockchain.headers.subscribe endpoint
2026-04-09T08:53:52.476000Z TestFramework (INFO): Test the blockchain.scripthash.subscribe endpoint
2026-04-09T08:53:57.447000Z TestFramework (INFO): Test the blockchain.address.get_scripthash endpoint
2026-04-09T08:53:57.451000Z TestFramework (INFO): Test the blockchain.estimatefee endpoint
2026-04-09T08:53:57.452000Z TestFramework (INFO): Test the blockchain.relayfee endpoint
2026-04-09T08:53:58.517000Z TestFramework (ERROR): Unexpected exception
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 89, in run_test
    self.test_relay_fee()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 1977, in test_relay_fee
    self.restart_node(0)
  File "/work/test/functional/test_framework/test_framework.py", line 646, in restart_node
    self.stop_node(i)
  File "/work/test/functional/test_framework/test_framework.py", line 632, in stop_node
    self.nodes[i].stop_node(expected_stderr, wait=wait)
  File "/work/test/functional/test_framework/test_node.py", line 551, in stop_node
    self.wait_until_stopped(expected_stderr=expected_stderr)
  File "/work/test/functional/test_framework/test_node.py", line 590, in wait_until_stopped
    wait_until_helper_internal(
  File "/work/test/functional/test_framework/util.py", line 325, in wait_until_helper_internal
    if predicate():
       ^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 591, in <lambda>
    lambda: self.is_node_stopped(**kwargs),
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 572, in is_node_stopped
    raise AssertionError(f"Unexpected stderr {stderr} != {expected_stderr}")
AssertionError: Unexpected stderr pthread lock: Invalid argument != 
2026-04-09T08:53:58.570000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
2026-04-09T08:53:58.570000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_085250_14539/chronik_electrum_blockchain_23
2026-04-09T08:53:58.570000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_085250_14539/chronik_electrum_blockchain_23/test_framework.log
2026-04-09T08:53:58.570000Z TestFramework (ERROR): 
2026-04-09T08:53:58.570000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_085250_14539/chronik_electrum_blockchain_23' to consolidate all logs
2026-04-09T08:53:58.570000Z TestFramework (ERROR): 
2026-04-09T08:53:58.570000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2026-04-09T08:53:58.570000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2026-04-09T08:53:58.570000Z TestFramework (ERROR):
------- Stderr: -------
[node 0] Cleaning up leftover process

Each failure log is accessible here:
Bitcoin ABC functional tests: chronik_electrum_blockchain.py

pthread lock: Invalid argument

Looks like a RocksDB error on shutdown.

In D19801#450027, @PiRK wrote:

pthread lock: Invalid argument

Looks like a RocksDB error on shutdown.

Weird there is no error in the node logs, and it happens after the coins cache flush (so not related to rocksdb). Restarting the tests

In D19801#450027, @PiRK wrote:

pthread lock: Invalid argument

Looks like a RocksDB error on shutdown.

Weird there is no error in the node logs, and it happens after the coins cache flush (so not related to rocksdb). Restarting the tests

I'm not 100% sure it is related to rocksdb, but google found only rocksdb related issues for this error.
So I assumed we were somehow still querying rocksdb via Chronik Electrum after the DB was closed. But I can't find in the codebase how/when (in what order wrt the karyon server) the db is closed

Failed tests logs:

====== Bitcoin ABC functional tests: chronik_electrum_blockchain.py ======

------- Stdout: -------
2026-04-09T16:13:50.856000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_161249_26269/chronik_electrum_blockchain_23
2026-04-09T16:13:53.727000Z TestFramework (INFO): Test the blockchain.headers.subscribe endpoint
2026-04-09T16:13:54.787000Z TestFramework (INFO): Test the blockchain.scripthash.subscribe endpoint
2026-04-09T16:13:59.462000Z TestFramework (INFO): Test the blockchain.address.get_scripthash endpoint
2026-04-09T16:13:59.464000Z TestFramework (INFO): Test the blockchain.estimatefee endpoint
2026-04-09T16:13:59.465000Z TestFramework (INFO): Test the blockchain.relayfee endpoint
2026-04-09T16:14:00.281000Z TestFramework (ERROR): Unexpected exception
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 89, in run_test
    self.test_relay_fee()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 1977, in test_relay_fee
    self.restart_node(0)
  File "/work/test/functional/test_framework/test_framework.py", line 646, in restart_node
    self.stop_node(i)
  File "/work/test/functional/test_framework/test_framework.py", line 632, in stop_node
    self.nodes[i].stop_node(expected_stderr, wait=wait)
  File "/work/test/functional/test_framework/test_node.py", line 551, in stop_node
    self.wait_until_stopped(expected_stderr=expected_stderr)
  File "/work/test/functional/test_framework/test_node.py", line 590, in wait_until_stopped
    wait_until_helper_internal(
  File "/work/test/functional/test_framework/util.py", line 325, in wait_until_helper_internal
    if predicate():
       ^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 591, in <lambda>
    lambda: self.is_node_stopped(**kwargs),
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 565, in is_node_stopped
    assert return_code == expected_ret_code, self._node_msg(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: [node 0] Node returned unexpected exit code (-6) vs (0) when stopping
2026-04-09T16:14:00.334000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
2026-04-09T16:14:00.334000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_161249_26269/chronik_electrum_blockchain_23
2026-04-09T16:14:00.334000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_161249_26269/chronik_electrum_blockchain_23/test_framework.log
2026-04-09T16:14:00.334000Z TestFramework (ERROR): 
2026-04-09T16:14:00.334000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260409_161249_26269/chronik_electrum_blockchain_23' to consolidate all logs
2026-04-09T16:14:00.335000Z TestFramework (ERROR): 
2026-04-09T16:14:00.335000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2026-04-09T16:14:00.335000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2026-04-09T16:14:00.335000Z TestFramework (ERROR):
------- Stderr: -------
[node 0] Cleaning up leftover process

Each failure log is accessible here:
Bitcoin ABC functional tests: chronik_electrum_blockchain.py

Fabien planned changes to this revision.Thu, Apr 9, 17:01

Tail of the build log:


---- test_history stdout ----
Error: HTTP request error

Caused by:
   0: error sending request for url (https://chronik.e.cash/script/p2pk/04678afdb0fe5548271967f1a67130b7105cd6a828e03909a67962e0ea1f61deb649f6bc3f4cef38c4f35504e51ec112de5c384df7ba0b8d578a4c702b6bf11d5f/confirmed-txs?page=0): connection closed before message completed
   1: connection closed before message completed

Location:
    /work/modules/bitcoinsuite-chronik-client/src/failover.rs:183:14

---- test_tx stdout ----
Error: HTTP request error

Caused by:
   0: error sending request for url (https://chronik.e.cash/tx/f4184fc596403b9d638783cf57adfe4c75c605f6356fbc91338530e9831e9e16): connection closed before message completed
   1: connection closed before message completed

Location:
    /work/modules/bitcoinsuite-chronik-client/src/failover.rs:183:14

---- test_tx_missing stdout ----

thread 'test_tx_missing' panicked at modules/bitcoinsuite-chronik-client/tests/test_chronik_client.rs:130:5:
assertion failed: `(left == right)`

Diff < left / right > :
<HttpRequestError
>ChronikError {
>    status_code: 404,
>    error: Error {
>        msg: "404: Transaction 0000000000000000000000000000000000000000000000000000000000000000 not found in the index",
>    },
>    error_msg: "404: Transaction 0000000000000000000000000000000000000000000000000000000000000000 not found in the index",
>}




failures:
    test_block
    test_block_txs
    test_blockchain_info
    test_blocks
    test_broadcast_tx
    test_broadcast_txs
    test_chronik_info
    test_history
    test_raw_tx
    test_raw_tx_missing
    test_slpv1_token
    test_slpv2_token
    test_tx
    test_tx_missing

test result: FAILED. 0 passed; 14 failed; 0 ignored; 0 measured; 0 filtered out; finished in 2.03s

error: test failed, to rerun pass `-p bitcoinsuite-chronik-client --test test_chronik_client`
Build build-bitcoinsuite-chronik-client failed with exit code 101

The build failure is unrelated, I'm investigating

This revision is now accepted and ready to land.Fri, Apr 10, 11:21

Failed tests logs:

====== Bitcoin ABC functional tests: chronik_electrum_blockchain.py ======

------- Stdout: -------
2026-04-10T11:50:21.086000Z TestFramework (INFO): Initializing test directory /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260410_114949_27849/chronik_electrum_blockchain_15
2026-04-10T11:50:25.930000Z TestFramework (INFO): Test the blockchain.headers.subscribe endpoint
2026-04-10T11:50:27.048000Z TestFramework (INFO): Test the blockchain.scripthash.subscribe endpoint
2026-04-10T11:50:32.260000Z TestFramework (INFO): Test the blockchain.address.get_scripthash endpoint
2026-04-10T11:50:32.263000Z TestFramework (INFO): Test the blockchain.estimatefee endpoint
2026-04-10T11:50:32.264000Z TestFramework (INFO): Test the blockchain.relayfee endpoint
2026-04-10T11:50:33.599000Z TestFramework (ERROR): Unexpected exception
Traceback (most recent call last):
  File "/work/test/functional/test_framework/test_framework.py", line 152, in main
    self._run_test_internal()
  File "/work/test/functional/test_framework/test_framework.py", line 142, in _run_test_internal
    self.run_test()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 89, in run_test
    self.test_relay_fee()
  File "/work/test/functional/chronik_electrum_blockchain.py", line 1977, in test_relay_fee
    self.restart_node(0)
  File "/work/test/functional/test_framework/test_framework.py", line 646, in restart_node
    self.stop_node(i)
  File "/work/test/functional/test_framework/test_framework.py", line 632, in stop_node
    self.nodes[i].stop_node(expected_stderr, wait=wait)
  File "/work/test/functional/test_framework/test_node.py", line 551, in stop_node
    self.wait_until_stopped(expected_stderr=expected_stderr)
  File "/work/test/functional/test_framework/test_node.py", line 590, in wait_until_stopped
    wait_until_helper_internal(
  File "/work/test/functional/test_framework/util.py", line 325, in wait_until_helper_internal
    if predicate():
       ^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 591, in <lambda>
    lambda: self.is_node_stopped(**kwargs),
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/work/test/functional/test_framework/test_node.py", line 565, in is_node_stopped
    assert return_code == expected_ret_code, self._node_msg(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
AssertionError: [node 0] Node returned unexpected exit code (-6) vs (0) when stopping
2026-04-10T11:50:33.651000Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
2026-04-10T11:50:33.651000Z TestFramework (WARNING): Not cleaning up dir /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260410_114949_27849/chronik_electrum_blockchain_15
2026-04-10T11:50:33.651000Z TestFramework (ERROR): Test failed. Test logging available at /work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260410_114949_27849/chronik_electrum_blockchain_15/test_framework.log
2026-04-10T11:50:33.652000Z TestFramework (ERROR): 
2026-04-10T11:50:33.652000Z TestFramework (ERROR): Hint: Call /work/test/functional/combine_logs.py '/work/abc-ci-builds/build-chronik-plugins/test/tmp/test_runner_โ‚ฟโ‚ต_๐Ÿƒ_20260410_114949_27849/chronik_electrum_blockchain_15' to consolidate all logs
2026-04-10T11:50:33.652000Z TestFramework (ERROR): 
2026-04-10T11:50:33.652000Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2026-04-10T11:50:33.652000Z TestFramework (ERROR): https://github.com/Bitcoin-ABC/bitcoin-abc/issues
2026-04-10T11:50:33.652000Z TestFramework (ERROR):
------- Stderr: -------
[node 0] Cleaning up leftover process

Each failure log is accessible here:
Bitcoin ABC functional tests: chronik_electrum_blockchain.py

This revision was landed with ongoing or failed builds.Fri, Apr 10, 11:59
This revision was automatically updated to reflect the committed changes.