Skip to main content

max / audiofiles

Emit machine-readable bench results, analyse after ingest, track peak RSS The bench only printed tables, so no run was comparable to another and "did that change help" could only be answered by eyeballing two scrollbacks. AF_BENCH_JSON now writes a versioned object per run; `schema` is bumped when a key changes meaning so an old baseline cannot be silently compared against a run measuring something else. The ingest mode now analyses a bounded slice of what it imported (AF_BENCH_ANALYZE, default 2000). Two reasons: analysis throughput at vault scale is a number in its own right, and without any audio_analysis rows the class and bpm filter timings measured empty result sets, which the bench had to disclaim rather than report. Bounded because analysis is far dearer than import and would otherwise dominate at NSynth scale. Peak RSS comes from VmHWM rather than sampling VmRSS at the end, which would miss the peak entirely, and the peak is the number that decides whether a large import fits in memory. Also documents that baselines need an idle corpus drive: a run taken while a dataset downloaded to the same disk read 40.7 files/s against 204 for the same corpus, which the JSON makes easy to mistake for a regression.
Co-Authored-By
Claude Opus 5 (1M context) <noreply@anthropic.com>
Author: Max Johnson <me@maxj.phd> · 2026-07-29 16:44 UTC
Signed with PGP, not checked
Commit: 2a9a2a1362c70cccf285152e1d4e40d13833ab63
Parent: 6aab421
3 files changed, +193 insertions, -3 deletions
M crates/audiofiles-bench/src/ingest.rs +108 -3
@@ -13,15 +13,38 @@
13 13 //!
14 14 //! Reported per batch rather than as one average, because the number that
15 15 //! matters is whether throughput is flat or degrading as the vault grows.
16 + //!
17 + //! Take baselines with the corpus drive otherwise idle. Import is I/O bound, so
18 + //! anything else touching the same spindle lands directly in the number: a run
19 + //! taken while a dataset was downloading to the same drive read 40.7 files/s
20 + //! against 204 for the same corpus on an idle one. The JSON output makes that
21 + //! kind of contamination easy to mistake for a regression.
16 22
17 23 use std::path::{Path, PathBuf};
18 24 use std::time::Instant;
19 25
26 + use audiofiles_core::analysis::{self, config::AnalysisConfig};
20 27 use audiofiles_core::db::Database;
21 28 use audiofiles_core::id_types::SampleHash;
22 29 use audiofiles_core::search::{self, SearchFilter, SearchScope};
23 30 use audiofiles_core::store::SampleStore;
24 31 use audiofiles_core::vfs;
32 + use rayon::prelude::*;
33 +
34 + use crate::report::{Report, peak_rss_mb};
35 +
36 + /// How many samples to analyse after import.
37 + ///
38 + /// Bounded because analysis is orders of magnitude dearer than import and the
39 + /// point here is to populate `audio_analysis` so the filter queries below
40 + /// measure something, not to benchmark the DSP (the default bench mode does
41 + /// that per file). At NSynth scale an unbounded pass would dominate the run.
42 + fn analyze_budget() -> usize {
43 + std::env::var("AF_BENCH_ANALYZE")
44 + .ok()
45 + .and_then(|v| v.parse().ok())
46 + .unwrap_or(2000)
47 + }
25 48
26 49 /// Deterministic reorder of the file list.
27 50 ///
@@ -107,7 +130,7 @@
107 130 }
108 131
109 132 /// Measure the query paths the browser list and filter panel depend on.
110 - fn report_query_latency(db: &Database) {
133 + fn report_query_latency(db: &Database, report: &mut Report) {
111 134 let n = count_samples(db);
112 135 let nodes: i64 = db
113 136 .conn()
@@ -144,6 +167,7 @@
144 167 let _ = count_samples(db);
145 168 });
146 169 println!(" count(*) {ms:>8.2} ms");
170 + report.set("count_star_ms", (ms * 100.0).round() / 100.0);
147 171
148 172 let mut filter = SearchFilter {
149 173 scope: SearchScope::Global,
@@ -153,12 +177,14 @@
153 177 let _ = search::search_global(db, &filter);
154 178 });
155 179 println!(" search_global (no filter) {ms:>6.2} ms <- worst-case list load");
180 + report.set("search_unfiltered_ms", (ms * 100.0).round() / 100.0);
156 181
157 182 filter.text_query = "kick".to_string();
158 183 let ms = time_query(5, || {
159 184 let _ = search::search_global(db, &filter);
160 185 });
161 186 println!(" search_global (text) {ms:>6.2} ms <- search box keystroke");
187 + report.set("search_text_ms", (ms * 100.0).round() / 100.0);
162 188
163 189 filter.text_query.clear();
164 190 filter.classifications = vec!["kick".to_string()];
@@ -166,6 +192,7 @@
166 192 let _ = search::search_global(db, &filter);
167 193 });
168 194 println!(" search_global (class) {ms:>6.2} ms <- filter panel");
195 + report.set("search_class_ms", (ms * 100.0).round() / 100.0);
169 196
170 197 filter.classifications.clear();
171 198 filter.bpm_min = Some(120.0);
@@ -174,6 +201,7 @@
174 201 let _ = search::search_global(db, &filter);
175 202 });
176 203 println!(" search_global (bpm range) {ms:>6.2} ms");
204 + report.set("search_bpm_ms", (ms * 100.0).round() / 100.0);
177 205 }
178 206
179 207 /// Run the ingest benchmark against `corpus`, building a scratch vault at
@@ -184,6 +212,8 @@
184 212 println!(" corpus: {}", corpus.display());
185 213 println!(" vault: {}", vault.display());
186 214
215 + let mut report = Report::new("ingest");
216 +
187 217 let mut files = Vec::new();
188 218 collect(corpus, &mut files);
189 219 files.sort();
@@ -248,6 +278,10 @@
248 278 let mut cumulative = 0usize;
249 279 let mut failures = 0usize;
250 280 let mut link_failures = 0usize;
281 + // (hash, source path) for the analysis pass. The source file and the stored
282 + // blob are byte-identical by construction, so analysing either is the same
283 + // measurement and this avoids an extension lookup per sample.
284 + let mut imported: Vec<(String, PathBuf)> = Vec::with_capacity(files.len());
251 285
252 286 for chunk in files.chunks(batch) {
253 287 let mut bytes = 0u64;
@@ -267,12 +301,13 @@
267 301 vfs_id,
268 302 None,
269 303 &name,
270 - &SampleHash::from_trusted(hash),
304 + &SampleHash::from_trusted(hash.clone()),
271 305 )
272 306 .is_err()
273 307 {
274 308 link_failures += 1;
275 309 }
310 + imported.push((hash, path.clone()));
276 311 bytes += std::fs::metadata(path).map_or(0, |m| m.len());
277 312 cumulative += 1;
278 313 }
@@ -332,6 +367,22 @@
332 367 total_files as f64 / total_s,
333 368 (total_bytes as f64 / 1e6) / total_s,
334 369 );
370 + report.set("import_files", total_files);
371 + report.set("import_bytes", total_bytes);
372 + report.set(
373 + "import_files_per_sec",
374 + ((total_files as f64 / total_s) * 10.0).round() / 10.0,
375 + );
376 + report.set(
377 + "import_mb_per_sec",
378 + (((total_bytes as f64 / 1e6) / total_s) * 10.0).round() / 10.0,
379 + );
380 + if let (Some(first), Some(last)) = (stats.first(), stats.last()) {
381 + // The scaling signal, not a throughput figure: negative means the vault
382 + // got slower as it filled.
383 + let delta = (last.files_per_sec() - first.files_per_sec()) / first.files_per_sec() * 100.0;
384 + report.set("import_throughput_drift_pct", (delta * 10.0).round() / 10.0);
385 + }
335 386
336 387 // Dedup: re-importing the same files must hit the content-addressed store
337 388 // and skip the copy. If this is not dramatically faster, dedup is not
@@ -372,16 +423,70 @@
372 423 );
373 424 }
374 425
426 + // Analysis pass. Two purposes: it is a throughput number in its own right at
427 + // vault scale, and without it `audio_analysis` stays empty and the class and
428 + // bpm filter timings below measure nothing.
429 + println!();
430 + println!("━━━ ANALYSIS AT SCALE ━━━");
431 + println!();
432 + let budget = analyze_budget();
433 + let to_analyze: Vec<(String, PathBuf)> = imported.into_iter().take(budget).collect();
434 + if to_analyze.is_empty() {
435 + println!(" skipped (AF_BENCH_ANALYZE=0)");
436 + } else {
437 + println!(
438 + " analysing {} samples (AF_BENCH_ANALYZE={budget})",
439 + to_analyze.len()
440 + );
441 + let config = AnalysisConfig::default();
442 + let start = Instant::now();
443 + let results: Vec<_> = to_analyze
444 + .par_iter()
445 + .filter_map(|(hash, path)| analysis::analyze_sample(hash, path, &config).ok())
446 + .collect();
447 + let analyze_s = start.elapsed().as_secs_f64();
448 +
449 + let save_start = Instant::now();
450 + let saved = analysis::save_analysis_batch(&db, &results).is_ok();
451 + let save_s = save_start.elapsed().as_secs_f64();
452 +
453 + let rate = results.len() as f64 / analyze_s.max(1e-9);
454 + println!(
455 + " analysed {} in {analyze_s:.1}s ({rate:.1} files/s)",
456 + results.len()
457 + );
458 + println!(
459 + " persisted {} rows in {save_s:.2}s{}",
460 + results.len(),
461 + if saved { "" } else { " (SAVE FAILED)" }
462 + );
463 + if results.len() < to_analyze.len() {
464 + println!(
465 + " {} file(s) failed analysis",
466 + to_analyze.len() - results.len()
467 + );
468 + }
469 + report.set("analysis_files", results.len());
470 + report.set("analysis_files_per_sec", (rate * 10.0).round() / 10.0);
471 + report.set("analysis_persist_s", (save_s * 100.0).round() / 100.0);
472 + }
473 +
375 474 println!();
376 475 println!("━━━ QUERY LATENCY (backs the browser UI) ━━━");
377 476 println!();
378 - report_query_latency(&db);
477 + report_query_latency(&db, &mut report);
379 478
380 479 // Left in place deliberately: the vault is the artifact to point the app at
381 480 // for eyeballing UI responsiveness at this size.
382 481 println!();
482 + if let Some(rss) = peak_rss_mb() {
483 + // High-water across the whole run, so it covers the import and analysis
484 + // peaks rather than whatever happens to be resident at the end.
485 + println!(" peak RSS: {rss:.1} MB");
486 + }
383 487 println!(
384 488 " scratch vault left at {} for UI inspection",
385 489 vault.display()
386 490 );
491 + report.write();
387 492 }
M crates/audiofiles-bench/src/main.rs +1
@@ -14,6 +14,7 @@
14 14
15 15 mod accuracy;
16 16 mod ingest;
17 + mod report;
17 18
18 19 use std::collections::HashMap;
19 20 use std::path::{Path, PathBuf};
A crates/audiofiles-bench/src/report.rs +84
@@ -1,0 +1,84 @@
1 + //! Machine-readable benchmark output.
2 + //!
3 + //! The printed tables are for reading; this is for diffing. Without a stable
4 + //! serialised form every number is a one-off observation, so "did that change
5 + //! help" can only be answered by eyeballing two terminal scrollbacks.
6 + //!
7 + //! Set `AF_BENCH_JSON` to a path to emit one object per run:
8 + //!
9 + //! AF_BENCH_JSON=/tmp/base.json cargo run --release -p audiofiles-bench -- ingest
10 + //! # ...change something...
11 + //! AF_BENCH_JSON=/tmp/new.json cargo run --release -p audiofiles-bench -- ingest
12 + //! diff <(jq -S . /tmp/base.json) <(jq -S . /tmp/new.json)
13 + //!
14 + //! `schema` is bumped whenever a key changes meaning, so an old baseline cannot
15 + //! be silently compared against a new run measuring something different.
16 +
17 + use std::io::Write;
18 + use std::time::{SystemTime, UNIX_EPOCH};
19 +
20 + use serde_json::{Map, Value};
21 +
22 + /// Bump when an existing key changes meaning or unit. Adding a key is not a
23 + /// schema change; a comparison tool can treat a missing key as "not measured".
24 + const SCHEMA: u32 = 1;
25 +
26 + pub(crate) struct Report {
27 + mode: &'static str,
28 + metrics: Map<String, Value>,
29 + }
30 +
31 + impl Report {
32 + pub(crate) fn new(mode: &'static str) -> Self {
33 + Self {
34 + mode,
35 + metrics: Map::new(),
36 + }
37 + }
38 +
39 + /// Record one metric. Keys are `snake_case` and carry their unit
40 + /// (`_ms`, `_mb_s`, `_pct`) so a diff is readable without the schema.
41 + pub(crate) fn set(&mut self, key: &str, value: impl Into<Value>) {
42 + self.metrics.insert(key.to_string(), value.into());
43 + }
44 +
45 + /// Write to `AF_BENCH_JSON` if set. A run with the variable unset is the
46 + /// normal case and must stay silent.
47 + pub(crate) fn write(&self) {
48 + let Ok(path) = std::env::var("AF_BENCH_JSON") else {
49 + return;
50 + };
51 + let mut root = Map::new();
52 + root.insert("schema".into(), SCHEMA.into());
53 + root.insert("mode".into(), self.mode.into());
54 + // Unix seconds rather than a formatted date: no date dependency in this
55 + // crate, and a comparison tool wants an integer anyway.
56 + if let Ok(d) = SystemTime::now().duration_since(UNIX_EPOCH) {
57 + root.insert("unix_time".into(), d.as_secs().into());
58 + }
59 + if let Some(rss) = peak_rss_mb() {
60 + root.insert("peak_rss_mb".into(), rss.into());
61 + }
62 + root.insert("metrics".into(), Value::Object(self.metrics.clone()));
63 +
64 + let text = serde_json::to_string_pretty(&Value::Object(root)).unwrap_or_default();
65 + match std::fs::File::create(&path).and_then(|mut f| f.write_all(text.as_bytes())) {
66 + Ok(()) => println!("\n wrote {path}"),
67 + // A failed write must not look like a failed benchmark.
68 + Err(e) => eprintln!("\n could not write {path}: {e}"),
69 + }
70 + }
71 + }
72 +
73 + /// Peak resident set size in MB, high-water for the whole process lifetime.
74 + ///
75 + /// `VmHWM` rather than `VmRSS`: sampling current RSS after a run misses the
76 + /// peak, which is the number that decides whether a large import fits in
77 + /// memory. Linux only; returns None elsewhere, and callers treat that as "not
78 + /// measured" rather than zero.
79 + pub(crate) fn peak_rss_mb() -> Option<f64> {
80 + let status = std::fs::read_to_string("/proc/self/status").ok()?;
81 + let line = status.lines().find(|l| l.starts_with("VmHWM:"))?;
82 + let kb: f64 = line.split_whitespace().nth(1)?.parse().ok()?;
83 + Some(kb / 1024.0)
84 + }