Skip to content

Commit 064db93

Browse files
committed
Add build timing capture from cargo's --timings JSON output
Introduces a timings module with a visitor pattern for optionally intercepting cargo timing-info messages during builds. Timings are captured only when capture_timings is enabled in config, the toolchain is nightly/CI, and running in local/CLI mode (not agent mode).
1 parent 8ccb676 commit 064db93

File tree

13 files changed

+497
-11
lines changed

13 files changed

+497
-11
lines changed

src/agent/mod.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -181,6 +181,7 @@ fn run_experiment(
181181
threads_count,
182182
&agent.config,
183183
&|| agent.next_crate(&ex.name),
184+
true,
184185
)
185186
.map_err(|err| (Some(Box::new(ex)), err))?;
186187
Ok(())

src/cli.rs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -441,6 +441,7 @@ impl Crater {
441441
threads,
442442
&config,
443443
&|| Ok(crates.lock().unwrap().pop()),
444+
false,
444445
);
445446
workspace.purge_all_build_dirs()?;
446447
res?;

src/config.rs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -97,6 +97,8 @@ pub struct Config {
9797
pub local_crates: HashMap<String, CrateConfig>,
9898
pub server: ServerConfig,
9999
pub sandbox: SandboxConfig,
100+
#[serde(default = "default_false")]
101+
pub capture_timings: bool,
100102
}
101103

102104
impl Config {
@@ -264,6 +266,7 @@ impl Default for Config {
264266
experiment_completed: "".into(),
265267
},
266268
},
269+
capture_timings: false,
267270
}
268271
}
269272
}

src/db/migrations.rs

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -365,6 +365,27 @@ fn migrations() -> Vec<(&'static str, MigrationKind)> {
365365
MigrationKind::SQL("alter table agents add column latest_work_for text;"),
366366
));
367367

368+
migrations.push((
369+
"create_build_timings_table",
370+
MigrationKind::SQL(
371+
"
372+
CREATE TABLE build_timings (
373+
experiment TEXT NOT NULL,
374+
crate TEXT NOT NULL,
375+
toolchain TEXT NOT NULL,
376+
package_id TEXT NOT NULL,
377+
target_name TEXT NOT NULL,
378+
target_kind TEXT NOT NULL,
379+
mode TEXT NOT NULL,
380+
duration REAL NOT NULL,
381+
rmeta_time REAL,
382+
FOREIGN KEY (experiment) REFERENCES experiments(name) ON DELETE CASCADE
383+
);
384+
CREATE INDEX build_timings__experiment ON build_timings (experiment);
385+
",
386+
),
387+
));
388+
368389
migrations
369390
}
370391

src/lib.rs

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@
1717
//! - [`results`] — Traits and types for per-crate test results and build logs
1818
//! - [`runner`] — Experiment execution engine
1919
//! - [`server`] — HTTP server for the web UI and agent API
20+
//! - [`timings`] — Build timing capture from cargo's `--timings` JSON output
2021
//! - [`toolchain`] — Rust toolchain abstraction
2122
//! - [`utils`] — Shared utilities (HTTP, size formatting, hex encoding, etc.)
2223
//!
@@ -52,6 +53,7 @@ pub mod report;
5253
pub mod results;
5354
pub mod runner;
5455
pub mod server;
56+
pub mod timings;
5557
pub mod toolchain;
5658

5759
pub(crate) static GIT_REVISION: Option<&str> = include!(concat!(env!("OUT_DIR"), "/sha"));

src/results/db.rs

Lines changed: 153 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ use crate::prelude::*;
55
use crate::results::{
66
DeleteResults, EncodedLog, EncodingType, ReadResults, TestResult, WriteResults,
77
};
8+
use crate::timings::TimingInfo;
89
use crate::toolchain::Toolchain;
910
use base64::Engine;
1011
use rustwide::logging::{self, LogStorage};
@@ -145,6 +146,69 @@ impl<'a> DatabaseDB<'a> {
145146
Ok(())
146147
}
147148

