1 #![allow(missing_docs)]
2 use super::{
3 event::MockEvent,
4 field as mock_field,
5 span::{MockSpan, NewSpan},
6 };
7 use std::{
8 collections::{HashMap, VecDeque},
9 fmt,
10 sync::{
11 atomic::{AtomicUsize, Ordering},
12 Arc, Mutex,
13 },
14 thread,
15 };
16 use tracing::{
17 level_filters::LevelFilter,
18 span::{self, Attributes, Id},
19 subscriber::Interest,
20 Event, Metadata, Subscriber,
21 };
22
23 #[derive(Debug, Eq, PartialEq)]
24 pub enum Expect {
25 Event(MockEvent),
26 FollowsFrom {
27 consequence: MockSpan,
28 cause: MockSpan,
29 },
30 Enter(MockSpan),
31 Exit(MockSpan),
32 CloneSpan(MockSpan),
33 DropSpan(MockSpan),
34 Visit(MockSpan, mock_field::Expect),
35 NewSpan(NewSpan),
36 Nothing,
37 }
38
39 struct SpanState {
40 name: &'static str,
41 refs: usize,
42 meta: &'static Metadata<'static>,
43 }
44
45 struct Running<F: Fn(&Metadata<'_>) -> bool> {
46 spans: Mutex<HashMap<Id, SpanState>>,
47 expected: Arc<Mutex<VecDeque<Expect>>>,
48 current: Mutex<Vec<Id>>,
49 ids: AtomicUsize,
50 max_level: Option<LevelFilter>,
51 filter: F,
52 name: String,
53 }
54
55 pub struct MockSubscriber<F: Fn(&Metadata<'_>) -> bool> {
56 expected: VecDeque<Expect>,
57 max_level: Option<LevelFilter>,
58 filter: F,
59 name: String,
60 }
61
62 pub struct MockHandle(Arc<Mutex<VecDeque<Expect>>>, String);
63
mock() -> MockSubscriber<fn(&Metadata<'_>) -> bool>64 pub fn mock() -> MockSubscriber<fn(&Metadata<'_>) -> bool> {
65 MockSubscriber {
66 expected: VecDeque::new(),
67 filter: (|_: &Metadata<'_>| true) as for<'r, 's> fn(&'r Metadata<'s>) -> _,
68 max_level: None,
69 name: thread::current()
70 .name()
71 .unwrap_or("mock_subscriber")
72 .to_string(),
73 }
74 }
75
76 impl<F> MockSubscriber<F>
77 where
78 F: Fn(&Metadata<'_>) -> bool + 'static,
79 {
80 /// Overrides the name printed by the mock subscriber's debugging output.
81 ///
82 /// The debugging output is displayed if the test panics, or if the test is
83 /// run with `--nocapture`.
84 ///
85 /// By default, the mock subscriber's name is the name of the test
86 /// (*technically*, the name of the thread where it was created, which is
87 /// the name of the test unless tests are run with `--test-threads=1`).
88 /// When a test has only one mock subscriber, this is sufficient. However,
89 /// some tests may include multiple subscribers, in order to test
90 /// interactions between multiple subscribers. In that case, it can be
91 /// helpful to give each subscriber a separate name to distinguish where the
92 /// debugging output comes from.
named(self, name: impl ToString) -> Self93 pub fn named(self, name: impl ToString) -> Self {
94 Self {
95 name: name.to_string(),
96 ..self
97 }
98 }
99
enter(mut self, span: MockSpan) -> Self100 pub fn enter(mut self, span: MockSpan) -> Self {
101 self.expected.push_back(Expect::Enter(span));
102 self
103 }
104
follows_from(mut self, consequence: MockSpan, cause: MockSpan) -> Self105 pub fn follows_from(mut self, consequence: MockSpan, cause: MockSpan) -> Self {
106 self.expected
107 .push_back(Expect::FollowsFrom { consequence, cause });
108 self
109 }
110
event(mut self, event: MockEvent) -> Self111 pub fn event(mut self, event: MockEvent) -> Self {
112 self.expected.push_back(Expect::Event(event));
113 self
114 }
115
exit(mut self, span: MockSpan) -> Self116 pub fn exit(mut self, span: MockSpan) -> Self {
117 self.expected.push_back(Expect::Exit(span));
118 self
119 }
120
clone_span(mut self, span: MockSpan) -> Self121 pub fn clone_span(mut self, span: MockSpan) -> Self {
122 self.expected.push_back(Expect::CloneSpan(span));
123 self
124 }
125
126 #[allow(deprecated)]
drop_span(mut self, span: MockSpan) -> Self127 pub fn drop_span(mut self, span: MockSpan) -> Self {
128 self.expected.push_back(Expect::DropSpan(span));
129 self
130 }
131
done(mut self) -> Self132 pub fn done(mut self) -> Self {
133 self.expected.push_back(Expect::Nothing);
134 self
135 }
136
record<I>(mut self, span: MockSpan, fields: I) -> Self where I: Into<mock_field::Expect>,137 pub fn record<I>(mut self, span: MockSpan, fields: I) -> Self
138 where
139 I: Into<mock_field::Expect>,
140 {
141 self.expected.push_back(Expect::Visit(span, fields.into()));
142 self
143 }
144
new_span<I>(mut self, new_span: I) -> Self where I: Into<NewSpan>,145 pub fn new_span<I>(mut self, new_span: I) -> Self
146 where
147 I: Into<NewSpan>,
148 {
149 self.expected.push_back(Expect::NewSpan(new_span.into()));
150 self
151 }
152
with_filter<G>(self, filter: G) -> MockSubscriber<G> where G: Fn(&Metadata<'_>) -> bool + 'static,153 pub fn with_filter<G>(self, filter: G) -> MockSubscriber<G>
154 where
155 G: Fn(&Metadata<'_>) -> bool + 'static,
156 {
157 MockSubscriber {
158 expected: self.expected,
159 filter,
160 max_level: self.max_level,
161 name: self.name,
162 }
163 }
164
with_max_level_hint(self, hint: impl Into<LevelFilter>) -> Self165 pub fn with_max_level_hint(self, hint: impl Into<LevelFilter>) -> Self {
166 Self {
167 max_level: Some(hint.into()),
168 ..self
169 }
170 }
171
run(self) -> impl Subscriber172 pub fn run(self) -> impl Subscriber {
173 let (subscriber, _) = self.run_with_handle();
174 subscriber
175 }
176
run_with_handle(self) -> (impl Subscriber, MockHandle)177 pub fn run_with_handle(self) -> (impl Subscriber, MockHandle) {
178 let expected = Arc::new(Mutex::new(self.expected));
179 let handle = MockHandle(expected.clone(), self.name.clone());
180 let subscriber = Running {
181 spans: Mutex::new(HashMap::new()),
182 expected,
183 current: Mutex::new(Vec::new()),
184 ids: AtomicUsize::new(1),
185 filter: self.filter,
186 max_level: self.max_level,
187 name: self.name,
188 };
189 (subscriber, handle)
190 }
191 }
192
193 impl<F> Subscriber for Running<F>
194 where
195 F: Fn(&Metadata<'_>) -> bool + 'static,
196 {
enabled(&self, meta: &Metadata<'_>) -> bool197 fn enabled(&self, meta: &Metadata<'_>) -> bool {
198 println!("[{}] enabled: {:#?}", self.name, meta);
199 let enabled = (self.filter)(meta);
200 println!("[{}] enabled -> {}", self.name, enabled);
201 enabled
202 }
203
register_callsite(&self, meta: &'static Metadata<'static>) -> Interest204 fn register_callsite(&self, meta: &'static Metadata<'static>) -> Interest {
205 println!("[{}] register_callsite: {:#?}", self.name, meta);
206 if self.enabled(meta) {
207 Interest::always()
208 } else {
209 Interest::never()
210 }
211 }
212
max_level_hint(&self) -> Option<LevelFilter>213 fn max_level_hint(&self) -> Option<LevelFilter> {
214 println!("[{}] max_level_hint -> {:?}", self.name, self.max_level);
215 self.max_level
216 }
217
record(&self, id: &Id, values: &span::Record<'_>)218 fn record(&self, id: &Id, values: &span::Record<'_>) {
219 let spans = self.spans.lock().unwrap();
220 let mut expected = self.expected.lock().unwrap();
221 let span = spans
222 .get(id)
223 .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id));
224 println!(
225 "[{}] record: {}; id={:?}; values={:?};",
226 self.name, span.name, id, values
227 );
228 let was_expected = matches!(expected.front(), Some(Expect::Visit(_, _)));
229 if was_expected {
230 if let Expect::Visit(expected_span, mut expected_values) = expected.pop_front().unwrap()
231 {
232 if let Some(name) = expected_span.name() {
233 assert_eq!(name, span.name);
234 }
235 let context = format!("span {}: ", span.name);
236 let mut checker = expected_values.checker(&context, &self.name);
237 values.record(&mut checker);
238 checker.finish();
239 }
240 }
241 }
242
event(&self, event: &Event<'_>)243 fn event(&self, event: &Event<'_>) {
244 let name = event.metadata().name();
245 println!("[{}] event: {};", self.name, name);
246 match self.expected.lock().unwrap().pop_front() {
247 None => {}
248 Some(Expect::Event(mut expected)) => {
249 let get_parent_name = || {
250 let stack = self.current.lock().unwrap();
251 let spans = self.spans.lock().unwrap();
252 event
253 .parent()
254 .and_then(|id| spans.get(id))
255 .or_else(|| stack.last().and_then(|id| spans.get(id)))
256 .map(|s| s.name.to_string())
257 };
258 expected.check(event, get_parent_name, &self.name);
259 }
260 Some(ex) => ex.bad(&self.name, format_args!("observed event {:#?}", event)),
261 }
262 }
263
record_follows_from(&self, consequence_id: &Id, cause_id: &Id)264 fn record_follows_from(&self, consequence_id: &Id, cause_id: &Id) {
265 let spans = self.spans.lock().unwrap();
266 if let Some(consequence_span) = spans.get(consequence_id) {
267 if let Some(cause_span) = spans.get(cause_id) {
268 println!(
269 "[{}] record_follows_from: {} (id={:?}) follows {} (id={:?})",
270 self.name, consequence_span.name, consequence_id, cause_span.name, cause_id,
271 );
272 match self.expected.lock().unwrap().pop_front() {
273 None => {}
274 Some(Expect::FollowsFrom {
275 consequence: ref expected_consequence,
276 cause: ref expected_cause,
277 }) => {
278 if let Some(name) = expected_consequence.name() {
279 assert_eq!(name, consequence_span.name);
280 }
281 if let Some(name) = expected_cause.name() {
282 assert_eq!(name, cause_span.name);
283 }
284 }
285 Some(ex) => ex.bad(
286 &self.name,
287 format_args!(
288 "consequence {:?} followed cause {:?}",
289 consequence_span.name, cause_span.name
290 ),
291 ),
292 }
293 }
294 };
295 }
296
new_span(&self, span: &Attributes<'_>) -> Id297 fn new_span(&self, span: &Attributes<'_>) -> Id {
298 let meta = span.metadata();
299 let id = self.ids.fetch_add(1, Ordering::SeqCst);
300 let id = Id::from_u64(id as u64);
301 println!(
302 "[{}] new_span: name={:?}; target={:?}; id={:?};",
303 self.name,
304 meta.name(),
305 meta.target(),
306 id
307 );
308 let mut expected = self.expected.lock().unwrap();
309 let was_expected = matches!(expected.front(), Some(Expect::NewSpan(_)));
310 let mut spans = self.spans.lock().unwrap();
311 if was_expected {
312 if let Expect::NewSpan(mut expected) = expected.pop_front().unwrap() {
313 let get_parent_name = || {
314 let stack = self.current.lock().unwrap();
315 span.parent()
316 .and_then(|id| spans.get(id))
317 .or_else(|| stack.last().and_then(|id| spans.get(id)))
318 .map(|s| s.name.to_string())
319 };
320 expected.check(span, get_parent_name, &self.name);
321 }
322 }
323 spans.insert(
324 id.clone(),
325 SpanState {
326 name: meta.name(),
327 meta,
328 refs: 1,
329 },
330 );
331 id
332 }
333
enter(&self, id: &Id)334 fn enter(&self, id: &Id) {
335 let spans = self.spans.lock().unwrap();
336 if let Some(span) = spans.get(id) {
337 println!("[{}] enter: {}; id={:?};", self.name, span.name, id);
338 match self.expected.lock().unwrap().pop_front() {
339 None => {}
340 Some(Expect::Enter(ref expected_span)) => {
341 if let Some(name) = expected_span.name() {
342 assert_eq!(name, span.name);
343 }
344 }
345 Some(ex) => ex.bad(&self.name, format_args!("entered span {:?}", span.name)),
346 }
347 };
348 self.current.lock().unwrap().push(id.clone());
349 }
350
exit(&self, id: &Id)351 fn exit(&self, id: &Id) {
352 if std::thread::panicking() {
353 // `exit()` can be called in `drop` impls, so we must guard against
354 // double panics.
355 println!("[{}] exit {:?} while panicking", self.name, id);
356 return;
357 }
358 let spans = self.spans.lock().unwrap();
359 let span = spans
360 .get(id)
361 .unwrap_or_else(|| panic!("[{}] no span for ID {:?}", self.name, id));
362 println!("[{}] exit: {}; id={:?};", self.name, span.name, id);
363 match self.expected.lock().unwrap().pop_front() {
364 None => {}
365 Some(Expect::Exit(ref expected_span)) => {
366 if let Some(name) = expected_span.name() {
367 assert_eq!(name, span.name);
368 }
369 let curr = self.current.lock().unwrap().pop();
370 assert_eq!(
371 Some(id),
372 curr.as_ref(),
373 "[{}] exited span {:?}, but the current span was {:?}",
374 self.name,
375 span.name,
376 curr.as_ref().and_then(|id| spans.get(id)).map(|s| s.name)
377 );
378 }
379 Some(ex) => ex.bad(&self.name, format_args!("exited span {:?}", span.name)),
380 };
381 }
382
clone_span(&self, id: &Id) -> Id383 fn clone_span(&self, id: &Id) -> Id {
384 let name = self.spans.lock().unwrap().get_mut(id).map(|span| {
385 let name = span.name;
386 println!(
387 "[{}] clone_span: {}; id={:?}; refs={:?};",
388 self.name, name, id, span.refs
389 );
390 span.refs += 1;
391 name
392 });
393 if name.is_none() {
394 println!("[{}] clone_span: id={:?};", self.name, id);
395 }
396 let mut expected = self.expected.lock().unwrap();
397 let was_expected = if let Some(Expect::CloneSpan(ref span)) = expected.front() {
398 assert_eq!(
399 name,
400 span.name(),
401 "[{}] expected to clone a span named {:?}",
402 self.name,
403 span.name()
404 );
405 true
406 } else {
407 false
408 };
409 if was_expected {
410 expected.pop_front();
411 }
412 id.clone()
413 }
414
drop_span(&self, id: Id)415 fn drop_span(&self, id: Id) {
416 let mut is_event = false;
417 let name = if let Ok(mut spans) = self.spans.try_lock() {
418 spans.get_mut(&id).map(|span| {
419 let name = span.name;
420 if name.contains("event") {
421 is_event = true;
422 }
423 println!(
424 "[{}] drop_span: {}; id={:?}; refs={:?};",
425 self.name, name, id, span.refs
426 );
427 span.refs -= 1;
428 name
429 })
430 } else {
431 None
432 };
433 if name.is_none() {
434 println!("[{}] drop_span: id={:?}", self.name, id);
435 }
436 if let Ok(mut expected) = self.expected.try_lock() {
437 let was_expected = match expected.front() {
438 Some(Expect::DropSpan(ref span)) => {
439 // Don't assert if this function was called while panicking,
440 // as failing the assertion can cause a double panic.
441 if !::std::thread::panicking() {
442 assert_eq!(name, span.name());
443 }
444 true
445 }
446 Some(Expect::Event(_)) => {
447 if !::std::thread::panicking() {
448 assert!(is_event, "[{}] expected an event", self.name);
449 }
450 true
451 }
452 _ => false,
453 };
454 if was_expected {
455 expected.pop_front();
456 }
457 }
458 }
459
current_span(&self) -> tracing_core::span::Current460 fn current_span(&self) -> tracing_core::span::Current {
461 let stack = self.current.lock().unwrap();
462 match stack.last() {
463 Some(id) => {
464 let spans = self.spans.lock().unwrap();
465 let state = spans.get(id).expect("state for current span");
466 tracing_core::span::Current::new(id.clone(), state.meta)
467 }
468 None => tracing_core::span::Current::none(),
469 }
470 }
471 }
472
473 impl MockHandle {
new(expected: Arc<Mutex<VecDeque<Expect>>>, name: String) -> Self474 pub fn new(expected: Arc<Mutex<VecDeque<Expect>>>, name: String) -> Self {
475 Self(expected, name)
476 }
477
assert_finished(&self)478 pub fn assert_finished(&self) {
479 if let Ok(ref expected) = self.0.lock() {
480 assert!(
481 !expected.iter().any(|thing| thing != &Expect::Nothing),
482 "\n[{}] more notifications expected: {:#?}",
483 self.1,
484 **expected
485 );
486 }
487 }
488 }
489
490 impl Expect {
bad(&self, name: impl AsRef<str>, what: fmt::Arguments<'_>)491 pub fn bad(&self, name: impl AsRef<str>, what: fmt::Arguments<'_>) {
492 let name = name.as_ref();
493 match self {
494 Expect::Event(e) => panic!(
495 "\n[{}] expected event {}\n[{}] but instead {}",
496 name, e, name, what,
497 ),
498 Expect::FollowsFrom { consequence, cause } => panic!(
499 "\n[{}] expected consequence {} to follow cause {} but instead {}",
500 name, consequence, cause, what,
501 ),
502 Expect::Enter(e) => panic!(
503 "\n[{}] expected to enter {}\n[{}] but instead {}",
504 name, e, name, what,
505 ),
506 Expect::Exit(e) => panic!(
507 "\n[{}] expected to exit {}\n[{}] but instead {}",
508 name, e, name, what,
509 ),
510 Expect::CloneSpan(e) => {
511 panic!(
512 "\n[{}] expected to clone {}\n[{}] but instead {}",
513 name, e, name, what,
514 )
515 }
516 Expect::DropSpan(e) => {
517 panic!(
518 "\n[{}] expected to drop {}\n[{}] but instead {}",
519 name, e, name, what,
520 )
521 }
522 Expect::Visit(e, fields) => panic!(
523 "\n[{}] expected {} to record {}\n[{}] but instead {}",
524 name, e, fields, name, what,
525 ),
526 Expect::NewSpan(e) => panic!(
527 "\n[{}] expected {}\n[{}] but instead {}",
528 name, e, name, what
529 ),
530 Expect::Nothing => panic!(
531 "\n[{}] expected nothing else to happen\n[{}] but {} instead",
532 name, name, what,
533 ),
534 }
535 }
536 }
537