Skip to content

Commit

Permalink
attributes: don't record primitive types of the function arguments as…
Browse files Browse the repository at this point in the history
… `fmt::Debug` (#1378)

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.
  • Loading branch information
Folyd authored and hawkw committed Jun 1, 2021
1 parent 9702bf5 commit 9c031d7
Show file tree
Hide file tree
Showing 6 changed files with 118 additions and 32 deletions.
122 changes: 104 additions & 18 deletions tracing-attributes/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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
///
Expand Down Expand Up @@ -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
Expand All @@ -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();
Expand Down Expand Up @@ -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(),
};

Expand Down Expand Up @@ -1044,20 +1057,93 @@ impl Parse for Level {
}
}

fn param_names(pat: Pat) -> Box<dyn Iterator<Item = Ident>> {
/// 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<dyn Iterator<Item = (Ident, RecordType)>> {
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
Expand Down
2 changes: 1 addition & 1 deletion tracing-attributes/tests/async_fn.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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)),
Expand Down
2 changes: 1 addition & 1 deletion tracing-attributes/tests/destructuring.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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())
Expand Down
2 changes: 1 addition & 1 deletion tracing-attributes/tests/err.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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())
Expand Down
6 changes: 3 additions & 3 deletions tracing-attributes/tests/fields.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(),
);
Expand All @@ -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(),
Expand Down Expand Up @@ -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, || {
Expand Down
16 changes: 8 additions & 8 deletions tracing-attributes/tests/instrument.rs
Original file line number Diff line number Diff line change
Expand Up @@ -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(),
),
)
Expand All @@ -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(),
),
)
Expand Down Expand Up @@ -108,15 +108,15 @@ 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())
.drop_span(span)
.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())
Expand Down Expand Up @@ -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())
Expand Down Expand Up @@ -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())
Expand Down

0 comments on commit 9c031d7

Please sign in to comment.