Lab I6: Writing Diagnostics for Integration Bugs

Background

Lab I4 taught you to attribute a cross-component failure; Lab I5 taught you to reproduce it. Both were about you doing detective work after the fact. This lab inverts the problem: instead of diagnosing failures by hand, you improve the signal Firecracker emits at its boundaries so the next cross-component failure explains itself — to you, to a maintainer, and to the operator who will never read the source. This is a contribution-oriented lab. The output isn't a write-up; it's a patch.

Here is the gap it closes. Firecracker sits at the bottom of a stack, surrounded by layers it does not own — the guest kernel, KVM, the host, the orchestrator (see the integration-labs index). When something goes wrong at one of those boundaries, Firecracker often has exactly the information needed to point at the culprit — it just doesn't always emit it. A KVM_SET_USER_MEMORY_REGION that fails with EINVAL, a device that drops a virtqueue descriptor, a snapshot whose memory layout doesn't match the file, a /dev/kvm open that returns EACCES — at each of these, Firecracker knows the failing syscall, the errno, and the context, but a thin error message throws that away. A better error, a new metric, or a captured serial line turns a multi-hour cross-component investigation (I4's whole toolkit) into a single log line that names the owning layer.

You will pick a real boundary where Firecracker's signal is weak, study how it logs and meters today (logging & metrics deep dive), improve the diagnostic — a better error message at the KVM/device/host edge, a log or metric addition, or better serial/console capture — and package it as a PR-quality contribution with a test. The work is small in lines and large in leverage: every future operator who hits that boundary gets the answer for free.

This is a review-it / build-it lab.

Why This Lab Matters for Contributors

• Diagnostics patches are some of the best first real contributions to Firecracker. They're low-risk (they don't change behavior, only what's reported), high-value (they save maintainers and operators real time), and they prove you understand a boundary deeply enough to know what signal is missing.
• The maintainers explicitly value good error messages — a recurring theme across the curriculum (Level 8, Lab 8.3). An error that names the failing syscall and the likely cause is the difference between a misfiled firecracker issue and an operator fixing their own host config.
• It closes the loop on this whole section: I4 attributes, I5 reproduces, I6 makes the next attribution unnecessary. A contributor who upgrades the signal at a boundary removes a recurring class of misfiled issues permanently.

Prerequisites

cd ~/firecracker
# How Firecracker logs and meters today — your raw material.
rg -n "macro_rules! error|warn!|info!|debug!|METRICS|IncMetric|SharedIncMetric" src/vmm/src/logger/ | head
ls src/vmm/src/logger/
# Where metrics are DEFINED (the per-subsystem counters you can extend).
rg -n "struct .*Metrics|SharedIncMetric|SharedStoreMetric" src/vmm/src/logger/metrics.rs | head

Note: Diagnostics changes are additive and behavior-preserving — that's what makes them safe and reviewable. A good diagnostics PR adds signal without changing what Firecracker does. If your change alters control flow or device behavior, it's not a diagnostics PR anymore; split it.

Step-by-Step Tasks

Step 1: Inventory the signal Firecracker emits today

Before adding signal, map what exists. Firecracker has three diagnostic channels; know each one's shape and where it's wired.

# 1) The LOG — structured lines via the logger; levels Error/Warn/Info/Debug.
rg -n "error!|warn!|info!|debug!" src/vmm/src/ | wc -l
rg -n "level|show_level|show_log_origin|LevelFilter" src/vmm/src/logger/ | head

# 2) METRICS — counters/gauges per subsystem (block, net, vsock, vcpu, api, seccomp...).
rg -n "struct .*Metrics" src/vmm/src/logger/metrics.rs | head -40
rg -n "\.inc\(\)|\.add\(|IncMetric|StoreMetric" src/vmm/src/devices/virtio/block/ | head

# 3) The SERIAL CONSOLE — the guest's own voice (16550 UART); FC writes it to stdout.
rg -n "serial|Serial|console|ttyS0|vm-superio" src/vmm/src/devices/legacy/ | head

The diagnostic gaps live where one of these channels should carry boundary information but doesn't — a swallowed errno, a missing counter, a console line that wasn't captured.

Step 2: Find a boundary where the signal is weak

Use I4's boundary table as a checklist and hunt for places where Firecracker fails or degrades at an edge but reports it thinly. Concrete hunting grounds:

# KVM boundary: ioctls whose errors get mapped to a generic message. The errno is gold;
# is it preserved and reported?
rg -n "KVM_|ioctl|kvm_ioctls|\.map_err|VcpuError|VmError|errno" src/vmm/src/vstate/ | head -30

# Device boundary: queue errors, dropped descriptors, malformed requests — are they METERED?
rg -n "error!|warn!|drop|invalid|InvalidDescriptor|QueueError|\.inc\(\)" \
  src/vmm/src/devices/virtio/block/ src/vmm/src/devices/virtio/net/ | head

# Host boundary: file opens, mmap, tap creation — does the error name the syscall + path?
rg -n "openat|open\(|mmap|TAP|/dev/net/tun|/dev/kvm|\.map_err|io::Error" src/vmm/src/ | head

# Snapshot boundary: a layout/version mismatch — does the error say WHICH and WHY?
rg -n "load_snapshot|deserialize|version|MemBackend|\.map_err" src/vmm/src/persist.rs | head

Pick one concrete gap. Good candidates, each a real recurring misfile from I4:

Step 3: Reproduce the weak signal — see what an operator sees

Before improving it, witness the bad experience. Trigger your chosen boundary failure (I5's repro skills) and capture exactly what Firecracker emits today. This is your before-state and your motivation.

# Example: the /dev/kvm permission case. Make it fail, read the current message.
sudo chmod 000 /dev/kvm   # on a THROWAWAY host — break it deliberately
./firecracker --api-sock /tmp/fc.sock 2>fc-before.log &
# ... drive the API to InstanceStart ...
cat fc-before.log         # what does FC say? probably too little to name the cause
sudo chmod 660 /dev/kvm   # restore

# Capture the current log/metric/console for your specific boundary:
rg -i "error|fail" fc-before.log

Write down the current output verbatim. If it already names the syscall, errno, and likely cause, pick a different gap — this one's fine. The ones worth fixing are the ones that send an operator (or you) into a multi-hour I4 investigation for what the errno already knew.

Step 4: Improve the diagnostic — error, metric, or capture

Now make the change. Match the kind of signal to the boundary (Step 1's table). Three patterns, with the discipline for each:

A better error message (the most common). Preserve the underlying error and add actionable context — what failed, why it likely failed, and which layer to look at.

#![allow(unused)]
fn main() {
// BEFORE (illustrative): throws away the errno and the cause.
//   File::open("/dev/kvm").map_err(|_| Error::KvmOpen)?;
//
// AFTER: name the syscall, keep the errno, point at the owning layer.
File::open("/dev/kvm").map_err(|e| {
    // Match Firecracker's existing error style — read neighbors before inventing one.
    Error::KvmOpen(format!(
        "failed to open /dev/kvm: {e}. Check that /dev/kvm exists and is accessible \
         (are you in the `kvm` group? if jailed, did the jailer mknod /dev/kvm into the chroot?)"
    ))
})?;
}

A new metric (for rates and tallies — dropped descriptors, failed I/O, throttle events). Add a counter to the right subsystem's metrics struct and increment it at the failure site.

# Find the subsystem's metrics struct, add a SharedIncMetric, increment at the failure site.
rg -n "struct BlockDeviceMetrics|SharedIncMetric|pub .*: SharedIncMetric" src/vmm/src/logger/metrics.rs
# Then at the drop/error site:  METRICS.block.<your_new_counter>.inc();
rg -n "METRICS\.|\.inc\(\)" src/vmm/src/devices/virtio/block/ | head

Better serial/console capture (for the guest-kernel boundary). Ensure the guest's output is reliably captured and surfaced — the serial console is the guest's only voice, and a dropped console line is a lost panic message.

rg -n "serial|console|stdout|write|out_buffer|flush" src/vmm/src/devices/legacy/serial.rs 2>/dev/null

Tip: Read three or four existing errors/metrics in the same file before you write yours, and match their style exactly — the level (error! vs warn!), the phrasing, whether they include the errno, how metrics are named. A diagnostics PR that doesn't match the house style gets style comments instead of merge approvals. Run tools/devtool fmt and checkstyle.

Step 5: Add a test that proves the signal fires

A diagnostics change without a test can silently rot — the next refactor drops your log line and nobody notices. Prove the signal fires: a unit test that the error contains the context, or an integration test that the metric increments / the log line appears.

# Unit test: the error carries the new context.
rg -n "#\[test\]|assert!|assert_eq!|contains" src/vmm/src/vstate/ | head
# Integration test: drive the failure, assert the metric/log.
rg -rn "metrics|log|assert|FC_metrics|fc.log|\.json" tests/integration_tests/functional/ | head

#![allow(unused)]
fn main() {
// Unit-test sketch: the improved error names the cause.
#[test]
fn kvm_open_error_is_actionable() {
    let e = Error::KvmOpen("failed to open /dev/kvm: Permission denied. Check ...".into());
    let msg = e.to_string();
    assert!(msg.contains("/dev/kvm"));
    assert!(msg.contains("kvm` group") || msg.contains("jailer"));  // actionable hint
}
}

For a metric, the integration test triggers the failure (e.g. submits a malformed block request) and asserts the counter in the metrics JSON went up. That assertion is what keeps your diagnostic alive across future refactors.

Step 6: Verify end to end and package the PR

Re-run your Step-3 reproduction and confirm the after signal actually helps — a reader who hits this boundary now learns the owning layer from one line. Then package it as a Firecracker PR per the contribution rules.

# After your change: re-trigger the failure and read the improved output.
# It should now name the syscall/errno/cause and point at the owning layer.

# House gates BEFORE you push (Level 2).
tools/devtool fmt
tools/devtool checkstyle
tools/devtool checkbuild --all
tools/devtool test -- <your new/affected tests>

# DCO sign-off on every commit; a CHANGELOG entry; ≤72-char title.
git commit -s -m "diagnostics: name /dev/kvm errno and owning layer on KVM open failure"

The PR description should show the before and after signal verbatim (the operator's view), explain which recurring misfiled-issue class it prevents, and note the test that guards it. That before/after, plus a test, is what makes a diagnostics PR an easy two maintainer approvals.

Implementation Requirements / Deliverables

• An inventory of the three diagnostic channels (log, metrics, serial) and where each is wired, with at least one concrete weak-signal boundary identified.
• The current ("before") output for your chosen boundary, captured verbatim from a real reproduction.
• A diagnostics improvement — a better boundary error message, a new metric, or better console capture — that is additive and behavior-preserving, matching the existing style.
• A test (unit or integration) that proves the new signal fires and carries the context.
• An "after" capture showing the improved signal naming the failing syscall/errno and the owning layer.
• The change packaged to Firecracker's bar: fmt/checkstyle/checkbuild clean, a DCO-signed commit, a CHANGELOG entry, and a PR description with before/after and the misfile class it prevents.

Troubleshooting

My change alters behavior, not just signal

Then it isn't a diagnostics PR — split it. Adding a warn! or a metric must not change what Firecracker does. If you found a real behavior bug while adding signal, fix it in a separate PR (and the diagnostic might be how you prove the fix in its test).

The error type doesn't carry a string / can't hold context

Many of Firecracker's errors are enums without a message field. Read how the surrounding errors are structured — you may need to add a variant or a context field, which is itself a reviewable improvement. Match the crate's error pattern (thiserror-style, Display impls) rather than inventing one.

Where do I increment a metric vs write a log line?

Rates and tallies (how often something happens — dropped descriptors, failed I/O, throttles) → a metric (machine-readable, aggregatable). A specific, contextual event a human needs to read (this open failed, with this errno, for this reason) → a log line. Boundary failures often want both: a metric to count and a warn!/error! to explain.

The guest's panic still isn't captured

Confirm console=ttyS0 is in the guest boot args and that you're capturing Firecracker's stdout/stderr. If the console output is being dropped under load or on shutdown, that buffering/flush behavior is itself the diagnostic bug to fix — see the serial device.

checkstyle/clippy rejects my change

Clippy is warnings-as-errors. Run tools/devtool fmt (it runs clippy --fix) and checkstyle locally before pushing; match the existing error/metric naming and the log level conventions in the file you touched.

Expected Output

A small, PR-ready diff that turns a weak boundary signal into an actionable one, with a test, presented as before/after:

BEFORE (operator sees):
  ERROR ... failed to start microVM

AFTER (operator sees):
  ERROR ... failed to open /dev/kvm: Permission denied (EACCES). Check that /dev/kvm
  exists and is accessible: are you in the `kvm` group? If running under the jailer,
  did it mknod /dev/kvm into the chroot? [host/jailer boundary]

TEST: kvm_open_error_is_actionable  ... ok

The "after" line resolves, by itself, a failure that previously sent an operator through the entire I4 decision tree.

Stretch Goals

1. A metric for a silent device drop. Find a place a virtio device drops or rejects a request without metering it, add the counter, and write the integration test that triggers a drop and asserts the count. Silent drops are a real diagnostic black hole.
2. Enrich an ioctl error with the errno and a cause hint. Pick a KVM ioctl whose failure is opaque and make its error name the ioctl, the errno, and the likely host/CPU-feature cause. Cross-reference the KVM ioctl cheat-sheet.
3. Snapshot version mismatch made legible. Improve the snapshot-load error so it reports the file's format version vs the binary's and which component mismatched (see snapshotting masterclass Lab 3).
4. A diagnose.sh companion. Pair your in-FC signal with the host-side layered-instrument script from I4, so the boundary is covered from both sides.
5. Find a real diagnostics issue. gh issue list --repo firecracker-microvm/firecracker --search "error message OR confusing OR unclear OR diagnostic in:title,body state:open" — pick one, improve the signal, and open the PR.

Validation / Self-check

Answer without notes; these gate completion:

1. Name Firecracker's three diagnostic channels and which boundary each is best for.
2. What makes a diagnostics change safe to review and merge? What disqualifies it from being one?
3. For a given boundary failure, how do you decide between a log line and a metric (or both)?
4. Why must a diagnostics improvement ship with a test, and what does the test assert?
5. Take the /dev/kvm EACCES case: what should the improved error name, and which layer does it point at?
6. Why are diagnostics PRs good first real contributions, and what does a strong one's PR description contain?
7. How does I6 "make the next attribution unnecessary" — what does upgrading a boundary signal remove permanently?

When you can find a weak boundary signal, improve it additively to name the failing syscall and the owning layer, prove it with a test, and package it to Firecracker's contribution bar, you've completed Lab I6 — and the cross-repo & integration section.

Next: you now attribute (I4), reproduce (I5), and instrument (I6) cross-component bugs — the full integration-contributor skill set. Take it into the release, review & governance section to understand how such contributions are reviewed and shipped, or put the whole curriculum together in the capstone — one real contribution cycle from issue to merged PR.