From 5dd8bd394422c80b7737fa00d92be3347924d311 Mon Sep 17 00:00:00 2001 From: Floris Bruynooghe Date: Tue, 17 Sep 2024 14:48:21 +0200 Subject: [PATCH] fix(iroh-blobs): preserve tracing subscriber in the LocalPool (#2735) ## Description This preserves the tracing subscriber that is installed in the current thread when the LocalPool is created. It then installs it into every thread managed by the pool, ensuring that tracing output from the pool is preserved. ## Breaking Changes Why is this even pub? But fine: `iroh_blobs::util::local_pool::LocalPool` will now install the tracing subscriber of the thread creating the pool, into each thread managed by the pool. Practically this should not break any code already managing their tracing subscribers either manually inside tasks or by setting a global subscriber before creating the pool. But if you really liked the behaviour of swallowing the logs on doing this it's a breaking change. ## Notes & open questions Maybe this should be configurable, though since this is just an internal tool for us I think we're fine just always having this behaviour. Fixes #2577 Replaces #2589 ## Change checklist - [x] Self-review. - [x] Documentation updates following the [style guide](https://rust-lang.github.io/rfcs/1574-more-api-documentation-conventions.html#appendix-a-full-conventions-text), if relevant. - [x] Tests if relevant. - [x] All breaking changes documented. --- iroh-blobs/src/util/local_pool.rs | 31 +++++++++++++++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/iroh-blobs/src/util/local_pool.rs b/iroh-blobs/src/util/local_pool.rs index 4465d86b66..d6492e144c 100644 --- a/iroh-blobs/src/util/local_pool.rs +++ b/iroh-blobs/src/util/local_pool.rs @@ -41,6 +41,9 @@ enum Message { /// and then wait for all threads to finish executing their loops before /// returning. This means that all currently executing tasks will be allowed to /// run to completion. +/// +/// The pool will install the [`tracing::Subscriber`] which was set on the current thread of +/// where it was created as the default subscriber in all spawned threads. #[derive(Debug)] pub struct LocalPool { threads: Vec>, @@ -165,9 +168,11 @@ impl LocalPool { shutdown_sem: Arc, handle: tokio::runtime::Handle, ) -> std::io::Result> { + let tracing_dispatcher = tracing::dispatcher::get_default(|dispatcher| dispatcher.clone()); std::thread::Builder::new() .name(thread_name) .spawn(move || { + let _tracing_guard = tracing::dispatcher::set_default(&tracing_dispatcher); let mut s = JoinSet::new(); let mut last_panic = None; let mut handle_join = |res: Option>| -> bool { @@ -536,6 +541,8 @@ impl CancellationToken { mod tests { use std::{sync::atomic::AtomicU64, time::Duration}; + use tracing::info; + use super::*; /// A struct that simulates a long running drop operation @@ -577,6 +584,30 @@ mod tests { x.forget(); } + #[tokio::test] + async fn test_tracing() { + // This test wants to make sure that logging inside the pool propagates to the + // tracing subscriber that was set for the current thread at the time the pool was + // created. + // + // Look, there should be a custom tracing subscriber here that allows us to inspect + // the messages sent to it so we can verify it received all the messages. But have + // you ever tried to implement a tracing subscriber? In the mean time this test will + // just always pass, to really see the test run it with: + // + // cargo nextest run -p iroh-blobs local_pool::tests::test_tracing --success-output final + // + // and eyeball the output. yolo + let _guard = iroh_test::logging::setup(); + info!("hello from the test"); + let pool = LocalPool::single(); + pool.spawn(|| async move { + info!("hello from the pool"); + }) + .await + .unwrap(); + } + #[tokio::test] async fn test_drop() { let _ = tracing_subscriber::fmt::try_init();