diff --git a/tracing-attributes/src/attr.rs b/tracing-attributes/src/attr.rs index 2af0400f2b..6bb586ef40 100644 --- a/tracing-attributes/src/attr.rs +++ b/tracing-attributes/src/attr.rs @@ -6,6 +6,14 @@ use quote::{quote, quote_spanned, ToTokens}; use syn::ext::IdentExt as _; use syn::parse::{Parse, ParseStream}; +/// Arguments to `#[instrument(err(...))]` and `#[instrument(ret(...))]` which describe how the +/// return value event should be emitted. +#[derive(Clone, Default, Debug)] +pub(crate) struct EventArgs { + level: Option, + pub(crate) mode: FormatMode, +} + #[derive(Clone, Default, Debug)] pub(crate) struct InstrumentArgs { level: Option, @@ -15,51 +23,15 @@ pub(crate) struct InstrumentArgs { pub(crate) follows_from: Option, pub(crate) skips: HashSet, pub(crate) fields: Option, - pub(crate) err_mode: Option, - pub(crate) ret_mode: Option, + pub(crate) err_args: Option, + pub(crate) ret_args: Option, /// Errors describing any unrecognized parse inputs that we skipped. parse_warnings: Vec, } impl InstrumentArgs { - pub(crate) fn level(&self) -> impl ToTokens { - fn is_level(lit: &LitInt, expected: u64) -> bool { - match lit.base10_parse::() { - Ok(value) => value == expected, - Err(_) => false, - } - } - - match &self.level { - Some(Level::Str(ref lit)) if lit.value().eq_ignore_ascii_case("trace") => { - quote!(tracing::Level::TRACE) - } - Some(Level::Str(ref lit)) if lit.value().eq_ignore_ascii_case("debug") => { - quote!(tracing::Level::DEBUG) - } - Some(Level::Str(ref lit)) if lit.value().eq_ignore_ascii_case("info") => { - quote!(tracing::Level::INFO) - } - Some(Level::Str(ref lit)) if lit.value().eq_ignore_ascii_case("warn") => { - quote!(tracing::Level::WARN) - } - Some(Level::Str(ref lit)) if lit.value().eq_ignore_ascii_case("error") => { - quote!(tracing::Level::ERROR) - } - Some(Level::Int(ref lit)) if is_level(lit, 1) => quote!(tracing::Level::TRACE), - Some(Level::Int(ref lit)) if is_level(lit, 2) => quote!(tracing::Level::DEBUG), - Some(Level::Int(ref lit)) if is_level(lit, 3) => quote!(tracing::Level::INFO), - Some(Level::Int(ref lit)) if is_level(lit, 4) => quote!(tracing::Level::WARN), - Some(Level::Int(ref lit)) if is_level(lit, 5) => quote!(tracing::Level::ERROR), - Some(Level::Path(ref pat)) => quote!(#pat), - Some(_) => quote! { - compile_error!( - "unknown verbosity level, expected one of \"trace\", \ - \"debug\", \"info\", \"warn\", or \"error\", or a number 1-5" - ) - }, - None => quote!(tracing::Level::INFO), - } + pub(crate) fn level(&self) -> Level { + self.level.clone().unwrap_or(Level::Info) } pub(crate) fn target(&self) -> impl ToTokens { @@ -154,12 +126,12 @@ impl Parse for InstrumentArgs { args.fields = Some(input.parse()?); } else if lookahead.peek(kw::err) { let _ = input.parse::(); - let mode = FormatMode::parse(input)?; - args.err_mode = Some(mode); + let err_args = EventArgs::parse(input)?; + args.err_args = Some(err_args); } else if lookahead.peek(kw::ret) { let _ = input.parse::()?; - let mode = FormatMode::parse(input)?; - args.ret_mode = Some(mode); + let ret_args = EventArgs::parse(input)?; + args.ret_args = Some(ret_args); } else if lookahead.peek(Token![,]) { let _ = input.parse::()?; } else { @@ -177,6 +149,55 @@ impl Parse for InstrumentArgs { } } +impl EventArgs { + pub(crate) fn level(&self, default: Level) -> Level { + self.level.clone().unwrap_or(default) + } +} + +impl Parse for EventArgs { + fn parse(input: ParseStream<'_>) -> syn::Result { + if !input.peek(syn::token::Paren) { + return Ok(Self::default()); + } + let content; + let _ = syn::parenthesized!(content in input); + let mut result = Self::default(); + let mut parse_one_arg = + || { + let lookahead = content.lookahead1(); + if lookahead.peek(kw::level) { + if result.level.is_some() { + return Err(content.error("expected only a single `level` argument")); + } + result.level = Some(content.parse()?); + } else if result.mode != FormatMode::default() { + return Err(content.error("expected only a single format argument")); + } else if let Some(ident) = content.parse::>()? { + match ident.to_string().as_str() { + "Debug" => result.mode = FormatMode::Debug, + "Display" => result.mode = FormatMode::Display, + _ => return Err(syn::Error::new( + ident.span(), + "unknown event formatting mode, expected either `Debug` or `Display`", + )), + } + } + Ok(()) + }; + parse_one_arg()?; + if !content.is_empty() { + if content.lookahead1().peek(Token![,]) { + let _ = content.parse::()?; + parse_one_arg()?; + } else { + return Err(content.error("expected `,` or `)`")); + } + } + Ok(result) + } +} + struct StrArg { value: LitStr, _p: std::marker::PhantomData, @@ -247,27 +268,6 @@ impl Default for FormatMode { } } -impl Parse for FormatMode { - fn parse(input: ParseStream<'_>) -> syn::Result { - if !input.peek(syn::token::Paren) { - return Ok(FormatMode::default()); - } - let content; - let _ = syn::parenthesized!(content in input); - let maybe_mode: Option = content.parse()?; - maybe_mode.map_or(Ok(FormatMode::default()), |ident| { - match ident.to_string().as_str() { - "Debug" => Ok(FormatMode::Debug), - "Display" => Ok(FormatMode::Display), - _ => Err(syn::Error::new( - ident.span(), - "unknown error mode, must be Debug or Display", - )), - } - }) - } -} - #[derive(Clone, Debug)] pub(crate) struct Fields(pub(crate) Punctuated); @@ -363,9 +363,12 @@ impl ToTokens for FieldKind { } #[derive(Clone, Debug)] -enum Level { - Str(LitStr), - Int(LitInt), +pub(crate) enum Level { + Trace, + Debug, + Info, + Warn, + Error, Path(Path), } @@ -375,9 +378,37 @@ impl Parse for Level { let _ = input.parse::()?; let lookahead = input.lookahead1(); if lookahead.peek(LitStr) { - Ok(Self::Str(input.parse()?)) + let str: LitStr = input.parse()?; + match str.value() { + s if s.eq_ignore_ascii_case("trace") => Ok(Level::Trace), + s if s.eq_ignore_ascii_case("debug") => Ok(Level::Debug), + s if s.eq_ignore_ascii_case("info") => Ok(Level::Info), + s if s.eq_ignore_ascii_case("warn") => Ok(Level::Warn), + s if s.eq_ignore_ascii_case("error") => Ok(Level::Error), + _ => Err(input.error( + "unknown verbosity level, expected one of \"trace\", \ + \"debug\", \"info\", \"warn\", or \"error\", or a number 1-5", + )), + } } else if lookahead.peek(LitInt) { - Ok(Self::Int(input.parse()?)) + fn is_level(lit: &LitInt, expected: u64) -> bool { + match lit.base10_parse::() { + Ok(value) => value == expected, + Err(_) => false, + } + } + let int: LitInt = input.parse()?; + match &int { + i if is_level(i, 1) => Ok(Level::Trace), + i if is_level(i, 2) => Ok(Level::Debug), + i if is_level(i, 3) => Ok(Level::Info), + i if is_level(i, 4) => Ok(Level::Warn), + i if is_level(i, 5) => Ok(Level::Error), + _ => Err(input.error( + "unknown verbosity level, expected one of \"trace\", \ + \"debug\", \"info\", \"warn\", or \"error\", or a number 1-5", + )), + } } else if lookahead.peek(Ident) { Ok(Self::Path(input.parse()?)) } else { @@ -386,6 +417,19 @@ impl Parse for Level { } } +impl ToTokens for Level { + fn to_tokens(&self, tokens: &mut TokenStream) { + match self { + Level::Trace => tokens.extend(quote!(tracing::Level::TRACE)), + Level::Debug => tokens.extend(quote!(tracing::Level::DEBUG)), + Level::Info => tokens.extend(quote!(tracing::Level::INFO)), + Level::Warn => tokens.extend(quote!(tracing::Level::WARN)), + Level::Error => tokens.extend(quote!(tracing::Level::ERROR)), + Level::Path(ref pat) => tokens.extend(quote!(#pat)), + } + } +} + mod kw { syn::custom_keyword!(fields); syn::custom_keyword!(skip); diff --git a/tracing-attributes/src/expand.rs b/tracing-attributes/src/expand.rs index 0390a8c44e..d6b7855615 100644 --- a/tracing-attributes/src/expand.rs +++ b/tracing-attributes/src/expand.rs @@ -10,7 +10,7 @@ use syn::{ }; use crate::{ - attr::{Field, Fields, FormatMode, InstrumentArgs}, + attr::{Field, Fields, FormatMode, InstrumentArgs, Level}, MaybeItemFn, MaybeItemFnRef, }; @@ -116,7 +116,8 @@ fn gen_block( .map(|name| quote!(#name)) .unwrap_or_else(|| quote!(#instrumented_function_name)); - let level = args.level(); + let args_level = args.level(); + let level = args_level.clone(); let follows_from = args.follows_from.iter(); let follows_from = quote! { @@ -232,21 +233,33 @@ fn gen_block( let target = args.target(); - let err_event = match args.err_mode { - Some(FormatMode::Default) | Some(FormatMode::Display) => { - Some(quote!(tracing::error!(target: #target, error = %e))) + let err_event = match args.err_args { + Some(event_args) => { + let level_tokens = event_args.level(Level::Error); + match event_args.mode { + FormatMode::Default | FormatMode::Display => Some(quote!( + tracing::event!(target: #target, #level_tokens, error = %e) + )), + FormatMode::Debug => Some(quote!( + tracing::event!(target: #target, #level_tokens, error = ?e) + )), + } } - Some(FormatMode::Debug) => Some(quote!(tracing::error!(target: #target, error = ?e))), _ => None, }; - let ret_event = match args.ret_mode { - Some(FormatMode::Display) => Some(quote!( - tracing::event!(target: #target, #level, return = %x) - )), - Some(FormatMode::Default) | Some(FormatMode::Debug) => Some(quote!( - tracing::event!(target: #target, #level, return = ?x) - )), + let ret_event = match args.ret_args { + Some(event_args) => { + let level_tokens = event_args.level(args_level); + match event_args.mode { + FormatMode::Display => Some(quote!( + tracing::event!(target: #target, #level_tokens, return = %x) + )), + FormatMode::Default | FormatMode::Debug => Some(quote!( + tracing::event!(target: #target, #level_tokens, return = ?x) + )), + } + } _ => None, }; diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index 6165803695..269e32522c 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -227,10 +227,20 @@ mod expand; /// 42 /// } /// ``` -/// The return value event will have the same level as the span generated by `#[instrument]`. -/// By default, this will be `TRACE`, but if the level is overridden, the event will be at the same +/// The level of the return value event defaults to the same level as the span generated by `#[instrument]`. +/// By default, this will be `TRACE`, but if the span level is overridden, the event will be at the same /// level. /// +/// It's also possible to override the level for the `ret` event independently: +/// +/// ``` +/// # use tracing_attributes::instrument; +/// #[instrument(ret(level = "warn"))] +/// fn my_function() -> i32 { +/// 42 +/// } +/// ``` +/// /// **Note**: if the function returns a `Result`, `ret` will record returned values if and /// only if the function returns [`Result::Ok`]. /// @@ -257,6 +267,16 @@ mod expand; /// } /// ``` /// +/// Similarly, you can override the level of the `err` event: +/// +/// ``` +/// # use tracing_attributes::instrument; +/// #[instrument(err(level = "info"))] +/// fn my_function(arg: usize) -> Result<(), std::io::Error> { +/// Ok(()) +/// } +/// ``` +/// /// By default, error values will be recorded using their `std::fmt::Display` implementations. /// If an error implements `std::fmt::Debug`, it can be recorded using its `Debug` implementation /// instead, by writing `err(Debug)`: diff --git a/tracing-attributes/tests/err.rs b/tracing-attributes/tests/err.rs index d062a2b7c1..842a6e0e3a 100644 --- a/tracing-attributes/tests/err.rs +++ b/tracing-attributes/tests/err.rs @@ -252,3 +252,72 @@ fn test_err_custom_target() { }); handle.assert_finished(); } + +#[instrument(err(level = "info"))] +fn err_info() -> Result { + u8::try_from(1234) +} + +#[test] +fn test_err_info() { + let span = span::mock().named("err_info"); + let (collector, handle) = collector::mock() + .new_span(span.clone()) + .enter(span.clone()) + .event(event::mock().at_level(Level::INFO)) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + with_default(collector, || err_info().ok()); + handle.assert_finished(); +} + +#[instrument(err(Debug, level = "info"))] +fn err_dbg_info() -> Result { + u8::try_from(1234) +} + +#[test] +fn test_err_dbg_info() { + let span = span::mock().named("err_dbg_info"); + let (collector, handle) = collector::mock() + .new_span(span.clone()) + .enter(span.clone()) + .event( + event::mock().at_level(Level::INFO).with_fields( + field::mock("error") + // use the actual error value that will be emitted, so + // that this test doesn't break if the standard library + // changes the `fmt::Debug` output from the error type + // in the future. + .with_value(&tracing::field::debug(u8::try_from(1234).unwrap_err())), + ), + ) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + with_default(collector, || err_dbg_info().ok()); + handle.assert_finished(); +} + +#[instrument(level = "warn", err(level = "info"))] +fn err_warn_info() -> Result { + u8::try_from(1234) +} + +#[test] +fn test_err_warn_info() { + let span = span::mock().named("err_warn_info").at_level(Level::WARN); + let (collector, handle) = collector::mock() + .new_span(span.clone()) + .enter(span.clone()) + .event(event::mock().at_level(Level::INFO)) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + with_default(collector, || err_warn_info().ok()); + handle.assert_finished(); +} diff --git a/tracing-attributes/tests/ret.rs b/tracing-attributes/tests/ret.rs index fce206e0f6..2511e0a520 100644 --- a/tracing-attributes/tests/ret.rs +++ b/tracing-attributes/tests/ret.rs @@ -253,3 +253,53 @@ fn test_ret_and_ok() { with_default(collector, || ret_and_ok().ok()); handle.assert_finished(); } + +#[instrument(level = "warn", ret(level = "info"))] +fn ret_warn_info() -> i32 { + 42 +} + +#[test] +fn test_warn_info() { + let span = span::mock().named("ret_warn_info").at_level(Level::WARN); + let (collector, handle) = collector::mock() + .new_span(span.clone()) + .enter(span.clone()) + .event( + event::mock() + .with_fields(field::mock("return").with_value(&tracing::field::debug(42))) + .at_level(Level::INFO), + ) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + + with_default(collector, ret_warn_info); + handle.assert_finished(); +} + +#[instrument(ret(level = "warn", Debug))] +fn ret_dbg_warn() -> i32 { + 42 +} + +#[test] +fn test_dbg_warn() { + let span = span::mock().named("ret_dbg_warn").at_level(Level::INFO); + let (collector, handle) = collector::mock() + .new_span(span.clone()) + .enter(span.clone()) + .event( + event::mock() + .with_fields(field::mock("return").with_value(&tracing::field::debug(42))) + .at_level(Level::WARN), + ) + .exit(span.clone()) + .drop_span(span) + .done() + .run_with_handle(); + + with_default(collector, ret_dbg_warn); + handle.assert_finished(); +}