Rollup merge of rust-lang#157190 - khyperia:nonrecursive-tracing-json, r=jieyouxu

Silence recursive RUSTC_LOG_FORMAT_JSON messages

We print a *lot* of debug messages while formatting the arguments of another, outer, debug message. For example, these two `debug!` lines are responsible for **75%** of all log messages when running with `RUSTC_LOG=trace RUSTC_LOG_FORMAT_JSON=1`, because we format paths to string a *lot* when debug logging:

https://github.com/rust-lang/rust/blob/c315891193c35827c2d789adce686f8a5481778f/compiler/rustc_hir/src/definitions.rs#L153-L156

The default rustc log formatter, `tracing_tree::HierarchicalLayer`, blocks all "recursive" tracing messages, dropping them:

https://github.com/davidbarsky/tracing-tree/blob/79627fc72ae7dcf95af16e047797e60494679678/src/lib.rs#L410-L412

However, `RUSTC_LOG_FORMAT_JSON` does not. This is mildly annoying, since once logged, it's impossible to tell that a message is "recursive", so which means that [my lil rustc log viewer](https://github.com/khyperia/khys-rustc-log-viewer), as [well as Jana's](https://git.donsz.nl/jana/logviewer), can only fully filter these messages out, rather than only showing them when they are top-level logs.

This change implements a very criminal, primitive recursion check, in a very hacky way, in rustc_log - I am not proud of this code, and wish there was a better way of doing this. As far as I can tell, though, this is the easiest/most effective way of implementing this - `tracing` doesn't provide nice tools for this kind of thing.

Before this change:

```
khyperia@argon /d/rust (main)> RUSTC_LOG_FORMAT_JSON=1 RUSTC_LOG=trace rustc +stage1 -Znext-solver=globally tests/ui/const-generics/gca/non-type-equality-ok.rs &| wc -l
1443792 lines
khyperia@argon /d/rust (main)> RUSTC_LOG_FORMAT_JSON=1 RUSTC_LOG=trace rustc +stage1 -Znext-solver=globally tests/ui/const-generics/gca/non-type-equality-ok.rs &| wc -c
3513565523 = 3.5 gigabytes
```

After this change:

```
khyperia@argon /d/rust (main)> RUSTC_LOG_FORMAT_JSON=1 RUSTC_LOG=trace rustc +stage1 -Znext-solver=globally tests/ui/const-generics/gca/non-type-equality-ok.rs &| wc -l
84104 lines = 5.8% of the number of lines
khyperia@argon /d/rust (main)> RUSTC_LOG_FORMAT_JSON=1 RUSTC_LOG=trace rustc +stage1 -Znext-solver=globally tests/ui/const-generics/gca/non-type-equality-ok.rs &| wc -c
257480205 = 257 megabytes = 7.3% the amount of data
```

FYI @jdonszelmann

r? @jieyouxu

Author: JonathanBrouwer

compiler/rustc_log/src/lib.rs

@@ -33,19 +33,20 @@
 //! debugging, you can make changes inside those crates and quickly run main.rs
 //! to read the debug logs.
 
+use std::cell::Cell;
 use std::env::{self, VarError};
 use std::fmt::{self, Display};
 use std::fs::File;
 use std::io::{self, IsTerminal};
 use std::sync::Mutex;
 
 use tracing::dispatcher::SetGlobalDefaultError;
-use tracing::{Event, Subscriber};
+use tracing::{Event, Subscriber, span};
 use tracing_subscriber::filter::{Directive, EnvFilter, LevelFilter};
 use tracing_subscriber::fmt::FmtContext;
 use tracing_subscriber::fmt::format::{self, FmtSpan, FormatEvent, FormatFields};
 use tracing_subscriber::fmt::writer::BoxMakeWriter;
-use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::layer::{Context, SubscriberExt};
 use tracing_subscriber::{Layer, Registry};
 // Re-export tracing
 pub use {tracing, tracing_core, tracing_subscriber};
@@ -175,6 +176,7 @@ where
             .with_thread_ids(verbose_thread_ids)
             .with_thread_names(verbose_thread_ids)
             .with_span_events(FmtSpan::ACTIVE);
+        let fmt_layer = NonrecursiveLayer { inner: fmt_layer };
         Layer::boxed(fmt_layer)
     } else {
         let mut layer = tracing_tree::HierarchicalLayer::default()
@@ -286,3 +288,105 @@ impl From<SetGlobalDefaultError> for Error {
         Error::AlreadyInit(tracing_error)
     }
 }
+
+thread_local! {
+    static NONRECURSIVE_GUARD_LOCK: Cell<bool> = const { Cell::new(false) };
+}
+
+struct NonrecursiveGuard;
+
+impl NonrecursiveGuard {
+    fn lock() -> Option<NonrecursiveGuard> {
+        if !NONRECURSIVE_GUARD_LOCK.replace(true) { Some(NonrecursiveGuard) } else { None }
+    }
+}
+
+impl Drop for NonrecursiveGuard {
+    fn drop(&mut self) {
+        NONRECURSIVE_GUARD_LOCK.set(false);
+    }
+}
+
+/// Many debug messages that rustc emits produce additional debug messages when formatting the
+/// arguments to the original debug message. [`tracing_tree::HierarchicalLayer`] (used by the
+/// default output format) filters these out, but [`tracing_subscriber::fmt::format::Json`] (used by
+/// `RUSTC_LOG_FORMAT_JSON`) does not. So, implement a simple recursion check to filter these
+/// messages out.
+struct NonrecursiveLayer<S> {
+    inner: S,
+}
+
+impl<S: Subscriber, L: Layer<S>> Layer<S> for NonrecursiveLayer<L> {
+    fn on_register_dispatch(&self, subscriber: &tracing::Dispatch) {
+        self.inner.on_register_dispatch(subscriber)
+    }
+
+    fn on_layer(&mut self, subscriber: &mut S) {
+        self.inner.on_layer(subscriber)
+    }
+
+    fn register_callsite(
+        &self,
+        metadata: &'static tracing::Metadata<'static>,
+    ) -> tracing_core::Interest {
+        self.inner.register_callsite(metadata)
+    }
+
+    fn enabled(&self, metadata: &tracing::Metadata<'_>, ctx: Context<'_, S>) -> bool {
+        self.inner.enabled(metadata, ctx)
+    }
+
+    fn on_new_span(&self, attrs: &span::Attributes<'_>, id: &span::Id, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_new_span(attrs, id, ctx)
+        }
+    }
+
+    fn on_record(&self, span: &span::Id, values: &span::Record<'_>, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_record(span, values, ctx)
+        }
+    }
+
+    fn on_follows_from(&self, span: &span::Id, follows: &span::Id, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_follows_from(span, follows, ctx)
+        }
+    }
+
+    fn event_enabled(&self, event: &Event<'_>, ctx: Context<'_, S>) -> bool {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.event_enabled(event, ctx)
+        } else {
+            false
+        }
+    }
+
+    fn on_event(&self, event: &Event<'_>, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_event(event, ctx)
+        }
+    }
+
+    fn on_enter(&self, id: &span::Id, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_enter(id, ctx)
+        }
+    }
+
+    fn on_exit(&self, id: &span::Id, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_exit(id, ctx)
+        }
+    }
+
+    fn on_close(&self, id: span::Id, ctx: Context<'_, S>) {
+        if let Some(_) = NonrecursiveGuard::lock() {
+            self.inner.on_close(id, ctx)
+        }
+    }
+
+    fn on_id_change(&self, old: &span::Id, new: &span::Id, ctx: Context<'_, S>) {
+        self.inner.on_id_change(old, new, ctx)
+    }
+}