CI: `blockchain::esplora::bdk_blockchain_tests::test_sync_stop_gap_20` occationally fails

[evanlinjin]

Describe the bug

CI: blockchain::esplora::bdk_blockchain_tests::test_sync_stop_gap_20 occationally fails.

The command that fails

$ cargo test --no-default-features --features test-esplora,use-esplora-ureq,verify esplora::bdk_blockchain_tests

Occurences

• https://github.com/bitcoindevkit/bdk/runs/7163681328?check_suite_focus=true

[rajarshimaitra]

I have been witnessing few occasional failures in blockchain tests in my local too.. Seems like some kind of resource blocking thingy happening somewhere?? I was seeing "resource unavailable" errors few days ago when running blockchian tests all together.. Which I can't seem to reproduce anymore.. Could be something related??

From the error message it seems something got timed out while waiting for some stuffs..

[evanlinjin]

I have been witnessing few occasional failures in blockchain tests in my local too.. Seems like some kind of resource blocking thingy happening somewhere?? I was seeing "resource unavailable" errors few days ago when running blockchian tests all together.. Which I can't seem to reproduce anymore.. Could be something related??

From the error message it seems something got timed out while waiting for some stuffs..

Same here. Would it make sense to implement some retry logic/exponential backoff?

We can keep track of the errors and where they occur here.

[rajarshimaitra]

Same here. Would it make sense to implement some retry logic/exponential backoff?

We do have an exponential pole at electrum calls

bdk/src/testutils/blockchain_tests.rs

Lines 345 to 359 in 063d51f

	fn exponential_backoff_poll<T, F>(mut poll: F) -> T
	where
	F: FnMut() -> Option<T>,
	{
	let mut delay = Duration::from_millis(64);
	loop {
	match poll() {
	Some(data) => break data,
	None if delay.as_millis() < 512 => delay = delay.mul_f32(2.0),
	None => {}
	}
	std::thread::sleep(delay);
	}
	}

To me it seems for some reason the electrum calls isn't returning and some resources are not being free??

The error seems to disappear in single test runs.. Only when I run all the blockchian tests together..

[afilini]

This looks like a bug in electrsd:

[2022-07-02T18:30:55Z ERROR electrsd] early exit with: ExitStatus(unix_wait_status(134))

Maybe it doesn't handle too much load well. I'll see if I can somehow attach a debugger and reproduce.

[evanlinjin]

This is a one-off failure, not sure if it is related.

failures:

---- blockchain::esplora::bdk_blockchain_tests::test_double_spend stdout ----
thread 'blockchain::esplora::bdk_blockchain_tests::test_double_spend' panicked at 'called `Result::unwrap()` on an `Err` value: JSON(Error("expected value", line: 1, column: 1))', src/testutils/blockchain_tests.rs:65:56
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    blockchain::esplora::bdk_blockchain_tests::test_double_spend

[afilini]

Maybe it's related to this? bitcoindevkit/rust-electrum-client#67

[evanlinjin]

failures:

---- blockchain::esplora::bdk_blockchain_tests::test_sync_address_index_should_not_decrement stdout ----
thread 'blockchain::esplora::bdk_blockchain_tests::test_sync_address_index_should_not_decrement' panicked at 'called `Result::unwrap()` on an `Err` value: EarlyExit(ExitStatus(unix_wait_status(134)))', src/testutils/blockchain_tests.rs:36:75
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace


failures:
    blockchain::esplora::bdk_blockchain_tests::test_sync_address_index_should_not_decrement

test result: FAILED. 256 passed; 1 failed; 5 ignored; 0 measured; 0 filtered out; finished in 6.41s

[evanlinjin]

 failures:
error: test failed, to rerun pass '--lib'
---- blockchain::esplora::bdk_blockchain_tests::test_tx_chain stdout ----
thread 'blockchain::esplora::bdk_blockchain_tests::test_tx_chain' panicked at 'called `Result::unwrap()` on an `Err` value: EarlyExit(ExitStatus(unix_wait_status(134)))', src/testutils/blockchain_tests.rs:36:75
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
failures:
    blockchain::esplora::bdk_blockchain_tests::test_tx_chain

[evanlinjin]

---- blockchain::electrum::test::bdk_blockchain_tests::test_sync_bump_fee_basic stdout ----
thread 'blockchain::electrum::test::bdk_blockchain_tests::test_sync_bump_fee_basic' panicked at 'called `Result::unwrap()` on an `Err` value: IOError(Os { code: 104, kind: ConnectionReset, message: "Connection reset by peer" })', src/testutils/blockchain_tests.rs:65:56
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

[evanlinjin]

This one is the craziest yet: https://gist.github.com/evanlinjin/3079251115e64edc355f46d0d63edb1e

[rajarshimaitra]

Yes.. I have been seeing this one in my local..

[evanlinjin]

Yes.. I have been seeing this one in my local..

I mean if the error states "Resource TEMPORARILY unavailable", I think we can safely wrap the calls with exponential back-off logic. I did see a function in the tests for exponential back-off, so maybe we can reuse that.

[afilini]

My guess: the tcp send buffer gets filled up because core can't process all those requests at once. Increasing the number of threads would probably help.

Source https://linux.die.net/man/2/send:

When the message does not fit into the send buffer of the socket, send() normally blocks, unless the socket has been placed in nonblocking I/O mode. In nonblocking mode it would fail with the error EAGAIN or EWOULDBLOCK in this case