Rollup merge of #142123 - Kobzol:timings, r=nnethercote

Implement initial support for timing sections (`--json=timings`)

This PR implements initial support for emitting high-level compilation section timings. The idea is to provide a very lightweight way of emitting durations of various compilation sections (frontend, backend, linker, or on a more granular level macro expansion, typeck, borrowck, etc.). The ultimate goal is to stabilize this output (in some form), make Cargo pass `--json=timings` and then display this information in the HTML output of `cargo build --timings`, to make it easier to quickly profile "what takes so long" during the compilation of a Cargo project. I would personally also like if Cargo printed some of this information in the interactive `cargo build` output, but the `build --timings` use-case is the main one.

Now, this information is already available with several other sources, but I don't think that we can just use them as they are, which is why I proposed a new way of outputting this data (`--json=timings`):
- This data is available under `-Zself-profile`, but that is very expensive and forever unstable. It's just a too big of a hammer to tell us the duration it took to run the linker.
- It could also be extracted with `-Ztime-passes`. That is pretty much "for free" in terms of performance, and it can be emitted in a structured form to JSON via `-Ztime-passes-format=json`. I guess that one alternative might be to stabilize this flag in some form, but that form might just be `--json=timings`? I guess what we could do in theory is take the already emitted time passes and reuse them for `--json=timings`. Happy to hear suggestions!

I'm sending this PR mostly for a vibeck, to see if the way I implemented it is passable. There are some things to figure out:
- How do we represent the sections? Originally I wanted to output `{ section, duration }`, but then I realized that it might be more useful to actually emit `start` and `end` events. Both because it enables to see the output incrementally (in case compilation takes a long time and you read the outputs directly, or Cargo decides to show this data in `cargo build` some day in the future), and because it makes it simpler to represent hierarchy (see below). The timestamps currently emit microseconds elapsed from a predetermined point in time (~start of rustc), but otherwise they are fully opaque, and should be only ever used to calculate the duration using `end - start`. We could also precompute the duration for the user in the `end` event, but that would require doing more work in rustc, which I would ideally like to avoid :P
- Do we want to have some form of hierarchy? I think that it would be nice to show some more granular sections rather than just frontend/backend/linker (e.g. macro expansion, typeck and borrowck as a part of the frontend). But for that we would need some way of representing hierarchy. A simple way would be something like `{ parent: "frontend" }`, but I realized that with start/end timestamps we get the hierarchy "for free", only the client will need to reconstruct it from the order of start/end events (e.g. `start A`, `start B` means that `B` is a child of `A`).
- What exactly do we want to stabilize? This is probably a question for later. I think that we should definitely stabilize the format of the emitted JSON objects, and *maybe* some specific section names (but we should also make it clear that they can be missing, e.g. you don't link everytime you invoke `rustc`).

The PR be tested e.g. with `rustc +stage1 src/main.rs --json=timings --error-format=json -Zunstable-options` on a crate without dependencies (it is not easy to use `--json` with stock Cargo, because it also passes this flag to `rustc`, so this will later need Cargo integration to be usable with it).

Zulip discussions: [#t-compiler > Outputting time spent in various compiler sections](https://rust-lang.zulipchat.com/#narrow/channel/131828-t-compiler/topic/Outputting.20time.20spent.20in.20various.20compiler.20sections/with/518850162)

MCP: https://github.com/rust-lang/compiler-team/issues/873

r? ``@nnethercote``

1 files changed, 28 insertions, 1 deletions

diff --git a/compiler/rustc_errors/src/json.rs b/compiler/rustc_errors/src/json.rs
index a6583407b7e..d67e2ba2d60 100644
--- a/compiler/rustc_errors/src/json.rs
+++ b/compiler/rustc_errors/src/json.rs
@@ -28,9 +28,10 @@ use termcolor::{ColorSpec, WriteColor};
 use crate::diagnostic::IsLint;
 use crate::emitter::{
     ColorConfig, Destination, Emitter, HumanEmitter, HumanReadableErrorType, OutputTheme,
-    should_show_source_code,
+    TimingEvent, should_show_source_code,
 };
 use crate::registry::Registry;
+use crate::timings::{TimingRecord, TimingSection};
 use crate::translation::{Translate, to_fluent_args};
 use crate::{
     CodeSuggestion, FluentBundle, LazyFallbackBundle, MultiSpan, SpanLabel, Subdiag, Suggestions,
@@ -104,6 +105,7 @@ impl JsonEmitter {
 enum EmitTyped<'a> {
     Diagnostic(Diagnostic),
     Artifact(ArtifactNotification<'a>),
+    SectionTiming(SectionTimestamp<'a>),
     FutureIncompat(FutureIncompatReport<'a>),
     UnusedExtern(UnusedExterns<'a>),
 }
@@ -135,6 +137,21 @@ impl Emitter for JsonEmitter {
         }
     }
 
+    fn emit_timing_section(&mut self, record: TimingRecord, event: TimingEvent) {
+        let event = match event {
+            TimingEvent::Start => "start",
+            TimingEvent::End => "end",
+        };
+        let name = match record.section {
+            TimingSection::Linking => "link",
+        };
+        let data = SectionTimestamp { name, event, timestamp: record.timestamp };
+        let result = self.emit(EmitTyped::SectionTiming(data));
+        if let Err(e) = result {
+            panic!("failed to print timing section: {e:?}");
+        }
+    }
+
     fn emit_future_breakage_report(&mut self, diags: Vec<crate::DiagInner>, registry: &Registry) {
         let data: Vec<FutureBreakageItem<'_>> = diags
             .into_iter()
@@ -264,6 +281,16 @@ struct ArtifactNotification<'a> {
 }
 
 #[derive(Serialize)]
+struct SectionTimestamp<'a> {
+    /// Name of the section
+    name: &'a str,
+    /// Start/end of the section
+    event: &'a str,
+    /// Opaque timestamp.
+    timestamp: u128,
+}
+
+#[derive(Serialize)]
 struct FutureBreakageItem<'a> {
     // Always EmitTyped::Diagnostic, but we want to make sure it gets serialized
     // with "$message_type".