1 use std::{
2 ptr,
3 sync::atomic::{AtomicPtr, Ordering},
4 thread::{self, JoinHandle},
5 time::Duration,
6 };
7
8 use tracing::Subscriber;
9 use tracing_core::{span, Metadata};
10
11 struct TestSubscriber {
12 creator_thread: String,
13 sleep: Duration,
14 callsite: AtomicPtr<Metadata<'static>>,
15 }
16
17 impl TestSubscriber {
new(sleep_micros: u64) -> Self18 fn new(sleep_micros: u64) -> Self {
19 let creator_thread = thread::current()
20 .name()
21 .unwrap_or("<unknown thread>")
22 .to_owned();
23 Self {
24 creator_thread,
25 sleep: Duration::from_micros(sleep_micros),
26 callsite: AtomicPtr::new(ptr::null_mut()),
27 }
28 }
29 }
30
31 impl Subscriber for TestSubscriber {
register_callsite(&self, metadata: &'static Metadata<'static>) -> tracing_core::Interest32 fn register_callsite(&self, metadata: &'static Metadata<'static>) -> tracing_core::Interest {
33 if !self.sleep.is_zero() {
34 thread::sleep(self.sleep);
35 }
36
37 self.callsite
38 .store(metadata as *const _ as *mut _, Ordering::SeqCst);
39 println!(
40 "{creator} from {thread:?}: register_callsite: {callsite:#?}",
41 creator = self.creator_thread,
42 callsite = metadata as *const _,
43 thread = thread::current().name(),
44 );
45 tracing_core::Interest::always()
46 }
47
event(&self, event: &tracing_core::Event<'_>)48 fn event(&self, event: &tracing_core::Event<'_>) {
49 let stored_callsite = self.callsite.load(Ordering::SeqCst);
50 let event_callsite: *mut Metadata<'static> = event.metadata() as *const _ as *mut _;
51
52 println!(
53 "{creator} from {thread:?}: event (with callsite): {event_callsite:#?} (stored callsite: {stored_callsite:#?})",
54 creator = self.creator_thread,
55 thread = thread::current().name(),
56 );
57
58 // This assert is the actual test.
59 assert_eq!(
60 stored_callsite, event_callsite,
61 "stored callsite: {stored_callsite:#?} does not match event \
62 callsite: {event_callsite:#?}. Was `event` called before \
63 `register_callsite`?"
64 );
65 }
66
enabled(&self, _metadata: &Metadata<'_>) -> bool67 fn enabled(&self, _metadata: &Metadata<'_>) -> bool {
68 true
69 }
new_span(&self, _span: &span::Attributes<'_>) -> span::Id70 fn new_span(&self, _span: &span::Attributes<'_>) -> span::Id {
71 span::Id::from_u64(0)
72 }
record(&self, _span: &span::Id, _values: &span::Record<'_>)73 fn record(&self, _span: &span::Id, _values: &span::Record<'_>) {}
record_follows_from(&self, _span: &span::Id, _follows: &span::Id)74 fn record_follows_from(&self, _span: &span::Id, _follows: &span::Id) {}
enter(&self, _span: &tracing_core::span::Id)75 fn enter(&self, _span: &tracing_core::span::Id) {}
exit(&self, _span: &tracing_core::span::Id)76 fn exit(&self, _span: &tracing_core::span::Id) {}
77 }
78
subscriber_thread(idx: usize, register_sleep_micros: u64) -> JoinHandle<()>79 fn subscriber_thread(idx: usize, register_sleep_micros: u64) -> JoinHandle<()> {
80 thread::Builder::new()
81 .name(format!("subscriber-{idx}"))
82 .spawn(move || {
83 // We use a sleep to ensure the starting order of the 2 threads.
84 let subscriber = TestSubscriber::new(register_sleep_micros);
85 let _subscriber_guard = tracing::subscriber::set_default(subscriber);
86
87 tracing::info!("event-from-{idx}", idx = idx);
88
89 // Wait a bit for everything to end (we don't want to remove the subscriber
90 // immediately because that will mix up the test).
91 thread::sleep(Duration::from_millis(100));
92 })
93 .expect("failed to spawn thread")
94 }
95
96 #[test]
event_before_register()97 fn event_before_register() {
98 let subscriber_1_register_sleep_micros = 100;
99 let subscriber_2_register_sleep_micros = 0;
100
101 let jh1 = subscriber_thread(1, subscriber_1_register_sleep_micros);
102
103 // This delay ensures that the event!() in the first thread is executed first.
104 thread::sleep(Duration::from_micros(50));
105 let jh2 = subscriber_thread(2, subscriber_2_register_sleep_micros);
106
107 jh1.join().expect("failed to join thread");
108 jh2.join().expect("failed to join thread");
109 }
110