use serde::{Deserialize, Serialize};
use crate::api::OcrTimings;
#[derive(Debug, Clone, PartialEq, Serialize, Deserialize)]
pub struct LedgerConservation {
pub attributed_ms: f64,
pub total_ms: f64,
pub residual_ms: f64,
pub tolerance_ms: f64,
pub conserved: bool,
pub excess_ms: f64,
pub interpretation: String,
}
#[derive(Debug, Clone, Copy, Default, PartialEq, Serialize, Deserialize)]
pub struct TimingLedger {
pub total_ms: f64,
pub input_preprocess_ms: f64,
pub input_decode_ms: f64,
pub input_resize_ms: f64,
pub input_other_ms: f64,
pub input_crop_ms: f64,
pub input_named_within_ms: f64,
pub input_overflow_ms: f64,
pub detector_preprocess_ms: f64,
pub detector_infer_ms: f64,
pub detector_postprocess_ms: f64,
pub classifier_preprocess_ms: f64,
pub classifier_infer_ms: f64,
pub classifier_postprocess_ms: f64,
pub recognizer_preprocess_ms: f64,
pub recognizer_infer_ms: f64,
pub recognizer_postprocess_ms: f64,
pub formula_ms: f64,
pub table_detect_ms: f64,
pub table_structure_infer_ms: f64,
pub table_backfill_ms: f64,
pub page_postprocess_ms: f64,
pub unattributed_ms: f64,
}
impl TimingLedger {
pub fn from_timings(timings: &OcrTimings) -> Self {
let value = |raw: f32| f64::from(raw);
let decode = value(timings.decode_ms);
let resize = value(timings.resize_ms);
let crop = value(timings.crop_ms);
let outer_preprocess = value(timings.preprocess_ms);
let input_other = (outer_preprocess - decode - resize - crop).max(0.0);
let named_input = decode + resize + crop;
let input_budget = (outer_preprocess - input_other).max(0.0);
let input_named_within = named_input.min(input_budget);
let input_overflow = (named_input - input_budget).max(0.0);
let mut ledger = Self {
total_ms: value(timings.total_ms),
input_preprocess_ms: outer_preprocess,
input_decode_ms: decode,
input_resize_ms: resize,
input_other_ms: input_other,
input_crop_ms: crop,
input_named_within_ms: input_named_within,
input_overflow_ms: input_overflow,
detector_preprocess_ms: value(timings.detector_preprocess_ms),
detector_infer_ms: value(timings.detector_infer_ms),
detector_postprocess_ms: value(timings.detector_postprocess_ms),
classifier_preprocess_ms: value(timings.classifier_preprocess_ms),
classifier_infer_ms: value(timings.classifier_infer_ms),
classifier_postprocess_ms: value(timings.classifier_postprocess_ms),
recognizer_preprocess_ms: value(timings.recognizer_preprocess_ms),
recognizer_infer_ms: value(timings.recognizer_infer_ms),
recognizer_postprocess_ms: value(timings.recognizer_postprocess_ms),
formula_ms: value(timings.formula_ms),
table_detect_ms: value(timings.table_detect_ms),
table_structure_infer_ms: value(timings.table_structure_infer_ms),
table_backfill_ms: value(timings.table_backfill_ms),
page_postprocess_ms: value(timings.postprocess_ms),
unattributed_ms: 0.0,
};
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
ledger
}
pub fn attributed_ms(&self) -> f64 {
self.input_named_within_ms
+ self.input_overflow_ms
+ self.input_other_ms
+ self.detector_preprocess_ms
+ self.detector_infer_ms
+ self.detector_postprocess_ms
+ self.classifier_preprocess_ms
+ self.classifier_infer_ms
+ self.classifier_postprocess_ms
+ self.recognizer_preprocess_ms
+ self.recognizer_infer_ms
+ self.recognizer_postprocess_ms
+ self.formula_ms
+ self.table_detect_ms
+ self.table_structure_infer_ms
+ self.table_backfill_ms
+ self.page_postprocess_ms
}
pub fn inference_ms(&self) -> f64 {
self.detector_infer_ms
+ self.classifier_infer_ms
+ self.recognizer_infer_ms
+ self.table_structure_infer_ms
}
pub fn model_preprocess_ms(&self) -> f64 {
self.detector_preprocess_ms + self.classifier_preprocess_ms + self.recognizer_preprocess_ms
}
pub fn model_postprocess_ms(&self) -> f64 {
self.detector_postprocess_ms
+ self.classifier_postprocess_ms
+ self.recognizer_postprocess_ms
}
pub fn input_ms(&self) -> f64 {
self.input_named_within_ms + self.input_other_ms
}
pub fn rust_ms(&self) -> f64 {
self.input_ms()
+ self.model_preprocess_ms()
+ self.model_postprocess_ms()
+ self.page_postprocess_ms
+ self.formula_ms
+ self.table_detect_ms
+ self.table_backfill_ms
}
pub fn conservation(&self) -> LedgerConservation {
let attributed = self.attributed_ms();
let residual = attributed - self.total_ms;
let tolerance = (1e-6_f64 * 16.0).max(self.total_ms.abs() * 1e-6);
let conserved = residual.abs() <= tolerance;
LedgerConservation {
attributed_ms: attributed,
total_ms: self.total_ms,
residual_ms: residual,
tolerance_ms: tolerance,
conserved,
excess_ms: (-residual).max(0.0),
interpretation: conservation_interpretation(residual, self.total_ms, tolerance),
}
}
pub fn shares(&self) -> Option<LedgerShares> {
if self.total_ms <= 0.0 {
return None;
}
let share = |value: f64| value / self.total_ms;
Some(LedgerShares {
input_share: share(self.input_ms()),
input_decode_share: share(self.input_decode_ms),
input_resize_share: share(self.input_resize_ms),
input_other_share: share(self.input_other_ms),
input_crop_share: share(self.input_crop_ms),
model_preprocess_share: share(self.model_preprocess_ms()),
inference_share: share(self.inference_ms()),
detector_infer_share: share(self.detector_infer_ms),
classifier_infer_share: share(self.classifier_infer_ms),
recognizer_infer_share: share(self.recognizer_infer_ms),
model_postprocess_share: share(self.model_postprocess_ms()),
detector_postprocess_share: share(self.detector_postprocess_ms),
classifier_postprocess_share: share(self.classifier_postprocess_ms),
recognizer_postprocess_share: share(self.recognizer_postprocess_ms),
page_postprocess_share: share(self.page_postprocess_ms),
formula_share: share(self.formula_ms),
table_detect_share: share(self.table_detect_ms),
table_structure_infer_share: share(self.table_structure_infer_ms),
table_backfill_share: share(self.table_backfill_ms),
rust_share: share(self.rust_ms()),
unattributed_share: share(self.unattributed_ms),
})
}
pub fn mean(ledgers: &[Self]) -> Self {
if ledgers.is_empty() {
return Self::default();
}
let divisor = ledgers.len() as f64;
let sum = |pick: fn(&Self) -> f64| ledgers.iter().map(pick).sum::<f64>() / divisor;
Self {
total_ms: sum(|l| l.total_ms),
input_preprocess_ms: sum(|l| l.input_preprocess_ms),
input_decode_ms: sum(|l| l.input_decode_ms),
input_resize_ms: sum(|l| l.input_resize_ms),
input_other_ms: sum(|l| l.input_other_ms),
input_crop_ms: sum(|l| l.input_crop_ms),
input_named_within_ms: sum(|l| l.input_named_within_ms),
input_overflow_ms: sum(|l| l.input_overflow_ms),
detector_preprocess_ms: sum(|l| l.detector_preprocess_ms),
detector_infer_ms: sum(|l| l.detector_infer_ms),
detector_postprocess_ms: sum(|l| l.detector_postprocess_ms),
classifier_preprocess_ms: sum(|l| l.classifier_preprocess_ms),
classifier_infer_ms: sum(|l| l.classifier_infer_ms),
classifier_postprocess_ms: sum(|l| l.classifier_postprocess_ms),
recognizer_preprocess_ms: sum(|l| l.recognizer_preprocess_ms),
recognizer_infer_ms: sum(|l| l.recognizer_infer_ms),
recognizer_postprocess_ms: sum(|l| l.recognizer_postprocess_ms),
formula_ms: sum(|l| l.formula_ms),
table_detect_ms: sum(|l| l.table_detect_ms),
table_structure_infer_ms: sum(|l| l.table_structure_infer_ms),
table_backfill_ms: sum(|l| l.table_backfill_ms),
page_postprocess_ms: sum(|l| l.page_postprocess_ms),
unattributed_ms: sum(|l| l.unattributed_ms),
}
}
}
fn conservation_interpretation(residual_ms: f64, total_ms: f64, tolerance_ms: f64) -> String {
let share = |value: f64| {
if total_ms > 0.0 {
value / total_ms * 100.0
} else {
0.0
}
};
if residual_ms.abs() <= tolerance_ms {
format!(
"conserved: the named components form a strict partition of total_ms for this \
sample, to within the {tolerance_ms:.6} ms rounding tolerance."
)
} else if residual_ms < 0.0 {
let gap_ms = -residual_ms;
format!(
"NOT a strict partition, and NOT a wrong total either: this is a SCOPE difference \
between total_ms and the sum of its named parts. residual_ms = {residual_ms:.6}, \
i.e. the named components sum to {gap_ms:.6} ms ({share:.2}% of total_ms) LESS than \
total_ms. The two timing windows are SEQUENTIAL and do not overlap: the outer \
OcrTimings::preprocess_ms window runs from rapid_structure.rs:619 to :719 and \
inner.run() is only entered at :720, whose own end-to-end window runs from \
rapid_structure.rs:106 to :130; total_ms is their sum \
(total_ms = exec.e2e_ms + preprocess_ms, rapid_structure.rs:910). No wall-clock interval \
is therefore counted twice. What the residual measures is the part of inner.run()'s \
own window that falls outside every named stage window and therefore has no \
component in this ledger: the resize inside prepare_image \
(rapid_structure.rs:156-162), apply_vertical_padding (rapid_structure.rs:189-195), \
crop_text_regions (rapid_structure.rs:210-212), and the recognizer's batch assembly \
(rec/recognizer.rs:89-98, 222-231). total_ms is a single wall-clock measurement and \
is unaffected by how the parts are named; conversely, because the parts were \
measured independently, this ledger alone cannot decide which side is closer to \
the real elapsed time, so it does NOT claim that total_ms overstates. This ledger \
is a DIAGNOSTIC instrument, not acceptance evidence: every share is valid only to \
within {gap_ms:.6} ms ({share:.2}% of total_ms), and the stage-6 conclusion (ONNX \
Runtime inference is an order of magnitude larger than every Rust component) is not \
affected by a residual of this size.",
share = share(gap_ms),
)
} else {
format!(
"NOT a strict partition: residual_ms = {residual_ms:.6} is positive, i.e. the named \
components sum to MORE than the reported total_ms by {residual_ms:.6} ms \
({share:.2}% of total_ms). This is a SCOPE difference in the opposite direction (a \
component whose measurement scope reaches outside the window that total_ms covers, \
or a component measured twice relative to it), not a statement about the accuracy \
of total_ms, and it says nothing about the two windows overlapping: they are \
sequential (rapid_structure.rs:619-719 then :106-130). This ledger is a DIAGNOSTIC \
instrument, not acceptance evidence: every share is valid only to within \
{residual_ms:.6} ms ({share:.2}% of total_ms).",
share = share(residual_ms),
)
}
}
#[derive(Debug, Clone, Copy, PartialEq, Serialize, Deserialize)]
pub struct LedgerShares {
pub input_share: f64,
pub input_decode_share: f64,
pub input_resize_share: f64,
pub input_other_share: f64,
pub input_crop_share: f64,
pub model_preprocess_share: f64,
pub inference_share: f64,
pub detector_infer_share: f64,
pub classifier_infer_share: f64,
pub recognizer_infer_share: f64,
pub model_postprocess_share: f64,
pub detector_postprocess_share: f64,
pub classifier_postprocess_share: f64,
pub recognizer_postprocess_share: f64,
pub page_postprocess_share: f64,
pub formula_share: f64,
pub table_detect_share: f64,
pub table_structure_infer_share: f64,
pub table_backfill_share: f64,
pub rust_share: f64,
pub unattributed_share: f64,
}
#[cfg(test)]
mod tests {
use super::TimingLedger;
use crate::api::OcrTimings;
fn assert_stage_totals(timings: &OcrTimings) {
assert!(
(f64::from(timings.detector_preprocess_ms)
+ f64::from(timings.detector_infer_ms)
+ f64::from(timings.detector_postprocess_ms)
- f64::from(timings.detect_ms))
.abs()
< 1e-3,
"detector stage breakdown must sum to detect_ms"
);
assert!(
(f64::from(timings.classifier_preprocess_ms)
+ f64::from(timings.classifier_infer_ms)
+ f64::from(timings.classifier_postprocess_ms)
- f64::from(timings.classify_ms))
.abs()
< 1e-3,
"classifier stage breakdown must sum to classify_ms"
);
assert!(
(f64::from(timings.recognizer_preprocess_ms)
+ f64::from(timings.recognizer_infer_ms)
+ f64::from(timings.recognizer_postprocess_ms)
- f64::from(timings.recognize_ms))
.abs()
< 1e-3,
"recognizer stage breakdown must sum to recognize_ms"
);
assert!(
(f64::from(timings.preprocess_ms)
+ f64::from(timings.detect_ms)
+ f64::from(timings.classify_ms)
+ f64::from(timings.recognize_ms)
+ f64::from(timings.postprocess_ms)
+ f64::from(timings.formula_ms)
+ f64::from(timings.table_detect_ms)
+ f64::from(timings.table_structure_infer_ms)
+ f64::from(timings.table_backfill_ms)
- f64::from(timings.total_ms))
.abs()
< 1e-3,
"the page-level identity must hold: total = preprocess + det + cls + rec + postprocess \
(+ formula)"
);
}
#[test]
fn ledger_is_conserved_for_a_full_sample() {
let timings = OcrTimings {
decode_ms: 5.0,
resize_ms: 6.0,
crop_ms: 1.5,
preprocess_ms: 13.0,
detector_preprocess_ms: 3.0,
detector_infer_ms: 500.0,
detector_postprocess_ms: 20.0,
detect_ms: 523.0,
classifier_preprocess_ms: 1.0,
classifier_infer_ms: 2.0,
classifier_postprocess_ms: 0.5,
classify_ms: 3.5,
recognizer_preprocess_ms: 4.0,
recognizer_infer_ms: 280.0,
recognizer_postprocess_ms: 40.0,
recognize_ms: 324.0,
formula_ms: 0.0,
table_detect_ms: 0.0,
table_structure_infer_ms: 0.0,
table_backfill_ms: 0.0,
postprocess_ms: 7.0,
total_ms: 13.0 + 523.0 + 3.5 + 324.0 + 7.0,
};
assert_stage_totals(&timings);
let ledger = TimingLedger::from_timings(&timings);
assert_eq!(ledger.input_decode_ms, 5.0);
assert_eq!(ledger.input_resize_ms, 6.0);
assert_eq!(
ledger.input_other_ms, 0.5,
"the outer preprocess window minus decode/resize/crop is the unnamed remainder"
);
assert_eq!(ledger.input_crop_ms, 1.5);
assert_eq!(
ledger.input_named_within_ms, 12.5,
"all three named input parts fit inside the outer window budget (13.0 - 0.5 other)"
);
assert_eq!(
ledger.input_overflow_ms, 0.0,
"nothing overflows the outer window in this sample"
);
assert_eq!(
ledger.input_ms(),
13.0,
"input_ms is exactly preprocess_ms (the named three + the unnamed remainder)"
);
assert!(
ledger.input_ms() <= ledger.input_preprocess_ms,
"the input invariant must hold by construction: {} <= {}",
ledger.input_ms(),
ledger.input_preprocess_ms
);
assert_eq!(ledger.model_preprocess_ms(), 3.0 + 1.0 + 4.0);
assert_eq!(ledger.model_postprocess_ms(), 20.0 + 0.5 + 40.0);
assert_eq!(ledger.inference_ms(), 500.0 + 2.0 + 280.0);
assert_eq!(
ledger.rust_ms(),
13.0 + 8.0 + 60.5 + 7.0,
"rust = input + model preprocess + model postprocess + page postprocess"
);
assert_eq!(ledger.unattributed_ms, 0.0);
let conservation = ledger.conservation();
assert!(
conservation.conserved,
"the ledger must be conserved: {conservation:?}"
);
assert!(conservation.residual_ms.abs() < 1e-9);
let shares = ledger.shares().expect("a positive total has shares");
assert!(
(shares.rust_share + shares.inference_share - 1.0).abs() < 1e-9,
"in this synthetic sample the ledger accounts for the whole total"
);
}
#[test]
fn real_world_outer_window_does_not_conserve_the_reported_total() {
let timings = OcrTimings {
decode_ms: 0.0042,
resize_ms: 74.3112,
crop_ms: 20.1184,
preprocess_ms: 380.23,
detector_preprocess_ms: 37.0154,
detector_infer_ms: 413.5526,
detector_postprocess_ms: 28.2756,
detect_ms: 478.9129,
classifier_preprocess_ms: 0.0,
classifier_infer_ms: 0.0,
classifier_postprocess_ms: 0.0,
classify_ms: 0.0,
recognizer_preprocess_ms: 42.3413,
recognizer_infer_ms: 340.9351,
recognizer_postprocess_ms: 437.192,
recognize_ms: 825.0736,
formula_ms: 0.0,
table_detect_ms: 0.0,
table_structure_infer_ms: 0.0,
table_backfill_ms: 0.0,
postprocess_ms: 0.0716,
total_ms: 1779.9879,
};
let detector_sum = f64::from(timings.detector_preprocess_ms)
+ f64::from(timings.detector_infer_ms)
+ f64::from(timings.detector_postprocess_ms);
assert!(
(detector_sum - f64::from(timings.detect_ms)).abs() < 0.1,
"the real sample's stage breakdown is close but not exact: {detector_sum} vs {}",
timings.detect_ms
);
let ledger = TimingLedger::from_timings(&timings);
let conservation = ledger.conservation();
assert!(
!conservation.conserved,
"the outer window and the stage timings do not compose into total_ms: {conservation:?}"
);
assert!(
conservation.residual_ms < -50.0,
"the residual must be reported with its real magnitude, got {}",
conservation.residual_ms
);
assert!(
(conservation.residual_ms + ledger.unattributed_ms).abs() < 1e-4,
"residual and unattributed must agree: {conservation:?} vs {}",
ledger.unattributed_ms
);
assert!(
(conservation.excess_ms + conservation.residual_ms).abs() < 1e-9,
"a negative residual means the named parts sit inside the total window, so excess_ms \
must be |residual|: {conservation:?}"
);
assert!(
conservation.excess_ms > 50.0,
"this sample's scope residual must keep its real magnitude: {conservation:?}"
);
let text = &conservation.interpretation;
for needle in [
"NOT a strict partition",
"SCOPE difference",
"DIAGNOSTIC instrument, not acceptance evidence",
"valid only to within",
"unaffected",
] {
assert!(
text.contains(needle),
"the interpretation must state `{needle}` so `conserved = false` cannot be \
mistaken for a wrong total: {text}"
);
}
assert!(
text.contains(&format!("residual_ms = {:.6}", conservation.residual_ms)),
"the interpretation must quote the actual residual: {text}"
);
}
#[test]
fn interpretation_states_sequential_windows_and_never_claims_overlap() {
let mut ledger = TimingLedger {
total_ms: 1000.0,
input_preprocess_ms: 80.0,
input_named_within_ms: 8.0,
detector_infer_ms: 900.0,
..TimingLedger::default()
};
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
let conservation = ledger.conservation();
assert!(!conservation.conserved, "{conservation:?}");
assert_eq!(conservation.residual_ms, -92.0);
assert_eq!(conservation.excess_ms, 92.0);
assert_eq!(
ledger.unattributed_ms, 92.0,
"unattributed_ms is the opposite sign of residual_ms"
);
let text = &conservation.interpretation;
for needle in [
"residual_ms = -92.000000",
"the named components sum to 92.000000 ms",
"SEQUENTIAL and do not overlap",
"rapid_structure.rs:619 to :719",
"rapid_structure.rs:106 to :130",
"rapid_structure.rs:910",
"No wall-clock interval is therefore counted twice",
"SCOPE difference",
"prepare_image",
"apply_vertical_padding",
"crop_text_regions",
"recognizer.rs:89-98",
"DIAGNOSTIC instrument, not acceptance evidence",
"valid only to within 92.000000 ms",
"9.20% of total_ms",
] {
assert!(
text.contains(needle),
"the interpretation must state `{needle}`: {text}"
);
}
for forbidden in [
"windows overlap",
"the same wall-clock interval is counted in two",
"is duplicated",
"cross the inner run() boundary",
] {
assert!(
!text.contains(forbidden),
"the interpretation must NOT claim `{forbidden}` (the windows are sequential): \
{text}"
);
}
}
#[test]
fn positive_residual_is_explained_as_a_different_direction() {
let mut ledger = TimingLedger {
total_ms: 100.0,
detector_infer_ms: 110.0,
..TimingLedger::default()
};
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
let conservation = ledger.conservation();
assert_eq!(conservation.residual_ms, 10.0);
assert!(!conservation.conserved);
assert_eq!(
conservation.excess_ms, 0.0,
"excess_ms is max(0, -residual), so a positive residual reports 0.0"
);
assert!(
conservation.interpretation.contains("is positive"),
"unexpected interpretation: {}",
conservation.interpretation
);
assert!(
conservation
.interpretation
.contains("sum to MORE than the reported total_ms by 10.000000 ms"),
"a positive residual must state its direction and magnitude: {}",
conservation.interpretation
);
assert!(
!conservation
.interpretation
.contains("the same wall-clock interval is counted in two"),
"a positive residual must not be described as overlapping windows: {}",
conservation.interpretation
);
assert!(
conservation
.interpretation
.contains("they are sequential (rapid_structure.rs:619-719 then :106-130)"),
"a positive residual must still cite the sequential window relationship: {}",
conservation.interpretation
);
}
#[test]
fn input_overflow_keeps_the_input_invariant_by_construction() {
let timings = OcrTimings {
decode_ms: 2.0,
resize_ms: 7.0,
crop_ms: 3.0,
preprocess_ms: 5.0,
detector_preprocess_ms: 1.0,
detector_infer_ms: 10.0,
detector_postprocess_ms: 1.0,
detect_ms: 12.0,
classifier_preprocess_ms: 0.0,
classifier_infer_ms: 0.0,
classifier_postprocess_ms: 0.0,
classify_ms: 0.0,
recognizer_preprocess_ms: 1.0,
recognizer_infer_ms: 20.0,
recognizer_postprocess_ms: 2.0,
recognize_ms: 23.0,
formula_ms: 0.0,
table_detect_ms: 0.0,
table_structure_infer_ms: 0.0,
table_backfill_ms: 0.0,
postprocess_ms: 3.0,
total_ms: 5.0 + 12.0 + 0.0 + 23.0 + 3.0,
};
let ledger = TimingLedger::from_timings(&timings);
assert_eq!(
ledger.input_other_ms, 0.0,
"when the named three exceed the window there is no unnamed remainder"
);
assert_eq!(
ledger.input_overflow_ms, 7.0,
"the 7 ms of named input time outside the outer window must be explicit"
);
assert_eq!(
ledger.input_named_within_ms, 5.0,
"only the part the outer window covers is counted as input"
);
assert_eq!(
ledger.input_ms(),
5.0,
"input_ms is clipped to the outer window: decode + resize + crop - overflow"
);
assert!(
ledger.input_ms() <= ledger.input_preprocess_ms,
"the input invariant must hold by construction even in the overflow branch: \
{} <= {}",
ledger.input_ms(),
ledger.input_preprocess_ms
);
assert!(
ledger.input_decode_ms + ledger.input_resize_ms + ledger.input_crop_ms
> ledger.input_preprocess_ms,
"this sample must really exercise the overflow branch"
);
let raw_named = ledger.input_decode_ms + ledger.input_resize_ms + ledger.input_crop_ms;
let conservation = ledger.conservation();
assert_eq!(
conservation.residual_ms, ledger.input_overflow_ms,
"the overflow is the only scope difference in this sample, and it makes the named \
parts sum to MORE than total_ms: {conservation:?}"
);
assert_eq!(
conservation.residual_ms,
raw_named
+ ledger.detector_preprocess_ms
+ ledger.detector_infer_ms
+ ledger.detector_postprocess_ms
+ ledger.recognizer_preprocess_ms
+ ledger.recognizer_infer_ms
+ ledger.recognizer_postprocess_ms
+ ledger.page_postprocess_ms
- ledger.total_ms,
"the raw named parts (including the overflow) must reconcile to total_ms"
);
assert!(
!conservation.conserved,
"a 7 ms scope difference must fail the conservation check"
);
assert_eq!(
conservation.excess_ms, 0.0,
"a positive residual reports excess_ms = 0.0 (the opposite direction)"
);
assert!(
conservation
.interpretation
.contains("SCOPE difference in the opposite direction"),
"the overflow must be read as a scope difference in the opposite direction: {}",
conservation.interpretation
);
assert!(
conservation
.interpretation
.contains("they are sequential (rapid_structure.rs:619-719 then :106-130)"),
"the overflow interpretation must still cite the sequential relationship: {}",
conservation.interpretation
);
let shares = ledger.shares().expect("shares");
assert!(
(shares.rust_share * ledger.total_ms + shares.inference_share * ledger.total_ms
- (ledger.attributed_ms() - ledger.input_overflow_ms))
.abs()
< 1e-9,
"rust_ms + inference_ms must equal attributed_ms minus the input overflow, because \
rust_ms uses the clipped input_ms while attributed_ms keeps the raw input parts"
);
assert!(
(ledger.rust_ms() + ledger.inference_ms() - ledger.attributed_ms()
+ ledger.input_overflow_ms)
.abs()
< 1e-9,
"the only difference between rust + inference and attributed must be the overflow"
);
}
#[test]
fn documented_input_formula_holds_in_both_branches() {
let fits = OcrTimings {
decode_ms: 4.0,
resize_ms: 5.0,
crop_ms: 1.0,
preprocess_ms: 12.0,
..OcrTimings::default()
};
let overflows = OcrTimings {
decode_ms: 2.0,
resize_ms: 7.0,
crop_ms: 3.0,
preprocess_ms: 5.0,
..OcrTimings::default()
};
let fits_ledger = TimingLedger::from_timings(&fits);
let overflow_ledger = TimingLedger::from_timings(&overflows);
assert_eq!(
fits_ledger.input_overflow_ms, 0.0,
"branch 1 must not overflow: {fits_ledger:?}"
);
assert_eq!(
overflow_ledger.input_overflow_ms, 7.0,
"branch 2 must overflow: {overflow_ledger:?}"
);
for ledger in [fits_ledger, overflow_ledger] {
let raw = ledger.input_decode_ms + ledger.input_resize_ms + ledger.input_crop_ms;
assert!(
(ledger.input_named_within_ms + ledger.input_other_ms - ledger.input_ms()).abs()
< 1e-9,
"the documented definition must hold: input_named_within + input_other == \
input_ms(), got {ledger:?}"
);
assert!(
(raw - (ledger.input_named_within_ms + ledger.input_overflow_ms)).abs() < 1e-9,
"the three raw input fields must reconcile to input_named_within_ms + \
input_overflow_ms, got {ledger:?}"
);
assert!(
ledger.input_ms() <= ledger.input_preprocess_ms,
"the input invariant must hold by construction: {} <= {}, got {ledger:?}",
ledger.input_ms(),
ledger.input_preprocess_ms
);
}
let raw_fits =
fits_ledger.input_decode_ms + fits_ledger.input_resize_ms + fits_ledger.input_crop_ms;
assert!(
(raw_fits + fits_ledger.input_other_ms - fits_ledger.input_ms()).abs() < 1e-9,
"without overflow the retracted formula is equivalent to the definition"
);
let raw_overflow = overflow_ledger.input_decode_ms
+ overflow_ledger.input_resize_ms
+ overflow_ledger.input_crop_ms;
assert!(
(raw_overflow + overflow_ledger.input_other_ms - overflow_ledger.input_ms()).abs()
> 1.0,
"with overflow the retracted formula must be false, otherwise this test would not \
pin the documented change: {overflow_ledger:?}"
);
}
#[test]
fn ledger_is_conserved_when_a_stage_is_disabled() {
let timings = OcrTimings {
decode_ms: 5.0,
resize_ms: 6.0,
crop_ms: 0.0,
preprocess_ms: 11.0,
detector_preprocess_ms: 3.0,
detector_infer_ms: 500.0,
detector_postprocess_ms: 20.0,
detect_ms: 523.0,
classifier_preprocess_ms: 0.0,
classifier_infer_ms: 0.0,
classifier_postprocess_ms: 0.0,
classify_ms: 0.0,
recognizer_preprocess_ms: 4.0,
recognizer_infer_ms: 280.0,
recognizer_postprocess_ms: 40.0,
recognize_ms: 324.0,
formula_ms: 0.0,
table_detect_ms: 0.0,
table_structure_infer_ms: 0.0,
table_backfill_ms: 0.0,
postprocess_ms: 7.0,
total_ms: 11.0 + 523.0 + 0.0 + 324.0 + 7.0,
};
assert_stage_totals(&timings);
let ledger = TimingLedger::from_timings(&timings);
assert_eq!(ledger.classifier_preprocess_ms, 0.0);
assert_eq!(ledger.classifier_infer_ms, 0.0);
assert_eq!(ledger.classifier_postprocess_ms, 0.0);
assert_eq!(ledger.input_other_ms, 0.0);
assert_eq!(ledger.input_ms(), 11.0);
assert_eq!(ledger.inference_ms(), 780.0);
assert!(ledger.unattributed_ms.abs() < 1e-9, "{ledger:?}");
assert!(
ledger.conservation().conserved,
"a disabled stage must not break conservation"
);
}
#[test]
fn ledger_accounts_for_formula_routing() {
let timings = OcrTimings {
decode_ms: 1.0,
resize_ms: 2.0,
crop_ms: 0.5,
preprocess_ms: 4.0,
detector_preprocess_ms: 1.0,
detector_infer_ms: 10.0,
detector_postprocess_ms: 1.0,
detect_ms: 12.0,
classifier_preprocess_ms: 0.0,
classifier_infer_ms: 0.0,
classifier_postprocess_ms: 0.0,
classify_ms: 0.0,
recognizer_preprocess_ms: 1.0,
recognizer_infer_ms: 20.0,
recognizer_postprocess_ms: 2.0,
recognize_ms: 23.0,
formula_ms: 50.0,
table_detect_ms: 0.0,
table_structure_infer_ms: 0.0,
table_backfill_ms: 0.0,
postprocess_ms: 3.0,
total_ms: 4.0 + 12.0 + 0.0 + 23.0 + 3.0 + 50.0,
};
assert_stage_totals(&timings);
let ledger = TimingLedger::from_timings(&timings);
assert_eq!(ledger.formula_ms, 50.0);
assert_eq!(ledger.input_other_ms, 0.5);
assert_eq!(ledger.unattributed_ms, 0.0);
assert!(ledger.conservation().conserved);
let shares = ledger.shares().expect("shares");
assert!(shares.formula_share > 0.5, "formula must dominate here");
}
#[test]
fn ledger_accounts_for_the_table_stage() {
let timings = OcrTimings {
decode_ms: 1.0,
resize_ms: 2.0,
crop_ms: 0.5,
preprocess_ms: 4.0,
detector_preprocess_ms: 1.0,
detector_infer_ms: 10.0,
detector_postprocess_ms: 1.0,
detect_ms: 12.0,
classifier_preprocess_ms: 0.0,
classifier_infer_ms: 0.0,
classifier_postprocess_ms: 0.0,
classify_ms: 0.0,
recognizer_preprocess_ms: 1.0,
recognizer_infer_ms: 20.0,
recognizer_postprocess_ms: 2.0,
recognize_ms: 23.0,
formula_ms: 0.0,
table_detect_ms: 5.0,
table_structure_infer_ms: 40.0,
table_backfill_ms: 3.0,
postprocess_ms: 2.0,
total_ms: 4.0 + 12.0 + 0.0 + 23.0 + 2.0 + 5.0 + 40.0 + 3.0,
};
assert_stage_totals(&timings);
let ledger = TimingLedger::from_timings(&timings);
assert_eq!(ledger.table_detect_ms, 5.0);
assert_eq!(ledger.table_structure_infer_ms, 40.0);
assert_eq!(ledger.table_backfill_ms, 3.0);
assert_eq!(ledger.inference_ms(), 70.0);
assert_eq!(ledger.rust_ms(), 19.0);
assert!(
ledger.unattributed_ms.abs() < 1e-9,
"table components must stay named, not fall into the residual: {ledger:?}"
);
let conservation = ledger.conservation();
assert!(conservation.conserved, "{conservation:?}");
assert!(
(ledger.rust_ms()
+ ledger.inference_ms()
+ ledger.input_overflow_ms
+ ledger.unattributed_ms
- ledger.total_ms)
.abs()
< 1e-9,
"the timing_split identity must survive the table components: {ledger:?}"
);
let shares = ledger.shares().expect("shares");
assert!(shares.table_structure_infer_share > 0.0);
assert!(shares.table_detect_share > 0.0);
assert!(shares.table_backfill_share > 0.0);
assert_eq!(shares.formula_share, 0.0);
}
#[test]
fn ledger_exposes_the_residual_instead_of_hiding_it() {
let mut ledger = TimingLedger {
total_ms: 100.0,
detector_infer_ms: 90.0,
..TimingLedger::default()
};
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
let conservation = ledger.conservation();
assert_eq!(conservation.residual_ms, -10.0);
assert_eq!(
conservation.excess_ms, 10.0,
"the residual magnitude is what the shares are valid to within"
);
assert!(
!conservation.conserved,
"a 10 ms difference must fail the conservation check"
);
ledger.input_decode_ms = 10.0;
ledger.input_named_within_ms = 10.0;
ledger.input_preprocess_ms = 10.0;
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
assert_eq!(ledger.unattributed_ms, 0.0);
let conserved = ledger.conservation();
assert!(conserved.conserved);
assert_eq!(conserved.excess_ms, 0.0);
assert_eq!(ledger.input_overflow_ms, 0.0);
assert!(ledger.input_ms() <= ledger.input_preprocess_ms);
assert!(
conserved.interpretation.contains("strict partition"),
"a conserved ledger must say so: {}",
conserved.interpretation
);
}
#[test]
fn mean_ledger_is_conserved() {
let sample = |infer: f64, decode: f64| {
let mut ledger = TimingLedger {
total_ms: decode + infer,
detector_infer_ms: infer,
input_decode_ms: decode,
input_preprocess_ms: decode,
input_named_within_ms: decode,
..TimingLedger::default()
};
ledger.unattributed_ms = ledger.total_ms - ledger.attributed_ms();
ledger
};
let ledgers = vec![sample(90.0, 10.0), sample(150.0, 50.0), sample(210.0, 90.0)];
let mean = TimingLedger::mean(&ledgers);
assert!((mean.total_ms - 200.0).abs() < 1e-9);
assert!((mean.detector_infer_ms - 150.0).abs() < 1e-9);
assert!((mean.input_decode_ms - 50.0).abs() < 1e-9);
assert!((mean.input_named_within_ms - 50.0).abs() < 1e-9);
assert!((mean.input_overflow_ms - 0.0).abs() < 1e-9);
assert!((mean.input_ms() - 50.0).abs() < 1e-9);
assert!(
mean.input_ms() <= mean.input_preprocess_ms,
"the mean ledger must keep the input invariant: {} <= {}",
mean.input_ms(),
mean.input_preprocess_ms
);
assert!(
mean.conservation().conserved,
"the mean of conserved ledgers must be conserved: {:?}",
mean.conservation()
);
}
#[test]
fn mean_of_nothing_is_zero() {
let mean = TimingLedger::mean(&[]);
assert_eq!(mean, TimingLedger::default());
assert!(mean.shares().is_none());
}
}
#[cfg(test)]
mod baseline_schema_tests {
use std::{fs, path::PathBuf};
#[test]
fn committed_provider_reports_are_schema_labelled() {
let dir = PathBuf::from(env!("CARGO_MANIFEST_DIR")).join("tests/baseline/windows-baseline");
if !dir.is_dir() {
eprintln!(
"skipping committed provider-report audit: benchmark evidence is not packaged"
);
return;
}
let mut checked = 0usize;
let mut unlabelled: Vec<String> = Vec::new();
for entry in fs::read_dir(&dir).expect("baseline directory must exist") {
let path = entry.expect("readable directory entry").path();
if path.extension().and_then(|ext| ext.to_str()) != Some("json") {
continue;
}
let text = fs::read_to_string(&path).expect("baseline report must be readable UTF-8");
let value: serde_json::Value = match serde_json::from_str(&text) {
Ok(value) => value,
Err(error) => panic!("{} is not valid JSON: {error}", path.display()),
};
let Some(split) = value.get("timing_split") else {
continue;
};
checked += 1;
let current =
split.get("identity").is_some() && split.get("identity_residual_ms").is_some();
if current {
continue;
}
let historical = value.get("historical").and_then(|v| v.as_bool()) == Some(true)
&& value
.get("timing_split_schema")
.and_then(|v| v.as_u64())
.is_some();
if !historical {
unlabelled.push(path.file_name().unwrap().to_string_lossy().into_owned());
}
}
assert!(
checked > 0,
"no committed report carried a timing_split section, so this scan proves nothing"
);
assert!(
unlabelled.is_empty(),
"these committed reports carry an unlabelled pre-identity timing_split: {unlabelled:?}; \
regenerate them or mark them historical (historical: true + timing_split_schema)"
);
}
}