Lab 1: Measure and optimize boot time

Background

The < 125 ms boot budget is the most-watched number in Firecracker, and the project measures it with a beautifully minimal trick: a pseudo BootTimer device. Firecracker captures a start timestamp at InstanceStart; the guest, instrumented at the very end of its boot, writes a single magic byte to a known MMIO address; the BootTimer device catches that write, computes now - start_ts, and logs Guest-boot-time = N us. That single MMIO write — negligible overhead, no clock skew between host and guest — is the project's ground truth for "how long until the guest was ready." The pytest performance suite drives this end to end and asserts the result is within spec, which is how a boot-time regression fails CI.

This lab makes you the measurement. You will boot a microVM and read the Guest-boot-time log line, run the test_boottime.py harness, find the magic byte and the device in the source, break the boot time into its critical-path phases, experiment with real levers (kernel config, fewer devices, the cmdline, and snapshots that skip boot entirely), and finally introduce a regression and detect it against a baseline — while telling real regressions apart from run-to-run noise. Every claim in the boot-time engineering essay becomes a number you produced.

Why This Matters for Contributors

Boot time is a defended number: a change that adds 10 ms to boot is a regression even if it ships a useful feature, and the maintainers will ask what your PR does to the boot-time test. "I didn't check" is not an answer. A contributor who can measure boot to userspace, attribute the time to a phase, quantify a lever, and present a distribution with pinned context is exactly who can credibly touch the boot path — kernel loading, device attachment, cmdline defaults, vCPU setup. This lab is the reps that produce that. It also teaches the measurement discipline that the whole performance intensive depends on: baseline, iterate, separate signal from noise, explain.

Prerequisites

• You completed Level 9, Lab 9.3 and the performance-density overview readiness check.
• A working firecracker binary, a vmlinux-* kernel, and a rootfs whose init writes the boot-complete magic byte (the CI rootfs does; a stock distro may not — see Troubleshooting).
• The pytest performance harness runnable: tools/devtool test -- integration_tests/performance/.
• Read Boot-Time Optimization.

# The BootTimer device and the boot-time test exist on your branch.
rg -n "BootTimer|MAGIC_VALUE_SIGNAL_GUEST_BOOT_COMPLETE|Guest-boot-time|start_ts" \
  src/vmm/src/devices/pseudo/boot_timer.rs
ls tests/integration_tests/performance/test_boottime.py

Step-by-Step Tasks

Step 1 — Find the BootTimer device and the magic byte

Before measuring, read the mechanism. The device handles a single-byte write at offset zero; if the byte is the magic value (123 — verify on your branch), it computes the elapsed time and logs it.

# The device, the magic value, the offset, and the log line.
rg -n "BootTimer|MAGIC_VALUE_SIGNAL_GUEST_BOOT_COMPLETE|123|offset|Guest-boot-time|now|start_ts|Instant" \
  src/vmm/src/devices/pseudo/boot_timer.rs

# Where the device is attached and where start_ts is captured at InstanceStart.
rg -n "BootTimer|boot_timer|start_ts|TimestampUs|attach" src/vmm/src/builder.rs src/vmm/src/

You should be able to state: the magic value (verify — the essay says 123), that the write is a single byte at offset 0, that start_ts is captured when the microVM starts, and that the device logs both wall-clock and CPU time. This is the contract you'll rely on for every number in this lab.

Step 2 — Boot a microVM and read Guest-boot-time

Boot with the logger pointed at a file, then grep the boot-time line. Keep the device set minimal (no extra net/drives you don't need — they're on the critical path).

API=/tmp/fc.sock
rm -f "$API" /tmp/fc.log; touch /tmp/fc.log
sudo ./firecracker --api-sock "$API" &

# Point the logger at a file so we can grep the boot-time line.
curl -X PUT --unix-socket "$API" --data '{"log_path":"/tmp/fc.log","level":"Info"}' http://localhost/logger

