Add #[test_log(default_log_filter = "___")]

Users can now specify a default_log_filter via #[test_log(default_log_filter = "foo")]
which will be used when RUST_LOG is not specified.

Please note that because env_logger / tracing is initialized globally,
it is possible that this value will be ignored if they have already been
initialized by a different test.

Fixes: #25

examples/main.rs

@@ -0,0 +1,14 @@
+//! Use this file for iterating on the derive code. You can view the
+//! expanded code for any given configuration by updating this file and
+//! running:
+//!
+//! ```sh
+//! cargo expand --tests --example main
+//! ```
+
+#[test_log::test]
+fn works() {
+  assert_eq!(2 + 2, 4);
+}
+
+fn main() {}

src/lib.rs

@@ -14,8 +14,13 @@ use proc_macro2::TokenStream as Tokens;
 
 use quote::quote;
 
+use syn::parse::Parse;
 use syn::parse_macro_input;
+use syn::Attribute;
+use syn::Expr;
 use syn::ItemFn;
+use syn::Lit;
+use syn::Meta;
 
 
 /// A procedural macro for the `test` attribute.
@@ -85,6 +90,7 @@ fn try_test(attr: TokenStream, input: ItemFn) -> syn::Result<Tokens> {
   } else {
     attr.into()
   };
