tracing: improve code generation at trace points significantly (#3398)

`ValueSet`s contain both a `FieldSet` reference and a slice of
(`&Field`, `Option<&dyn Value>`) pairs. In cases where `ValueSet`s are
generated via documented interfaces (specifically, `tracing::event!` and
other macros), the `Field` references are redundant, because the
`ValueSet` contains a value slot for every field (either a value or
`None`), in the correct order.

As a result, the code generated by the macros is terrible--it must
put a `Field` on the stack for each field--that's 32 bytes per field!
This is a lot of work for apparently no purpose at runtime, and it
can't be moved into a read-only data section since it's intermixed with
dynamic data.

Fix this by adding a variant of `ValueSet` that skips the `Field`
references, knowing that it represents the full set of fields. Keep
the old kind of `ValueSet`, too--it's still needed by `Span::record`,
by old versions of crates, and potentially by third-party crates using
undocumented methods such as `FieldSet::value_set`.

In some adhoc tests on x86_64 Linux, this reduces the code size as
follows:
* One-field event: 258 bytes to 189 bytes, 25% reduction.
* Five-field event: 638 bytes to 276 bytes, **57%** reduction.
* In a larger project with lots of events, ~5% reduction in .text section.

tracing-core/src/field.rs

@@ -165,10 +165,18 @@ pub struct FieldSet {
 
 /// A set of fields and values for a span.
 pub struct ValueSet<'a> {
-    values: &'a [(&'a Field, Option<&'a (dyn Value + 'a)>)],
+    values: Values<'a>,
     fields: &'a FieldSet,
 }
 
+enum Values<'a> {
+    /// A set of field-value pairs. Fields may be for the wrong field set, some
+    /// fields may be missing, and fields may be in any order.
+    Explicit(&'a [(&'a Field, Option<&'a (dyn Value + 'a)>)]),
+    /// A list of values corresponding exactly to the fields in a `FieldSet`.
+    All(&'a [Option<&'a (dyn Value + 'a)>]),
+}
+
 /// An iterator over a set of fields.
 #[derive(Debug)]
 pub struct Iter {
@@ -922,7 +930,22 @@ impl FieldSet {
     {
         ValueSet {
             fields: self,
-            values: values.borrow(),
+            values: Values::Explicit(values.borrow()),
+        }
+    }
+
+    /// Returns a new `ValueSet` for `values`. These values must exactly
+    /// correspond to the fields in this `FieldSet`.
+    ///
+    /// If `values` does not meet this requirement, the behavior of the
+    /// constructed `ValueSet` is unspecified (but not undefined). You will
+    /// probably observe panics or mismatched field/values.
+    #[doc(hidden)]
+    pub fn value_set_all<'v>(&'v self, values: &'v [Option<&'v (dyn Value + 'v)>]) -> ValueSet<'v> {
+        debug_assert_eq!(values.len(), self.len());
+        ValueSet {
+            fields: self,
+            values: Values::All(values),
         }
     }
 
@@ -1033,13 +1056,24 @@ impl ValueSet<'_> {
     ///
     /// [visitor]: Visit
     pub fn record(&self, visitor: &mut dyn Visit) {
-        let my_callsite = self.callsite();
-        for (field, value) in self.values {
-            if field.callsite() != my_callsite {
-                continue;
+        match self.values {
+            Values::Explicit(values) => {
+                let my_callsite = self.callsite();
+                for (field, value) in values {
+                    if field.callsite() != my_callsite {
+                        continue;
+                    }
+                    if let Some(value) = *value {
+                        value.record(field, visitor);
+                    }
+                }
             }
-            if let Some(value) = value {
-                value.record(field, visitor);
+            Values::All(values) => {
+                for (field, value) in self.fields.iter().zip(values.iter()) {
+                    if let Some(value) = *value {
+                        value.record(&field, visitor);
+                    }
+                }
             }
         }
     }
@@ -1050,28 +1084,42 @@ impl ValueSet<'_> {
     /// [visitor]: Visit
     /// [`ValueSet::record()`]: ValueSet::record()
     pub fn len(&self) -> usize {
-        let my_callsite = self.callsite();
-        self.values
-            .iter()
-            .filter(|(field, _)| field.callsite() == my_callsite)
-            .count()
+        match self.values {
+            Values::Explicit(values) => {
+                let my_callsite = self.callsite();
+                values
+                    .iter()
+                    .filter(|(field, _)| field.callsite() == my_callsite)
+                    .count()
+            }
+            Values::All(values) => values.len(),
+        }
     }
 
     /// Returns `true` if this `ValueSet` contains a value for the given `Field`.
     pub(crate) fn contains(&self, field: &Field) -> bool {
-        field.callsite() == self.callsite()
-            && self
-                .values
+        if field.callsite() != self.callsite() {
+            return false;
+        }
+        match self.values {
+            Values::Explicit(values) => values
                 .iter()
-                .any(|(key, val)| *key == field && val.is_some())
+                .any(|(key, val)| *key == field && val.is_some()),
+            Values::All(values) => values[field.i].is_some(),
+        }
     }
 
     /// Returns true if this `ValueSet` contains _no_ values.
     pub fn is_empty(&self) -> bool {
-        let my_callsite = self.callsite();
-        self.values
-            .iter()
-            .all(|(key, val)| val.is_none() || key.callsite() != my_callsite)
+        match self.values {
+            Values::All(values) => values.iter().all(|v| v.is_none()),
+            Values::Explicit(values) => {
+                let my_callsite = self.callsite();
+                values
+                    .iter()
+                    .all(|(key, val)| val.is_none() || key.callsite() != my_callsite)
+            }
+        }
     }
 
     pub(crate) fn field_set(&self) -> &FieldSet {
@@ -1081,30 +1129,17 @@ impl ValueSet<'_> {
 
 impl fmt::Debug for ValueSet<'_> {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        self.values
-            .iter()
-            .fold(&mut f.debug_struct("ValueSet"), |dbg, (key, v)| {
-                if let Some(val) = v {
-                    val.record(key, dbg);
-                }
-                dbg
-            })
-            .field("callsite", &self.callsite())
-            .finish()
+        let mut s = f.debug_struct("ValueSet");
+        self.record(&mut s);
+        s.field("callsite", &self.callsite()).finish()
     }
 }
 
 impl fmt::Display for ValueSet<'_> {
     fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
-        self.values
-            .iter()
-            .fold(&mut f.debug_map(), |dbg, (key, v)| {
-                if let Some(val) = v {
-                    val.record(key, dbg);
-                }
-                dbg
-            })
-            .finish()
+        let mut s = f.debug_map();
+        self.record(&mut s);
+        s.finish()
     }
 }
 

tracing/src/macros.rs

@@ -2814,7 +2814,7 @@ macro_rules! level_enabled {
 macro_rules! valueset {
 
     // === base case ===
-    (@ { $(,)* $($val:expr),* $(,)* }, $next:expr $(,)*) => {
+    (@ { $(,)* $($val:expr),* $(,)* } $(,)*) => {
         &[ $($val),* ]
     };
 
@@ -2822,192 +2822,164 @@ macro_rules! valueset {
 
     // TODO(#1138): determine a new syntax for uninitialized span fields, and
     // re-enable this.
-    // (@{ $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = _, $($rest:tt)*) => {
-    //     $crate::valueset!(@ { $($out),*, (&$next, None) }, $next, $($rest)*)
+    // (@{ $(,)* $($out:expr),* }, $($k:ident).+ = _, $($rest:tt)*) => {
+    //     $crate::valueset!(@ { $($out),*, (None) }, $($rest)*)
     // };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = ?$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = ?$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = %$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = %$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = $val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = $val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$($k).+ as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$($k).+ as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, ?$($k:ident).+, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, ?$($k:ident).+, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$($k).+) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$($k).+) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, %$($k:ident).+, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, %$($k:ident).+, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$($k).+) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$($k).+) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = ?$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = ?$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = %$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = %$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+ = $val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+ = $val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($k:ident).+) => {
+    (@ { $(,)* $($out:expr),* }, $($k:ident).+) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$($k).+ as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$($k).+ as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, ?$($k:ident).+) => {
+    (@ { $(,)* $($out:expr),* }, ?$($k:ident).+) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$($k).+) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$($k).+) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, %$($k:ident).+) => {
+    (@ { $(,)* $($out:expr),* }, %$($k:ident).+) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$($k).+) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$($k).+) as &dyn $crate::field::Value)) },
         )
     };
 
     // Handle literal names
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = ?$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = ?$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = %$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = %$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = $val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = $val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = ?$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = ?$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = %$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = %$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, $k:literal = $val:expr) => {
+    (@ { $(,)* $($out:expr),* }, $k:literal = $val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, $crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, ($crate::__macro_support::Option::Some(&$val as &dyn $crate::field::Value)) },
         )
     };
 
     // Handle constant names
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = ?$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = ?$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = %$val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = %$val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = $val:expr, $($rest:tt)*) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = $val:expr, $($rest:tt)*) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$val as &dyn $crate::field::Value)) },
             $($rest)*
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = ?$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = ?$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$crate::field::debug(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = %$val:expr) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = %$val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$crate::field::display(&$val) as &dyn $crate::field::Value)) },
         )
     };