curl -X PUT --unix-socket "$API" --data \
 '{"kernel_image_path":"./vmlinux-6.1.x","boot_args":"console=ttyS0 reboot=k panic=1 pci=off nomodule 8250.nr_uarts=0 i8042.noaux i8042.nomux i8042.nopnp i8042.dumbkbd"}' \
 http://localhost/boot-source
curl -X PUT --unix-socket "$API" --data \
 '{"drive_id":"rootfs","path_on_host":"./ubuntu-24.04.ext4","is_root_device":true,"is_read_only":false}' \
 http://localhost/drives/rootfs
curl -X PUT --unix-socket "$API" --data '{"vcpu_count":1,"mem_size_mib":256}' http://localhost/machine-config
curl -X PUT --unix-socket "$API" --data '{"action_type":"InstanceStart"}' http://localhost/actions

sleep 2
grep "Guest-boot-time" /tmp/fc.log
# Guest-boot-time = 98765 us, ... (CPU: NNN us)   <-- your boot-to-userspace number

That number is boot from InstanceStart (vCPU enters KVM_RUN) to the guest writing the magic byte. Record it with the full context (kernel, rootfs, boot args, host) — a boot-time number without that is unfalsifiable.

Step 3 — Run the regression harness

The hand measurement is one sample; the harness runs many and asserts the spec. Run it and read what it pins.

# The boot-time integration test — the actual regression gate.
sed -n '1,80p' tests/integration_tests/performance/test_boottime.py
rg -n "DEFAULT_BOOT_ARGS|boot_args|Guest-boot-time|threshold|assert|vcpu|mem" \
  tests/integration_tests/performance/test_boottime.py

./tools/devtool test -- integration_tests/performance/test_boottime.py 2>&1 | tail -30

Note what the test does that your hand measurement didn't: it pins specific guest kernels and a known boot-args string, runs multiple configurations (vCPU count, memory), parses the Guest-boot-time log line, and asserts it's under a threshold. The pinning is the point — it makes the number reproducible and a regression detectable.

Step 4 — Break the critical path into phases

