1use crate::metrics::{MacroStageId, MetricId};
26use crate::schema::{RunState, StateMeasurement};
27use crate::schema_v2::{
28 CacheEffectivenessV2, CausalProfileV2, Evidence, QueueDepthV2, RetryRecordV2,
29};
30use serde::{Deserialize, Serialize};
31
32pub const RUN_INSIGHT_V2_VERSION: u16 = 1;
33
34const SERIAL_CONCURRENCY_MILLI: u64 = 1_500;
36const MATERIAL_SHARE_PPM: u64 = 50_000;
38const SERIAL_REPORT_SHARE_PPM: u64 = 10_000;
40const AMPLIFICATION_FLOOR_BYTES: u64 = 1024 * 1024;
42const SERIAL_FLOOR_MILLI: u64 = 700;
45const SERIAL_EXCLUSIVITY_PPM: u64 = 600_000;
48const MEMORY_FLOOR_BYTES: u64 = 64 * 1024 * 1024;
50const AMPLIFICATION_MILLI: u64 = 2_000;
52
53fn ppm(part: u64, whole: u64) -> u64 {
54 if whole == 0 {
55 return 0;
56 }
57 u64::try_from((u128::from(part) * 1_000_000) / u128::from(whole)).unwrap_or(u64::MAX)
58}
59
60fn milli(part: u64, whole: u64) -> u64 {
61 if whole == 0 {
62 return 0;
63 }
64 u64::try_from((u128::from(part) * 1_000) / u128::from(whole)).unwrap_or(u64::MAX)
65}
66
67fn per_second_milli(count: u64, elapsed_ns: u64) -> u64 {
68 if elapsed_ns == 0 {
69 return 0;
70 }
71 u64::try_from((u128::from(count) * 1_000_000_000_000) / u128::from(elapsed_ns))
72 .unwrap_or(u64::MAX)
73}
74
75fn mib_per_second_milli(bytes: u64, elapsed_ns: u64) -> u64 {
76 if elapsed_ns == 0 {
77 return 0;
78 }
79 u64::try_from((u128::from(bytes) * 1_000_000_000_000) / (u128::from(elapsed_ns) * 1_048_576))
80 .unwrap_or(u64::MAX)
81}
82
83fn format_bytes(bytes: u64) -> String {
84 const UNITS: [(&str, u64); 4] = [
85 ("GiB", 1024 * 1024 * 1024),
86 ("MiB", 1024 * 1024),
87 ("KiB", 1024),
88 ("B", 1),
89 ];
90 for (label, scale) in UNITS {
91 if bytes >= scale {
92 return format!("{:.1} {label}", bytes as f64 / scale as f64);
93 }
94 }
95 format!("{bytes} B")
96}
97
98fn format_ms(nanoseconds: u64) -> String {
99 format!("{:.3} ms", nanoseconds as f64 / 1_000_000.0)
100}
101
102fn format_ratio(value_milli: u64) -> String {
103 format!("{:.2}x", value_milli as f64 / 1_000.0)
104}
105
106fn format_percent_ppm(value_ppm: u64) -> String {
107 format!("{:.1}%", value_ppm as f64 / 10_000.0)
108}
109
110#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize, Deserialize)]
112#[serde(rename_all = "kebab-case")]
113pub enum BottleneckKindV2 {
114 SerialPhase,
116 ParallelStarvation,
118 QueueStarvation,
120 StageBound,
122 MemoryFloor,
124 MemoryAmplification,
126 CacheMiss,
128 RetriedWork,
130 FixedOverhead,
132 Insufficient,
134}
135
136impl BottleneckKindV2 {
137 pub const fn as_str(self) -> &'static str {
138 match self {
139 Self::SerialPhase => "serial-phase",
140 Self::ParallelStarvation => "parallel-starvation",
141 Self::QueueStarvation => "queue-starvation",
142 Self::StageBound => "stage-bound",
143 Self::MemoryFloor => "memory-floor",
144 Self::MemoryAmplification => "memory-amplification",
145 Self::CacheMiss => "cache-miss",
146 Self::RetriedWork => "retried-work",
147 Self::FixedOverhead => "fixed-overhead",
148 Self::Insufficient => "insufficient-evidence",
149 }
150 }
151}
152
153#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
155pub struct FindingV2 {
156 pub version: u16,
157 pub kind: BottleneckKindV2,
158 pub severity: u8,
160 pub impact_ns: u64,
162 pub impact_share_ppm: u64,
163 pub subject: String,
165 pub statement: String,
167}
168
169#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
171pub struct PhaseInsightV2 {
172 pub version: u16,
173 pub state: RunState,
174 pub wall_ns: u64,
175 pub share_ppm: u64,
176 pub cpu_ns: u64,
177 pub speedup_milli: u64,
179 pub serial: bool,
181 pub mib_per_second_milli: u64,
182 pub units_per_second_milli: u64,
183 pub resident_start_bytes: u64,
184 pub resident_end_bytes: u64,
185 pub threads_start: u64,
186 pub threads_end: u64,
187}
188
189#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
191pub struct ThroughputInsightV2 {
192 pub version: u16,
193 pub wall_ns: u64,
194 pub input_bytes: u64,
195 pub input_units: u64,
196 pub mib_per_second_milli: u64,
198 pub units_per_second_milli: u64,
200 pub ns_per_unit: u64,
201 pub ns_per_byte_milli: u64,
203 pub cpu_ns_per_byte_milli: u64,
205 pub phases: Vec<PhaseInsightV2>,
206}
207
208#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
210pub struct StageMemoryV2 {
211 pub version: u16,
212 pub metric_id: Option<MetricId>,
214 pub allocations: u64,
215 pub allocated_bytes: u64,
216 pub live_bytes: u64,
217 pub peak_live_bytes: u64,
218}
219
220#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
222pub struct MemoryInsightV2 {
223 pub version: u16,
224 pub peak_resident_bytes: u64,
226 pub peak_source: String,
228 pub baseline_resident_bytes: u64,
230 pub engine_init_resident_bytes: u64,
232 pub input_driven_resident_bytes: u64,
234 pub input_bytes: u64,
235 pub amplification_milli: u64,
237 pub scanner_threads: u64,
238 pub resident_per_scanner_thread_bytes: u64,
241 pub input_driven_per_scanner_thread_bytes: u64,
243 pub allocations: u64,
244 pub allocated_bytes: u64,
245 pub deallocated_bytes: u64,
246 pub allocation_peak_live_bytes: u64,
247 pub allocated_per_input_byte_milli: u64,
249 pub stages: Vec<StageMemoryV2>,
251}
252
253#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
255pub struct ParallelismInsightV2 {
256 pub version: u16,
257 pub logical_cpus: u64,
258 pub scanner_threads: u64,
259 pub wall_ns: u64,
260 pub process_cpu_ns: u64,
261 pub achieved_speedup_milli: u64,
263 pub parallel_efficiency_ppm: u64,
265 pub speedup_ceiling_milli: u64,
267 pub worker_count: u64,
268 pub active_worker_count: u64,
269 pub instrumented_busy_ns: u64,
271 pub instrumented_blocked_ns: u64,
273 pub worker_capacity_ns: u64,
275 pub idle_ns: u64,
276 pub idle_share_ppm: u64,
277 pub busiest_busy_ns: u64,
278 pub median_busy_ns: u64,
279 pub imbalance_ppm: u64,
281 pub busy_off_cpu_ns: u64,
285 pub source_blocked_ns: u64,
286 pub scanner_blocked_ns: u64,
287 pub queues: Vec<QueueDepthV2>,
288}
289
290#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize, Deserialize)]
292#[serde(rename_all = "kebab-case")]
293pub enum SerialScopeV2 {
294 Phase,
296 Stage,
298}
299
300#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
302pub struct SerialRegionV2 {
303 pub version: u16,
304 pub scope: SerialScopeV2,
305 pub subject: String,
306 pub wall_ns: u64,
307 pub share_ppm: u64,
308 pub concurrency_milli: u64,
310 pub worker_count: u64,
311 pub exclusivity_ppm: u64,
315 pub declared: bool,
317}
318
319#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
321pub struct StageAttributionV2 {
322 pub version: u16,
323 pub metric_id: MetricId,
324 pub macro_stage_id: MacroStageId,
325 pub calls: u64,
326 pub elapsed_ns: u64,
327 pub share_of_recorded_ppm: u64,
328 pub ns_per_call: u64,
329 pub ns_per_input_unit: u64,
330 pub ns_per_input_byte_milli: u64,
332 pub bytes: u64,
334 pub mib_per_second_milli: u64,
335 pub concurrency_milli: u64,
336 pub worker_count: u64,
337}
338
339#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
341pub struct BackendAttributionV2 {
342 pub version: u16,
343 pub backend: String,
344 pub batches: u64,
345 pub recovered_batches: u64,
346 pub share_ppm: u64,
347}
348
349#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
351pub struct InsightCoverageV2 {
352 pub version: u16,
353 pub process_metrics: bool,
354 pub allocation_tracking: bool,
355 pub stage_concurrency: bool,
356 pub worker_occupancy: bool,
357 pub dropped_span_events: u64,
358 pub notes: Vec<String>,
360}
361
362#[derive(Clone, Debug, Eq, PartialEq, Serialize, Deserialize)]
364pub struct RunInsightV2 {
365 pub version: u16,
366 pub findings: Vec<FindingV2>,
368 pub throughput: ThroughputInsightV2,
369 pub memory: MemoryInsightV2,
370 pub parallelism: ParallelismInsightV2,
371 pub serial_regions: Vec<SerialRegionV2>,
372 pub stages: Vec<StageAttributionV2>,
374 pub backends: Vec<BackendAttributionV2>,
375 pub caches: Vec<CacheEffectivenessV2>,
376 pub retries: Vec<RetryRecordV2>,
377 pub coverage: InsightCoverageV2,
378}
379
380impl RunInsightV2 {
381 pub fn derive(profile: &CausalProfileV2) -> Self {
383 let wall_ns = profile.wall_time_ns;
384 let identity = &profile.identity;
385 let input_bytes = identity.workload.raw_source_bytes;
386 let input_units = identity.workload.source_units;
387 let logical_cpus = u64::from(identity.host.logical_cpus);
388 let scanner_threads = u64::try_from(identity.scanner_threads_requested).unwrap_or(0);
389
390 let process_cpu_ns = process_cpu_ns(profile);
391 let phases = derive_phases(profile, wall_ns, input_bytes, input_units);
392 let memory = derive_memory(profile, input_bytes, scanner_threads.max(1));
393 let (serial_regions, serial_wall_ns) = derive_serial(profile, &phases, wall_ns);
394 let parallelism = derive_parallelism(
395 profile,
396 wall_ns,
397 process_cpu_ns,
398 logical_cpus,
399 scanner_threads,
400 serial_wall_ns,
401 );
402 let stages = derive_stages(profile, input_bytes, input_units);
403 let backends = derive_backends(profile);
404 let coverage = derive_coverage(profile, &memory, ¶llelism);
405
406 let throughput = ThroughputInsightV2 {
407 version: RUN_INSIGHT_V2_VERSION,
408 wall_ns,
409 input_bytes,
410 input_units,
411 mib_per_second_milli: mib_per_second_milli(input_bytes, wall_ns),
412 units_per_second_milli: per_second_milli(input_units, wall_ns),
413 ns_per_unit: if input_units == 0 {
414 0
415 } else {
416 wall_ns / input_units
417 },
418 ns_per_byte_milli: milli(wall_ns, input_bytes),
419 cpu_ns_per_byte_milli: milli(process_cpu_ns, input_bytes),
420 phases,
421 };
422
423 let findings = rank_findings(
424 wall_ns,
425 &throughput,
426 &memory,
427 ¶llelism,
428 &serial_regions,
429 &stages,
430 &profile.caches,
431 &profile.retries,
432 );
433
434 Self {
435 version: RUN_INSIGHT_V2_VERSION,
436 findings,
437 throughput,
438 memory,
439 parallelism,
440 serial_regions,
441 stages,
442 backends,
443 caches: profile.caches.clone(),
444 retries: profile.retries.clone(),
445 coverage,
446 }
447 }
448
449 pub fn bottleneck(&self) -> &FindingV2 {
451 self.findings.first().expect("findings is never empty")
452 }
453
454 pub fn render_summary(&self) -> String {
459 let mut out = String::with_capacity(2_048);
460 let bottleneck = self.bottleneck();
461 out.push_str(&format!(
462 "bottleneck {} {}\n",
463 bottleneck.kind.as_str(),
464 bottleneck.statement
465 ));
466 for finding in self.findings.iter().skip(1) {
467 out.push_str(&format!(
468 " also {} {}\n",
469 finding.kind.as_str(),
470 finding.statement
471 ));
472 }
473
474 let throughput = &self.throughput;
475 let small_input = throughput.input_bytes < AMPLIFICATION_FLOOR_BYTES;
478 let per_mib = if small_input {
479 "n/a (input below 1 MiB)".to_owned()
480 } else {
481 format_ms(throughput.ns_per_byte_milli * 1_048_576 / 1_000)
482 };
483 out.push_str(&format!(
484 "throughput wall={} input={} units={} rate={:.2} MiB/s files_per_s={:.1} per_file={} per_MiB={per_mib}\n",
485 format_ms(throughput.wall_ns),
486 format_bytes(throughput.input_bytes),
487 throughput.input_units,
488 throughput.mib_per_second_milli as f64 / 1_000.0,
489 throughput.units_per_second_milli as f64 / 1_000.0,
490 format_ms(throughput.ns_per_unit),
491 ));
492
493 for phase in &throughput.phases {
494 out.push_str(&format!(
495 " phase {:<10} wall={:>12} share={:>6} cpu={:>8} rss={:>10} -> {:<10} threads={}->{}{}\n",
496 phase_name(phase.state),
497 format_ms(phase.wall_ns),
498 format_percent_ppm(phase.share_ppm),
499 format_ratio(phase.speedup_milli),
500 format_bytes(phase.resident_start_bytes),
501 format_bytes(phase.resident_end_bytes),
502 phase.threads_start,
503 phase.threads_end,
504 if phase.serial { " SERIAL" } else { "" },
505 ));
506 }
507
508 let memory = &self.memory;
509 let amplification = if small_input {
510 "n/a (input below 1 MiB)".to_owned()
511 } else {
512 format_ratio(memory.amplification_milli)
513 };
514 out.push_str(&format!(
515 "memory peak={} ({}) engine_init_floor={} input_driven={} amplification={amplification} per_scanner_thread={} threads={}\n",
516 format_bytes(memory.peak_resident_bytes),
517 memory.peak_source,
518 format_bytes(memory.engine_init_resident_bytes),
519 format_bytes(memory.input_driven_resident_bytes),
520 format_bytes(memory.resident_per_scanner_thread_bytes),
521 memory.scanner_threads,
522 ));
523 if memory.allocated_bytes != 0 {
524 out.push_str(&format!(
525 " allocator allocations={} allocated={} freed={} peak_live={} per_input_byte={}\n",
526 memory.allocations,
527 format_bytes(memory.allocated_bytes),
528 format_bytes(memory.deallocated_bytes),
529 format_bytes(memory.allocation_peak_live_bytes),
530 format_ratio(memory.allocated_per_input_byte_milli),
531 ));
532 }
533 for stage in memory.stages.iter().take(5) {
534 out.push_str(&format!(
535 " owns {:<24} allocated={:>10} peak_live={:>10} allocations={}\n",
536 stage
537 .metric_id
538 .map_or("outside-any-span", crate::MetricId::as_str),
539 format_bytes(stage.allocated_bytes),
540 format_bytes(stage.peak_live_bytes),
541 stage.allocations,
542 ));
543 }
544
545 let parallel = &self.parallelism;
546 out.push_str(&format!(
547 "parallelism achieved={} of {} cpus (efficiency={}) ceiling={} workers={}/{} busy={} blocked={} idle={} ({})\n",
548 format_ratio(parallel.achieved_speedup_milli),
549 parallel.logical_cpus,
550 format_percent_ppm(parallel.parallel_efficiency_ppm),
551 format_ratio(parallel.speedup_ceiling_milli),
552 parallel.active_worker_count,
553 parallel.worker_count,
554 format_ms(parallel.instrumented_busy_ns),
555 format_ms(parallel.instrumented_blocked_ns),
556 format_ms(parallel.idle_ns),
557 format_percent_ppm(parallel.idle_share_ppm),
558 ));
559 out.push_str(&format!(
560 " workers busiest={} median={} imbalance={} process_cpu={} in_span_off_cpu={} source_wait={} scanner_wait={}\n",
561 format_ms(parallel.busiest_busy_ns),
562 format_ms(parallel.median_busy_ns),
563 format_percent_ppm(parallel.imbalance_ppm),
564 format_ms(parallel.process_cpu_ns),
565 format_ms(parallel.busy_off_cpu_ns),
566 format_ms(parallel.source_blocked_ns),
567 format_ms(parallel.scanner_blocked_ns),
568 ));
569 for queue in ¶llel.queues {
570 out.push_str(&format!(
571 " queue {:?} high_water={} enqueued={} dequeued={}\n",
572 queue.queue, queue.high_water, queue.enqueues, queue.dequeues,
573 ));
574 }
575
576 for region in self.serial_regions.iter().take(8) {
577 out.push_str(&format!(
578 "serial {:<6} {:<22} wall={:>12} share={:>6} concurrency={} exclusivity={} workers={}{}\n",
579 match region.scope {
580 SerialScopeV2::Phase => "phase",
581 SerialScopeV2::Stage => "stage",
582 },
583 region.subject,
584 format_ms(region.wall_ns),
585 format_percent_ppm(region.share_ppm),
586 format_ratio(region.concurrency_milli),
587 format_percent_ppm(region.exclusivity_ppm),
588 region.worker_count,
589 if region.declared { " declared" } else { "" },
590 ));
591 }
592
593 for stage in self.stages.iter().take(8) {
594 out.push_str(&format!(
595 "cost {:<24} total={:>12} share={:>6} calls={:<9} per_call={:>10} per_file={:>10} concurrency={}\n",
596 stage.metric_id.as_str(),
597 format_ms(stage.elapsed_ns),
598 format_percent_ppm(stage.share_of_recorded_ppm),
599 stage.calls,
600 format_ms(stage.ns_per_call),
601 format_ms(stage.ns_per_input_unit),
602 format_ratio(stage.concurrency_milli),
603 ));
604 }
605
606 for backend in &self.backends {
607 out.push_str(&format!(
608 "backend {:<16} batches={} recovered={} share={}\n",
609 backend.backend,
610 backend.batches,
611 backend.recovered_batches,
612 format_percent_ppm(backend.share_ppm),
613 ));
614 }
615
616 for record in &self.retries {
617 out.push_str(&format!(
618 "retry {:<24} attempts={}\n",
619 record.cause.as_str(),
620 record.attempts,
621 ));
622 }
623
624 for cache in &self.caches {
625 out.push_str(&format!(
626 "cache {:<24} hits={} misses={} hit_rate={}\n",
627 cache.cache.as_str(),
628 cache.hits,
629 cache.misses,
630 format_percent_ppm(cache.hit_rate_ppm),
631 ));
632 }
633
634 for note in &self.coverage.notes {
635 out.push_str(&format!("gap {note}\n"));
636 }
637 out
638 }
639}
640
641fn phase_name(state: RunState) -> &'static str {
642 match state {
643 RunState::Created => "created",
644 RunState::Acquiring => "acquiring",
645 RunState::Scanning => "scanning",
646 RunState::Resolving => "resolving",
647 RunState::Verifying => "verifying",
648 RunState::Reporting => "reporting",
649 RunState::Completed => "completed",
650 RunState::Failed => "failed",
651 }
652}
653
654fn process_cpu_ns(profile: &CausalProfileV2) -> u64 {
655 let start = profile.resources.start.cpu_time_ms.unwrap_or_default();
656 let finish = profile.resources.finish.cpu_time_ms.unwrap_or_default();
657 finish.saturating_sub(start).saturating_mul(1_000_000)
658}
659
660fn derive_phases(
661 profile: &CausalProfileV2,
662 wall_ns: u64,
663 input_bytes: u64,
664 input_units: u64,
665) -> Vec<PhaseInsightV2> {
666 profile
667 .states
668 .iter()
669 .map(|state: &StateMeasurement| {
670 let cpu_ns = state
671 .cpu_time_ms
672 .unwrap_or_default()
673 .saturating_mul(1_000_000);
674 let speedup_milli = milli(cpu_ns, state.elapsed_ns);
675 let parallel_capable = matches!(
678 state.state,
679 RunState::Acquiring | RunState::Scanning | RunState::Verifying
680 );
681 PhaseInsightV2 {
682 version: RUN_INSIGHT_V2_VERSION,
683 state: state.state,
684 wall_ns: state.elapsed_ns,
685 share_ppm: ppm(state.elapsed_ns, wall_ns),
686 cpu_ns,
687 speedup_milli,
688 serial: parallel_capable
689 && speedup_milli < SERIAL_CONCURRENCY_MILLI
690 && ppm(state.elapsed_ns, wall_ns) >= SERIAL_REPORT_SHARE_PPM,
691 mib_per_second_milli: mib_per_second_milli(input_bytes, state.elapsed_ns),
692 units_per_second_milli: per_second_milli(input_units, state.elapsed_ns),
693 resident_start_bytes: state.resident_start_bytes.unwrap_or_default(),
694 resident_end_bytes: state.resident_end_bytes.unwrap_or_default(),
695 threads_start: state.threads_start.unwrap_or_default(),
696 threads_end: state.threads_end.unwrap_or_default(),
697 }
698 })
699 .collect()
700}
701
702fn derive_memory(
703 profile: &CausalProfileV2,
704 input_bytes: u64,
705 scanner_threads: u64,
706) -> MemoryInsightV2 {
707 let kernel_peak = match &profile.system {
708 Evidence::Recorded { value } => match &value.memory.resident_high_water_bytes.value {
709 Evidence::Recorded { value } => Some(*value),
710 Evidence::Unavailable { .. } => None,
711 },
712 Evidence::Unavailable { .. } => None,
713 };
714 let sampled_peak = profile.resources.max_observed_resident_bytes;
715 let (peak_resident_bytes, peak_source) = match (kernel_peak, sampled_peak) {
716 (Some(kernel), sampled) => (kernel.max(sampled.unwrap_or(0)), "kernel-vmhwm"),
719 (None, Some(sampled)) => (sampled, "boundary-samples"),
720 (None, None) => (0, "unavailable"),
721 };
722
723 let baseline_resident_bytes = profile
724 .resources
725 .start
726 .resident_bytes
727 .or_else(|| {
728 profile
729 .states
730 .first()
731 .and_then(|state| state.resident_start_bytes)
732 })
733 .unwrap_or_default();
734 let engine_init_resident_bytes = profile
737 .states
738 .iter()
739 .find(|state| state.state == RunState::Scanning)
740 .and_then(|state| state.resident_start_bytes)
741 .or(Some(baseline_resident_bytes))
742 .unwrap_or_default();
743
744 let (allocations, allocated_bytes, deallocated_bytes, allocation_peak_live_bytes, stages) =
745 match &profile.system {
746 Evidence::Recorded { value } => {
747 let totals = match &value.allocation.totals {
748 Evidence::Recorded { value } => (
749 value.allocations,
750 value.allocated_bytes,
751 value.deallocated_bytes,
752 value.peak_live_bytes,
753 ),
754 Evidence::Unavailable { .. } => (0, 0, 0, 0),
755 };
756 let mut stages: Vec<StageMemoryV2> = value
757 .allocation
758 .stages
759 .iter()
760 .filter(|stage| stage.allocated_bytes != 0 || stage.peak_live_bytes != 0)
761 .map(|stage| StageMemoryV2 {
762 version: RUN_INSIGHT_V2_VERSION,
763 metric_id: stage.metric_id,
764 allocations: stage.allocations,
765 allocated_bytes: stage.allocated_bytes,
766 live_bytes: stage.live_bytes,
767 peak_live_bytes: stage.peak_live_bytes,
768 })
769 .collect();
770 stages.sort_by(|left, right| {
771 right
772 .allocated_bytes
773 .cmp(&left.allocated_bytes)
774 .then_with(|| left.metric_id.cmp(&right.metric_id))
775 });
776 (totals.0, totals.1, totals.2, totals.3, stages)
777 }
778 Evidence::Unavailable { .. } => (0, 0, 0, 0, Vec::new()),
779 };
780
781 let input_driven_resident_bytes =
782 peak_resident_bytes.saturating_sub(engine_init_resident_bytes);
783 MemoryInsightV2 {
784 version: RUN_INSIGHT_V2_VERSION,
785 peak_resident_bytes,
786 peak_source: peak_source.to_owned(),
787 baseline_resident_bytes,
788 engine_init_resident_bytes,
789 input_driven_resident_bytes,
790 input_bytes,
791 amplification_milli: milli(peak_resident_bytes, input_bytes),
792 scanner_threads,
793 resident_per_scanner_thread_bytes: peak_resident_bytes / scanner_threads.max(1),
794 input_driven_per_scanner_thread_bytes: input_driven_resident_bytes / scanner_threads.max(1),
795 allocations,
796 allocated_bytes,
797 deallocated_bytes,
798 allocation_peak_live_bytes,
799 allocated_per_input_byte_milli: milli(allocated_bytes, input_bytes),
800 stages,
801 }
802}
803
804fn overlapping_work_ns(
811 stages: &[crate::schema_v2::StageConcurrencyV2],
812 subject: &crate::schema_v2::StageConcurrencyV2,
813) -> u64 {
814 stages
815 .iter()
816 .filter(|other| other.metric_id != subject.metric_id && other.window_ns != 0)
817 .fold(0_u64, |total, other| {
818 let start = other.first_start_ns.max(subject.first_start_ns);
819 let end = other.last_end_ns.min(subject.last_end_ns);
820 let Some(overlap) = end.checked_sub(start) else {
821 return total;
822 };
823 let density_milli = other.concurrency_milli;
827 let share = u64::try_from((u128::from(density_milli) * u128::from(overlap)) / 1_000)
828 .unwrap_or(u64::MAX);
829 total.saturating_add(share)
830 })
831}
832
833fn derive_serial(
834 profile: &CausalProfileV2,
835 phases: &[PhaseInsightV2],
836 wall_ns: u64,
837) -> (Vec<SerialRegionV2>, u64) {
838 let mut regions: Vec<SerialRegionV2> = phases
839 .iter()
840 .filter(|phase| phase.serial && phase.wall_ns != 0)
841 .map(|phase| SerialRegionV2 {
842 version: RUN_INSIGHT_V2_VERSION,
843 scope: SerialScopeV2::Phase,
844 subject: phase_name(phase.state).to_owned(),
845 wall_ns: phase.wall_ns,
846 share_ppm: phase.share_ppm,
847 concurrency_milli: phase.speedup_milli,
848 worker_count: 1,
849 exclusivity_ppm: 1_000_000,
852 declared: false,
853 })
854 .collect();
855 let serial_wall_ns = regions
857 .iter()
858 .fold(0_u64, |total, region| total.saturating_add(region.wall_ns));
859
860 regions.extend(profile.stage_concurrency.iter().filter_map(|stage| {
861 if stage.window_ns == 0 {
862 return None;
863 }
864 let share_ppm = ppm(stage.window_ns, wall_ns);
865 if share_ppm < SERIAL_REPORT_SHARE_PPM {
866 return None;
867 }
868 let other_ns = overlapping_work_ns(&profile.stage_concurrency, stage);
869 let own_ns = u64::try_from(
870 (u128::from(stage.concurrency_milli) * u128::from(stage.window_ns)) / 1_000,
871 )
872 .unwrap_or(u64::MAX);
873 let exclusivity_ppm = ppm(own_ns, own_ns.saturating_add(other_ns));
874 let looks_serial = stage.concurrency_milli >= SERIAL_FLOOR_MILLI
880 && stage.concurrency_milli < SERIAL_CONCURRENCY_MILLI
881 && exclusivity_ppm >= SERIAL_EXCLUSIVITY_PPM;
882 if !looks_serial && stage.declared_serial_calls == 0 {
883 return None;
884 }
885 Some(SerialRegionV2 {
886 version: RUN_INSIGHT_V2_VERSION,
887 scope: SerialScopeV2::Stage,
888 subject: stage.metric_id.as_str().to_owned(),
889 wall_ns: stage.window_ns,
890 share_ppm,
891 concurrency_milli: stage.concurrency_milli,
892 worker_count: stage.worker_count,
893 exclusivity_ppm,
894 declared: stage.declared_serial_calls != 0,
895 })
896 }));
897 regions.sort_by(|left, right| {
898 right
899 .wall_ns
900 .cmp(&left.wall_ns)
901 .then_with(|| left.subject.cmp(&right.subject))
902 });
903 (regions, serial_wall_ns)
904}
905
906fn derive_parallelism(
907 profile: &CausalProfileV2,
908 wall_ns: u64,
909 process_cpu_ns: u64,
910 logical_cpus: u64,
911 scanner_threads: u64,
912 serial_wall_ns: u64,
913) -> ParallelismInsightV2 {
914 let occupancy = profile.worker_occupancy.as_ref();
915 let worker_count = occupancy.map_or(0, |occupancy| occupancy.worker_count);
916 let instrumented_busy_ns = occupancy.map_or(0, |occupancy| occupancy.busy_ns);
917 let instrumented_blocked_ns = occupancy.map_or(0, |occupancy| occupancy.blocked_ns);
918 let worker_capacity_ns = wall_ns.saturating_mul(worker_count);
919 let idle_ns = worker_capacity_ns
920 .saturating_sub(instrumented_busy_ns)
921 .saturating_sub(instrumented_blocked_ns);
922 let busiest_busy_ns = occupancy.map_or(0, |occupancy| occupancy.busiest_busy_ns);
923 let median_busy_ns = occupancy.map_or(0, |occupancy| occupancy.median_busy_ns);
924
925 let blocked_ns_for = |metric: MetricId| -> u64 {
926 profile
927 .blocked_waits
928 .iter()
929 .find(|record| record.metric_id == metric)
930 .map_or(0, |record| record.blocked_ns)
931 };
932
933 let speedup_ceiling_milli = if serial_wall_ns == 0 {
937 logical_cpus.saturating_mul(1_000)
938 } else {
939 milli(wall_ns, serial_wall_ns)
940 };
941
942 ParallelismInsightV2 {
943 version: RUN_INSIGHT_V2_VERSION,
944 logical_cpus,
945 scanner_threads,
946 wall_ns,
947 process_cpu_ns,
948 achieved_speedup_milli: milli(process_cpu_ns, wall_ns),
949 parallel_efficiency_ppm: ppm(process_cpu_ns, wall_ns.saturating_mul(logical_cpus)),
950 speedup_ceiling_milli,
951 worker_count,
952 active_worker_count: occupancy.map_or(0, |occupancy| occupancy.active_worker_count),
953 instrumented_busy_ns,
954 instrumented_blocked_ns,
955 worker_capacity_ns,
956 idle_ns,
957 idle_share_ppm: ppm(idle_ns, worker_capacity_ns),
958 busiest_busy_ns,
959 median_busy_ns,
960 imbalance_ppm: ppm(
961 busiest_busy_ns.saturating_sub(median_busy_ns),
962 busiest_busy_ns,
963 ),
964 busy_off_cpu_ns: instrumented_busy_ns.saturating_sub(process_cpu_ns),
965 source_blocked_ns: blocked_ns_for(MetricId::SourceQueueWait),
966 scanner_blocked_ns: blocked_ns_for(MetricId::ScannerQueueWait),
967 queues: profile.queue_depths.clone(),
968 }
969}
970
971fn derive_stages(
972 profile: &CausalProfileV2,
973 input_bytes: u64,
974 input_units: u64,
975) -> Vec<StageAttributionV2> {
976 let recorded_ns = profile
977 .stages
978 .iter()
979 .fold(0_u64, |total, stage| total.saturating_add(stage.elapsed_ns));
980 let mut rows: Vec<StageAttributionV2> = profile
981 .stages
982 .iter()
983 .filter(|stage| stage.calls != 0)
984 .map(|stage| {
985 let concurrency = profile
986 .stage_concurrency
987 .iter()
988 .find(|record| record.metric_id == stage.stage.metric_id());
989 let bytes = concurrency.map_or(0, |record| record.bytes);
990 StageAttributionV2 {
991 version: RUN_INSIGHT_V2_VERSION,
992 metric_id: stage.stage.metric_id(),
993 macro_stage_id: stage.stage.macro_stage_id(),
994 calls: stage.calls,
995 elapsed_ns: stage.elapsed_ns,
996 share_of_recorded_ppm: ppm(stage.elapsed_ns, recorded_ns),
997 ns_per_call: stage.elapsed_ns / stage.calls.max(1),
998 ns_per_input_unit: if input_units == 0 {
999 0
1000 } else {
1001 stage.elapsed_ns / input_units
1002 },
1003 ns_per_input_byte_milli: milli(stage.elapsed_ns, input_bytes),
1004 bytes,
1005 mib_per_second_milli: mib_per_second_milli(
1006 bytes,
1007 concurrency.map_or(0, |record| record.window_ns),
1008 ),
1009 concurrency_milli: concurrency.map_or(0, |record| record.concurrency_milli),
1010 worker_count: concurrency.map_or(0, |record| record.worker_count),
1011 }
1012 })
1013 .collect();
1014 rows.sort_by(|left, right| {
1015 right
1016 .elapsed_ns
1017 .cmp(&left.elapsed_ns)
1018 .then_with(|| left.metric_id.cmp(&right.metric_id))
1019 });
1020 rows
1021}
1022
1023fn derive_backends(profile: &CausalProfileV2) -> Vec<BackendAttributionV2> {
1024 let mut totals: Vec<(String, u64, u64)> = Vec::new();
1025 for batch in &profile.identity.route.batches {
1026 let recovered = u64::from(matches!(
1027 batch.recovered_from_backend,
1028 Evidence::Recorded { .. }
1029 ));
1030 match totals
1031 .iter_mut()
1032 .find(|(backend, _, _)| backend == &batch.completed_backend)
1033 {
1034 Some(entry) => {
1035 entry.1 += 1;
1036 entry.2 += recovered;
1037 }
1038 None => totals.push((batch.completed_backend.clone(), 1, recovered)),
1039 }
1040 }
1041 let batch_total = totals.iter().fold(0_u64, |total, entry| total + entry.1);
1042 let mut rows: Vec<BackendAttributionV2> = totals
1043 .into_iter()
1044 .map(
1045 |(backend, batches, recovered_batches)| BackendAttributionV2 {
1046 version: RUN_INSIGHT_V2_VERSION,
1047 backend,
1048 batches,
1049 recovered_batches,
1050 share_ppm: ppm(batches, batch_total),
1051 },
1052 )
1053 .collect();
1054 rows.sort_by(|left, right| {
1055 right
1056 .batches
1057 .cmp(&left.batches)
1058 .then_with(|| left.backend.cmp(&right.backend))
1059 });
1060 rows
1061}
1062
1063fn derive_coverage(
1064 profile: &CausalProfileV2,
1065 memory: &MemoryInsightV2,
1066 parallelism: &ParallelismInsightV2,
1067) -> InsightCoverageV2 {
1068 let mut notes = Vec::new();
1069 let process_metrics = memory.peak_resident_bytes != 0;
1070 if !process_metrics {
1071 notes.push(
1072 "resident memory is unavailable, so every memory conclusion is missing".to_owned(),
1073 );
1074 }
1075 let allocation_tracking = memory.allocated_bytes != 0;
1076 if !allocation_tracking {
1077 notes.push(
1078 "the tracking allocator is not installed, so allocation volume and per-stage ownership are absent"
1079 .to_owned(),
1080 );
1081 }
1082 let stage_concurrency = !profile.stage_concurrency.is_empty();
1083 if !stage_concurrency {
1084 notes.push(
1085 "no micro-function recorded a span, so serial detection falls back to phase CPU ratios"
1086 .to_owned(),
1087 );
1088 }
1089 let worker_occupancy = parallelism.worker_count != 0;
1090 if !worker_occupancy {
1091 notes.push("no worker shard registered, so busy versus idle time is absent".to_owned());
1092 }
1093 if parallelism.process_cpu_ns == 0 {
1094 notes.push(
1095 "process CPU time is unavailable, so achieved speedup cannot be computed".to_owned(),
1096 );
1097 }
1098 if profile.events.dropped_span_events != 0 {
1099 notes.push(format!(
1100 "{} span records were dropped for capacity; aggregate counters remain exact",
1101 profile.events.dropped_span_events
1102 ));
1103 }
1104 InsightCoverageV2 {
1105 version: RUN_INSIGHT_V2_VERSION,
1106 process_metrics,
1107 allocation_tracking,
1108 stage_concurrency,
1109 worker_occupancy,
1110 dropped_span_events: profile.events.dropped_span_events,
1111 notes,
1112 }
1113}
1114
1115fn finding(
1116 kind: BottleneckKindV2,
1117 severity: u8,
1118 impact_ns: u64,
1119 wall_ns: u64,
1120 subject: impl Into<String>,
1121 statement: impl Into<String>,
1122) -> FindingV2 {
1123 FindingV2 {
1124 version: RUN_INSIGHT_V2_VERSION,
1125 kind,
1126 severity,
1127 impact_ns,
1128 impact_share_ppm: ppm(impact_ns, wall_ns),
1129 subject: subject.into(),
1130 statement: statement.into(),
1131 }
1132}
1133
1134fn rank_findings(
1135 wall_ns: u64,
1136 throughput: &ThroughputInsightV2,
1137 memory: &MemoryInsightV2,
1138 parallelism: &ParallelismInsightV2,
1139 serial_regions: &[SerialRegionV2],
1140 stages: &[StageAttributionV2],
1141 caches: &[CacheEffectivenessV2],
1142 retries: &[RetryRecordV2],
1143) -> Vec<FindingV2> {
1144 let mut findings = Vec::new();
1145
1146 for region in serial_regions
1147 .iter()
1148 .filter(|region| region.share_ppm >= MATERIAL_SHARE_PPM)
1149 .take(3)
1150 {
1151 findings.push(finding(
1152 BottleneckKindV2::SerialPhase,
1153 if region.share_ppm >= 250_000 { 3 } else { 2 },
1154 region.wall_ns,
1155 wall_ns,
1156 region.subject.clone(),
1157 format!(
1158 "{} is a serial barrier: {} of wall ({}) at {} workers, and no extra thread removes it",
1159 region.subject,
1160 format_ms(region.wall_ns),
1161 format_percent_ppm(region.share_ppm),
1162 format_ratio(region.concurrency_milli),
1163 ),
1164 ));
1165 }
1166
1167 if parallelism.logical_cpus > 1 && parallelism.process_cpu_ns != 0 {
1168 let half_the_box = parallelism.logical_cpus.saturating_mul(500);
1169 if parallelism.achieved_speedup_milli < half_the_box {
1170 findings.push(finding(
1171 BottleneckKindV2::ParallelStarvation,
1172 if parallelism.parallel_efficiency_ppm < 250_000 {
1173 3
1174 } else {
1175 2
1176 },
1177 wall_ns.saturating_sub(
1178 parallelism
1179 .process_cpu_ns
1180 .checked_div(parallelism.logical_cpus)
1181 .unwrap_or(wall_ns),
1182 ),
1183 wall_ns,
1184 "worker-pool",
1185 format!(
1186 "the run reached {} of {} logical CPUs ({} efficiency); {} of CPU time ran in {} of wall, and the Amdahl ceiling from measured serial work is {}",
1187 format_ratio(parallelism.achieved_speedup_milli),
1188 parallelism.logical_cpus,
1189 format_percent_ppm(parallelism.parallel_efficiency_ppm),
1190 format_ms(parallelism.process_cpu_ns),
1191 format_ms(wall_ns),
1192 format_ratio(parallelism.speedup_ceiling_milli),
1193 ),
1194 ));
1195 }
1196 }
1197
1198 if parallelism.instrumented_blocked_ns > parallelism.instrumented_busy_ns
1199 && parallelism.instrumented_blocked_ns != 0
1200 {
1201 findings.push(finding(
1202 BottleneckKindV2::QueueStarvation,
1203 2,
1204 parallelism.instrumented_blocked_ns,
1205 wall_ns,
1206 "source-queue",
1207 format!(
1208 "workers spent {} blocked against {} busy; the source side is not feeding the pool",
1209 format_ms(parallelism.instrumented_blocked_ns),
1210 format_ms(parallelism.instrumented_busy_ns),
1211 ),
1212 ));
1213 }
1214
1215 if memory.peak_resident_bytes >= MEMORY_FLOOR_BYTES
1216 && memory.engine_init_resident_bytes.saturating_mul(2) >= memory.peak_resident_bytes
1217 {
1218 findings.push(finding(
1219 BottleneckKindV2::MemoryFloor,
1220 if memory.input_bytes < 1_048_576 { 3 } else { 1 },
1221 0,
1222 wall_ns,
1223 "engine-init",
1224 format!(
1225 "{} of the {} peak is standing the engine up, not the input: {} of input produced only {} of extra resident memory",
1226 format_bytes(memory.engine_init_resident_bytes),
1227 format_bytes(memory.peak_resident_bytes),
1228 format_bytes(memory.input_bytes),
1229 format_bytes(memory.input_driven_resident_bytes),
1230 ),
1231 ));
1232 }
1233
1234 if memory.input_bytes >= MEMORY_FLOOR_BYTES && memory.amplification_milli >= AMPLIFICATION_MILLI
1235 {
1236 findings.push(finding(
1237 BottleneckKindV2::MemoryAmplification,
1238 2,
1239 0,
1240 wall_ns,
1241 "resident-amplification",
1242 format!(
1243 "peak resident is {} of the input: {} held for {}",
1244 format_ratio(memory.amplification_milli),
1245 format_bytes(memory.peak_resident_bytes),
1246 format_bytes(memory.input_bytes),
1247 ),
1248 ));
1249 }
1250
1251 for cache in caches
1252 .iter()
1253 .filter(|cache| cache.hit_rate_ppm < 500_000 && cache.misses >= 8)
1254 {
1255 findings.push(finding(
1256 BottleneckKindV2::CacheMiss,
1257 1,
1258 0,
1259 wall_ns,
1260 cache.cache.as_str(),
1261 format!(
1262 "{} served {} of {} lookups ({}); every miss pays the full cost again",
1263 cache.cache.as_str(),
1264 cache.hits,
1265 cache.hits.saturating_add(cache.misses),
1266 format_percent_ppm(cache.hit_rate_ppm),
1267 ),
1268 ));
1269 }
1270
1271 let retry_attempts = retries
1272 .iter()
1273 .fold(0_u64, |total, record| total.saturating_add(record.attempts));
1274 if retry_attempts != 0 {
1275 let worst = retries
1276 .iter()
1277 .max_by_key(|record| record.attempts)
1278 .expect("a nonzero total implies at least one record");
1279 findings.push(finding(
1280 BottleneckKindV2::RetriedWork,
1281 2,
1282 0,
1283 wall_ns,
1284 worst.cause.as_str(),
1285 format!(
1286 "{retry_attempts} operations were attempted again, {} of them for {}; a retry that fires is a failure that was not designed out",
1287 worst.attempts,
1288 worst.cause.as_str(),
1289 ),
1290 ));
1291 }
1292
1293 let scanning_ns = throughput
1294 .phases
1295 .iter()
1296 .filter(|phase| phase.state == RunState::Scanning)
1297 .fold(0_u64, |total, phase| total.saturating_add(phase.wall_ns));
1298 let non_scanning_ns = wall_ns.saturating_sub(scanning_ns);
1299 if scanning_ns != 0 && non_scanning_ns > scanning_ns {
1300 findings.push(finding(
1301 BottleneckKindV2::FixedOverhead,
1302 2,
1303 non_scanning_ns,
1304 wall_ns,
1305 "outside-scanning",
1306 format!(
1307 "{} of {} wall ran outside scanning; scanning itself took {}",
1308 format_ms(non_scanning_ns),
1309 format_ms(wall_ns),
1310 format_ms(scanning_ns),
1311 ),
1312 ));
1313 }
1314
1315 if let Some(stage) = stages.first() {
1316 if stage.share_of_recorded_ppm >= 400_000 && stage.concurrency_milli != 0 {
1317 findings.push(finding(
1318 BottleneckKindV2::StageBound,
1319 1,
1320 stage.elapsed_ns,
1321 wall_ns,
1322 stage.metric_id.as_str(),
1323 format!(
1324 "{} holds {} of recorded stage time across {} calls at {} per call",
1325 stage.metric_id.as_str(),
1326 format_percent_ppm(stage.share_of_recorded_ppm),
1327 stage.calls,
1328 format_ms(stage.ns_per_call),
1329 ),
1330 ));
1331 }
1332 }
1333
1334 if findings.is_empty() {
1335 findings.push(finding(
1336 BottleneckKindV2::Insufficient,
1337 0,
1338 wall_ns,
1339 wall_ns,
1340 "run",
1341 format!(
1342 "no phase, worker, cache, or memory measurement crossed a reporting threshold in {}",
1343 format_ms(wall_ns)
1344 ),
1345 ));
1346 }
1347
1348 findings.sort_by(|left, right| {
1349 right
1350 .severity
1351 .cmp(&left.severity)
1352 .then_with(|| right.impact_ns.cmp(&left.impact_ns))
1353 .then_with(|| left.subject.cmp(&right.subject))
1354 });
1355 let mut seen: Vec<BottleneckKindV2> = Vec::with_capacity(findings.len());
1358 findings.retain(|finding| {
1359 if seen.contains(&finding.kind) {
1360 return false;
1361 }
1362 seen.push(finding.kind);
1363 true
1364 });
1365 findings
1366}