Logging and Metrics

A VMM that runs thousands of microVMs per host and powers Lambda and Fargate cannot be debugged with println!. Firecracker ships two structured observability subsystems: a logger (human-readable log lines at configurable levels, to a file or pipe) and a metrics system (a tree of numeric counters, serialized as JSON, flushed on demand or on a timer). Together they are how an operator answers "is this microVM healthy, and if not, where did it break" without attaching a debugger to a process that is, by design, seccomp-jailed and hard to introspect.

This chapter covers the logger (PUT /logger, levels, log_path), the metrics system (PUT /metrics, the serialized counter tree, the FlushMetrics action), the structure of the instance/Firecracker metrics, and the log-instrument/tracing tooling — and how operators actually use all of it to debug.

Note: Both subsystems are configured before boot by pointing them at a path (a file or a named pipe). Firecracker writes structured output to that path; it does not run an agent or open a network socket. In production the path is usually a FIFO the orchestrator drains, so the jailed VMM needs no extra privileges to be observable.

The logger

rg -n "struct Logger|LoggerConfig|log_path|level|LevelFilter|fn init|show_level|show_log_origin" src/vmm/src/logger/
find src/vmm/src/logger -name "*.rs"

The logger is configured by PUT /logger (pre-boot) or the logger section of a config file:

curl -X PUT --unix-socket /tmp/fc.sock --data '{
  "log_path": "fc.log",
  "level": "Debug",
  "show_level": true,
  "show_log_origin": true
}' http://localhost/logger

Levels filter monotonically: Debug shows everything down to Debug; Error shows only errors. Crucially, the logger is set up before the heavy machinery starts, so configuration errors and boot failures land in the log. Inside the code, logging goes through the standard log macros (error!, warn!, info!, debug!, trace!) — rg -n "error!\(|warn!\(|info!\(" src/vmm/src/ to see call sites.

The metrics system

rg -n "struct .*Metrics|FirecrackerMetrics|SharedIncMetric|SharedStoreMetric|IncMetric|StoreMetric|fn flush" src/vmm/src/logger/

Metrics are a fixed tree of counters, not arbitrary key/values. Firecracker defines a global metrics structure (find it with rg -n "FirecrackerMetrics|struct .*Metrics" src/vmm/src/logger/) whose fields are sub-structs per subsystem (API server, block, net, vsock, vcpu, seccomp, signals, …), each containing individual counters. The counter types:

They're "shared" because multiple threads (vCPU threads, the VMM thread) update them concurrently — the types use atomics so increments are lock-free. Configure the sink with PUT /metrics:

curl -X PUT --unix-socket /tmp/fc.sock \
  --data '{"metrics_path":"fc-metrics.fifo"}' http://localhost/metrics

On flush, the whole tree is serialized to JSON and written to metrics_path as one line, e.g. (shape, abbreviated):

{"utc_timestamp_ms":...,"api_server":{"process_startup_time_us":...},
 "block":{"read_count":1234,"write_count":56,"queue_event_count":...,"flush_count":...},
 "net":{"rx_packets_count":...,"tx_packets_count":...},
 "seccomp":{"num_faults":0},"signals":{"sigbus":0,"sigsegv":0},
 "vcpu":{"exit_io_in":...,"exit_mmio_read":...,"failures":...}}

Each flush emits a delta-able snapshot: counters are cumulative, so an operator diffs two flushes to get rates.

Flushing metrics

rg -n "FlushMetrics|flush_metrics|metrics_interval|periodic|TimerFd|fn flush" src/vmm/src/

Metrics are flushed in two ways:

1. On demand — PUT /actions {"action_type":"FlushMetrics"} writes one snapshot immediately.
2. Periodically — Firecracker also flushes on a timer (a timerfd registered with the EventManager), so a draining orchestrator gets a steady stream without polling the API.

flowchart LR
    Counters["FirecrackerMetrics tree (atomic counters)"] --> Trigger{flush trigger}
    Trigger -->|"PUT /actions FlushMetrics"| Ser["serialize tree → JSON"]
    Trigger -->|"periodic timerfd"| Ser
    Ser --> Path["write one line to metrics_path (file/FIFO)"]
    Path --> Drain["orchestrator drains + ships to monitoring"]

Tip: Because each flush is a full cumulative snapshot, the natural monitoring pattern is "ship every line, diff consecutive lines for rates, alert on counters that should stay zero" — seccomp.num_faults, signals.sigbus/sigsegv, and *.failures are the ones that should never move.

