Skip to content

feat(log): add more log events #16390

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
epage merged 5 commits into from
Dec 15, 2025
Merged

feat(log): add more log events #16390

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
0e20b6f
refactor: rename to make root units outstanding
weihanglo Dec 12, 2025
07902c7
feat(log): unit-gragh construction events
weihanglo Dec 12, 2025
d259e47
feat(log): dependency resolution events
weihanglo Dec 12, 2025
e668300
feat(log): unit-registered event
weihanglo Dec 12, 2025
9a238b9
fix(log): fix unit_to_index mapping from bcx
weihanglo Dec 12, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
5 changes: 5 additions & 0 deletions src/cargo/core/compiler/build_context/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,9 @@ pub struct BuildContext<'a, 'gctx> {
/// The dependency graph of units to compile.
pub unit_graph: UnitGraph,

/// A map from unit to index.
pub unit_to_index: HashMap<Unit, u64>,

/// Reverse-dependencies of documented units, used by the `rustdoc --scrape-examples` flag.
pub scrape_units: Vec<Unit>,

Expand All @@ -96,6 +99,7 @@ impl<'a, 'gctx> BuildContext<'a, 'gctx> {
target_data: RustcTargetData<'gctx>,
roots: Vec<Unit>,
unit_graph: UnitGraph,
unit_to_index: HashMap<Unit, u64>,
scrape_units: Vec<Unit>,
) -> CargoResult<BuildContext<'a, 'gctx>> {
let all_kinds = unit_graph
Expand All @@ -116,6 +120,7 @@ impl<'a, 'gctx> BuildContext<'a, 'gctx> {
target_data,
roots,
unit_graph,
unit_to_index,
scrape_units,
all_kinds,
})
Expand Down
16 changes: 1 addition & 15 deletions src/cargo/core/compiler/timings/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,6 @@ use crate::util::{CargoResult, GlobalContext};

use cargo_util::paths;
use indexmap::IndexMap;
use itertools::Itertools as _;
use std::collections::HashMap;
use std::io::BufWriter;
use std::time::{Duration, Instant};
Expand Down Expand Up @@ -53,9 +52,6 @@ pub struct Timings<'gctx> {
/// Total number of dirty units.
total_dirty: u32,
/// A map from unit to index.
///
/// This for saving log size.
/// Only the unit-started event needs to hold the entire unit information.
unit_to_index: HashMap<Unit, u64>,
/// Time tracking for each individual unit.
unit_times: Vec<UnitTime>,
Expand Down Expand Up @@ -174,13 +170,6 @@ impl<'gctx> Timings<'gctx> {
None
}
};
let unit_to_index = bcx
.unit_graph
.keys()
.sorted()
.enumerate()
.map(|(i, unit)| (unit.clone(), i as u64))
.collect();

