| 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 | |