+  let mut attribute_args = AttributeArgs::default();
 
   let ItemFn {
     attrs,
@@ -93,12 +99,21 @@ fn try_test(attr: TokenStream, input: ItemFn) -> syn::Result<Tokens> {
     block,
   } = input;
 
-  let logging_init = expand_logging_init();
-  let tracing_init = expand_tracing_init();
+  let mut non_test_log_attrs = vec![];
+  for attr in attrs {
+    let matched = attribute_args.try_parse_attr_single(&attr)?;
+    // Keep only attrs that didn't match the #[test_log(_)] syntax.
+    if !matched {
+      non_test_log_attrs.push(attr);
+    }
+  }
+
+  let logging_init = expand_logging_init(&attribute_args);
+  let tracing_init = expand_tracing_init(&attribute_args);
 
   let result = quote! {
     #[#inner_test]
-    #(#attrs)*
+    #(#non_test_log_attrs)*
     #vis #sig {
       // We put all initialization code into a separate module here in
       // order to prevent potential ambiguities that could result in
@@ -126,12 +141,78 @@ fn try_test(attr: TokenStream, input: ItemFn) -> syn::Result<Tokens> {
 }
 
 
+#[derive(Debug, Default)]
+struct AttributeArgs {
+  default_log_filter: Option<String>,
+}
+
+impl AttributeArgs {
+  fn try_parse_attr_single(&mut self, attr: &Attribute) -> syn::Result<bool> {
+    if !attr.path().is_ident("test_log") {
+      return Ok(false)
+    }
+
+    let nested_meta = attr.parse_args_with(Meta::parse)?;
+    let Meta::NameValue(name_value) = nested_meta else {
+      return Err(syn::Error::new_spanned(
+        &nested_meta,
+        "Expected NameValue syntax, e.g. 'default_log_filter = \"debug\"'.",
+      ))
+    };
+
+    let Some(ident) = name_value.path.get_ident() else {
+      return Err(syn::Error::new_spanned(
+        &name_value.path,
+        "Expected NameValue syntax, e.g. 'default_log_filter = \"debug\"'.",
+      ))
+    };
+
+    let arg_ref = if ident == "default_log_filter" {
+      &mut self.default_log_filter
+    } else {
+      return Err(syn::Error::new_spanned(
+        &name_value.path,
+        "Unrecognized attribute, see documentation for details.",
+      ))
+    };
+
+    if let Expr::Lit(lit) = &name_value.value {
+      if let Lit::Str(lit_str) = &lit.lit {
+        *arg_ref = Some(lit_str.value());
+      }
+    }
+
+    // If we couldn't parse the value on the right-hand side because it was some
+    // unexpected type, e.g. #[test_log::log(default_log_filter=10)], return an error.
+    if arg_ref.is_none() {
+      return Err(syn::Error::new_spanned(
+        &name_value.value,
+        "Failed to parse value, expected a string!",
+      ))
+    }
+
+    Ok(true)
+  }
+}
+
+
 /// Expand the initialization code for the `log` crate.
-fn expand_logging_init() -> Tokens {
+fn expand_logging_init(attribute_args: &AttributeArgs) -> Tokens {
+  let add_default_log_filter = if let Some(default_log_filter) = &attribute_args.default_log_filter
+  {
+    quote! {
+      let env_logger_builder = env_logger_builder
+        .parse_env(env_logger::Env::default().default_filter_or(#default_log_filter));
+    }
+  } else {
+    quote! {}
+  };
   #[cfg(feature = "log")]
   quote! {
     {
-      let _ = ::env_logger::builder().is_test(true).try_init();
+      let mut env_logger_builder = ::env_logger::builder();
+      #add_default_log_filter
+      let _ = env_logger_builder.is_test(true).try_init();
     }
   }
   #[cfg(not(feature = "log"))]
@@ -140,8 +221,23 @@ fn expand_logging_init() -> Tokens {
 
 
 /// Expand the initialization code for the `tracing` crate.
-fn expand_tracing_init() -> Tokens {
-  #[cfg(feature = "trace")]
+#[cfg(not(feature = "trace"))]
+fn expand_tracing_init(_attribute_args: &AttributeArgs) -> Tokens {
+  quote! {}
+}
+
+#[cfg(feature = "trace")]
+fn expand_tracing_init(attribute_args: &AttributeArgs) -> Tokens {
+  let env_filter = if let Some(default_log_filter) = &attribute_args.default_log_filter {
+    quote! {
+      ::tracing_subscriber::EnvFilter::builder()
+        .with_default_directive(#default_log_filter.parse().expect("test-log: default_log_filter must be valid"))
+        .from_env_lossy()
+    }
+  } else {
+    quote! { ::tracing_subscriber::EnvFilter::from_default_env() }
+  };
+
   quote! {
     {
       let __internal_event_filter = {
@@ -172,12 +268,10 @@ fn expand_tracing_init() -> Tokens {
       };
 
       let _ = ::tracing_subscriber::FmtSubscriber::builder()
-        .with_env_filter(::tracing_subscriber::EnvFilter::from_default_env())
+        .with_env_filter(#env_filter)
         .with_span_events(__internal_event_filter)
         .with_test_writer()
         .try_init();
     }
   }
-  #[cfg(not(feature = "trace"))]
-  quote! {}
 }

tests/default_log_filter.rs

@@ -0,0 +1,22 @@
+//! This test needs to be defined in a separate file because it depends
+//! on global state (logger) and can't be run in parallel/the same
+//! process with other tests to avoid flakiness (other tests
+//! initializing `env_logger` first).
+
+#![cfg(feature = "log")]
+
+use std::env;
+
+use logging::log_enabled;
+use logging::Level;
+
+
+#[test_log::test(tokio::test)]
+#[test_log(default_log_filter = "debug")]
+async fn with_inner_test_attribute_and_default_log_filter_defined() {
+  // Check that RUST_LOG isn't set, because that could affect the
+  // outcome of this test since we're checking that we fallback to
+  // "debug" if no RUST_LOG is set.
+  assert!(env::var(env_logger::DEFAULT_FILTER_ENV).is_err());
+  assert!(log_enabled!(Level::Debug));
+}

tests/mod.rs

@@ -68,6 +68,19 @@ async fn instrumented(input: usize) -> usize {
   result
 }
 
+/// To run the tracing tests and manually verify the output, run with
+/// the `trace` feature:
+/// ```sh
+/// cargo test --features trace trace_with_custom_runtime -- --nocapture
+/// ```
+///
+/// Log level can be configured via the `RUST_LOG` env variable and span
+/// events for `#[instrumented]` can be configured via the
+/// `RUST_LOG_SPAN_EVENTS` env variable:
+/// ```sh
+/// RUST_LOG=debug RUST_LOG_SPAN_EVENTS=full \
+///   cargo test --features trace trace_with_custom_runtime -- --nocapture
+/// ```
 #[test_log::test]
 fn trace_with_custom_runtime() {
   let rt = Builder::new_current_thread().build().unwrap();
@@ -86,6 +99,14 @@ async fn trace_with_tokio_attribute() {
   debug!("done");
 }
 
+#[test_log::test(tokio::test)]
+#[test_log(default_log_filter = "info")]
+async fn trace_with_default_log_filter() {
+  instrumented(6).await;
+  instrumented(4).await;
+  debug!("done");
+}
+
 #[test_log::test(tokio::test(flavor = "multi_thread", worker_threads = 1))]
 async fn trace_with_tokio_attribute_with_arguments() {
   instrumented(6).await;