-    (@ { $(,)* $($out:expr),* }, $next:expr, { $k:expr } = $val:expr) => {
+    (@ { $(,)* $($out:expr),* }, { $k:expr } = $val:expr) => {
         $crate::valueset!(
-            @ { $($out),*, (&$next, Some(&$val as &dyn $crate::field::Value)) },
-            $next,
+            @ { $($out),*, (Some(&$val as &dyn $crate::field::Value)) },
         )
     };
 
     // Remainder is unparsable, but exists --- must be format args!
-    (@ { $(,)* $($out:expr),* }, $next:expr, $($rest:tt)+) => {
-        $crate::valueset!(
-            @ { (&$next, $crate::__macro_support::Option::Some(&$crate::__macro_support::format_args!($($rest)+) as &dyn $crate::field::Value)), $($out),* },
-            $next,
-        )
+    (@ { $(,)* $($out:expr),* }, $($rest:tt)+) => {
+        $crate::valueset!(@ { ($crate::__macro_support::Option::Some(&$crate::__macro_support::format_args!($($rest)+) as &dyn $crate::field::Value)), $($out),* },)
     };
 
     // === entry ===
     ($fields:expr, $($kvs:tt)+) => {
         {
-            let mut iter = $fields.iter();
-            $fields.value_set($crate::valueset!(
+            #[allow(unused_imports)]
+            $fields.value_set_all($crate::valueset!(
                 @ { },
-                $crate::__macro_support::Iterator::next(&mut iter).expect("FieldSet corrupted (this is a bug)"),
                 $($kvs)+
             ))
         }
     };
     ($fields:expr,) => {
         {
-            $fields.value_set(&[])
+            $fields.value_set_all(&[])
         }
     };
 }