Repository navigation
TP hangs up too quickly (before fully sending SetupConnection.Error) #84
Description
Is there an existing issue for this?
- I have searched the existing issues
Current behaviour
the following Integration Test made me realize that TP doesn't respond with a SetupConnection.Error
#[tokio::test]
async fn debug_test() {
start_tracing();
use roles_logic_sv2::common_messages_sv2::{SetupConnection, Protocol};
use roles_logic_sv2::parsers::{AnyMessage, CommonMessages};
use integration_tests_sv2::start_sniffer;
use integration_tests_sv2::start_tracing;
use integration_tests_sv2::sniffer::{MessageDirection, ReplaceMessage};
use const_sv2::MESSAGE_TYPE_SETUP_CONNECTION;
use const_sv2::MESSAGE_TYPE_SETUP_CONNECTION_ERROR;
use std::convert::TryInto;
// start TemplateProvider
let (_tp, tp_addr) = integration_tests_sv2::start_template_provider(None);
// message we are going to replace on the request from Pool
let setup_connection = SetupConnection {
protocol: Protocol::MiningProtocol, // not supported by a TP
min_version: 2,
max_version: 2,
flags: 0,
endpoint_host: "0.0.0.0".to_string().into_bytes().try_into().unwrap(),
endpoint_port: 8081,
vendor: "".to_string().into_bytes().try_into().unwrap(),
hardware_version: "".to_string().into_bytes().try_into().unwrap(),
firmware: "".to_string().into_bytes().try_into().unwrap(),
device_id: "".to_string().into_bytes().try_into().unwrap(),
};
let message_replacement = AnyMessage::Common(CommonMessages::SetupConnection(setup_connection));
let intercept = ReplaceMessage::new(
MessageDirection::ToUpstream,
MESSAGE_TYPE_SETUP_CONNECTION,
message_replacement,
);
// sniffer that will be used to intercept the Pool's request and replace it with one that contains an unsupported protocol
let (sniffer_a, sniffer_a_addr) =
start_sniffer("A".to_string(), tp_addr, false, Some(intercept.into())).await;
// start pool
let _ = integration_tests_sv2::start_pool(Some(sniffer_a_addr)).await;
// prints None
println!("response from TP {:?}", sniffer_a.next_message_from_upstream());
// hangs until timeout
sniffer_a.wait_for_message_type(MessageDirection::ToDownstream, MESSAGE_TYPE_SETUP_CONNECTION_ERROR).await;
}According to the spec, I would expect it to return a SetupConnection.Error with error_code = unsupported-protocol
Expected behaviour
#[tokio::test]
async fn debug_test() {
start_tracing();
use roles_logic_sv2::common_messages_sv2::{SetupConnection, Protocol};
use roles_logic_sv2::parsers::{AnyMessage, CommonMessages};
use integration_tests_sv2::start_sniffer;
use integration_tests_sv2::start_tracing;
use integration_tests_sv2::sniffer::{MessageDirection, ReplaceMessage};
use const_sv2::MESSAGE_TYPE_SETUP_CONNECTION;
use const_sv2::MESSAGE_TYPE_SETUP_CONNECTION_ERROR;
use std::convert::TryInto;
// start TemplateProvider
let (_tp, tp_addr) = integration_tests_sv2::start_template_provider(None);
// message we are going to replace on the request from Pool
let setup_connection = SetupConnection {
protocol: Protocol::MiningProtocol, // not supported by a TP
min_version: 2,
max_version: 2,
flags: 0,
endpoint_host: "0.0.0.0".to_string().into_bytes().try_into().unwrap(),
endpoint_port: 8081,
vendor: "".to_string().into_bytes().try_into().unwrap(),
hardware_version: "".to_string().into_bytes().try_into().unwrap(),
firmware: "".to_string().into_bytes().try_into().unwrap(),
device_id: "".to_string().into_bytes().try_into().unwrap(),
};
let message_replacement = AnyMessage::Common(CommonMessages::SetupConnection(setup_connection));
let intercept = ReplaceMessage::new(
MessageDirection::ToUpstream,
MESSAGE_TYPE_SETUP_CONNECTION,
message_replacement,
);
// sniffer that will be used to intercept the Pool's request and replace it with one that contains an unsupported protocol
let (sniffer_a, sniffer_a_addr) =
start_sniffer("A".to_string(), tp_addr, false, Some(intercept.into())).await;
// start pool
let _ = integration_tests_sv2::start_pool(Some(sniffer_a_addr)).await;
// prints Some(SetupConnectionError)
println!("response from TP {:?}", sniffer_a.next_message_from_upstream());
// returns without error
sniffer_a.wait_for_message_type(MessageDirection::ToDownstream, MESSAGE_TYPE_SETUP_CONNECTION_ERROR).await;
}Steps to reproduce
Integration Tests described above
Relevant log output
No response
How did you obtain Bitcoin Core
Other
What version of Bitcoin Core are you using?
Operating system and version
MacOS Sonoma Version 14.4.1 (23E224)
Machine specifications
No response
Activity
Sjors commentedon Mar 17, 2025
There is a check that returns
SetupConnection.Errorwithunsupported-protocol:bitcoin/src/sv2/connman.cpp
Lines 279 to 285 in b4eb739
Perhaps it's checking for the wrong thing?
Can you also post the TP logs with
-debug=sv2 -loglevel=sv2:trace?plebhash commentedon Mar 17, 2025
logs from Integration Test:
I added some extra log lines into the pool source that should be triggered whenever it receives a
SetupConnection.Error, but I never see them being printed.this indicates that TP simply closes the connection before sending any response.
logs from TP:
Sjors commentedon Mar 17, 2025
Ah interesting, so we're hanging up too quickly:
That message never makes it.
@vasild any idea?
[-]TP doesn't reply with `SetupConnection.Error` when presented with an unsupported protocol request[/-][+]TP hangs up too quickly (before fully sending `SetupConnection.Error`)[/+]vasild commentedon Mar 19, 2025
The code is queuing the message for sending in
Sv2Client::m_send_messagesand then closes the socket immediately after that, before actually sending the queued message. What about closing the connection only if the send queue is empty? Untested:Sjors commentedon Mar 19, 2025
That seems reasonable, thanks! Will try.
Sjors commentedon Mar 20, 2025
@plebhash I added the above potential fix to the
sv2branch, can you try it?If it doesn't help, please let me know how to reproduce the integration test.
plebhash commentedon Mar 20, 2025
same behavior
in order to reproduce with integration tests, do the following:
cd test/integration-teststemplate-providerdirectory, e.g.:cargo t success_pool_template_provider_connectiontemplate-provider/bitcoin-sv2-tp-0.1.13/bin/bitcoindwith the binary you want to testtests/debug.rstests/debug.rscargo t debug_test -- --nocapturethe
wait_for_message_typehas a timeout of 1 minute, and here's what you will see in the logs:ideally, the test should exit gracefully without hitting the 60s timeout, and the
println!should haveSomeand notNoneSjors commentedon Mar 20, 2025
Where does
cargo tget the TP from?Note that there was a recent build system change in Bitcoin Core, so the binary is going to be in
build/bin/bitcoind, not inbuild/src/bitcoind. Make sure there's no dangling old version there.Sjors commentedon Mar 20, 2025
The test fails after a minute, but it did receive "SetupConnectionError with error code unsupported-protocol":
plebhash commentedon Mar 20, 2025
It fetches it from https://github.com/Sjors/bitcoin/releases. Currently it's pointing to v0.1.13 but we're about to merge a PR that points to v0.1.15.
That was my mistake when testing your changes. Sorry for that. I was basically using an old build.
That's just because the test is poorly structured, that was my bad.
Essentially
next_message_from_upstreampops the message from the queue where it's stored, and thenwait_for_message_typecannot find it. If we switch the order of these two lines the timeout goes away.Anyways, the problem has been solved. Thanks and apologies for the confusion!
Sjors commentedon Mar 20, 2025
Nice! 🎉
This doesn't seem like a big enough bug to warrant a fresh release, but I'll probably bake one next week - waiting for some more goodies to be merged into Bitcoin Core, so my rebase hell is lighter.
fixup: close connection only if the send queue is empty
Merge bitcoin#31576: test: Move `script_assets_tests` into its own suite
Merge pull request #84 from ajtowns/202507-inq29-apo
Squashed 'src/ipc/libmultiprocess/' changes from 3c69d12..27ada40809