1 | #![cfg (feature = "env-filter" )] |
2 | |
3 | mod per_layer; |
4 | |
5 | use tracing::{self, subscriber::with_default, Level}; |
6 | use tracing_mock::{expect, layer, span, subscriber}; |
7 | use tracing_subscriber::{ |
8 | filter::{EnvFilter, LevelFilter}, |
9 | prelude::*, |
10 | Registry, |
11 | }; |
12 | |
13 | #[test] |
14 | fn level_filter_event() { |
15 | let filter: EnvFilter = "info" .parse().expect("filter should parse" ); |
16 | let (subscriber, finished) = subscriber::mock() |
17 | .event(expect::event().at_level(Level::INFO)) |
18 | .event(expect::event().at_level(Level::WARN)) |
19 | .event(expect::event().at_level(Level::ERROR)) |
20 | .only() |
21 | .run_with_handle(); |
22 | let subscriber = subscriber.with(filter); |
23 | |
24 | with_default(subscriber, || { |
25 | tracing::trace!("this should be disabled" ); |
26 | tracing::info!("this shouldn't be" ); |
27 | tracing::debug!(target: "foo" , "this should also be disabled" ); |
28 | tracing::warn!(target: "foo" , "this should be enabled" ); |
29 | tracing::error!("this should be enabled too" ); |
30 | }); |
31 | |
32 | finished.assert_finished(); |
33 | } |
34 | |
35 | #[test] |
36 | fn same_name_spans() { |
37 | let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace" |
38 | .parse() |
39 | .expect("filter should parse" ); |
40 | let (subscriber, finished) = subscriber::mock() |
41 | .new_span( |
42 | expect::span() |
43 | .named("foo" ) |
44 | .at_level(Level::TRACE) |
45 | .with_field(expect::field("bar" )), |
46 | ) |
47 | .new_span( |
48 | expect::span() |
49 | .named("foo" ) |
50 | .at_level(Level::TRACE) |
51 | .with_field(expect::field("baz" )), |
52 | ) |
53 | .only() |
54 | .run_with_handle(); |
55 | let subscriber = subscriber.with(filter); |
56 | with_default(subscriber, || { |
57 | tracing::trace_span!("foo" , bar = 1); |
58 | tracing::trace_span!("foo" , baz = 1); |
59 | }); |
60 | |
61 | finished.assert_finished(); |
62 | } |
63 | |
64 | #[test] |
65 | fn level_filter_event_with_target() { |
66 | let filter: EnvFilter = "info,stuff=debug" .parse().expect("filter should parse" ); |
67 | let (subscriber, finished) = subscriber::mock() |
68 | .event(expect::event().at_level(Level::INFO)) |
69 | .event(expect::event().at_level(Level::DEBUG).with_target("stuff" )) |
70 | .event(expect::event().at_level(Level::WARN).with_target("stuff" )) |
71 | .event(expect::event().at_level(Level::ERROR)) |
72 | .event(expect::event().at_level(Level::ERROR).with_target("stuff" )) |
73 | .only() |
74 | .run_with_handle(); |
75 | let subscriber = subscriber.with(filter); |
76 | |
77 | with_default(subscriber, || { |
78 | tracing::trace!("this should be disabled" ); |
79 | tracing::info!("this shouldn't be" ); |
80 | tracing::debug!(target: "stuff" , "this should be enabled" ); |
81 | tracing::debug!("but this shouldn't" ); |
82 | tracing::trace!(target: "stuff" , "and neither should this" ); |
83 | tracing::warn!(target: "stuff" , "this should be enabled" ); |
84 | tracing::error!("this should be enabled too" ); |
85 | tracing::error!(target: "stuff" , "this should be enabled also" ); |
86 | }); |
87 | |
88 | finished.assert_finished(); |
89 | } |
90 | |
91 | #[test] |
92 | fn level_filter_event_with_target_and_span_global() { |
93 | let filter: EnvFilter = "info,stuff[cool_span]=debug" |
94 | .parse() |
95 | .expect("filter should parse" ); |
96 | |
97 | let cool_span = span::named("cool_span" ); |
98 | let uncool_span = span::named("uncool_span" ); |
99 | let (layer, handle) = layer::mock() |
100 | .enter(cool_span.clone()) |
101 | .event( |
102 | expect::event() |
103 | .at_level(Level::DEBUG) |
104 | .in_scope(vec![cool_span.clone()]), |
105 | ) |
106 | .exit(cool_span) |
107 | .enter(uncool_span.clone()) |
108 | .exit(uncool_span) |
109 | .only() |
110 | .run_with_handle(); |
111 | |
112 | let subscriber = Registry::default().with(filter).with(layer); |
113 | |
114 | with_default(subscriber, || { |
115 | { |
116 | let _span = tracing::info_span!(target: "stuff" , "cool_span" ).entered(); |
117 | tracing::debug!("this should be enabled" ); |
118 | } |
119 | |
120 | tracing::debug!("should also be disabled" ); |
121 | |
122 | { |
123 | let _span = tracing::info_span!("uncool_span" ).entered(); |
124 | tracing::debug!("this should be disabled" ); |
125 | } |
126 | }); |
127 | |
128 | handle.assert_finished(); |
129 | } |
130 | |
131 | #[test] |
132 | fn not_order_dependent() { |
133 | // this test reproduces tokio-rs/tracing#623 |
134 | |
135 | let filter: EnvFilter = "stuff=debug,info" .parse().expect("filter should parse" ); |
136 | let (subscriber, finished) = subscriber::mock() |
137 | .event(expect::event().at_level(Level::INFO)) |
138 | .event(expect::event().at_level(Level::DEBUG).with_target("stuff" )) |
139 | .event(expect::event().at_level(Level::WARN).with_target("stuff" )) |
140 | .event(expect::event().at_level(Level::ERROR)) |
141 | .event(expect::event().at_level(Level::ERROR).with_target("stuff" )) |
142 | .only() |
143 | .run_with_handle(); |
144 | let subscriber = subscriber.with(filter); |
145 | |
146 | with_default(subscriber, || { |
147 | tracing::trace!("this should be disabled" ); |
148 | tracing::info!("this shouldn't be" ); |
149 | tracing::debug!(target: "stuff" , "this should be enabled" ); |
150 | tracing::debug!("but this shouldn't" ); |
151 | tracing::trace!(target: "stuff" , "and neither should this" ); |
152 | tracing::warn!(target: "stuff" , "this should be enabled" ); |
153 | tracing::error!("this should be enabled too" ); |
154 | tracing::error!(target: "stuff" , "this should be enabled also" ); |
155 | }); |
156 | |
157 | finished.assert_finished(); |
158 | } |
159 | |
160 | #[test] |
161 | fn add_directive_enables_event() { |
162 | // this test reproduces tokio-rs/tracing#591 |
163 | |
164 | // by default, use info level |
165 | let mut filter = EnvFilter::new(LevelFilter::INFO.to_string()); |
166 | |
167 | // overwrite with a more specific directive |
168 | filter = filter.add_directive("hello=trace" .parse().expect("directive should parse" )); |
169 | |
170 | let (subscriber, finished) = subscriber::mock() |
171 | .event(expect::event().at_level(Level::INFO).with_target("hello" )) |
172 | .event(expect::event().at_level(Level::TRACE).with_target("hello" )) |
173 | .only() |
174 | .run_with_handle(); |
175 | let subscriber = subscriber.with(filter); |
176 | |
177 | with_default(subscriber, || { |
178 | tracing::info!(target: "hello" , "hello info" ); |
179 | tracing::trace!(target: "hello" , "hello trace" ); |
180 | }); |
181 | |
182 | finished.assert_finished(); |
183 | } |
184 | |
185 | #[test] |
186 | fn span_name_filter_is_dynamic() { |
187 | let filter: EnvFilter = "info,[cool_span]=debug" |
188 | .parse() |
189 | .expect("filter should parse" ); |
190 | let (subscriber, finished) = subscriber::mock() |
191 | .event(expect::event().at_level(Level::INFO)) |
192 | .enter(expect::span().named("cool_span" )) |
193 | .event(expect::event().at_level(Level::DEBUG)) |
194 | .enter(expect::span().named("uncool_span" )) |
195 | .event(expect::event().at_level(Level::WARN)) |
196 | .event(expect::event().at_level(Level::DEBUG)) |
197 | .exit(expect::span().named("uncool_span" )) |
198 | .exit(expect::span().named("cool_span" )) |
199 | .enter(expect::span().named("uncool_span" )) |
200 | .event(expect::event().at_level(Level::WARN)) |
201 | .event(expect::event().at_level(Level::ERROR)) |
202 | .exit(expect::span().named("uncool_span" )) |
203 | .only() |
204 | .run_with_handle(); |
205 | let subscriber = subscriber.with(filter); |
206 | |
207 | with_default(subscriber, || { |
208 | tracing::trace!("this should be disabled" ); |
209 | tracing::info!("this shouldn't be" ); |
210 | let cool_span = tracing::info_span!("cool_span" ); |
211 | let uncool_span = tracing::info_span!("uncool_span" ); |
212 | |
213 | { |
214 | let _enter = cool_span.enter(); |
215 | tracing::debug!("i'm a cool event" ); |
216 | tracing::trace!("i'm cool, but not cool enough" ); |
217 | let _enter2 = uncool_span.enter(); |
218 | tracing::warn!("warning: extremely cool!" ); |
219 | tracing::debug!("i'm still cool" ); |
220 | } |
221 | |
222 | let _enter = uncool_span.enter(); |
223 | tracing::warn!("warning: not that cool" ); |
224 | tracing::trace!("im not cool enough" ); |
225 | tracing::error!("uncool error" ); |
226 | }); |
227 | |
228 | finished.assert_finished(); |
229 | } |
230 | |
231 | #[test] |
232 | fn method_name_resolution() { |
233 | #[allow (unused_imports)] |
234 | use tracing_subscriber::layer::{Filter, Layer}; |
235 | |
236 | let filter = EnvFilter::new("hello_world=info" ); |
237 | filter.max_level_hint(); |
238 | } |
239 | |
240 | // contains the same tests as the first half of this file |
241 | // but using EnvFilter as a `Filter`, not as a `Layer` |
242 | mod per_layer_filter { |
243 | use super::*; |
244 | |
245 | #[test] |
246 | fn level_filter_event() { |
247 | let filter: EnvFilter = "info" .parse().expect("filter should parse" ); |
248 | let (layer, handle) = layer::mock() |
249 | .event(expect::event().at_level(Level::INFO)) |
250 | .event(expect::event().at_level(Level::WARN)) |
251 | .event(expect::event().at_level(Level::ERROR)) |
252 | .only() |
253 | .run_with_handle(); |
254 | |
255 | let _subscriber = tracing_subscriber::registry() |
256 | .with(layer.with_filter(filter)) |
257 | .set_default(); |
258 | |
259 | tracing::trace!("this should be disabled" ); |
260 | tracing::info!("this shouldn't be" ); |
261 | tracing::debug!(target: "foo" , "this should also be disabled" ); |
262 | tracing::warn!(target: "foo" , "this should be enabled" ); |
263 | tracing::error!("this should be enabled too" ); |
264 | |
265 | handle.assert_finished(); |
266 | } |
267 | |
268 | #[test] |
269 | fn same_name_spans() { |
270 | let filter: EnvFilter = "[foo{bar}]=trace,[foo{baz}]=trace" |
271 | .parse() |
272 | .expect("filter should parse" ); |
273 | let (layer, handle) = layer::mock() |
274 | .new_span( |
275 | expect::span() |
276 | .named("foo" ) |
277 | .at_level(Level::TRACE) |
278 | .with_field(expect::field("bar" )), |
279 | ) |
280 | .new_span( |
281 | expect::span() |
282 | .named("foo" ) |
283 | .at_level(Level::TRACE) |
284 | .with_field(expect::field("baz" )), |
285 | ) |
286 | .only() |
287 | .run_with_handle(); |
288 | |
289 | let _subscriber = tracing_subscriber::registry() |
290 | .with(layer.with_filter(filter)) |
291 | .set_default(); |
292 | |
293 | tracing::trace_span!("foo" , bar = 1); |
294 | tracing::trace_span!("foo" , baz = 1); |
295 | |
296 | handle.assert_finished(); |
297 | } |
298 | |
299 | #[test] |
300 | fn level_filter_event_with_target() { |
301 | let filter: EnvFilter = "info,stuff=debug" .parse().expect("filter should parse" ); |
302 | let (layer, handle) = layer::mock() |
303 | .event(expect::event().at_level(Level::INFO)) |
304 | .event(expect::event().at_level(Level::DEBUG).with_target("stuff" )) |
305 | .event(expect::event().at_level(Level::WARN).with_target("stuff" )) |
306 | .event(expect::event().at_level(Level::ERROR)) |
307 | .event(expect::event().at_level(Level::ERROR).with_target("stuff" )) |
308 | .only() |
309 | .run_with_handle(); |
310 | |
311 | let _subscriber = tracing_subscriber::registry() |
312 | .with(layer.with_filter(filter)) |
313 | .set_default(); |
314 | |
315 | tracing::trace!("this should be disabled" ); |
316 | tracing::info!("this shouldn't be" ); |
317 | tracing::debug!(target: "stuff" , "this should be enabled" ); |
318 | tracing::debug!("but this shouldn't" ); |
319 | tracing::trace!(target: "stuff" , "and neither should this" ); |
320 | tracing::warn!(target: "stuff" , "this should be enabled" ); |
321 | tracing::error!("this should be enabled too" ); |
322 | tracing::error!(target: "stuff" , "this should be enabled also" ); |
323 | |
324 | handle.assert_finished(); |
325 | } |
326 | |
327 | #[test] |
328 | fn level_filter_event_with_target_and_span() { |
329 | let filter: EnvFilter = "stuff[cool_span]=debug" |
330 | .parse() |
331 | .expect("filter should parse" ); |
332 | |
333 | let cool_span = span::named("cool_span" ); |
334 | let (layer, handle) = layer::mock() |
335 | .enter(cool_span.clone()) |
336 | .event( |
337 | expect::event() |
338 | .at_level(Level::DEBUG) |
339 | .in_scope(vec![cool_span.clone()]), |
340 | ) |
341 | .exit(cool_span) |
342 | .only() |
343 | .run_with_handle(); |
344 | |
345 | let _subscriber = tracing_subscriber::registry() |
346 | .with(layer.with_filter(filter)) |
347 | .set_default(); |
348 | |
349 | { |
350 | let _span = tracing::info_span!(target: "stuff" , "cool_span" ).entered(); |
351 | tracing::debug!("this should be enabled" ); |
352 | } |
353 | |
354 | tracing::debug!("should also be disabled" ); |
355 | |
356 | { |
357 | let _span = tracing::info_span!("uncool_span" ).entered(); |
358 | tracing::debug!("this should be disabled" ); |
359 | } |
360 | |
361 | handle.assert_finished(); |
362 | } |
363 | |
364 | #[test] |
365 | fn not_order_dependent() { |
366 | // this test reproduces tokio-rs/tracing#623 |
367 | |
368 | let filter: EnvFilter = "stuff=debug,info" .parse().expect("filter should parse" ); |
369 | let (layer, finished) = layer::mock() |
370 | .event(expect::event().at_level(Level::INFO)) |
371 | .event(expect::event().at_level(Level::DEBUG).with_target("stuff" )) |
372 | .event(expect::event().at_level(Level::WARN).with_target("stuff" )) |
373 | .event(expect::event().at_level(Level::ERROR)) |
374 | .event(expect::event().at_level(Level::ERROR).with_target("stuff" )) |
375 | .only() |
376 | .run_with_handle(); |
377 | |
378 | let _subscriber = tracing_subscriber::registry() |
379 | .with(layer.with_filter(filter)) |
380 | .set_default(); |
381 | |
382 | tracing::trace!("this should be disabled" ); |
383 | tracing::info!("this shouldn't be" ); |
384 | tracing::debug!(target: "stuff" , "this should be enabled" ); |
385 | tracing::debug!("but this shouldn't" ); |
386 | tracing::trace!(target: "stuff" , "and neither should this" ); |
387 | tracing::warn!(target: "stuff" , "this should be enabled" ); |
388 | tracing::error!("this should be enabled too" ); |
389 | tracing::error!(target: "stuff" , "this should be enabled also" ); |
390 | |
391 | finished.assert_finished(); |
392 | } |
393 | |
394 | #[test] |
395 | fn add_directive_enables_event() { |
396 | // this test reproduces tokio-rs/tracing#591 |
397 | |
398 | // by default, use info level |
399 | let mut filter = EnvFilter::new(LevelFilter::INFO.to_string()); |
400 | |
401 | // overwrite with a more specific directive |
402 | filter = filter.add_directive("hello=trace" .parse().expect("directive should parse" )); |
403 | |
404 | let (layer, finished) = layer::mock() |
405 | .event(expect::event().at_level(Level::INFO).with_target("hello" )) |
406 | .event(expect::event().at_level(Level::TRACE).with_target("hello" )) |
407 | .only() |
408 | .run_with_handle(); |
409 | |
410 | let _subscriber = tracing_subscriber::registry() |
411 | .with(layer.with_filter(filter)) |
412 | .set_default(); |
413 | |
414 | tracing::info!(target: "hello" , "hello info" ); |
415 | tracing::trace!(target: "hello" , "hello trace" ); |
416 | |
417 | finished.assert_finished(); |
418 | } |
419 | |
420 | #[test] |
421 | fn span_name_filter_is_dynamic() { |
422 | let filter: EnvFilter = "info,[cool_span]=debug" |
423 | .parse() |
424 | .expect("filter should parse" ); |
425 | let cool_span = span::named("cool_span" ); |
426 | let uncool_span = span::named("uncool_span" ); |
427 | let (layer, finished) = layer::mock() |
428 | .event(expect::event().at_level(Level::INFO)) |
429 | .enter(cool_span.clone()) |
430 | .event( |
431 | expect::event() |
432 | .at_level(Level::DEBUG) |
433 | .in_scope(vec![cool_span.clone()]), |
434 | ) |
435 | .enter(uncool_span.clone()) |
436 | .event( |
437 | expect::event() |
438 | .at_level(Level::WARN) |
439 | .in_scope(vec![uncool_span.clone()]), |
440 | ) |
441 | .event( |
442 | expect::event() |
443 | .at_level(Level::DEBUG) |
444 | .in_scope(vec![uncool_span.clone()]), |
445 | ) |
446 | .exit(uncool_span.clone()) |
447 | .exit(cool_span) |
448 | .enter(uncool_span.clone()) |
449 | .event( |
450 | expect::event() |
451 | .at_level(Level::WARN) |
452 | .in_scope(vec![uncool_span.clone()]), |
453 | ) |
454 | .event( |
455 | expect::event() |
456 | .at_level(Level::ERROR) |
457 | .in_scope(vec![uncool_span.clone()]), |
458 | ) |
459 | .exit(uncool_span) |
460 | .only() |
461 | .run_with_handle(); |
462 | |
463 | let _subscriber = tracing_subscriber::registry() |
464 | .with(layer.with_filter(filter)) |
465 | .set_default(); |
466 | |
467 | tracing::trace!("this should be disabled" ); |
468 | tracing::info!("this shouldn't be" ); |
469 | let cool_span = tracing::info_span!("cool_span" ); |
470 | let uncool_span = tracing::info_span!("uncool_span" ); |
471 | |
472 | { |
473 | let _enter = cool_span.enter(); |
474 | tracing::debug!("i'm a cool event" ); |
475 | tracing::trace!("i'm cool, but not cool enough" ); |
476 | let _enter2 = uncool_span.enter(); |
477 | tracing::warn!("warning: extremely cool!" ); |
478 | tracing::debug!("i'm still cool" ); |
479 | } |
480 | |
481 | { |
482 | let _enter = uncool_span.enter(); |
483 | tracing::warn!("warning: not that cool" ); |
484 | tracing::trace!("im not cool enough" ); |
485 | tracing::error!("uncool error" ); |
486 | } |
487 | |
488 | finished.assert_finished(); |
489 | } |
490 | |
491 | #[test] |
492 | fn multiple_dynamic_filters() { |
493 | // Test that multiple dynamic (span) filters only apply to the layers |
494 | // they're attached to. |
495 | let (layer1, handle1) = { |
496 | let span = span::named("span1" ); |
497 | let filter: EnvFilter = "[span1]=debug" .parse().expect("filter 1 should parse" ); |
498 | let (layer, handle) = layer::named("layer1" ) |
499 | .enter(span.clone()) |
500 | .event( |
501 | expect::event() |
502 | .at_level(Level::DEBUG) |
503 | .in_scope(vec![span.clone()]), |
504 | ) |
505 | .exit(span) |
506 | .only() |
507 | .run_with_handle(); |
508 | (layer.with_filter(filter), handle) |
509 | }; |
510 | |
511 | let (layer2, handle2) = { |
512 | let span = span::named("span2" ); |
513 | let filter: EnvFilter = "[span2]=info" .parse().expect("filter 2 should parse" ); |
514 | let (layer, handle) = layer::named("layer2" ) |
515 | .enter(span.clone()) |
516 | .event( |
517 | expect::event() |
518 | .at_level(Level::INFO) |
519 | .in_scope(vec![span.clone()]), |
520 | ) |
521 | .exit(span) |
522 | .only() |
523 | .run_with_handle(); |
524 | (layer.with_filter(filter), handle) |
525 | }; |
526 | |
527 | let _subscriber = tracing_subscriber::registry() |
528 | .with(layer1) |
529 | .with(layer2) |
530 | .set_default(); |
531 | |
532 | tracing::info_span!("span1" ).in_scope(|| { |
533 | tracing::debug!("hello from span 1" ); |
534 | tracing::trace!("not enabled" ); |
535 | }); |
536 | |
537 | tracing::info_span!("span2" ).in_scope(|| { |
538 | tracing::info!("hello from span 2" ); |
539 | tracing::debug!("not enabled" ); |
540 | }); |
541 | |
542 | handle1.assert_finished(); |
543 | handle2.assert_finished(); |
544 | } |
545 | } |
546 | |