1use criterion::{criterion_group, criterion_main, Criterion};
2use std::time::Duration;
3use tracing::{dispatcher::Dispatch, span, Event, Id, Metadata};
4use tracing_subscriber::{prelude::*, EnvFilter};
5
6mod support;
7use support::MultithreadedBench;
8
9/// A subscriber that is enabled but otherwise does nothing.
10struct EnabledSubscriber;
11
12impl tracing::Subscriber for EnabledSubscriber {
13 fn new_span(&self, span: &span::Attributes<'_>) -> Id {
14 let _ = span;
15 Id::from_u64(0xDEAD_FACE)
16 }
17
18 fn event(&self, event: &Event<'_>) {
19 let _ = event;
20 }
21
22 fn record(&self, span: &Id, values: &span::Record<'_>) {
23 let _ = (span, values);
24 }
25
26 fn record_follows_from(&self, span: &Id, follows: &Id) {
27 let _ = (span, follows);
28 }
29
30 fn enabled(&self, metadata: &Metadata<'_>) -> bool {
31 let _ = metadata;
32 true
33 }
34
35 fn enter(&self, span: &Id) {
36 let _ = span;
37 }
38
39 fn exit(&self, span: &Id) {
40 let _ = span;
41 }
42}
43
44fn bench_static(c: &mut Criterion) {
45 let mut group = c.benchmark_group("static");
46
47 group.bench_function("baseline_single_threaded", |b| {
48 tracing::subscriber::with_default(EnabledSubscriber, || {
49 b.iter(|| {
50 tracing::info!(target: "static_filter", "hi");
51 tracing::debug!(target: "static_filter", "hi");
52 tracing::warn!(target: "static_filter", "hi");
53 tracing::trace!(target: "foo", "hi");
54 })
55 });
56 });
57 group.bench_function("single_threaded", |b| {
58 let filter = "static_filter=info"
59 .parse::<EnvFilter>()
60 .expect("should parse");
61 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
62 b.iter(|| {
63 tracing::info!(target: "static_filter", "hi");
64 tracing::debug!(target: "static_filter", "hi");
65 tracing::warn!(target: "static_filter", "hi");
66 tracing::trace!(target: "foo", "hi");
67 })
68 });
69 });
70 group.bench_function("enabled_one", |b| {
71 let filter = "static_filter=info"
72 .parse::<EnvFilter>()
73 .expect("should parse");
74 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
75 b.iter(|| {
76 tracing::info!(target: "static_filter", "hi");
77 })
78 });
79 });
80 group.bench_function("enabled_many", |b| {
81 let filter = "foo=debug,bar=trace,baz=error,quux=warn,static_filter=info"
82 .parse::<EnvFilter>()
83 .expect("should parse");
84 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
85 b.iter(|| {
86 tracing::info!(target: "static_filter", "hi");
87 })
88 });
89 });
90 group.bench_function("disabled_level_one", |b| {
91 let filter = "static_filter=info"
92 .parse::<EnvFilter>()
93 .expect("should parse");
94 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
95 b.iter(|| {
96 tracing::debug!(target: "static_filter", "hi");
97 })
98 });
99 });
100 group.bench_function("disabled_level_many", |b| {
101 let filter = "foo=debug,bar=info,baz=error,quux=warn,static_filter=info"
102 .parse::<EnvFilter>()
103 .expect("should parse");
104 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
105 b.iter(|| {
106 tracing::trace!(target: "static_filter", "hi");
107 })
108 });
109 });
110 group.bench_function("disabled_one", |b| {
111 let filter = "foo=info".parse::<EnvFilter>().expect("should parse");
112 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
113 b.iter(|| {
114 tracing::info!(target: "static_filter", "hi");
115 })
116 });
117 });
118 group.bench_function("disabled_many", |b| {
119 let filter = "foo=debug,bar=trace,baz=error,quux=warn,whibble=info"
120 .parse::<EnvFilter>()
121 .expect("should parse");
122 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
123 b.iter(|| {
124 tracing::info!(target: "static_filter", "hi");
125 })
126 });
127 });
128 group.bench_function("baseline_multithreaded", |b| {
129 let dispatch = Dispatch::new(EnabledSubscriber);
130 b.iter_custom(|iters| {
131 let mut total = Duration::from_secs(0);
132 for _ in 0..iters {
133 let bench = MultithreadedBench::new(dispatch.clone());
134 let elapsed = bench
135 .thread(|| {
136 tracing::info!(target: "static_filter", "hi");
137 })
138 .thread(|| {
139 tracing::debug!(target: "static_filter", "hi");
140 })
141 .thread(|| {
142 tracing::warn!(target: "static_filter", "hi");
143 })
144 .thread(|| {
145 tracing::warn!(target: "foo", "hi");
146 })
147 .run();
148 total += elapsed;
149 }
150 total
151 })
152 });
153 group.bench_function("multithreaded", |b| {
154 let filter = "static_filter=info"
155 .parse::<EnvFilter>()
156 .expect("should parse");
157 let dispatch = Dispatch::new(EnabledSubscriber.with(filter));
158 b.iter_custom(|iters| {
159 let mut total = Duration::from_secs(0);
160 for _ in 0..iters {
161 let bench = MultithreadedBench::new(dispatch.clone());
162 let elapsed = bench
163 .thread(|| {
164 tracing::info!(target: "static_filter", "hi");
165 })
166 .thread(|| {
167 tracing::debug!(target: "static_filter", "hi");
168 })
169 .thread(|| {
170 tracing::warn!(target: "static_filter", "hi");
171 })
172 .thread(|| {
173 tracing::warn!(target: "foo", "hi");
174 })
175 .run();
176 total += elapsed;
177 }
178 total
179 });
180 });
181 group.finish();
182}
183
184fn bench_dynamic(c: &mut Criterion) {
185 let mut group = c.benchmark_group("dynamic");
186
187 group.bench_function("baseline_single_threaded", |b| {
188 tracing::subscriber::with_default(EnabledSubscriber, || {
189 b.iter(|| {
190 tracing::info_span!("foo").in_scope(|| {
191 tracing::info!("hi");
192 tracing::debug!("hi");
193 });
194 tracing::info_span!("bar").in_scope(|| {
195 tracing::warn!("hi");
196 });
197 tracing::trace!("hi");
198 })
199 });
200 });
201 group.bench_function("single_threaded", |b| {
202 let filter = "[foo]=trace".parse::<EnvFilter>().expect("should parse");
203 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
204 b.iter(|| {
205 tracing::info_span!("foo").in_scope(|| {
206 tracing::info!("hi");
207 tracing::debug!("hi");
208 });
209 tracing::info_span!("bar").in_scope(|| {
210 tracing::warn!("hi");
211 });
212 tracing::trace!("hi");
213 })
214 });
215 });
216 group.bench_function("baseline_multithreaded", |b| {
217 let dispatch = Dispatch::new(EnabledSubscriber);
218 b.iter_custom(|iters| {
219 let mut total = Duration::from_secs(0);
220 for _ in 0..iters {
221 let bench = MultithreadedBench::new(dispatch.clone());
222 let elapsed = bench
223 .thread(|| {
224 let span = tracing::info_span!("foo");
225 let _ = span.enter();
226 tracing::info!("hi");
227 })
228 .thread(|| {
229 let span = tracing::info_span!("foo");
230 let _ = span.enter();
231 tracing::debug!("hi");
232 })
233 .thread(|| {
234 let span = tracing::info_span!("bar");
235 let _ = span.enter();
236 tracing::debug!("hi");
237 })
238 .thread(|| {
239 tracing::trace!("hi");
240 })
241 .run();
242 total += elapsed;
243 }
244 total
245 })
246 });
247 group.bench_function("multithreaded", |b| {
248 let filter = "[foo]=trace".parse::<EnvFilter>().expect("should parse");
249 let dispatch = Dispatch::new(EnabledSubscriber.with(filter));
250 b.iter_custom(|iters| {
251 let mut total = Duration::from_secs(0);
252 for _ in 0..iters {
253 let bench = MultithreadedBench::new(dispatch.clone());
254 let elapsed = bench
255 .thread(|| {
256 let span = tracing::info_span!("foo");
257 let _ = span.enter();
258 tracing::info!("hi");
259 })
260 .thread(|| {
261 let span = tracing::info_span!("foo");
262 let _ = span.enter();
263 tracing::debug!("hi");
264 })
265 .thread(|| {
266 let span = tracing::info_span!("bar");
267 let _ = span.enter();
268 tracing::debug!("hi");
269 })
270 .thread(|| {
271 tracing::trace!("hi");
272 })
273 .run();
274 total += elapsed;
275 }
276 total
277 })
278 });
279
280 group.finish();
281}
282
283fn bench_mixed(c: &mut Criterion) {
284 let mut group = c.benchmark_group("mixed");
285 group.bench_function("disabled", |b| {
286 let filter = "[foo]=trace,bar[quux]=debug,[{baz}]=debug,asdf=warn,wibble=info"
287 .parse::<EnvFilter>()
288 .expect("should parse");
289 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
290 b.iter(|| {
291 tracing::info!(target: "static_filter", "hi");
292 })
293 });
294 });
295 group.bench_function("disabled_by_level", |b| {
296 let filter = "[foo]=info,bar[quux]=debug,asdf=warn,static_filter=info"
297 .parse::<EnvFilter>()
298 .expect("should parse");
299 tracing::subscriber::with_default(EnabledSubscriber.with(filter), || {
300 b.iter(|| {
301 tracing::trace!(target: "static_filter", "hi");
302 })
303 });
304 });
305}
306
307criterion_group!(benches, bench_static, bench_dynamic, bench_mixed);
308criterion_main!(benches);
309