Add infrastructure for emitting timing sections

Author: Kobzol

compiler/rustc_errors/src/emitter.rs

@@ -34,6 +34,7 @@ use crate::snippet::{
     Annotation, AnnotationColumn, AnnotationType, Line, MultilineAnnotation, Style, StyledString,
 };
 use crate::styled_buffer::StyledBuffer;
+use crate::timings::TimingSection;
 use crate::translation::{Translate, to_fluent_args};
 use crate::{
     CodeSuggestion, DiagInner, DiagMessage, ErrCode, FluentBundle, LazyFallbackBundle, Level,
@@ -164,11 +165,16 @@ impl Margin {
     }
 }
 
+pub enum TimingSectionKind {
+    Start,
+    End,
+}
+
 const ANONYMIZED_LINE_NUM: &str = "LL";
 
 pub type DynEmitter = dyn Emitter + DynSend;
 
-/// Emitter trait for emitting errors.
+/// Emitter trait for emitting errors and other structured information.
 pub trait Emitter: Translate {
     /// Emit a structured diagnostic.
     fn emit_diagnostic(&mut self, diag: DiagInner, registry: &Registry);
@@ -177,6 +183,10 @@ pub trait Emitter: Translate {
     /// Currently only supported for the JSON format.
     fn emit_artifact_notification(&mut self, _path: &Path, _artifact_type: &str) {}
 
+    /// Emit a timestamp with start/end of a timing section.
+    /// Currently only supported for the JSON format.
+    fn emit_timing_section(&mut self, _section: TimingSection, _kind: TimingSectionKind) {}
+
     /// Emit a report about future breakage.
     /// Currently only supported for the JSON format.
     fn emit_future_breakage_report(&mut self, _diags: Vec<DiagInner>, _registry: &Registry) {}

compiler/rustc_errors/src/json.rs

@@ -13,6 +13,7 @@ use std::error::Report;
 use std::io::{self, Write};
 use std::path::Path;
 use std::sync::{Arc, Mutex};
+use std::time::Instant;
 use std::vec;
 
 use derive_setters::Setters;
@@ -28,9 +29,10 @@ use termcolor::{ColorSpec, WriteColor};
 use crate::diagnostic::IsLint;
 use crate::emitter::{
     ColorConfig, Destination, Emitter, HumanEmitter, HumanReadableErrorType, OutputTheme,
-    should_show_source_code,
+    TimingSectionKind, should_show_source_code,
 };
 use crate::registry::Registry;
+use crate::timings::TimingSection;
 use crate::translation::{Translate, to_fluent_args};
 use crate::{
     CodeSuggestion, FluentBundle, LazyFallbackBundle, MultiSpan, SpanLabel, Subdiag, Suggestions,
@@ -60,6 +62,8 @@ pub struct JsonEmitter {
     macro_backtrace: bool,
     track_diagnostics: bool,
     terminal_url: TerminalUrl,
+    #[setters(skip)]
+    start_timestamp: Instant,
 }
 
 impl JsonEmitter {
@@ -85,6 +89,7 @@ impl JsonEmitter {
             macro_backtrace: false,
             track_diagnostics: false,
             terminal_url: TerminalUrl::No,
+            start_timestamp: Instant::now(),
         }
     }
 
@@ -104,6 +109,7 @@ impl JsonEmitter {
 enum EmitTyped<'a> {
     Diagnostic(Diagnostic),
     Artifact(ArtifactNotification<'a>),
+    SectionTimestamp(SectionTimestamp<'a>),
     FutureIncompat(FutureIncompatReport<'a>),
     UnusedExtern(UnusedExterns<'a>),
 }
@@ -135,6 +141,26 @@ impl Emitter for JsonEmitter {
         }
     }
 
+    fn emit_timing_section(&mut self, section: TimingSection, kind: TimingSectionKind) {
+        let kind = match kind {
+            TimingSectionKind::Start => "start",
+            TimingSectionKind::End => "end",
+        };
+        let name = match section {
+            TimingSection::Linking => "link",
+        };
+        let time = Instant::now();
+        let data = SectionTimestamp {
+            name,
+            kind,
+            timestamp: time.duration_since(self.start_timestamp).as_micros(),
+        };
+        let result = self.emit(EmitTyped::SectionTimestamp(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()
@@ -263,6 +289,16 @@ struct ArtifactNotification<'a> {
     emit: &'a str,
 }
 
+#[derive(Serialize)]
+struct SectionTimestamp<'a> {
+    /// Name of the section
+    name: &'a str,
+    /// Start/end of the section
+    kind: &'a str,
+    /// Microseconds elapsed since some predetermined point in time (~start of the rustc process).
+    timestamp: u128,
+}
+
 #[derive(Serialize)]
 struct FutureBreakageItem<'a> {
     // Always EmitTyped::Diagnostic, but we want to make sure it gets serialized

compiler/rustc_errors/src/lib.rs

@@ -75,7 +75,9 @@ pub use snippet::Style;
 pub use termcolor::{Color, ColorSpec, WriteColor};
 use tracing::debug;
 
+use crate::emitter::TimingSectionKind;
 use crate::registry::Registry;
+use crate::timings::TimingSection;
 
 pub mod annotate_snippet_emitter_writer;
 pub mod codes;
@@ -91,6 +93,7 @@ mod snippet;
 mod styled_buffer;
 #[cfg(test)]
 mod tests;
+pub mod timings;
 pub mod translation;
 
 pub type PResult<'a, T> = Result<T, Diag<'a>>;
@@ -1144,6 +1147,14 @@ impl<'a> DiagCtxtHandle<'a> {
         self.inner.borrow_mut().emitter.emit_artifact_notification(path, artifact_type);
     }
 
+    pub fn emit_timing_section_start(&self, section: TimingSection) {
+        self.inner.borrow_mut().emitter.emit_timing_section(section, TimingSectionKind::Start);
+    }
+
+    pub fn emit_timing_section_end(&self, section: TimingSection) {
+        self.inner.borrow_mut().emitter.emit_timing_section(section, TimingSectionKind::End);
+    }
+
     pub fn emit_future_breakage_report(&self) {
         let inner = &mut *self.inner.borrow_mut();
         let diags = std::mem::take(&mut inner.future_breakage_diagnostics);

compiler/rustc_errors/src/timings.rs

@@ -0,0 +1,52 @@
+use crate::DiagCtxtHandle;
+
+/// A high-level section of the compilation process.
+#[derive(Copy, Clone, Debug)]
+pub enum TimingSection {
+    /// Time spent linking.
+    Linking,
+}
+
+/// Manages emission of start/end section timings, enabled through `--json=timings`.
+pub struct TimingSectionHandler {
+    enabled: bool,
+}
+
+impl TimingSectionHandler {
+    pub fn new(enabled: bool) -> Self {
+        Self { enabled }
+    }
+
+    /// Returns a RAII guard that will immediately emit a start the provided section, and then emit
+    /// its end when it is dropped.
+    pub fn start_section<'a>(
+        &self,
+        diag_ctxt: DiagCtxtHandle<'a>,
+        section: TimingSection,
+    ) -> TimingSectionGuard<'a> {
+        TimingSectionGuard::create(diag_ctxt, section, self.enabled)
+    }
+}
+
+pub struct TimingSectionGuard<'a> {
+    dcx: DiagCtxtHandle<'a>,
+    section: TimingSection,
+    enabled: bool,
+}
+
+impl<'a> TimingSectionGuard<'a> {
+    fn create(dcx: DiagCtxtHandle<'a>, section: TimingSection, enabled: bool) -> Self {
+        if enabled {
+            dcx.emit_timing_section_start(section);
+        }
+        Self { dcx, section, enabled }
+    }
+}
+
+impl<'a> Drop for TimingSectionGuard<'a> {
+    fn drop(&mut self) {
+        if self.enabled {
+            self.dcx.emit_timing_section_end(self.section);
+        }
+    }
+}

compiler/rustc_session/src/session.rs

@@ -18,6 +18,7 @@ use rustc_errors::emitter::{
     DynEmitter, HumanEmitter, HumanReadableErrorType, OutputTheme, stderr_destination,
 };
 use rustc_errors::json::JsonEmitter;
+use rustc_errors::timings::TimingSectionHandler;
 use rustc_errors::{
     Diag, DiagCtxt, DiagCtxtHandle, DiagMessage, Diagnostic, ErrorGuaranteed, FatalAbort,
     FluentBundle, LazyFallbackBundle, TerminalUrl, fallback_fluent_bundle,
@@ -156,6 +157,9 @@ pub struct Session {
     /// Used by `-Z self-profile`.
     pub prof: SelfProfilerRef,
 
+    /// Used to emit section timings events (enabled by `--json=timings`).
+    pub timings: TimingSectionHandler,
+
     /// Data about code being compiled, gathered during compilation.
     pub code_stats: CodeStats,
 
@@ -1137,6 +1141,8 @@ pub fn build_session(
         .as_ref()
         .map(|_| rng().next_u32().to_base_fixed_len(CASE_INSENSITIVE).to_string());
 
+    let timings = TimingSectionHandler::new(sopts.json_section_timings);
+
     let sess = Session {
         target,
         host,
@@ -1147,6 +1153,7 @@ pub fn build_session(
         io,
         incr_comp_session: RwLock::new(IncrCompSession::NotInitialized),
         prof,
+        timings,
         code_stats: Default::default(),
         lint_store: None,
         driver_lint_caps,