149+
pub fn store_timings(
150+
&self,
151+
ex: &Experiment,
152+
krate: &Crate,
153+
toolchain: &Toolchain,
154+
timings: &[TimingInfo],
155+
) -> Fallible<()> {
156+
for timing in timings {
157+
let target_kind = timing.target.kind.join(",");
158+
self.db.execute_cached(
159+
"INSERT INTO build_timings \
160+
(experiment, crate, toolchain, package_id, target_name, target_kind, mode, duration, rmeta_time) \
161+
VALUES (?1, ?2, ?3, ?4, ?5, ?6, ?7, ?8, ?9);",
162+
&[
163+
&ex.name as &dyn rusqlite::types::ToSql,
164+
&krate.id(),
165+
&toolchain.to_string(),
166+
&timing.package_id,
167+
&timing.target.name,
168+
&target_kind,
169+
&timing.mode,
170+
&timing.duration,
171+
&timing.rmeta_time,
172+
],
173+
)?;
174+
}
175+
Ok(())
176+
}
177+
178+
pub fn load_timings(
179+
&self,
180+
ex: &Experiment,
181+
krate: &Crate,
182+
toolchain: &Toolchain,
183+
) -> Fallible<Vec<TimingInfo>> {
184+
self.db.query(
185+
"SELECT package_id, target_name, target_kind, mode, duration, rmeta_time \
186+
FROM build_timings \
187+
WHERE experiment = ?1 AND crate = ?2 AND toolchain = ?3;",
188+
[&ex.name, &krate.id(), &toolchain.to_string()],
189+
|row| {
190+
let target_kind: String = row.get("target_kind")?;
191+
let kinds: Vec<String> = target_kind.split(',').map(|s| s.to_string()).collect();
192+
Ok(TimingInfo {
193+
package_id: row.get("package_id")?,
194+
target: crate::timings::TimingTarget {
195+
kind: kinds,
196+
crate_types: Vec::new(),
197+
name: row.get("target_name")?,
198+
src_path: String::new(),
199+
edition: String::new(),
200+
doc: false,
201+
doctest: false,
202+
test: false,
203+
},
204+
mode: row.get("mode")?,
205+
duration: row.get("duration")?,
206+
rmeta_time: row.get("rmeta_time")?,
207+
})
208+
},
209+
)
210+
}
211+
148212
fn insert_into_results(
149213
&self,
150214
ex: &Experiment,
@@ -274,6 +338,16 @@ impl crate::runner::RecordProgress for DatabaseDB<'_> {
274338
}
275339
Ok(())
276340
}
341+
342+
fn record_timings(
343+
&self,
344+
ex: &Experiment,
345+
krate: &Crate,
346+
toolchain: &Toolchain,
347+
timings: &[TimingInfo],
348+
) -> Fallible<()> {
349+
self.store_timings(ex, krate, toolchain, timings)
350+
}
277351
}
278352

279353
impl DeleteResults for DatabaseDB<'_> {
@@ -470,6 +544,85 @@ mod tests {
470544
.is_none());
471545
}
472546

