Observability

A runtime a service cannot see into is a runtime a service cannot operate. This chapter is about the numbers a host needs, and the distinction between debugging instrumentation (rich, expensive, off by default) and production telemetry (cheap, always on, alertable).


Two Audiences

Debugging instrumentationProduction telemetry
Audienceyou, at a terminal, with a reproductiona service, at 3am, without one
Examples--trace-gc, --trace-tables, ember traceStats, tracing spans, GC pause histogram
Costmay be 1000× (--gc-stress)must be ~free
Defaultoffon
Outputstderr, human-readablestructured, machine-consumable

Building both is not duplication. The trace tells you what happened in this run; the metric tells you that something is happening across all runs, which is what you have at 3am.


Stats: Utilization, Not Just Violations

#![allow(unused)]
fn main() {
pub struct Stats {
    // Work
    pub instructions: u64,        pub instruction_budget: u64,
    pub calls: u64,               pub native_calls: u64,
    // Memory
    pub allocations: u64,         pub bytes_allocated_total: u64,
    pub live_objects: usize,      pub peak_memory: usize,
    pub memory_budget: usize,
    // Collector
    pub gc_runs: u32,             pub gc_pause_total: Duration,
    pub gc_pause_max: Duration,
    // Stack
    pub max_stack_depth: usize,   pub max_call_depth: usize,
    pub call_depth_budget: usize,
}
}

The budgets are in the struct alongside the usage, so a consumer can compute utilization without knowing the configuration. That is the difference between a metric a service can alert on and a number it has to join against something else.

#![allow(unused)]
fn main() {
impl Stats {
    pub fn instruction_utilization(&self) -> f64 { /* ... */ }
    pub fn memory_utilization(&self) -> f64      { /* ... */ }
    pub fn depth_utilization(&self) -> f64       { /* ... */ }
}
}

Alert at 80%, not 100%. A policy at 100% is a failed request; a policy at 80% is a warning that the next feature will break it. This is the single most useful sentence in the chapter and it belongs in docs/embedding.md.


Per-Evaluation Emission

The capstone's shape, and the one to document:

#![allow(unused)]
fn main() {
let stats = engine.evaluate::<_, f64>("score", (&user, &article))?;
tracing::info!(
    policy = %policy_version,
    instructions = stats.instructions,
    utilization = stats.instruction_utilization(),
    peak_memory = stats.peak_memory,
    gc_runs = stats.gc_runs,
    gc_pause_us = stats.gc_pause_total.as_micros(),
    "policy evaluated"
);
}

Four things a service actually does with that:

  1. Alert on utilization > 0.8, sustained.
  2. Compare two policy versions during an A/B — same inputs, different instruction counts.
  3. Attribute latency: a p99 spike that correlates with gc_pause_max is a collector problem, not a policy problem, and without the number you would have guessed.
  4. Capacity-plan: instructions per request × requests per second is a number you can multiply.

The Heap Census

$ ember run --stats policy.ember
--- heap census ---
  Table      1,014     ~122 KB
  EmberStr   1,022     ~ 29 KB
  Closure       12     ~  1 KB
  Upvalue        7     ~  0 KB
  UserData  10,000     ~640 KB
  total     12,055     ~792 KB   (peak 810 KB, 3 collections, 4.1 ms total pause)

A census by type is how you find a leak that is not a bug. A closure registered as a callback and never dropped keeps every variable it captured, transitively; the collector is behaving correctly and the program is wrong. No pause-time metric will show you that, and a growing Closure count will.


GC Pause Distribution

$ ember run --trace-gc --stats long_running.ember
--- gc ---
  runs:        184
  total pause: 412 ms
  mean:        2.2 ms
  p50:         1.1 ms
  p95:         6.8 ms
  max:        31.4 ms     ← THIS is the number that matters

Report the distribution, not the mean. A mean pause of 2.2 ms sounds fine and a max of 31 ms is what shows up in your p99 latency. This is also the measurement that decides whether an incremental collector is worth building — and deciding that from the max rather than the mean is the difference between building it because you needed it and building it because it sounded advanced.

Separate mark from sweep, too: mark scales with the live set and sweep with the whole heap, and they respond to different fixes.


Cost, and Making It Honest

Every counter is an increment on a hot path. The rule:

  • Counters that are free (instructions, calls, allocations) stay always-on. They are one += 1 on a value already in cache.
  • Anything requiring a timer (gc_pause_*) is on only when collecting, which is already rare.
  • Anything per-object (the census) is computed on demand by walking the heap, not maintained incrementally.

And then measure it, because "it should be free" is a hypothesis:

cargo bench --features no-stats -- fib_25
cargo bench                     -- fib_25

If the delta is in the noise — it should be — then delete the no-stats feature. Observability with no measurable cost should not have an off switch, and having measured it is what lets you say so. Same argument as the instruction budget's.


Determinism as an Observability Property

Two runs of the same script on the same inputs produce identical stats — same instruction count, same allocation count, same everything except wall-clock timings.

That is worth stating because of what it enables:

  • A regression test on instruction count. If a compiler change makes the corpus execute 3% more instructions, CI can fail. That is a performance test with no timing noise at all, and it is strictly better than a benchmark for catching accidental pessimization.
  • Reproducible A/B comparisons. Policy v1 versus v2 on the same candidate set, compared by instructions rather than by wall clock.
#![allow(unused)]
fn main() {
#[test]
fn instruction_counts_are_stable_across_runs_and_engines() {
    for case in corpus() {
        let a = Engine::with_seed(1).run_counting(&case.src);
        let b = Engine::with_seed(999).run_counting(&case.src);
        assert_eq!(a, b, "{} instruction count is not deterministic", case.name);
    }
}
}

Things to Notice

  • Two audiences, two mechanisms. A trace answers "what happened here"; a metric answers "is something happening everywhere".
  • Ship the budget alongside the usage, or the consumer cannot compute utilization.
  • Alert at 80%. 100% is already a failed request.
  • Report the pause distribution. The max is what lands in your p99; the mean is what makes you complacent.
  • A heap census finds leaks the collector is correct about.
  • Measure the observability overhead, then delete the off switch if the number says you can.
  • Deterministic instruction counts make a timing-free performance regression test, which is better than a benchmark for catching pessimization.

Validation / Self-check

  1. Give the two observability audiences and the different properties each mechanism needs.
  2. Why does Stats carry the budgets as well as the usage?
  3. Why alert at 80% rather than 100%?
  4. What does a heap census find that a pause-time metric cannot?
  5. Why report the pause distribution rather than the mean? Which number decides the incremental-GC question?
  6. Which counters are always-on and why? What did you measure, and what did you delete?
  7. How does determinism turn instruction count into a performance regression test, and why is that better than a benchmark for that purpose?

Next: Performance Engineering.