A single number hides where time goes. The boot is three qualitatively different phases; attribute time to each.

  InstanceStart
        │
        ▼   ── Firecracker host userspace (you control this) ──
   Phase 1: VMM setup    parse+copy vmlinux ELF · build zero page/e820 · create vCPUs
                         · set long-mode registers · attach minimal devices · register guest RAM
        │
        ▼   ── guest kernel (you influence via config/cmdline) ──
   Phase 2: kernel init  NO decompress (uncompressed vmlinux) · probe few MMIO devices (no PCI)
                         · init drivers · mount rootfs · page-table setup
        │
        ▼   ── userspace (the workload's concern) ──
   Phase 3: init→app     init system · your application · first useful work (magic byte written here)

Attribute the phases:

# Phase 1 boundaries: when does the vCPU first enter KVM_RUN vs when is setup done?
rg -n "fn load_kernel|configure_system|setup_boot|build_microvm_for_boot|create_vcpus|InstanceStart" \
  src/vmm/src/builder.rs src/vmm/src/arch/x86_64/ | head

# Phase 2: add `loglevel=8` / drop `quiet` to the guest cmdline to get kernel timestamps,
#   then read dmesg-style timing inside the guest (the [    0.xxxxx] stamps):
#   boot_args: "console=ttyS0 reboot=k panic=1 pci=off loglevel=7 printk.time=1"
# In the guest after boot:
#   dmesg | tail -40    # the last [   N.NNN] stamp ≈ kernel-init end; compare to Guest-boot-time

The lesson: Phase 1 is Firecracker's code (and where VMM efficiency shows), Phase 2 is the guest kernel (shaped by the device model, boot protocol, and cmdline), Phase 3 is the workload's. The < 125 ms budget is dominated by 1 and 2, and almost every lever attacks one of them. Knowing which phase a regression lands in tells you whether to look at builder.rs or the guest config.

Step 5 — Experiment with the levers, quantify each

Now change one variable at a time, re-measure, and record the delta. Each row is a lever from the essay.

# Example: measure WITHOUT the cmdline optimizations (re-enable the slow probes) and compare.
#   boot_args: "console=ttyS0 reboot=k panic=1"   (no nomodule / nr_uarts / i8042 tuning)
# Re-run Steps 2 for each variant; record Guest-boot-time each time. ONE variable per run.

# The cmdline tokens the project's own test uses — every token cuts something:
rg -n "DEFAULT_BOOT_ARGS|nomodule|nr_uarts|i8042|cryptomgr" tests/integration_tests/performance/test_boottime.py
ls resources/guest_configs/

For each lever, write down: the baseline, the variant, the delta, and why (which phase, which init path). A lever you measured but can't explain isn't understood.

Step 6 — Snapshots: bypass boot entirely

The most dramatic "boot-time" technique is not booting. A snapshot restore reconstructs an already-booted microVM, skipping all three phases. Measure restore latency against your cold-boot number.

# Boot, snapshot (pause → create → resume), then restore a fresh microVM and time it.
# (Full snapshot flow is in Level 9, Lab 9.2; here just compare the latencies.)
curl -X PATCH --unix-socket "$API" --data '{"state":"Paused"}' http://localhost/vm
curl -X PUT --unix-socket "$API" --data \
 '{"snapshot_path":"/tmp/snap.file","mem_file_path":"/tmp/snap.mem","snapshot_type":"Full"}' \
 http://localhost/snapshot/create

# New process, restore, time to resume:
API2=/tmp/fc2.sock; rm -f "$API2"; sudo ./firecracker --api-sock "$API2" &
T0=$(date +%s%N)
curl -X PUT --unix-socket "$API2" --data \
 '{"snapshot_path":"/tmp/snap.file","mem_backend":{"backend_path":"/tmp/snap.mem","backend_type":"File"},"resume_vm":true}' \
 http://localhost/snapshot/load
T1=$(date +%s%N); echo "restore: $(( (T1-T0)/1000000 )) ms"

cold boot:   [ VMM setup ][ kernel init ][ userspace init ] → ready   (~tens–125 ms)
snapshot:    [ map state + on-demand pages ]                → ready   (~single-digit ms)

The restore should be an order of magnitude faster than cold boot. This is why, for production serverless, boot-time optimization and snapshotting are two halves of one strategy: optimize the boot you do pay (first launch + snapshot build), then amortize it across every cold start via restore.

Step 7 — Introduce and detect a regression

Finally, simulate the thing the harness defends against. Make boot slower deliberately (the easiest way without code: a fat cmdline + an extra device), establish that the harness or your hand measurement catches it, and prove it's a real regression and not noise.

# 1. Baseline: run your hand measurement (or the harness) N times, record the distribution.
for i in $(seq 1 7); do
  # ... re-boot with the OPTIMIZED config, grep Guest-boot-time, collect ...
  grep "Guest-boot-time" /tmp/fc.log | tail -1
done

# 2. Regress: boot with the de-optimized cmdline (Step 5), N times, record.
# 3. Compare distributions: is the median shift > the run-to-run spread?

Warning: Boot-time benchmarks are noisy — CPU frequency scaling, a cold page cache, a busy host, or NUMA effects can swamp the signal. Run multiple iterations, pin CPUs (taskset), warm the cache, and compare distributions. A "regression" that is within run-to-run noise is not a regression — reporting one is a classic beginner error a reviewer will catch.

Implementation Requirements / Deliverables

• The BootTimer magic value, offset, and log line located in the source.
• A Guest-boot-time number read from a hand boot, with full context recorded.
• test_boottime.py run; an explanation of what it pins and why.
• The boot broken into Phase 1/2/3 with time attributed to each (even approximately).
• At least three levers measured, each with baseline, variant, delta, and a why.
• A snapshot restore timed against cold boot, with the order-of-magnitude gap explained.
• A deliberately introduced regression detected against a baseline, with a distribution that separates signal from noise.

Troubleshooting

No Guest-boot-time line in the log

The guest's init didn't write the magic byte — a stock distro rootfs isn't instrumented for it. Use a CI/test rootfs (the suite ships one), or add a tiny init step in the guest that writes byte 123 to the BootTimer MMIO address. Confirm the device is attached: rg -n "BootTimer|boot_timer" src/vmm/src/builder.rs. Without the write, the measurement mechanism simply never fires.

Boot-time numbers swing wildly run to run

Noise. Pin CPUs (taskset -c 2,3 ./firecracker ...), disable frequency scaling (cpupower frequency-set -g performance), warm the page cache (boot once and discard), and run on a quiet host. Report the median and spread over ≥5 runs, not a single value.

The harness fails to find a kernel/rootfs

test_boottime.py pins specific artifacts. rg -n "vmlinux|rootfs|artifact|microvm" tests/integration_tests/performance/test_boottime.py to see what it expects, and make sure the test artifacts are present (the CI fetches them; locally you may need to provide them).

Restore is not faster than cold boot

Likely the memory file is being fully read eagerly, or the snapshot includes far more touched pages than a fresh boot needs. Confirm backend_type:"File" (or try UFFD for on-demand paging per Level 9), and measure to resume, not to first request. The win comes from on-demand page loading.

Phase attribution doesn't add up to the total

The phases overlap and the boundaries are fuzzy (Firecracker setup vs vCPU first instruction vs kernel first timestamp). Don't chase exactness — attribute time qualitatively (which phase dominates) and use the kernel printk.time=1 stamps as a guide for the Phase 2 boundary.

Expected Output

$ grep "Guest-boot-time" /tmp/fc.log
Guest-boot-time = 96213 us, ... (CPU: 41872 us)

# Lever deltas (illustrative — YOUR host's numbers will differ):
optimized cmdline:        ~96 ms median
de-optimized cmdline:    ~140 ms median   <-- re-enabled serial/i8042/module probes
snapshot restore:          ~6 ms          <-- bypassed all three phases

Stretch Goals

1. Attribute the cmdline tokens individually. Remove 8250.nr_uarts=0, i8042.*, nomodule, and cryptomgr.notests one at a time; measure each token's individual cost. Which one buys the most?
2. Boot-time across kernel versions. Run the harness against two pinned vmlinux versions and explain any difference (driver changes, init path changes).
3. Wall-clock vs CPU divergence. Find a change that increases CPU time while wall-clock barely moves on an idle host (the BootTimer logs both). Why does CPU time matter for density even when wall-clock hides it?
4. A guest-config diet. Build a leaner guest kernel from resources/guest_configs/ (drop a driver the microVM never uses) and quantify the Phase 2 saving.
5. Find a boot-time issue. gh issue list --repo firecracker-microvm/firecracker --search "boot OR boottime OR latency in:title state:open" — reproduce one and propose a measurement.

Validation / Self-check

Answer without notes; these gate completion:

1. Describe the BootTimer mechanism end to end: what is captured at InstanceStart, what the guest does, what the device computes, and what it logs. What is the magic byte?
2. Name the three boot phases, who owns each, and which two dominate the < 125 ms budget.
3. Pick three cmdline tokens and say what guest-kernel init path each one disables.
4. Why is a snapshot restore an order of magnitude faster than cold boot? What is restore latency bounded by?
5. You measure a 12 ms boot-time increase after a change. What must you establish before calling it a regression, and how do you separate signal from noise?
6. Why does the boot-time test pin the exact kernel, rootfs, and boot args? What would an unpinned benchmark fail to detect?
7. A PR adds a device to the boot path. What will the maintainers ask, and how do you answer it with a number?

Next: Lab 2: Oversubscription and density — take the per-microVM cost you just measured and multiply it by thousands: launch many microVMs on one host, measure aggregate overhead, reclaim with the balloon, and reason about the >20× statistical bet.