547+
#[test]
548+
fn test_store_and_load_timings() {
549+
let db = Database::temp().unwrap();
550+
let results = DatabaseDB::new(&db);
551+
let config = Config::default();
552+
let ctx = ActionsCtx::new(&db, &config);
553+
554+
crate::crates::lists::setup_test_lists(&db, &config).unwrap();
555+
556+
CreateExperiment::dummy("dummy").apply(&ctx).unwrap();
557+
let ex = Experiment::get(&db, "dummy").unwrap().unwrap();
558+
559+
let krate = Crate::Registry(RegistryCrate {
560+
name: "lazy_static".into(),
561+
version: "1".into(),
562+
});
563+
564+
let timings = vec![
565+
crate::timings::TimingInfo {
566+
package_id: "serde 1.0.0 (registry+https://github.com/rust-lang/crates.io-index)"
567+
.to_string(),
568+
target: crate::timings::TimingTarget {
569+
kind: vec!["lib".to_string()],
570+
crate_types: vec!["lib".to_string()],
571+
name: "serde".to_string(),
572+
src_path: "/path/to/src/lib.rs".to_string(),
573+
edition: "2021".to_string(),
574+
doc: true,
575+
doctest: true,
576+
test: true,
577+
},
578+
mode: "build".to_string(),
579+
duration: 12.5,
580+
rmeta_time: Some(8.3),
581+
},
582+
crate::timings::TimingInfo {
583+
package_id: "foo 0.1.0".to_string(),
584+
target: crate::timings::TimingTarget {
585+
kind: vec!["bin".to_string()],
586+
crate_types: vec!["bin".to_string()],
587+
name: "foo".to_string(),
588+
src_path: "/path/to/main.rs".to_string(),
589+
edition: "2021".to_string(),
590+
doc: false,
591+
doctest: false,
592+
test: false,
593+
},
594+
mode: "build".to_string(),
595+
duration: 1.0,
596+
rmeta_time: None,
597+
},
598+
];
599+
600+
results
601+
.store_timings(&ex, &krate, &MAIN_TOOLCHAIN, &timings)
602+
.unwrap();
603+
604+
let loaded = results.load_timings(&ex, &krate, &MAIN_TOOLCHAIN).unwrap();
605+
606+
assert_eq!(loaded.len(), 2);
607+
608+
assert_eq!(loaded[0].package_id, timings[0].package_id);
609+
assert_eq!(loaded[0].target.name, "serde");
610+
assert_eq!(loaded[0].target.kind, vec!["lib"]);
611+
assert_eq!(loaded[0].mode, "build");
612+
assert!((loaded[0].duration - 12.5).abs() < f64::EPSILON);
613+
assert!((loaded[0].rmeta_time.unwrap() - 8.3).abs() < f64::EPSILON);
614+
615+
assert_eq!(loaded[1].package_id, "foo 0.1.0");
616+
assert_eq!(loaded[1].target.name, "foo");
617+
assert_eq!(loaded[1].target.kind, vec!["bin"]);
618+
assert!((loaded[1].duration - 1.0).abs() < f64::EPSILON);
619+
assert!(loaded[1].rmeta_time.is_none());
620+
621+
// Different toolchain should return empty
622+
let empty = results.load_timings(&ex, &krate, &TEST_TOOLCHAIN).unwrap();
623+
assert!(empty.is_empty());
624+
}
625+
473626
#[test]
474627
fn test_store() {
475628
let db = Database::temp().unwrap();

src/runner/mod.rs

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -14,7 +14,7 @@
1414
//! 5. `run_test` — Creates a memory-limited, network-disabled sandbox,
1515
//! locks the build directory, and calls the mode-specific test function.
1616
//! 6. Mode functions (e.g. `test_build_and_test`) — Invoke the private
17-
//! helpers `build()` / `test()` which call `run_cargo`.
17+
//! helpers `run_cargo_build()` / `run_cargo_test()` which call `run_cargo`.
1818
//! 7. `run_cargo` — The lowest level: assembles the `cargo` command with
1919
//! flags and environment, streams JSON output through a line processor that
2020
//! detects ICEs, error codes, OOM, disk-full, and network issues, then maps
@@ -60,6 +60,7 @@ pub fn run_ex(
6060
threads_count: usize,
6161
config: &Config,
6262
next_crate: &(dyn Fn() -> Fallible<Option<Crate>> + Send + Sync),
63+
is_agent_mode: bool,
6364
) -> Fallible<()> {
6465
// Attempt to spin indefinitely until docker is up. Ideally, we would
6566
// decomission this agent until docker is up, instead of leaving the
@@ -120,6 +121,7 @@ pub fn run_ex(
120121
config,
121122
api,
122123
next_crate,
124+
is_agent_mode,
123125
)
124126
})
125127
.collect::<Vec<_>>();

src/runner/tasks.rs

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ use crate::experiments::Experiment;
66
use crate::prelude::*;
77
use crate::results::TestResult;
88
use crate::runner::test;
9+
use crate::timings::TimingVisitor;
910
use crate::toolchain::Toolchain;
1011
use rustwide::{Build, BuildDirectory};
1112
use std::collections::HashMap;
@@ -101,12 +102,13 @@ impl Task {
101102
config: &'ctx Config,
102103
build_dir: &'ctx HashMap<&'ctx crate::toolchain::Toolchain, Mutex<BuildDirectory>>,
103104
ex: &'ctx Experiment,
105+
timing_visitor: &'ctx mut dyn TimingVisitor,
104106
logs: &LogStorage,
105107
) -> Fallible<TestResult> {
106108
let (build_dir, action, test, toolchain, quiet): (
107109
_,
108110
_,
109-
fn(&TaskCtx, &Build, &_) -> _,
111+
fn(&TaskCtx, &Build, &_, &mut dyn TimingVisitor) -> _,
110112
_,
111113
_,
112114
) = match self.step {
@@ -140,6 +142,6 @@ impl Task {
140142
};
141143

142144
let ctx = TaskCtx::new(build_dir, config, ex, toolchain, &self.krate, quiet);
143-
test::run_test(action, &ctx, test, logs)
145+
test::run_test(action, &ctx, test, timing_visitor, logs)
144146
}
145147
}

0 commit comments

Comments
 (0)