From 37d55b6f1c36db96d4899ddcda4449e6bb2b853f Mon Sep 17 00:00:00 2001 From: Folyd Date: Fri, 7 May 2021 07:38:09 +0800 Subject: [PATCH] attributes: don't record primitive types of the function arguments as `fmt::Debug` (#1378) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The default behavior of `tracing::instrument` attribution will record all of the function arguments as `fmt::Debug`, which is overwhelmed and unnecessary for those primitive types, such as `bool`, `u8`, `i8`, `u16`, `i16`, `u32`, `i32`, `u64`, `i64`, `usize`, and `isize`. Another concerning reason is that we‘ll lose the type info of those primitive types when record by a `Visitor`, while those type infos is essential to some people. For example, I need to show my spans in Jaeger UI. Make the `tracing::instrument` records other function arguments as `fmt::Debug ` while not for those primitive types. However, I'm not good at naming. Maybe the `RecordType` enum and its variant aren't a good name? I'd love to seek suggestions. Thanks. --- tracing-attributes/src/lib.rs | 122 ++++++++++++++++++---- tracing-attributes/tests/async_fn.rs | 2 +- tracing-attributes/tests/destructuring.rs | 2 +- tracing-attributes/tests/err.rs | 2 +- tracing-attributes/tests/fields.rs | 6 +- tracing-attributes/tests/instrument.rs | 16 +-- 6 files changed, 118 insertions(+), 32 deletions(-) diff --git a/tracing-attributes/src/lib.rs b/tracing-attributes/src/lib.rs index 13ebabf5cb..09b42e840e 100644 --- a/tracing-attributes/src/lib.rs +++ b/tracing-attributes/src/lib.rs @@ -98,10 +98,15 @@ use syn::{ /// Instruments a function to create and enter a `tracing` [span] every time /// the function is called. /// -/// By default, the generated span's [name] will be the name of the function, -/// the span's [target] will be the current module path, and the span's [level] -/// will be [`INFO`], although these properties can be overridden. Any arguments -/// to that function will be recorded as fields using [`fmt::Debug`]. +/// Unless overriden, a span with `info` level will be generated. +/// The generated span's name will be the name of the function. +/// By default, all arguments to the function are included as fields on the +/// span. Arguments that are `tracing` [primitive types] implementing the +/// [`Value` trait] will be recorded as fields of that type. Types which do +/// not implement `Value` will be recorded using [`std::fmt::Debug`]. +/// +/// [primitive types]: https://docs.rs/tracing/latest/tracing/field/trait.Value.html#foreign-impls +/// [`Value` trait]: https://docs.rs/tracing/latest/tracing/field/trait.Value.html. /// /// # Overriding Span Attributes /// @@ -591,12 +596,17 @@ fn gen_block( let span = (|| { // Pull out the arguments-to-be-skipped first, so we can filter results // below. - let param_names: Vec<(Ident, Ident)> = params + let param_names: Vec<(Ident, (Ident, RecordType))> = params .clone() .into_iter() .flat_map(|param| match param { - FnArg::Typed(PatType { pat, .. }) => param_names(*pat), - FnArg::Receiver(_) => Box::new(iter::once(Ident::new("self", param.span()))), + FnArg::Typed(PatType { pat, ty, .. }) => { + param_names(*pat, RecordType::parse_from_ty(&*ty)) + } + FnArg::Receiver(_) => Box::new(iter::once(( + Ident::new("self", param.span()), + RecordType::Debug, + ))), }) // Little dance with new (user-exposed) names and old (internal) // names of identifiers. That way, we could do the following @@ -608,13 +618,13 @@ fn gen_block( // async fn foo(&self, v: usize) {} // } // ``` - .map(|x| { + .map(|(x, record_type)| { // if we are inside a function generated by async-trait <=0.1.43, we need to // take care to rewrite "_self" as "self" for 'user convenience' if self_type.is_some() && x == "_self" { - (Ident::new("self", x.span()), x) + (Ident::new("self", x.span()), (x, record_type)) } else { - (x.clone(), x) + (x.clone(), (x, record_type)) } }) .collect(); @@ -649,13 +659,16 @@ fn gen_block( true } }) - .map(|(user_name, real_name)| quote!(#user_name = tracing::field::debug(&#real_name))) + .map(|(user_name, (real_name, record_type))| match record_type { + RecordType::Value => quote!(#user_name = #real_name), + RecordType::Debug => quote!(#user_name = tracing::field::debug(&#real_name)), + }) .collect(); // replace every use of a variable with its original name if let Some(Fields(ref mut fields)) = args.fields { let mut replacer = IdentAndTypesRenamer { - idents: param_names, + idents: param_names.into_iter().map(|(a, (b, _))| (a, b)).collect(), types: Vec::new(), }; @@ -1044,20 +1057,93 @@ impl Parse for Level { } } -fn param_names(pat: Pat) -> Box> { +/// Indicates whether a field should be recorded as `Value` or `Debug`. +enum RecordType { + /// The field should be recorded using its `Value` implementation. + Value, + /// The field should be recorded using `tracing::field::debug()`. + Debug, +} + +impl RecordType { + /// Array of primitive types which should be recorded as [RecordType::Value]. + const TYPES_FOR_VALUE: [&'static str; 23] = [ + "bool", + "str", + "u8", + "i8", + "u16", + "i16", + "u32", + "i32", + "u64", + "i64", + "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, + } + } +} + +fn param_names(pat: Pat, record_type: RecordType) -> Box> { match pat { - Pat::Ident(PatIdent { ident, .. }) => Box::new(iter::once(ident)), - Pat::Reference(PatReference { pat, .. }) => param_names(*pat), + Pat::Ident(PatIdent { ident, .. }) => Box::new(iter::once((ident, record_type))), + Pat::Reference(PatReference { pat, .. }) => param_names(*pat, record_type), + // We can't get the concrete type of fields in the struct/tuple + // patterns by using `syn`. e.g. `fn foo(Foo { x, y }: Foo) {}`. + // Therefore, the struct/tuple patterns in the arguments will just + // always be recorded as `RecordType::Debug`. Pat::Struct(PatStruct { fields, .. }) => Box::new( fields .into_iter() - .flat_map(|FieldPat { pat, .. }| param_names(*pat)), + .flat_map(|FieldPat { pat, .. }| param_names(*pat, RecordType::Debug)), + ), + Pat::Tuple(PatTuple { elems, .. }) => Box::new( + elems + .into_iter() + .flat_map(|p| param_names(p, RecordType::Debug)), ), - Pat::Tuple(PatTuple { elems, .. }) => Box::new(elems.into_iter().flat_map(param_names)), Pat::TupleStruct(PatTupleStruct { pat: PatTuple { elems, .. }, .. - }) => Box::new(elems.into_iter().flat_map(param_names)), + }) => Box::new( + elems + .into_iter() + .flat_map(|p| param_names(p, RecordType::Debug)), + ), // The above *should* cover all cases of irrefutable patterns, // but we purposefully don't do any funny business here diff --git a/tracing-attributes/tests/async_fn.rs b/tracing-attributes/tests/async_fn.rs index c6225c1d71..11fcc2f73c 100644 --- a/tracing-attributes/tests/async_fn.rs +++ b/tracing-attributes/tests/async_fn.rs @@ -182,7 +182,7 @@ fn async_fn_with_async_trait_and_fields_expressions() { .new_span( span.clone().with_field( field::mock("_v") - .with_value(&tracing::field::debug(5)) + .with_value(&5usize) .and(field::mock("test").with_value(&tracing::field::debug(10))) .and(field::mock("val").with_value(&42u64)) .and(field::mock("val2").with_value(&42u64)), diff --git a/tracing-attributes/tests/destructuring.rs b/tracing-attributes/tests/destructuring.rs index 9d01d415ed..8d1e3c3d48 100644 --- a/tracing-attributes/tests/destructuring.rs +++ b/tracing-attributes/tests/destructuring.rs @@ -74,7 +74,7 @@ fn destructure_refs() { let (subscriber, handle) = subscriber::mock() .new_span( span.clone() - .with_field(field::mock("arg1").with_value(&format_args!("1")).only()), + .with_field(field::mock("arg1").with_value(&1usize).only()), ) .enter(span.clone()) .exit(span.clone()) diff --git a/tracing-attributes/tests/err.rs b/tracing-attributes/tests/err.rs index cfa30c0361..6e283d52f8 100644 --- a/tracing-attributes/tests/err.rs +++ b/tracing-attributes/tests/err.rs @@ -131,7 +131,7 @@ fn impl_trait_return_type() { let (subscriber, handle) = subscriber::mock() .new_span( span.clone() - .with_field(field::mock("x").with_value(&format_args!("10")).only()), + .with_field(field::mock("x").with_value(&10usize).only()), ) .enter(span.clone()) .exit(span.clone()) diff --git a/tracing-attributes/tests/fields.rs b/tracing-attributes/tests/fields.rs index de038ca7b1..521bbd5167 100644 --- a/tracing-attributes/tests/fields.rs +++ b/tracing-attributes/tests/fields.rs @@ -61,7 +61,7 @@ fn fields() { fn expr_field() { let span = span::mock().with_field( mock("s") - .with_value(&tracing::field::debug("hello world")) + .with_value(&"hello world") .and(mock("len").with_value(&"hello world".len())) .only(), ); @@ -74,7 +74,7 @@ fn expr_field() { fn two_expr_fields() { let span = span::mock().with_field( mock("s") - .with_value(&tracing::field::debug("hello world")) + .with_value(&"hello world") .and(mock("s.len").with_value(&"hello world".len())) .and(mock("s.is_empty").with_value(&false)) .only(), @@ -120,7 +120,7 @@ fn parameters_with_fields() { let span = span::mock().with_field( mock("foo") .with_value(&"bar") - .and(mock("param").with_value(&format_args!("1"))) + .and(mock("param").with_value(&1u32)) .only(), ); run_test(span, || { diff --git a/tracing-attributes/tests/instrument.rs b/tracing-attributes/tests/instrument.rs index e010c166cb..5a31430dc6 100644 --- a/tracing-attributes/tests/instrument.rs +++ b/tracing-attributes/tests/instrument.rs @@ -59,8 +59,8 @@ fn fields() { .new_span( span.clone().with_field( field::mock("arg1") - .with_value(&format_args!("2")) - .and(field::mock("arg2").with_value(&format_args!("false"))) + .with_value(&2usize) + .and(field::mock("arg2").with_value(&false)) .only(), ), ) @@ -70,8 +70,8 @@ fn fields() { .new_span( span2.clone().with_field( field::mock("arg1") - .with_value(&format_args!("3")) - .and(field::mock("arg2").with_value(&format_args!("true"))) + .with_value(&3usize) + .and(field::mock("arg2").with_value(&true)) .only(), ), ) @@ -108,7 +108,7 @@ fn skip() { let (subscriber, handle) = subscriber::mock() .new_span( span.clone() - .with_field(field::mock("arg1").with_value(&format_args!("2")).only()), + .with_field(field::mock("arg1").with_value(&2usize).only()), ) .enter(span.clone()) .exit(span.clone()) @@ -116,7 +116,7 @@ fn skip() { .new_span( span2 .clone() - .with_field(field::mock("arg1").with_value(&format_args!("3")).only()), + .with_field(field::mock("arg1").with_value(&3usize).only()), ) .enter(span2.clone()) .exit(span2.clone()) @@ -184,7 +184,7 @@ fn methods() { span.clone().with_field( field::mock("self") .with_value(&format_args!("Foo")) - .and(field::mock("arg1").with_value(&format_args!("42"))), + .and(field::mock("arg1").with_value(&42usize)), ), ) .enter(span.clone()) @@ -213,7 +213,7 @@ fn impl_trait_return_type() { let (subscriber, handle) = subscriber::mock() .new_span( span.clone() - .with_field(field::mock("x").with_value(&format_args!("10")).only()), + .with_field(field::mock("x").with_value(&10usize).only()), ) .enter(span.clone()) .exit(span.clone())