Skip to content

fix(tests): prevent span accumulation across async tasks #2007

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.

Sign up for GitHub

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

Merged
merged 4 commits into from
Oct 27, 2025
Merged

fix(tests): prevent span accumulation across async tasks #2007

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
aeb0ca0
fix(tests): prevent span accumulation across async tasks
iduartgomez Oct 27, 2025
4714994
Merge branch 'main' into fix/test-span-accumulation
sanity Oct 27, 2025
4c56827
Merge branch 'main' into fix/test-span-accumulation
sanity Oct 27, 2025
c963670
Merge branch 'main' into fix/test-span-accumulation
sanity Oct 27, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
75 changes: 13 additions & 62 deletions crates/core/src/test_utils.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,59 +42,6 @@ pub fn set_peer_id(peer_id: impl Into<String>) {
tracing::Span::current().record("test_node", peer_id);
}

/// Create a span with a peer identifier that will be included in all logs
/// within the span.
///
/// # Example
/// ```ignore
/// async fn start_gateway() {
/// let _span = with_peer_id("gateway");
/// tracing::info!("Starting gateway"); // Will include test_node="gateway"
/// // ... gateway initialization
/// }
///
/// async fn start_peer(id: usize) {
/// let _span = with_peer_id(format!("peer-{}", id));
/// tracing::info!("Starting peer"); // Will include test_node="peer-N"
/// // ... peer initialization
/// }
/// ```
///
/// # Note
/// The field name `test_node` is used to avoid conflicts with the production
/// `peer` field which contains the actual cryptographic PeerId.
///
/// # Important
/// The returned guard must be held for the entire duration you want the peer ID
/// to be active. When the guard is dropped, the span exits.
#[must_use = "Span guard must be held for the duration of the operation"]
pub fn with_peer_id(peer_id: impl Into<String>) -> impl Drop {
let peer_id = peer_id.into();
tracing::info_span!("test_peer", test_node = %peer_id).entered()
}

/// Execute a function with tracing enabled.
///
/// This function is now deprecated in favor of using the `#[test_log::test]` macro
/// which provides better integration with test frameworks and only shows logs for
/// failing tests.
///
/// # Deprecated
/// Use `#[test_log::test]` or `#[test_log::test(tokio::test)]` instead.
#[deprecated(
since = "0.1.0",
note = "Use #[test_log::test] or #[test_log::test(tokio::test)] instead"
)]
pub fn with_tracing<T>(f: impl FnOnce() -> T) -> T {
let subscriber = tracing_subscriber::fmt()
.with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
.with_line_number(true)
.with_file(true)
.with_span_events(tracing_subscriber::fmt::format::FmtSpan::CLOSE)
.finish();
tracing::subscriber::with_default(subscriber, f)
}

