summaryrefslogtreecommitdiffstats
path: root/vendor/tracing-tree/tests/format_time.rs
blob: b24b16652a7023e56e4333828fffb1ca5845ccd7 (plain)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
use std::{
    fmt::Write,
    sync::{
        atomic::{AtomicU64, Ordering},
        Arc,
    },
};

use tracing::{span, Level};
use tracing_subscriber::{layer::SubscriberExt, Registry};

use tracing_tree::{time::FormatTime, HierarchicalLayer};

#[derive(Debug)]
struct FormatTimeCounter(Arc<AtomicU64>);

impl FormatTime for FormatTimeCounter {
    fn format_time(&self, _w: &mut impl Write) -> std::fmt::Result {
        self.0.fetch_add(1, Ordering::Relaxed);
        Ok(())
    }
}

#[test]
fn format_time_num_calls() {
    let num_called = Arc::new(AtomicU64::new(0));
    let format_time_counter = FormatTimeCounter(Arc::clone(&num_called));

    let layer = HierarchicalLayer::default()
        .with_writer(std::io::stdout)
        .with_indent_lines(true)
        .with_indent_amount(2)
        .with_timer(format_time_counter)
        .with_thread_names(true)
        .with_thread_ids(true)
        .with_verbose_exit(true)
        .with_verbose_entry(true)
        .with_targets(true);

    let subscriber = Registry::default().with(layer);
    tracing::subscriber::set_global_default(subscriber).unwrap();

    let test_span = span!(Level::TRACE, "format-time-num-calls-test", version = %0.1);
    let _e = test_span.enter();

    tracing::info!("first event");
    assert_eq!(num_called.load(Ordering::Relaxed), 1);

    std::thread::sleep(std::time::Duration::from_millis(100));
    tracing::info!("second event");
    assert_eq!(num_called.load(Ordering::Relaxed), 2);

    let nested_span = span!(Level::TRACE, "nested-span");
    nested_span.in_scope(|| {
        tracing::debug!("nested event");
        assert_eq!(num_called.load(Ordering::Relaxed), 3);

        tracing::info!("important nested event");
        assert_eq!(num_called.load(Ordering::Relaxed), 4);
    });
    drop(nested_span);

    instrumented_function();
    assert_eq!(num_called.load(Ordering::Relaxed), 6);

    tracing::info!("exiting");
    assert_eq!(num_called.load(Ordering::Relaxed), 7);
}

#[tracing::instrument]
fn instrumented_function() {
    tracing::info!("instrumented function");
    nested_instrumented_function();
}

#[tracing::instrument]
fn nested_instrumented_function() {
    tracing::warn!("nested instrumented function");
}