The instance/Firecracker metrics structure

rg -n "struct .*Metrics" src/vmm/src/logger/ | head -40
rg -n "BlockDeviceMetrics|NetDeviceMetrics|VcpuMetrics|SeccompMetrics|SignalMetrics|ApiServerMetrics" src/vmm/src/

The tree mirrors the architecture, which makes it a map of where to look when something breaks:

When a device misbehaves, its metrics group is the first place to look — a climbing *.failures or a nonzero error counter localizes the fault before you ever open a log.

log-instrument and tracing

find src/log-instrument src/log-instrument-macros -name "*.rs" 2>/dev/null
rg -n "log_instrument|#\[instrument|trace!|clippy-tracing" src/

Firecracker carries an in-tree tracing facility, log-instrument (plus its proc-macro crate log-instrument-macros and the CI helper clippy-tracing). It can instrument function entry/exit so that, at Trace level, you get a call trace through the code — invaluable when tracing a request from the API socket all the way to a KVM_RUN exit. It is normally compiled out / disabled to keep the fast path lean; enable it when you are deliberately tracing a path. clippy-tracing is the tool that keeps the instrumentation annotations consistent across the tree (a CI/lint concern, not a runtime one).

How operators debug with these

A realistic debugging loop:

symptom: a microVM's guest network "feels stuck"
  1. metrics: diff two flushes → net.tx_packets_count flat, net.tx_rate_limiter_throttled climbing
        → it's being throttled, not broken
  2. logs at Debug: confirm rate-limiter messages, find the configured bucket size
  3. fix: PATCH the network-interface rate limiter, or correct the config
vs.
symptom: VMM process vanished
  1. metrics last flush: seccomp.num_faults > 0  → a denied syscall (a real bug or a missing rule)
        OR signals.sigsegv > 0  → a fault in the VMM
  2. log tail: the SIGSYS/SIGSEGV handler logged the offending syscall / address
        → see signals-shutdown-and-reset.md and seccomp-filtering.md

The two subsystems are complementary: metrics tell you that and where (which subsystem's counter moved); logs tell you why (the message and origin). Neither requires attaching to the process, which matters because the process is jailed.

Reading exercise

# 1. Logger config and levels.
rg -n "LoggerConfig|log_path|LevelFilter|show_log_origin" src/vmm/src/logger/

# 2. The metrics tree and counter types.
rg -n "struct .*Metrics|SharedIncMetric|SharedStoreMetric|IncMetric|StoreMetric" src/vmm/src/logger/

# 3. Configure both and trigger a flush by hand.
#    PUT /logger, PUT /metrics, then:
#    curl -X PUT --unix-socket /tmp/fc.sock --data '{"action_type":"FlushMetrics"}' http://localhost/actions
#    then read the metrics file.

# 4. The periodic flush timer.
rg -n "FlushMetrics|metrics.*timer|TimerFd|periodic" src/vmm/src/

# 5. Per-device metrics increments at the call site.
rg -n "\.inc\(\)|METRICS\.|\.add\(" src/vmm/src/devices/virtio/block/

# 6. The tracing facility.
rg -n "log_instrument|#\[instrument|clippy-tracing" src/

Answer:

1. How is the logger configured, what are the levels, and why must it be set up before boot?
2. What kind of structure are metrics? Contrast IncMetric and StoreMetric, and explain why the types are "shared."
3. What are the two ways metrics get flushed, and what does a single flush contain?
4. Name four metrics groups and what each tells you about the running microVM.
5. Which counters should always be zero, and what does it mean if they're not?
6. What is log-instrument for, and why is it normally compiled out?

Common bugs and symptoms

Validation: prove you understand this

1. Configure the logger and the metrics sink with two curl calls and explain each field.
2. Describe the metrics counter tree and the difference between an inc-metric and a store-metric.
3. Explain on-demand vs periodic flushing and why a flush is a cumulative snapshot.
4. Map three subsystems to their metrics groups and name a counter that localizes a fault in each.
5. Name the counters that must stay zero and what a nonzero value implies for each.
6. Walk a concrete debugging loop that uses metrics to localize and logs to diagnose a stuck device.

Next: signals-shutdown-and-reset.md — the signal handlers whose counters you just saw (SIGSYS, SIGBUS, SIGSEGV) and the orderly teardown of a microVM.