/// Format for test logger output
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub enum LogFormat {
Expand All @@ -113,28 +60,32 @@ pub enum LogFormat {
///
/// # Peer Identification
///
/// For multi-peer tests, use the `with_peer_id()` function in each async block:
/// For multi-peer tests, use `.instrument()` to attach isolated spans:
/// ```ignore
/// use tracing::Instrument;
///
/// let gateway = async {
/// let _span = with_peer_id("gateway");
/// tracing::info!("Gateway starting");
/// };
/// }
/// .instrument(tracing::info_span!("test_peer", test_node = "gateway"));
/// ```
///
/// # Example
/// ```ignore
/// use tracing::Instrument;
///
/// #[tokio::test]
/// async fn my_test() -> anyhow::Result<()> {
/// let _logger = TestLogger::new()
/// .with_json()
/// .with_level("debug")
/// .init();
///
/// // For multi-peer tests, use with_peer_id() in each async block
/// // For multi-peer tests, use .instrument() to isolate spans
/// let gateway = async {
/// let _span = with_peer_id("gateway");
/// tracing::info!("Gateway starting");
/// };
/// }
/// .instrument(tracing::info_span!("test_peer", test_node = "gateway"));
///
/// Ok(())
/// }
Expand Down Expand Up @@ -778,7 +729,7 @@ mod test {
fn test_logger_with_peer_id() {
let _logger = TestLogger::new().with_level("info").init();

let _span = with_peer_id("test-peer");
let _span = tracing::info_span!("test_peer", test_node = "test-peer").entered();

tracing::info!("Message with peer ID");
}
Expand Down Expand Up @@ -820,7 +771,7 @@ mod test {
async fn test_logger_async() {
let _logger = TestLogger::new().with_json().with_level("debug").init();

let _span = with_peer_id("async-peer");
let _span = tracing::info_span!("test_peer", test_node = "async-peer").entered();

tracing::info!("Async test message");
tokio::time::sleep(tokio::time::Duration::from_millis(10)).await;
Expand All @@ -836,7 +787,7 @@ mod test {
.init();

// Create a span with test_node field
let _span = with_peer_id("test-gateway");
let _span = tracing::info_span!("test_peer", test_node = "test-gateway").entered();

tracing::info!("Message from gateway");

Expand Down
15 changes: 8 additions & 7 deletions crates/core/tests/connectivity.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ use freenet::{
dev_tool::TransportKeypair,
local_node::NodeConfig,
server::serve_gateway,
test_utils::{self, make_get, make_put, with_peer_id},
test_utils::{self, make_get, make_put},
};
use freenet_stdlib::{
client_api::{ClientRequest, ContractResponse, HostResponse, WebApi},
Expand All @@ -20,6 +20,7 @@ use std::{
use testresult::TestResult;
use tokio::select;
use tokio_tungstenite::connect_async;
use tracing::Instrument;

static RNG: LazyLock<Mutex<rand::rngs::StdRng>> = LazyLock::new(|| {
Mutex::new(rand::rngs::StdRng::from_seed(
Expand Down Expand Up @@ -144,7 +145,6 @@ async fn test_gateway_reconnection() -> TestResult {

// Start gateway node with peer identification
let gateway = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = gateway_config.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -154,11 +154,11 @@ async fn test_gateway_reconnection() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

// Start peer node with peer identification
let peer = async move {
let _span = with_peer_id("peer-1");
tracing::info!("Starting peer node");
let config = peer_config.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -168,6 +168,7 @@ async fn test_gateway_reconnection() -> TestResult {
tracing::info!("Peer node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "peer-1"))
.boxed_local();

// Main test logic
Expand Down Expand Up @@ -374,7 +375,6 @@ async fn test_basic_gateway_connectivity() -> TestResult {

// Start the gateway node with peer identification
let gateway = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = config.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -384,6 +384,7 @@ async fn test_basic_gateway_connectivity() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

// Test logic
Expand Down Expand Up @@ -646,7 +647,6 @@ async fn test_three_node_network_connectivity() -> TestResult {

// Start gateway node with peer identification
let gateway = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = gateway_config.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -656,11 +656,11 @@ async fn test_three_node_network_connectivity() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

// Start first peer node with peer identification
let peer1 = async move {
let _span = with_peer_id("peer-1");
tokio::time::sleep(Duration::from_secs(5)).await;
tracing::info!("Starting peer 1 node");
let config = peer1_config.build().await?;
Expand All @@ -671,11 +671,11 @@ async fn test_three_node_network_connectivity() -> TestResult {
tracing::info!("Peer 1 node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "peer-1"))
.boxed_local();

// Start second peer node with peer identification
let peer2 = async move {
let _span = with_peer_id("peer-2");
tokio::time::sleep(Duration::from_secs(10)).await;
tracing::info!("Starting peer 2 node");
let config = peer2_config.build().await?;
Expand All @@ -686,6 +686,7 @@ async fn test_three_node_network_connectivity() -> TestResult {
tracing::info!("Peer 2 node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "peer-2"))
.boxed_local();

// Main test logic
Expand Down
16 changes: 8 additions & 8 deletions crates/core/tests/operations.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ use freenet::{
server::serve_gateway,
test_utils::{
self, load_delegate, make_get, make_put, make_subscribe, make_update,
verify_contract_exists, with_peer_id, TestLogger,
verify_contract_exists, TestLogger,
},
};
use freenet_stdlib::{
Expand Down Expand Up @@ -170,7 +170,6 @@ async fn test_put_contract() -> TestResult {

std::mem::drop(ws_api_port_socket_a); // Free the port so it does not fail on initialization
let node_a = async move {
let _span = with_peer_id("peer-a");
tracing::info!("Starting peer A node");
let config = config_a.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -180,12 +179,12 @@ async fn test_put_contract() -> TestResult {
tracing::info!("Peer A node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "peer-a"))
.boxed_local();

std::mem::drop(network_socket_b); // Free the port so it does not fail on initialization
std::mem::drop(ws_api_port_socket_b);
let node_b = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = config_b.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -195,6 +194,7 @@ async fn test_put_contract() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

let test = tokio::time::timeout(Duration::from_secs(180), async {
Expand Down Expand Up @@ -586,7 +586,6 @@ async fn test_put_merge_persists_state() -> TestResult {
// Start node A (peer)
std::mem::drop(ws_api_port_socket_a);
let node_a = async move {
let _span = with_peer_id("peer-a");
tracing::info!("Starting peer A node");
let config = config_a.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -596,13 +595,13 @@ async fn test_put_merge_persists_state() -> TestResult {
tracing::info!("Peer A node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "peer-a"))
.boxed_local();

// Start node B (gateway)
std::mem::drop(network_socket_b);
std::mem::drop(ws_api_port_socket_b);
let node_b = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = config_b.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -612,6 +611,7 @@ async fn test_put_merge_persists_state() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

let test = tokio::time::timeout(Duration::from_secs(180), async {
Expand Down Expand Up @@ -868,7 +868,6 @@ async fn test_multiple_clients_subscription() -> TestResult {

// Start node A (first client)
let node_a = async move {
let _span = with_peer_id("node-a");
tracing::info!("Starting node A");
let config = config_a.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -878,11 +877,11 @@ async fn test_multiple_clients_subscription() -> TestResult {
tracing::info!("Node A running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "node-a"))
.boxed_local();

// Start GW node
let node_gw = async {
let _span = with_peer_id("gateway");
tracing::info!("Starting gateway node");
let config = config_gw.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -892,11 +891,11 @@ async fn test_multiple_clients_subscription() -> TestResult {
tracing::info!("Gateway node running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "gateway"))
.boxed_local();

// Start node B (second client)
let node_b = async {
let _span = with_peer_id("node-b");
tracing::info!("Starting node B");
let config = config_b.build().await?;
let node = NodeConfig::new(config.clone())
Expand All @@ -906,6 +905,7 @@ async fn test_multiple_clients_subscription() -> TestResult {
tracing::info!("Node B running");
node.run().await
}
.instrument(tracing::info_span!("test_peer", test_node = "node-b"))
.boxed_local();

let test = tokio::time::timeout(Duration::from_secs(600), async {
Expand Down
Loading