backport changes from master

.github/workflows/CI.yml

@@ -237,9 +237,9 @@ jobs:
       working-directory: "tracing/test_static_max_level_features"
     - name: "Test tracing-core no-std support"
       run: cargo test --no-default-features
-      working-directory: tracing
+      working-directory: tracing-core
     - name: "Test tracing no-std support"
-      run: cargo test --no-default-features
+      run: cargo test --lib --tests --no-default-features
       working-directory: tracing
       # this skips running doctests under the `--no-default-features` flag,
       # as rustdoc isn't aware of cargo's feature flags.

examples/examples/panic_hook.rs

@@ -1,5 +1,9 @@
 //! This example demonstrates how `tracing` events can be recorded from within a
 //! panic hook, capturing the span context in which the program panicked.
+//!
+//! A custom panic hook can also be used to record panics that are captured
+//! using `catch_unwind`, such as when Tokio catches panics in spawned async
+//! tasks. See the `tokio_panic_hook.rs` example for an example of this.
 
 fn main() {
     let subscriber = tracing_subscriber::fmt()

examples/examples/tokio_panic_hook.rs

@@ -0,0 +1,54 @@
+//! This example demonstrates that a custom panic hook can be used to log panic
+//! messages even when panics are captured (such as when a Tokio task panics).
+//!
+//! This is essentially the same as the `panic_hook.rs` example, but modified to
+//! spawn async tasks using the Tokio runtime rather than panicking in a
+//! synchronous function. See the `panic_hook.rs` example for details on using
+//! custom panic hooks.
+#[tokio::main]
+async fn main() {
+    let subscriber = tracing_subscriber::fmt()
+        .with_max_level(tracing::Level::TRACE)
+        .finish();
+
+    // NOTE: Using `tracing` in a panic hook requires the use of the *global*
+    // trace dispatcher (`tracing::subscriber::set_global_default`), rather than
+    // the per-thread scoped dispatcher
+    // (`tracing::subscriber::with_default`/`set_default`). With the scoped trace
+    // dispatcher, the subscriber's thread-local context may already have been
+    // torn down by unwinding by the time the panic handler is reached.
+    tracing::subscriber::set_global_default(subscriber).unwrap();
+
+    std::panic::set_hook(Box::new(|panic| {
+        if let Some(location) = panic.location() {
+            tracing::error!(
+                message = %panic,
+                panic.file = location.file(),
+                panic.line = location.line(),
+                panic.column = location.column(),
+            );
+        } else {
+            tracing::error!(message = %panic);
+        }
+    }));
+
+    // Spawn tasks to check the numbers from 1-10.
+    let tasks = (0..10)
+        .map(|i| tokio::spawn(check_number(i)))
+        .collect::<Vec<_>>();
+    futures::future::join_all(tasks).await;
+
+    tracing::trace!("all tasks done");
+}
+
+#[tracing::instrument]
+async fn check_number(x: i32) {
+    tracing::trace!("checking number...");
+    tokio::task::yield_now().await;
+
+    if x % 2 == 0 {
+        panic!("I don't work with even numbers!");
+    }
+
+    tracing::info!("number checks out!")
+}

tracing-appender/src/inner.rs

@@ -64,7 +64,12 @@ impl InnerAppender {
             self.next_date = self.rotation.next_date(&now);
 
             match create_writer(&self.log_directory, &filename) {
-                Ok(writer) => self.writer = writer,
+                Ok(writer) => {
+                    if let Err(err) = self.writer.flush() {
+                        eprintln!("Couldn't flush previous writer: {}", err);
+                    }
+                    self.writer = writer
+                }
                 Err(err) => eprintln!("Couldn't create writer for logs: {}", err),
             }
         }

tracing-attributes/src/lib.rs

@@ -711,12 +711,9 @@ fn gen_block(
     // enter the span and then perform the rest of the body.
     // If `err` is in args, instrument any resulting `Err`s.
     if async_context {
-        if err {
+        let mk_fut = if err {
             quote_spanned!(block.span()=>
-                let __tracing_attr_span = #span;
-                // See comment on the default case at the end of this function
-                // for why we do this a bit roundabout.
-                let fut = async move {
+                async move {
                     match async move { #block }.await {
                         #[allow(clippy::unit_arg)]
                         Ok(x) => Ok(x),
@@ -725,46 +722,52 @@ fn gen_block(
                             Err(e)
                         }
                     }
-                };
-                if tracing::level_enabled!(#level) {
-                    tracing::Instrument::instrument(
-                        fut,
-                        __tracing_attr_span
-                    )
-                    .await
-                } else {
-                    fut.await
                 }
             )
         } else {
             quote_spanned!(block.span()=>
-                let __tracing_attr_span = #span;
-                // See comment on the default case at the end of this function
-                // for why we do this a bit roundabout.
-                let fut = async move { #block };
-                if tracing::level_enabled!(#level) {
-                    tracing::Instrument::instrument(
-                        fut,
-                        __tracing_attr_span
-                    )
-                    .await
-                } else {
-                    fut.await
-                }
+                async move { #block }
             )
-        }
-    } else if err {
-        quote_spanned!(block.span()=>
-            // See comment on the default case at the end of this function
-            // for why we do this a bit roundabout.
-            let __tracing_attr_span;
-            let __tracing_attr_guard;
+        };
+
+        return quote_spanned!(block.span()=>
             if tracing::level_enabled!(#level) {
-                __tracing_attr_span = #span;
-                __tracing_attr_guard = __tracing_attr_span.enter();
+                let __tracing_attr_span = #span;
+                tracing::Instrument::instrument(
+                    #mk_fut,
+                    __tracing_attr_span
+                )
+                .await
+            } else {
+                #mk_fut.await
             }
-            // pacify clippy::suspicious_else_formatting
-            let _ = ();
+        );
+    }
+
+    let span = quote_spanned!(block.span()=>
+        // These variables are left uninitialized and initialized only
+        // if the tracing level is statically enabled at this point.
+        // While the tracing level is also checked at span creation
+        // time, that will still create a dummy span, and a dummy guard
+        // and drop the dummy guard later. By lazily initializing these
+        // variables, Rust will generate a drop flag for them and thus
+        // only drop the guard if it was created. This creates code that
+        // is very straightforward for LLVM to optimize out if the tracing
+        // level is statically disabled, while not causing any performance
+        // regression in case the level is enabled.
+        let __tracing_attr_span;
+        let __tracing_attr_guard;
+        if tracing::level_enabled!(#level) {
+            __tracing_attr_span = #span;
+            __tracing_attr_guard = __tracing_attr_span.enter();
+        }
+        // pacify clippy::suspicious_else_formatting
+        let _ = ();
+    );
+
+    if err {
+        return quote_spanned!(block.span()=>
+            #span
             #[allow(clippy::redundant_closure_call)]
             match (move || #block)() {
                 #[allow(clippy::unit_arg)]
@@ -774,30 +777,13 @@ fn gen_block(
                     Err(e)
                 }
             }
-        )
-    } else {
-        quote_spanned!(block.span()=>
-            // These variables are left uninitialized and initialized only
-            // if the tracing level is statically enabled at this point.
-            // While the tracing level is also checked at span creation
-            // time, that will still create a dummy span, and a dummy guard
-            // and drop the dummy guard later. By lazily initializing these
-            // variables, Rust will generate a drop flag for them and thus
-            // only drop the guard if it was created. This creates code that
-            // is very straightforward for LLVM to optimize out if the tracing
-            // level is statically disabled, while not causing any performance
-            // regression in case the level is enabled.
-            let __tracing_attr_span;
-            let __tracing_attr_guard;
-            if tracing::level_enabled!(#level) {
-                __tracing_attr_span = #span;
-                __tracing_attr_guard = __tracing_attr_span.enter();
-            }
-            // pacify clippy::suspicious_else_formatting
-            let _ = ();
-            #block
-        )
+        );
     }
+
+    quote_spanned!(block.span()=>
+        #span
+        #block
+    )
 }
 
 #[derive(Default, Debug)]

tracing-core/src/field.rs

@@ -118,7 +118,7 @@ pub struct Iter {
 /// }
 ///
 /// impl<'a> Visit for StringVisitor<'a> {
-///     fn record_debug(&mut self, field: &Field, value: &fmt::Debug) {
+///     fn record_debug(&mut self, field: &Field, value: &dyn fmt::Debug) {
 ///         write!(self.string, "{} = {:?}; ", field.name(), value).unwrap();
 ///     }
 /// }

tracing-core/src/spin/once.rs

@@ -1,6 +1,9 @@
 use core::cell::UnsafeCell;
 use core::fmt;
-use core::sync::atomic::{spin_loop_hint as cpu_relax, AtomicUsize, Ordering};
+use core::sync::atomic::{AtomicUsize, Ordering};
+// TODO(eliza): replace with `core::hint::spin_loop` once our MSRV supports it.
+#[allow(deprecated)]
+use core::sync::atomic::spin_loop_hint as cpu_relax;
 
 /// A synchronization primitive which can be used to run a one-time global
 /// initialization. Unlike its std equivalent, this is generalized so that the
@@ -73,31 +76,41 @@ impl<T> Once<T> {
         let mut status = self.state.load(Ordering::SeqCst);
 
         if status == INCOMPLETE {
-            status = self
-                .state
-                .compare_and_swap(INCOMPLETE, RUNNING, Ordering::SeqCst);
-            if status == INCOMPLETE {
-                // We init
-                // We use a guard (Finish) to catch panics caused by builder
-                let mut finish = Finish {
-                    state: &self.state,
-                    panicked: true,
-                };
-                unsafe { *self.data.get() = Some(builder()) };
-                finish.panicked = false;
-
-                status = COMPLETE;
-                self.state.store(status, Ordering::SeqCst);
-
-                // This next line is strictly an optimization
-                return self.force_get();
+            status = match self.state.compare_exchange(
+                INCOMPLETE,
+                RUNNING,
+                Ordering::SeqCst,
+                Ordering::SeqCst,
+            ) {
+                Ok(status) => {
+                    debug_assert_eq!(
+                        status, INCOMPLETE,
+                        "if compare_exchange succeeded, previous status must be incomplete",
+                    );
+                    // We init
+                    // We use a guard (Finish) to catch panics caused by builder
+                    let mut finish = Finish {
+                        state: &self.state,
+                        panicked: true,
+                    };
+                    unsafe { *self.data.get() = Some(builder()) };
+                    finish.panicked = false;
+
+                    self.state.store(COMPLETE, Ordering::SeqCst);
+
+                    // This next line is strictly an optimization
+                    return self.force_get();
+                }
+                Err(status) => status,
             }
         }
 
         loop {
             match status {
                 INCOMPLETE => unreachable!(),
                 RUNNING => {
+                    // TODO(eliza): replace with `core::hint::spin_loop` once our MSRV supports it.
+                    #[allow(deprecated)]
                     // We spin
                     cpu_relax();
                     status = self.state.load(Ordering::SeqCst)
@@ -123,7 +136,12 @@ impl<T> Once<T> {
         loop {
             match self.state.load(Ordering::SeqCst) {
                 INCOMPLETE => return None,
-                RUNNING => cpu_relax(), // We spin
+
+                RUNNING => {
+                    // TODO(eliza): replace with `core::hint::spin_loop` once our MSRV supports it.
+                    #[allow(deprecated)]
+                    cpu_relax() // We spin
+                }
                 COMPLETE => return Some(self.force_get()),
                 PANICKED => panic!("Once has panicked"),
                 _ => unsafe { unreachable() },