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 is initialized globally, it is
possible that this value will be ignored if the logger is already
initialized.

Fixes: #25

examples/main.rs

@@ -0,0 +1,11 @@
+//! 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:
+//!
+//! cargo expand --tests --example main
+
+#[test_log::test]
+fn works() {
+  assert_eq!(2 + 2, 4);
+}
+
+fn main() {}

src/lib.rs

@@ -14,9 +14,7 @@ use proc_macro2::TokenStream as Tokens;
 
 use quote::quote;
 
-use syn::parse_macro_input;
-use syn::ItemFn;
-
+use syn::{parse::Parse, parse_macro_input, Attribute, Expr, ItemFn, Lit, Meta};
 
 /// A procedural macro for the `test` attribute.
 ///
@@ -72,12 +70,19 @@ use syn::ItemFn;
 /// ```
 #[proc_macro_attribute]
 pub fn test(attr: TokenStream, item: TokenStream) -> TokenStream {
+  let item = parse_macro_input!(item as ItemFn);
+  try_test(attr, item)
+    .unwrap_or_else(syn::Error::into_compile_error)
+    .into()
+}
+
+fn try_test(attr: TokenStream, input: ItemFn) -> syn::Result<Tokens> {
   let inner_test = if attr.is_empty() {
     quote! { ::core::prelude::v1::test }
   } else {
     attr.into()
   };
-  let input = parse_macro_input!(item as ItemFn);
+  let mut attribute_args = AttributeArgs::default();
 
   let ItemFn {
     attrs,
@@ -86,12 +91,21 @@ pub fn test(attr: TokenStream, item: TokenStream) -> TokenStream {
     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 = populate_attribute_args(&mut attribute_args, &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
@@ -115,26 +129,105 @@ pub fn test(attr: TokenStream, item: TokenStream) -> TokenStream {
       #block
     }
   };
-  result.into()
+  Ok(result)
+}
+
+#[derive(Debug, Default)]
+struct AttributeArgs {
+  default_log_filter: Option<String>,
 }
 
+fn populate_attribute_args(
+  attribute_args: &mut AttributeArgs,
+  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 attribute_args.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"))]
   quote! {}
 }
 
-
 /// 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 = {
@@ -165,12 +258,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,12 @@
+//! This test needs to be defined in a separate file because it depends on global state
+//! (logger) and can't be run in parallel / in the same process with other tests to avoid
+//! flakiness (other tests initializing the env_logger first).
+
+#[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!(std::env::var(env_logger::DEFAULT_FILTER_ENV).is_err());
+  assert!(logging::log_enabled!(logging::Level::Debug));
+}

tests/mod.rs

@@ -10,14 +10,12 @@ use tracing::error;
 use tracing::info;
 use tracing::instrument;
 
-
 mod something {
   pub type Error = String;
 }
 
 use something::Error;
 
-
 #[test_log::test]
 fn without_return_type() {
   assert_eq!(2 + 2, 4);
@@ -68,6 +66,12 @@ async fn instrumented(input: usize) -> usize {
   result
 }
 
+/// To run the tracing tests and manually verify the output, run with the 'trace' feature:
+/// 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:
+/// 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 +90,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;
@@ -109,7 +121,6 @@ impl<T> Foo for T {}
 #[test_log::test]
 fn unambiguous_map() {}
 
-
 /// A module used for testing the `test` attribute after importing it
 /// via `use` instead of using fuller qualified syntax.
 mod local {