Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

attributes: implement #[instrument(ret)] #1716

Merged
merged 17 commits into from
Nov 29, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 17 additions & 10 deletions tracing-attributes/src/attr.rs
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,8 @@ pub(crate) struct InstrumentArgs {
target: Option<LitStr>,
pub(crate) skips: HashSet<Ident>,
pub(crate) fields: Option<Fields>,
pub(crate) err_mode: Option<ErrorMode>,
pub(crate) err_mode: Option<FormatMode>,
pub(crate) ret_mode: Option<FormatMode>,
/// Errors describing any unrecognized parse inputs that we skipped.
parse_warnings: Vec<syn::Error>,
}
Expand Down Expand Up @@ -139,8 +140,12 @@ impl Parse for InstrumentArgs {
args.fields = Some(input.parse()?);
} else if lookahead.peek(kw::err) {
let _ = input.parse::<kw::err>();
let mode = ErrorMode::parse(input)?;
let mode = FormatMode::parse(input)?;
args.err_mode = Some(mode);
} else if lookahead.peek(kw::ret) {
let _ = input.parse::<kw::ret>()?;
let mode = FormatMode::parse(input)?;
args.ret_mode = Some(mode);
} else if lookahead.peek(Token![,]) {
let _ = input.parse::<Token![,]>()?;
} else {
Expand Down Expand Up @@ -199,29 +204,30 @@ impl Parse for Skips {
}

#[derive(Clone, Debug, Hash, PartialEq, Eq)]
pub(crate) enum ErrorMode {
pub(crate) enum FormatMode {
Default,
Display,
Debug,
}

impl Default for ErrorMode {
impl Default for FormatMode {
fn default() -> Self {
ErrorMode::Display
FormatMode::Default
}
}

impl Parse for ErrorMode {
impl Parse for FormatMode {
fn parse(input: ParseStream<'_>) -> syn::Result<Self> {
if !input.peek(syn::token::Paren) {
return Ok(ErrorMode::default());
return Ok(FormatMode::default());
}
let content;
let _ = syn::parenthesized!(content in input);
let maybe_mode: Option<Ident> = content.parse()?;
maybe_mode.map_or(Ok(ErrorMode::default()), |ident| {
maybe_mode.map_or(Ok(FormatMode::default()), |ident| {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think Display should be the default for return values, personally. Most return values will likely not implement Display --- Display was the default for errors simply because most errors implement the std::error::Error trait, which requires them to be Display. If we're always going to format return values, we should probably default to using Debug, and make Display be the one that the user opts in to.

With that said, I think we may actually want to change so that the default behavior is to record the return value as a tracing primitive value if it's one of the primitive Value types, and fall back to Display if it's not. We can look at the function signature's return type, and we already have code for determining whether a type is a primitive Value:

impl RecordType {
/// Array of primitive types which should be recorded as [RecordType::Value].
const TYPES_FOR_VALUE: &'static [&'static str] = &[
"bool",
"str",
"u8",
"i8",
"u16",
"i16",
"u32",
"i32",
"u64",
"i64",
"f32",
"f64",
"usize",
"isize",
"NonZeroU8",
"NonZeroI8",
"NonZeroU16",
"NonZeroI16",
"NonZeroU32",
"NonZeroI32",
"NonZeroU64",
"NonZeroI64",
"NonZeroUsize",
"NonZeroIsize",
"Wrapping",
];
/// Parse `RecordType` from [syn::Type] by looking up
/// the [RecordType::TYPES_FOR_VALUE] array.
fn parse_from_ty(ty: &syn::Type) -> Self {
match ty {
syn::Type::Path(syn::TypePath { path, .. })
if path
.segments
.iter()
.last()
.map(|path_segment| {
let ident = path_segment.ident.to_string();
Self::TYPES_FOR_VALUE.iter().any(|&t| t == ident)
})
.unwrap_or(false) =>
{
RecordType::Value
}
syn::Type::Reference(syn::TypeReference { elem, .. }) => {
RecordType::parse_from_ty(&*elem)
}
_ => RecordType::Debug,
}
}
}

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because we are special-casing Result<T, E>s, in order to do fallback'ing we need to extract T from the Result of syn::Type being returned, which I can find the way to do it. Therefore I'd go with the former change.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, that's fair; I think it should be possible to find Results and get the type parameter using syn, but it might be fairly complex. We can always add that in a future change.

match ident.to_string().as_str() {
"Debug" => Ok(ErrorMode::Debug),
"Display" => Ok(ErrorMode::Display),
"Debug" => Ok(FormatMode::Debug),
"Display" => Ok(FormatMode::Display),
_ => Err(syn::Error::new(
ident.span(),
"unknown error mode, must be Debug or Display",
Expand Down Expand Up @@ -356,4 +362,5 @@ mod kw {
syn::custom_keyword!(target);
syn::custom_keyword!(name);
syn::custom_keyword!(err);
syn::custom_keyword!(ret);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

personally, my preference would be to use return rather than ret, for consistency with the return keyword --- the abbreviation feels like it would just make things more confusing for the user. I'm open to being convinced otherwise, though, if most folks think that saving three letters here is really important...

also, the field name is return rather than ret, so it's a little surprising that they are different.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm reluctant to use return for the sake of syntax highlighting. return in this image is highlighted as a keyword,
but ideally err and return should be in the same color as they are both arguments. 2021-11-17-180810_7680x2160_scrot

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hmm, that's a good point; I hadn't considered that...

}
101 changes: 78 additions & 23 deletions tracing-attributes/src/expand.rs
Original file line number Diff line number Diff line change
Expand Up @@ -9,7 +9,7 @@ use syn::{
};

use crate::{
attr::{ErrorMode, Field, Fields, InstrumentArgs},
attr::{Field, Fields, FormatMode, InstrumentArgs},
MaybeItemFnRef,
};

Expand Down Expand Up @@ -191,8 +191,18 @@ fn gen_block<B: ToTokens>(
})();

let err_event = match args.err_mode {
Some(ErrorMode::Display) => Some(quote!(tracing::error!(error = %e))),
Some(ErrorMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
Some(FormatMode::Default) | Some(FormatMode::Display) => {
Some(quote!(tracing::error!(error = %e)))
}
Some(FormatMode::Debug) => Some(quote!(tracing::error!(error = ?e))),
_ => None,
};

let ret_event = match args.ret_mode {
Some(FormatMode::Display) => Some(quote!(tracing::event!(#level, return = %x))),
Some(FormatMode::Default) | Some(FormatMode::Debug) => {
Some(quote!(tracing::event!(#level, return = ?x)))
}
_ => None,
};

Expand All @@ -201,9 +211,26 @@ fn gen_block<B: ToTokens>(
// which is `instrument`ed using `tracing-futures`. Otherwise, this will
// enter the span and then perform the rest of the body.
// If `err` is in args, instrument any resulting `Err`s.
// If `ret` is in args, instrument any resulting `Ok`s when the function
// returns `Result`s, otherwise instrument any resulting values.
if async_context {
let mk_fut = match err_event {
Some(err_event) => quote_spanned!(block.span()=>
let mk_fut = match (err_event, ret_event) {
(Some(err_event), Some(ret_event)) => quote_spanned!(block.span()=>
async move {
match async move { #block }.await {
#[allow(clippy::unit_arg)]
Ok(x) => {
#ret_event;
Ok(x)
},
Err(e) => {
#err_event;
Err(e)
}
}
}
),
(Some(err_event), None) => quote_spanned!(block.span()=>
async move {
match async move { #block }.await {
#[allow(clippy::unit_arg)]
Expand All @@ -215,7 +242,14 @@ fn gen_block<B: ToTokens>(
}
}
),
None => quote_spanned!(block.span()=>
(None, Some(ret_event)) => quote_spanned!(block.span()=>
async move {
let x = async move { #block }.await;
#ret_event;
x
}
),
(None, None) => quote_spanned!(block.span()=>
async move { #block }
),
};
Expand Down Expand Up @@ -254,8 +288,23 @@ fn gen_block<B: ToTokens>(
}
);

if let Some(err_event) = err_event {
return quote_spanned!(block.span()=>
match (err_event, ret_event) {
(Some(err_event), Some(ret_event)) => quote_spanned! {block.span()=>
#span
#[allow(clippy::redundant_closure_call)]
match (move || #block)() {
#[allow(clippy::unit_arg)]
Ok(x) => {
#ret_event;
Ok(x)
},
Err(e) => {
#err_event;
Err(e)
}
}
},
(Some(err_event), None) => quote_spanned!(block.span()=>
#span
#[allow(clippy::redundant_closure_call)]
match (move || #block)() {
Expand All @@ -266,22 +315,28 @@ fn gen_block<B: ToTokens>(
Err(e)
}
}
);
}

quote_spanned!(block.span() =>
// Because `quote` produces a stream of tokens _without_ whitespace, the
// `if` and the block will appear directly next to each other. This
// generates a clippy lint about suspicious `if/else` formatting.
// Therefore, suppress the lint inside the generated code...
#[allow(clippy::suspicious_else_formatting)]
{
),
(None, Some(ret_event)) => quote_spanned!(block.span()=>
#span
// ...but turn the lint back on inside the function body.
#[warn(clippy::suspicious_else_formatting)]
#block
}
)
#[allow(clippy::redundant_closure_call)]
let x = (move || #block)();
hkmatsumoto marked this conversation as resolved.
Show resolved Hide resolved
#ret_event;
hkmatsumoto marked this conversation as resolved.
Show resolved Hide resolved
x
),
(None, None) => quote_spanned!(block.span() =>
// Because `quote` produces a stream of tokens _without_ whitespace, the
// `if` and the block will appear directly next to each other. This
// generates a clippy lint about suspicious `if/else` formatting.
// Therefore, suppress the lint inside the generated code...
#[allow(clippy::suspicious_else_formatting)]
{
#span
// ...but turn the lint back on inside the function body.
#[warn(clippy::suspicious_else_formatting)]
#block
}
),
}
}

/// Indicates whether a field should be recorded as `Value` or `Debug`.
Expand Down
40 changes: 40 additions & 0 deletions tracing-attributes/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -176,6 +176,35 @@ mod expand;
/// }
/// ```
///
/// Adding the `ret` argument to `#[instrument]` will emit an event with the function's
/// return value when the function returns:
///
/// ```
/// # use tracing_attributes::instrument;
/// #[instrument(ret)]
/// fn my_function() -> i32 {
/// 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
/// level.
///
hkmatsumoto marked this conversation as resolved.
Show resolved Hide resolved
/// **Note**: if the function returns a `Result<T, E>`, `ret` will record returned values if and
/// only if the function returns [`Result::Ok`].
///
/// By default, returned values will be recorded using their [`std::fmt::Debug`] implementations.
/// If a returned value implements [`std::fmt::Display`], it can be recorded using its `Display`
/// implementation instead, by writing `ret(Display)`:
///
/// ```
/// # use tracing_attributes::instrument;
/// #[instrument(ret(Display))]
/// fn my_function() -> i32 {
/// 42
/// }
/// ```
///
/// If the function returns a `Result<T, E>` and `E` implements `std::fmt::Display`, you can add
/// `err` or `err(Display)` to emit error events when the function returns `Err`:
///
Expand All @@ -199,6 +228,17 @@ mod expand;
/// }
/// ```
///
/// The `ret` and `err` arguments can be combined in order to record an event if a
/// function returns [`Result::Ok`] or [`Result::Err`]:
///
/// ```
/// # use tracing_attributes::instrument;
/// #[instrument(err, ret)]
/// fn my_function(arg: usize) -> Result<(), std::io::Error> {
/// Ok(())
/// }
/// ```
///
/// `async fn`s may also be instrumented:
///
/// ```
Expand Down
Loading