Skip to content

Commit e6b0a65

Browse files
authored
feat(log): make timing messages ready for HTML replay (#16382)
### What does this PR try to resolve? Split out from <#16377>. Two non-refactor changes are * `CompileMode` now implements `Deserialize` in a way that matches its `Serialize` impl. * `RunId` is now `20060724T012128000Z-<16-char-hex>`. Previously it was `2006-07-24T012128000Z-<16-char-hex>` ### How to test and review this PR?
2 parents 4bbbf21 + b8f996a commit e6b0a65

File tree

6 files changed

+171
-75
lines changed

6 files changed

+171
-75
lines changed

src/cargo/core/compiler/build_config.rs

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -204,6 +204,36 @@ impl ser::Serialize for CompileMode {
204204
}
205205
}
206206

207+
impl<'de> serde::Deserialize<'de> for CompileMode {
208+
fn deserialize<D>(deserializer: D) -> Result<Self, D::Error>
209+
where
210+
D: serde::Deserializer<'de>,
211+
{
212+
let s = String::deserialize(deserializer)?;
213+
match s.as_str() {
214+
"test" => Ok(CompileMode::Test),
215+
"build" => Ok(CompileMode::Build),
216+
"check" => Ok(CompileMode::Check { test: false }),
217+
"doc" => Ok(CompileMode::Doc),
218+
"doctest" => Ok(CompileMode::Doctest),
219+
"docscrape" => Ok(CompileMode::Docscrape),
220+
"run-custom-build" => Ok(CompileMode::RunCustomBuild),
221+
other => Err(serde::de::Error::unknown_variant(
222+
other,
223+
&[
224+
"test",
225+
"build",
226+
"check",
227+
"doc",
228+
"doctest",
229+
"docscrape",
230+
"run-custom-build",
231+
],
232+
)),
233+
}
234+
}
235+
}
236+
207237
impl CompileMode {
208238
/// Returns `true` if the unit is being checked.
209239
pub fn is_check(self) -> bool {

src/cargo/core/compiler/mod.rs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -46,7 +46,7 @@ mod output_depinfo;
4646
mod output_sbom;
4747
pub mod rustdoc;
4848
pub mod standard_lib;
49-
mod timings;
49+
pub mod timings;
5050
mod unit;
5151
pub mod unit_dependencies;
5252
pub mod unit_graph;

src/cargo/core/compiler/timings/mod.rs

Lines changed: 19 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
//! This module implements some simple tracking information for timing of how
44
//! long it takes for different units to compile.
55
6-
mod report;
6+
pub mod report;
77

88
use super::{CompileMode, Unit};
99
use crate::core::PackageId;
@@ -75,9 +75,9 @@ pub struct Timings<'gctx> {
7575
#[derive(Copy, Clone, serde::Serialize)]
7676
pub struct CompilationSection {
7777
/// Start of the section, as an offset in seconds from `UnitTime::start`.
78-
start: f64,
78+
pub start: f64,
7979
/// End of the section, as an offset in seconds from `UnitTime::start`.
80-
end: Option<f64>,
80+
pub end: Option<f64>,
8181
}
8282

8383
/// Tracking information for an individual unit.
@@ -107,18 +107,18 @@ struct UnitTime {
107107
///
108108
/// This is used by the HTML report's JavaScript to render the pipeline graph.
109109
#[derive(serde::Serialize)]
110-
struct UnitData {
111-
i: u64,
112-
name: String,
113-
version: String,
114-
mode: String,
115-
target: String,
116-
features: Vec<String>,
117-
start: f64,
118-
duration: f64,
119-
unblocked_units: Vec<u64>,
120-
unblocked_rmeta_units: Vec<u64>,
121-
sections: Option<Vec<(report::SectionName, report::SectionData)>>,
110+
pub struct UnitData {
111+
pub i: u64,
112+
pub name: String,
113+
pub version: String,
114+
pub mode: String,
115+
pub target: String,
116+
pub features: Vec<String>,
117+
pub start: f64,
118+
pub duration: f64,
119+
pub unblocked_units: Vec<u64>,
120+
pub unblocked_rmeta_units: Vec<u64>,
121+
pub sections: Option<Vec<(report::SectionName, report::SectionData)>>,
122122
}
123123

124124
impl<'gctx> Timings<'gctx> {
@@ -445,16 +445,16 @@ impl<'gctx> Timings<'gctx> {
445445
let concurrency = report::compute_concurrency(&unit_data);
446446

447447
let ctx = report::RenderContext {
448-
start_str: &self.start_str,
448+
start_str: self.start_str.clone(),
449449
root_units: &self.root_targets,
450-
profile: &self.profile,
450+
profile: self.profile.clone(),
451451
total_fresh: self.total_fresh,
452452
total_dirty: self.total_dirty,
453453
unit_data,
454454
concurrency,
455455
cpu_usage: &self.cpu_usage,
456-
rustc_version,
457-
host: &build_runner.bcx.rustc().host,
456+
rustc_version: rustc_version.into(),
457+
host: build_runner.bcx.rustc().host.to_string(),
458458
requested_targets,
459459
jobs: build_runner.bcx.jobs(),
460460
num_cpus,

src/cargo/core/compiler/timings/report.rs

Lines changed: 26 additions & 35 deletions
Original file line numberDiff line numberDiff line change
@@ -5,25 +5,19 @@ use std::collections::HashMap;
55
use std::collections::HashSet;
66
use std::io::Write;
77

8+
use indexmap::IndexMap;
89
use itertools::Itertools as _;
910

1011
use crate::CargoResult;
1112
use crate::core::compiler::Unit;
1213

14+
use super::CompilationSection;
1315
use super::UnitData;
1416
use super::UnitTime;
1517

16-
/// Contains post-processed data of individual compilation sections.
17-
enum AggregatedSections {
18-
/// We know the names and durations of individual compilation sections
19-
Sections(Vec<(SectionName, SectionData)>),
20-
/// We know only the total duration
21-
OnlyTotalDuration,
22-
}
23-
2418
/// Name of an individual compilation section.
2519
#[derive(Clone, Hash, Eq, PartialEq)]
26-
pub(super) enum SectionName {
20+
pub enum SectionName {
2721
Frontend,
2822
Codegen,
2923
Named(String),
@@ -67,11 +61,11 @@ impl serde::ser::Serialize for SectionName {
6761

6862
/// Postprocessed section data that has both start and an end.
6963
#[derive(Copy, Clone, serde::Serialize)]
70-
pub(super) struct SectionData {
64+
pub struct SectionData {
7165
/// Start (relative to the start of the unit)
72-
start: f64,
66+
pub start: f64,
7367
/// End (relative to the start of the unit)
74-
end: f64,
68+
pub end: f64,
7569
}
7670

7771
impl SectionData {
@@ -96,13 +90,13 @@ pub struct Concurrency {
9690

9791
pub struct RenderContext<'a> {
9892
/// A rendered string of when compilation started.
99-
pub start_str: &'a str,
93+
pub start_str: String,
10094
/// A summary of the root units.
10195
///
10296
/// Tuples of `(package_description, target_descriptions)`.
10397
pub root_units: &'a [(String, Vec<String>)],
10498
/// The build profile.
105-
pub profile: &'a str,
99+
pub profile: String,
106100
/// Total number of fresh units.
107101
pub total_fresh: u32,
108102
/// Total number of dirty units.
@@ -117,9 +111,9 @@ pub struct RenderContext<'a> {
117111
/// system.
118112
pub cpu_usage: &'a [(f64, f64)],
119113
/// Compiler version info, i.e., `rustc 1.92.0-beta.2 (0a411606e 2025-10-31)`.
120-
pub rustc_version: &'a str,
114+
pub rustc_version: String,
121115
/// The host triple (arch-platform-OS).
122-
pub host: &'a str,
116+
pub host: String,
123117
/// The requested target platforms of compilation for this build.
124118
pub requested_targets: &'a [&'a str],
125119
/// The number of jobs specified for this build.
@@ -131,7 +125,7 @@ pub struct RenderContext<'a> {
131125
}
132126

133127
/// Writes an HTML report.
134-
pub(super) fn write_html(ctx: RenderContext<'_>, f: &mut impl Write) -> CargoResult<()> {
128+
pub fn write_html(ctx: RenderContext<'_>, f: &mut impl Write) -> CargoResult<()> {
135129
// The last concurrency record should equal to the last unit finished time.
136130
let duration = ctx.concurrency.last().map(|c| c.t).unwrap_or(0.0);
137131
let roots: Vec<&str> = ctx
@@ -384,10 +378,7 @@ pub(super) fn to_unit_data(
384378
.iter()
385379
.filter_map(|unit| unit_map.get(unit).copied())
386380
.collect();
387-
let sections = match aggregate_sections(ut) {
388-
AggregatedSections::Sections(sections) => Some(sections),
389-
AggregatedSections::OnlyTotalDuration => None,
390-
};
381+
let sections = aggregate_sections(ut.sections.clone(), ut.duration, ut.rmeta_time);
391382

392383
UnitData {
393384
i,
@@ -407,7 +398,7 @@ pub(super) fn to_unit_data(
407398
}
408399

409400
/// Derives concurrency information from unit timing data.
410-
pub(super) fn compute_concurrency(unit_data: &[UnitData]) -> Vec<Concurrency> {
401+
pub fn compute_concurrency(unit_data: &[UnitData]) -> Vec<Concurrency> {
411402
if unit_data.is_empty() {
412403
return Vec::new();
413404
}
@@ -539,16 +530,17 @@ pub(super) fn compute_concurrency(unit_data: &[UnitData]) -> Vec<Concurrency> {
539530
/// in which case we use them to determine the headers.
540531
/// - We have at least one rmeta time, so we hard-code Frontend and Codegen headers.
541532
/// - We only have total durations, so we don't add any additional headers.
542-
fn aggregate_sections(unit_time: &UnitTime) -> AggregatedSections {
543-
let end = unit_time.duration;
544-
545-
if !unit_time.sections.is_empty() {
533+
pub fn aggregate_sections(
534+
sections: IndexMap<String, CompilationSection>,
535+
end: f64,
536+
rmeta_time: Option<f64>,
537+
) -> Option<Vec<(SectionName, SectionData)>> {
538+
if !sections.is_empty() {
546539
// We have some detailed compilation section timings, so we postprocess them
547540
// Since it is possible that we do not have an end timestamp for a given compilation
548541
// section, we need to iterate them and if an end is missing, we assign the end of
549542
// the section to the start of the following section.
550-
551-
let mut sections = unit_time.sections.clone().into_iter().fold(
543+
let mut sections = sections.into_iter().fold(
552544
// The frontend section is currently implicit in rustc.
553545
// It is assumed to start at compilation start and end when codegen starts,
554546
// So we hard-code it here.
@@ -593,11 +585,10 @@ fn aggregate_sections(unit_time: &UnitTime) -> AggregatedSections {
593585
},
594586
));
595587
}
596-
597-
AggregatedSections::Sections(sections)
598-
} else if let Some(rmeta) = unit_time.rmeta_time {
588+
Some(sections)
589+
} else if let Some(rmeta) = rmeta_time {
599590
// We only know when the rmeta time was generated
600-
AggregatedSections::Sections(vec![
591+
Some(vec![
601592
(
602593
SectionName::Frontend,
603594
SectionData {
@@ -614,13 +605,13 @@ fn aggregate_sections(unit_time: &UnitTime) -> AggregatedSections {
614605
),
615606
])
616607
} else {
617-
// We only know the total duration
618-
AggregatedSections::OnlyTotalDuration
608+
// No section data provided. We only know the total duration.
609+
None
619610
}
620611
}
621612

622613
/// Rounds seconds to 0.01s precision.
623-
fn round_to_centisecond(x: f64) -> f64 {
614+
pub fn round_to_centisecond(x: f64) -> f64 {
624615
(x * 100.0).round() / 100.0
625616
}
626617

src/cargo/util/log_message.rs

Lines changed: 15 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,12 @@
11
//! Messages for logging.
22
3+
use std::borrow::Cow;
34
use std::io::Write;
45
use std::path::PathBuf;
56

67
use cargo_util_schemas::core::PackageIdSpec;
78
use jiff::Timestamp;
9+
use serde::Deserialize;
810
use serde::Serialize;
911

1012
use crate::core::compiler::CompileMode;
@@ -13,7 +15,7 @@ use crate::core::compiler::fingerprint::DirtyReason;
1315
/// A log message.
1416
///
1517
/// Each variant represents a different type of event.
16-
#[derive(Serialize)]
18+
#[derive(Serialize, Deserialize)]
1719
#[serde(tag = "reason", rename_all = "kebab-case")]
1820
pub enum LogMessage {
1921
/// Emitted when a build starts.
@@ -57,7 +59,7 @@ pub enum LogMessage {
5759
/// Seconds elapsed from build start.
5860
elapsed: f64,
5961
/// Unit indices that were unblocked by this rmeta completion.
60-
#[serde(skip_serializing_if = "Vec::is_empty")]
62+
#[serde(default, skip_serializing_if = "Vec::is_empty")]
6163
unblocked: Vec<u64>,
6264
},
6365
/// Emitted when a section (e.g., rmeta, link) of the compilation unit starts.
@@ -89,7 +91,7 @@ pub enum LogMessage {
8991
/// Seconds elapsed from build start.
9092
elapsed: f64,
9193
/// Unit indices that were unblocked by this completion.
92-
#[serde(skip_serializing_if = "Vec::is_empty")]
94+
#[serde(default, skip_serializing_if = "Vec::is_empty")]
9395
unblocked: Vec<u64>,
9496
},
9597
/// Emitted when a unit needs to be rebuilt.
@@ -101,17 +103,18 @@ pub enum LogMessage {
101103
/// The compilation action this unit is for (check, build, test, etc.).
102104
mode: CompileMode,
103105
/// Reason why the unit is dirty and needs rebuilding.
106+
#[serde(skip_deserializing, default = "default_reason")]
104107
cause: DirtyReason,
105108
},
106109
}
107110

108111
/// Cargo target information.
109-
#[derive(Serialize)]
112+
#[derive(Serialize, Deserialize)]
110113
pub struct Target {
111114
/// Target name.
112-
name: String,
115+
pub name: String,
113116
/// Target kind (lib, bin, test, bench, example, build-script).
114-
kind: &'static str,
117+
pub kind: Cow<'static, str>,
115118
}
116119

117120
impl From<&crate::core::Target> for Target {
@@ -126,7 +129,8 @@ impl From<&crate::core::Target> for Target {
126129
TargetKind::Bench => "bench",
127130
TargetKind::ExampleLib(..) | TargetKind::ExampleBin => "example",
128131
TargetKind::CustomBuild => "build-script",
129-
},
132+
}
133+
.into(),
130134
}
131135
}
132136
}
@@ -153,3 +157,7 @@ impl LogMessage {
153157
Ok(())
154158
}
155159
}
160+
161+
fn default_reason() -> DirtyReason {
162+
DirtyReason::NothingObvious
163+
}

0 commit comments

Comments
 (0)