Timings {
gctx: bcx.gctx,
Expand All @@ -193,7 +182,7 @@ impl<'gctx> Timings<'gctx> {
profile,
total_fresh: 0,
total_dirty: 0,
unit_to_index,
unit_to_index: bcx.unit_to_index.clone(),
unit_times: Vec::new(),
active: HashMap::new(),
last_cpu_state,
Expand Down Expand Up @@ -237,9 +226,6 @@ impl<'gctx> Timings<'gctx> {
};
if let Some(logger) = build_runner.bcx.logger {
logger.log(LogMessage::UnitStarted {
package_id: unit_time.unit.pkg.package_id().to_spec(),
target: (&unit_time.unit.target).into(),
mode: unit_time.unit.mode,
index: self.unit_to_index[&unit_time.unit],
elapsed: start,
});
Expand Down
58 changes: 48 additions & 10 deletions src/cargo/ops/cargo_compile/mod.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,7 @@ use annotate_snippets::{Group, Level, Origin};
pub use compile_filter::{CompileFilter, FilterRule, LibRule};

pub(super) mod unit_generator;
use itertools::Itertools as _;
use unit_generator::UnitGenerator;

mod packages;
Expand Down Expand Up @@ -304,6 +305,11 @@ pub fn create_bcx<'a, 'gctx>(
}
};
let dry_run = false;

if let Some(logger) = logger {
let elapsed = ws.gctx().creation_time().elapsed().as_secs_f64();
logger.log(LogMessage::ResolutionStarted { elapsed });
}
let resolve = ops::resolve_ws_with_opts(
ws,
&mut target_data,
Expand All @@ -321,6 +327,11 @@ pub fn create_bcx<'a, 'gctx>(
specs_and_features,
} = resolve;

if let Some(logger) = logger {
let elapsed = ws.gctx().creation_time().elapsed().as_secs_f64();
logger.log(LogMessage::ResolutionFinished { elapsed });
}

let std_resolve_features = if let Some(crates) = &gctx.cli_unstable().build_std {
let (std_package_set, std_resolve, std_features) = standard_lib::resolve_std(
ws,
Expand Down Expand Up @@ -397,10 +408,15 @@ pub fn create_bcx<'a, 'gctx>(
})
.collect();

let mut units = Vec::new();
let mut root_units = Vec::new();
let mut unit_graph = HashMap::new();
let mut scrape_units = Vec::new();

if let Some(logger) = logger {
let elapsed = ws.gctx().creation_time().elapsed().as_secs_f64();
logger.log(LogMessage::UnitGraphStarted { elapsed });
}

for SpecsAndResolvedFeatures {
specs,
resolved_features,
Expand Down Expand Up @@ -479,14 +495,14 @@ pub fn create_bcx<'a, 'gctx>(
&profiles,
interner,
)?);
units.extend(targeted_root_units);
root_units.extend(targeted_root_units);
scrape_units.extend(targeted_scrape_units);
}

// TODO: In theory, Cargo should also dedupe the roots, but I'm uncertain
// what heuristics to use in that case.
if build_config.intent.wants_deps_docs() {
remove_duplicate_doc(build_config, &units, &mut unit_graph);
remove_duplicate_doc(build_config, &root_units, &mut unit_graph);
}

let host_kind_requested = build_config
Expand All @@ -496,29 +512,50 @@ pub fn create_bcx<'a, 'gctx>(
// Rebuild the unit graph, replacing the explicit host targets with
// CompileKind::Host, removing `artifact_target_for_features` and merging any dependencies
// shared with build and artifact dependencies.
(units, scrape_units, unit_graph) = rebuild_unit_graph_shared(
(root_units, scrape_units, unit_graph) = rebuild_unit_graph_shared(
interner,
unit_graph,
&units,
&root_units,
&scrape_units,
host_kind_requested.then_some(explicit_host_kind),
build_config.compile_time_deps_only,
);

// unit_graph must be immutable after this point.
let unit_graph = unit_graph;
let units: Vec<_> = unit_graph.keys().sorted().collect();
let unit_to_index: HashMap<_, _> = units
.iter()
.enumerate()
.map(|(i, &unit)| (unit.clone(), i as u64))
.collect();
if let Some(logger) = logger {
for (i, unit) in units.into_iter().enumerate() {
logger.log(LogMessage::UnitRegistered {
package_id: unit.pkg.package_id().to_spec(),
target: (&unit.target).into(),
mode: unit.mode,
index: i as u64,
});
}
let elapsed = ws.gctx().creation_time().elapsed().as_secs_f64();
logger.log(LogMessage::UnitGraphFinished { elapsed });
}

let mut extra_compiler_args = HashMap::new();
if let Some(args) = extra_args {
if units.len() != 1 {
if root_units.len() != 1 {
anyhow::bail!(
"extra arguments to `{}` can only be passed to one \
target, consider filtering\nthe package by passing, \
e.g., `--lib` or `--bin NAME` to specify a single target",
extra_args_name
);
}
extra_compiler_args.insert(units[0].clone(), args);
extra_compiler_args.insert(root_units[0].clone(), args);
}

for unit in units
for unit in root_units
.iter()
.filter(|unit| unit.mode.is_doc() || unit.mode.is_doc_test())
.filter(|unit| rustdoc_document_private_items || unit.target.is_bin())
Expand All @@ -541,7 +578,7 @@ pub fn create_bcx<'a, 'gctx>(

// Validate target src path for each root unit
let mut error_count: usize = 0;
for unit in &units {
for unit in &root_units {
if let Some(target_src_path) = unit.target.src_path().path() {
validate_target_path_as_source_file(
gctx,
Expand Down Expand Up @@ -619,8 +656,9 @@ where `<compatible-ver>` is the latest version supporting rustc {rustc_version}"
profiles,
extra_compiler_args,
target_data,
units,
root_units,
unit_graph,
unit_to_index,
scrape_units,
)?;

Expand Down
13 changes: 10 additions & 3 deletions src/cargo/ops/cargo_report/timings.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
//! The `cargo report timings` command.

use std::collections::HashMap;
use std::ffi::OsStr;
use std::fs::File;
use std::io::BufReader;
Expand Down Expand Up @@ -178,6 +179,8 @@ fn prepare_context(log: &Path, run_id: &RunId) -> CargoResult<RenderContext<'sta
};
let mut units: IndexMap<_, UnitEntry> = IndexMap::new();

let mut unit_by_index: HashMap<u64, _> = HashMap::new();

for (log_index, result) in serde_json::Deserializer::from_reader(reader)
.into_iter::<LogMessage>()
.enumerate()
Expand Down Expand Up @@ -208,13 +211,17 @@ fn prepare_context(log: &Path, run_id: &RunId) -> CargoResult<RenderContext<'sta
ctx.profile = profile;
ctx.rustc_version = rustc_version;
}
LogMessage::UnitStarted {
LogMessage::UnitRegistered {
package_id,
target,
mode,
index,
elapsed,
} => {
unit_by_index.insert(index, (package_id, target, mode));
}
LogMessage::UnitStarted { index, elapsed } => {
let (package_id, target, mode) = unit_by_index.get(&index).unwrap();

let version = package_id
.version()
.map(|v| v.to_string())
Expand All @@ -223,7 +230,7 @@ fn prepare_context(log: &Path, run_id: &RunId) -> CargoResult<RenderContext<'sta
// This is pretty similar to how the current `core::compiler::timings`
// renders `core::manifest::Target`. However, our target is
// a simplified type so we cannot reuse the same logic here.
let mut target_str = if target.kind == "lib" && mode == CompileMode::Build {
let mut target_str = if target.kind == "lib" && mode == &CompileMode::Build {
// Special case for brevity, since most dependencies hit this path.
"".to_string()
} else if target.kind == "build-script" {
Expand Down
39 changes: 33 additions & 6 deletions src/cargo/util/log_message.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -39,8 +39,30 @@ pub enum LogMessage {
/// Workspace root directory.
workspace_root: PathBuf,
},
/// Emitted when a compilation unit starts.
UnitStarted {
/// Emitted when resolving dependencies starts.
ResolutionStarted {
/// Seconds elapsed from build start.
elapsed: f64,
},
/// Emitted when resolving dependencies finishes.
ResolutionFinished {
/// Seconds elapsed from build start.
elapsed: f64,
},
/// Emitted when unit graph generation starts.
UnitGraphStarted {
/// Seconds elapsed from build start.
elapsed: f64,
},
/// Emitted when unit graph generation finishes.
UnitGraphFinished {
/// Seconds elapsed from build start.
elapsed: f64,
},
/// Emitted when a compilation unit is registered in the unit graph,
/// right before [`LogMessage::UnitGraphFinished`] that Cargo finalizes
/// the unit graph.
UnitRegistered {
/// Package ID specification.
package_id: PackageIdSpec,
/// Cargo target (lib, bin, example, etc.).
Expand All @@ -49,12 +71,17 @@ pub enum LogMessage {
mode: CompileMode,
/// Unit index for compact reference in subsequent events.
index: u64,
},
/// Emitted when a compilation unit starts.
UnitStarted {
/// Unit index from the associated unit-registered event.
index: u64,
/// Seconds elapsed from build start.
elapsed: f64,
},
/// Emitted when a section (e.g., rmeta, link) of the compilation unit finishes.
UnitRmetaFinished {
/// Unit index from the associated unit-started event.
/// Unit index from the associated unit-registered event.
index: u64,
/// Seconds elapsed from build start.
elapsed: f64,
Expand All @@ -66,7 +93,7 @@ pub enum LogMessage {
///
/// Requires `-Zsection-timings` to be enabled.
UnitSectionStarted {
/// Unit index from the associated unit-started event.
/// Unit index from the associated unit-registered event.
index: u64,
/// Seconds elapsed from build start.
elapsed: f64,
Expand All @@ -77,7 +104,7 @@ pub enum LogMessage {
///
/// Requires `-Zsection-timings` to be enabled.
UnitSectionFinished {
/// Unit index from the associated unit-started event.
/// Unit index from the associated unit-registered event.
index: u64,
/// Seconds elapsed from build start.
elapsed: f64,
Expand All @@ -86,7 +113,7 @@ pub enum LogMessage {
},
/// Emitted when a compilation unit finishes.
UnitFinished {
/// Unit index from the associated unit-started event.
/// Unit index from the associated unit-registered event.
index: u64,
/// Seconds elapsed from build start.
elapsed: f64,
Expand Down
Loading