Commit
This commit does not belong to any branch on this repository, and may belong to a fork outside of the repository.
tracing: fix recursive
register_callsite
deadlock (#2634)
## Motivation A deadlock exists when a collector's `register_callsite` method calls into code that also contains tracing instrumentation and triggers a second `register_callsite` call for the same callsite. This is because the current implementation of the `MacroCallsite` type holds a `core::sync::Once` which it uses to ensure that it is only added to the callsite registry a single time. This deadlock was fixed in v0.1.x in PR #2083, but the issue still exists on v0.2.x. ## Solution This branch forward-ports the solution from #2083. Rather than using a `core::sync::Once`, we now track the callsite's registration state directly in `MacroCallsite`. If a callsite has started registering, but has not yet completed, subsequent `register` calls will just immediately receive an `Interest::sometimes` until the registration has completed, rather than waiting to attempt their own registration. I've also forward-ported the tests for this that were added in #2083.
- Loading branch information
Showing
3 changed files
with
146 additions
and
13 deletions.
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,51 @@ | ||
use std::{sync::mpsc, thread, time::Duration}; | ||
use tracing::{ | ||
callsite, | ||
collect::{self, Collect, Interest}, | ||
metadata::Metadata, | ||
span, Event, | ||
}; | ||
|
||
#[test] | ||
fn rebuild_callsites_doesnt_deadlock() { | ||
pub struct EvilCollector; | ||
|
||
impl Collect for EvilCollector { | ||
fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest { | ||
tracing::info!(?meta, "registered a callsite"); | ||
Interest::always() | ||
} | ||
|
||
fn enabled(&self, _: &Metadata<'_>) -> bool { | ||
true | ||
} | ||
fn new_span(&self, _: &span::Attributes<'_>) -> span::Id { | ||
span::Id::from_u64(1) | ||
} | ||
fn record(&self, _: &span::Id, _: &span::Record<'_>) {} | ||
fn record_follows_from(&self, _: &span::Id, _: &span::Id) {} | ||
fn event(&self, _: &Event<'_>) {} | ||
fn enter(&self, _: &span::Id) {} | ||
fn exit(&self, _: &span::Id) {} | ||
fn current_span(&self) -> tracing_core::span::Current { | ||
unimplemented!() | ||
} | ||
} | ||
|
||
collect::set_global_default(EvilCollector).unwrap(); | ||
|
||
// spawn a thread, and assert it doesn't hang... | ||
let (tx, didnt_hang) = mpsc::channel(); | ||
let th = thread::spawn(move || { | ||
tracing::info!("hello world!"); | ||
callsite::rebuild_interest_cache(); | ||
tx.send(()).unwrap(); | ||
}); | ||
|
||
didnt_hang | ||
// Note: 60 seconds is *way* more than enough, but let's be generous in | ||
// case of e.g. slow CI machines. | ||
.recv_timeout(Duration::from_secs(60)) | ||
.expect("the thread must not have hung!"); | ||
th.join().expect("thread should join successfully"); | ||
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,49 @@ | ||
use std::{sync::mpsc, thread, time::Duration}; | ||
use tracing::{ | ||
collect::{self, Collect, Interest}, | ||
metadata::Metadata, | ||
span, Event, | ||
}; | ||
|
||
#[test] | ||
fn register_callsite_doesnt_deadlock() { | ||
pub struct EvilCollector; | ||
|
||
impl Collect for EvilCollector { | ||
fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest { | ||
tracing::info!(?meta, "registered a callsite"); | ||
Interest::always() | ||
} | ||
|
||
fn enabled(&self, _: &Metadata<'_>) -> bool { | ||
true | ||
} | ||
fn new_span(&self, _: &span::Attributes<'_>) -> span::Id { | ||
span::Id::from_u64(1) | ||
} | ||
fn record(&self, _: &span::Id, _: &span::Record<'_>) {} | ||
fn record_follows_from(&self, _: &span::Id, _: &span::Id) {} | ||
fn event(&self, _: &Event<'_>) {} | ||
fn enter(&self, _: &span::Id) {} | ||
fn exit(&self, _: &span::Id) {} | ||
fn current_span(&self) -> tracing_core::span::Current { | ||
unimplemented!() | ||
} | ||
} | ||
|
||
collect::set_global_default(EvilCollector).unwrap(); | ||
|
||
// spawn a thread, and assert it doesn't hang... | ||
let (tx, didnt_hang) = mpsc::channel(); | ||
let th = thread::spawn(move || { | ||
tracing::info!("hello world!"); | ||
tx.send(()).unwrap(); | ||
}); | ||
|
||
didnt_hang | ||
// Note: 60 seconds is *way* more than enough, but let's be generous in | ||
// case of e.g. slow CI machines. | ||
.recv_timeout(Duration::from_secs(60)) | ||
.expect("the thread must not have hung!"); | ||
th.join().expect("thread should join successfully"); | ||
} |