Skip to content

Commit c5fa327

Browse files
hawkwkaffarell
authored andcommitted
core: add a limited form of the linked-list callsite registry for v0.1.x (tokio-rs#2083)
## Motivation Currently on `v0.1.x`, the global callsite registry is implemented as a `Mutex<Vec<&'static dyn Callsite>>`. This has a few downsides: * Every time a callsite is registered, the `Mutex` must be locked. This can cause a deadlock when a `register_callsite` implementation calls into code that _also_ registers a callsite. See tokio-rs#2020 for details. * Registering callsites is relatively slow and forces the program to synchronize on the callsite registry (and not on *individual* callsites). This means that if two threads are both registering totally different callsites, both threads must wait for the lock. Although this overhead is amortized over the entire rest of the program, it does have an impact in short-running applications where any given callsite may only be hit once or twice. * Memory allocation may occur while the registry is locked. This makes the use of `tracing` inside of memory allocators difficult or impossible. On the `master` branch (v0.2.x), PR tokio-rs#988 rewrote the callsite registry to use an intrusive atomic singly-linked list of `Callsite`s. This removed the need for locking the callsite registry, and made it possible to register callsites without ever allocating memory. Because the callsite registry on v0.2 will *never* allocate, this also makes it possible to compile `tracing-core` for `no_std` platforms without requiring `liballoc`. Unfortunately, however, we cannot use an identical implementation on v0.1.x, because using the intrusive linked-list registry for *all* callsites requires a breaking change to the `Callsite` trait (in order to add a way to get the callsite's linked-list node), which we cannot make on v0.1.x. ## Solution This branch adds a linked-list callsite registry for v0.1.x in a way that allows us to benefit from *some* of the advantages of this approach in a majority of cases. The trick is introducing a new `DefaultCallsite` type in `tracing-core` that implements the `Callsite` trait. This type can contain an intrusive list node, and *when a callsite is a `DefaultCallsite`*, we can register it without having to push it to the `Mutex<Vec<...>>`. The locked vec still _exists_, for `Callsite`s that are *not* `DefaultCallsite`s, so we can't remove the `liballoc` dependency, but in most cases, we can avoid the mutex and allocation. Naturally, `tracing` has been updated to use the `DefaultCallsite` type from `tracing-core`, so the `Vec` will only be used in the following cases: * User code has a custom implementation of the `Callsite` trait, which is [not terribly common][1]. * An older version of the `tracing` crate is in use. This fixes the deadlock described in tokio-rs#2020 when `DefaultCallsite`s are used. Additionally, it should reduce the performance impact and memory usage of the callsite registry. Furthermore, I've changed the subscriber registry so that a `RwLock<Vec<dyn Dispatch>>` is only used when there actually are multiple subscribers in use. When there's only a global default subscriber, we can once again avoid locking for the registry of subscribers. When the `std` feature is disabled, thread-local scoped dispatchers are unavailable, so the single global subscriber will always be used on `no_std`. We can make additional changes, such as the ones from tokio-rs#2020, to _also_ resolve potential deadlocks when non-default callsites are in use, but since this branch rewrites a lot of the callsite registry code, that should probably be done in a follow-up. [1]: https://cs.github.com/?scopeName=All+repos&scope=&q=%28%2Fimpl+.*Callsite%2F+AND+language%3Arust%29+NOT+%28path%3A%2Ftracing%2F**+OR+path%3A%2Ftracing-*%2F**+OR+path%3A%2Ftokio-trace*%2F**%29%29 Signed-off-by: Eliza Weisman <eliza@buoyant.io>
1 parent f04ba10 commit c5fa327

File tree

5 files changed

+86
-23
lines changed

5 files changed

+86
-23
lines changed

tracing-core/src/callsite.rs

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -124,6 +124,28 @@ pub trait Callsite: Sync {
124124
///
125125
/// [metadata]: super::metadata::Metadata
126126
fn metadata(&self) -> &Metadata<'_>;
127+
128+
/// This method is an *internal implementation detail* of `tracing-core`. It
129+
/// is *not* intended to be called or overridden from downstream code.
130+
///
131+
/// The `Private` type can only be constructed from within `tracing-core`.
132+
/// Because this method takes a `Private` as an argument, it cannot be
133+
/// called from (safe) code external to `tracing-core`. Because it must
134+
/// *return* a `Private`, the only valid implementation possible outside of
135+
/// `tracing-core` would have to always unconditionally panic.
136+
///
137+
/// THIS IS BY DESIGN. There is currently no valid reason for code outside
138+
/// of `tracing-core` to override this method.
139+
// TODO(eliza): this could be used to implement a public downcasting API
140+
// for `&dyn Callsite`s in the future.
141+
#[doc(hidden)]
142+
#[inline]
143+
fn private_type_id(&self, _: private::Private<()>) -> private::Private<TypeId>
144+
where
145+
Self: 'static,
146+
{
147+
private::Private(TypeId::of::<Self>())
148+
}
127149
}
128150

129151
/// Uniquely identifies a [`Callsite`]

tracing-core/src/dispatcher.rs

Lines changed: 5 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -134,14 +134,15 @@ use crate::stdlib::{
134134
fmt,
135135
sync::{
136136
atomic::{AtomicBool, AtomicUsize, Ordering},
137-
Arc, Weak,
137+
Arc,
138138
},
139139
};
140140

141141
#[cfg(feature = "std")]
142142
use crate::stdlib::{
143143
cell::{Cell, RefCell, RefMut},
144144
error,
145+
sync::Weak,
145146
};
146147

147148
/// `Dispatch` trace data to a [`Subscriber`].
@@ -387,6 +388,7 @@ fn get_global() -> Option<&'static Dispatch> {
387388
}
388389
}
389390

391+
#[cfg(feature = "std")]
390392
pub(crate) struct Registrar(Weak<dyn Subscriber + Send + Sync>);
391393

392394
impl Dispatch {
@@ -412,6 +414,7 @@ impl Dispatch {
412414
me
413415
}
414416

417+
#[cfg(feature = "std")]
415418
pub(crate) fn registrar(&self) -> Registrar {
416419
Registrar(Arc::downgrade(&self.subscriber))
417420
}
@@ -651,14 +654,8 @@ where
651654
}
652655
}
653656

657+
#[cfg(feature = "std")]
654658
impl Registrar {
655-
pub(crate) fn try_register(
656-
&self,
657-
metadata: &'static Metadata<'static>,
658-
) -> Option<subscriber::Interest> {
659-
self.0.upgrade().map(|s| s.register_callsite(metadata))
660-
}
661-
662659
pub(crate) fn upgrade(&self) -> Option<Dispatch> {
663660
self.0.upgrade().map(|subscriber| Dispatch { subscriber })
664661
}

tracing/src/lib.rs

Lines changed: 10 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -1164,20 +1164,16 @@ pub mod __macro_support {
11641164
}
11651165
}
11661166

1167-
impl Callsite for MacroCallsite {
1168-
fn set_interest(&self, interest: Interest) {
1169-
let interest = match () {
1170-
_ if interest.is_never() => 0,
1171-
_ if interest.is_always() => 2,
1172-
_ => 1,
1173-
};
1174-
self.interest.store(interest, Ordering::SeqCst);
1175-
}
1176-
1177-
#[inline(always)]
1178-
fn metadata(&self) -> &Metadata<'static> {
1179-
self.meta
1180-
}
1167+
/// /!\ WARNING: This is *not* a stable API! /!\
1168+
/// This function, and all code contained in the `__macro_support` module, is
1169+
/// a *private* API of `tracing`. It is exposed publicly because it is used
1170+
/// by the `tracing` macros, but it is not part of the stable versioned API.
1171+
/// Breaking changes to this module may occur in small-numbered versions
1172+
/// without warning.
1173+
#[inline]
1174+
#[cfg(not(feature = "log"))]
1175+
pub fn __disabled_span(_: &'static Metadata<'static>) -> crate::Span {
1176+
crate::Span::none()
11811177
}
11821178

11831179
impl fmt::Debug for MacroCallsite {

tracing/src/macros.rs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3090,13 +3090,14 @@ macro_rules! __tracing_log {
30903090
use $crate::log;
30913091
let level = $crate::level_to_log!($level);
30923092
if level <= log::max_level() {
3093+
let meta = $callsite.metadata();
30933094
let log_meta = log::Metadata::builder()
30943095
.level(level)
30953096
.target(__CALLSITE.metadata().target())
30963097
.build();
30973098
let logger = log::logger();
30983099
if logger.enabled(&log_meta) {
3099-
$callsite.log(logger, log_meta, $value_set)
3100+
$crate::__macro_support::__tracing_log(meta, logger, log_meta, $value_set)
31003101
}
31013102
}
31023103
}}
Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,47 @@
1+
use std::{sync::mpsc, thread, time::Duration};
2+
use tracing::{
3+
metadata::Metadata,
4+
span,
5+
subscriber::{self, Interest, Subscriber},
6+
Event,
7+
};
8+
9+
#[test]
10+
fn register_callsite_doesnt_deadlock() {
11+
pub struct EvilSubscriber;
12+
13+
impl Subscriber for EvilSubscriber {
14+
fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest {
15+
tracing::info!(?meta, "registered a callsite");
16+
Interest::always()
17+
}
18+
19+
fn enabled(&self, _: &Metadata<'_>) -> bool {
20+
true
21+
}
22+
fn new_span(&self, _: &span::Attributes<'_>) -> span::Id {
23+
span::Id::from_u64(1)
24+
}
25+
fn record(&self, _: &span::Id, _: &span::Record<'_>) {}
26+
fn record_follows_from(&self, _: &span::Id, _: &span::Id) {}
27+
fn event(&self, _: &Event<'_>) {}
28+
fn enter(&self, _: &span::Id) {}
29+
fn exit(&self, _: &span::Id) {}
30+
}
31+
32+
subscriber::set_global_default(EvilSubscriber).unwrap();
33+
34+
// spawn a thread, and assert it doesn't hang...
35+
let (tx, didnt_hang) = mpsc::channel();
36+
let th = thread::spawn(move || {
37+
tracing::info!("hello world!");
38+
tx.send(()).unwrap();
39+
});
40+
41+
didnt_hang
42+
// Note: 60 seconds is *way* more than enough, but let's be generous in
43+
// case of e.g. slow CI machines.
44+
.recv_timeout(Duration::from_secs(60))
45+
.expect("the thread must not have hung!");
46+
th.join().expect("thread should join successfully");
47+
}

0 commit comments

Comments
 (0)