From 41cdc347f169731c1673683018fe65a7b31d3bbf Mon Sep 17 00:00:00 2001 From: ejc3 Date: Tue, 27 Oct 2026 13:58:14 +0000 Subject: [PATCH 1/3] warm-root: list the prefetch from a launch that restores the snapshot On the first host booted from the ce08eee9 AMI the prefetch list held 6163 files (334 MiB) and fcvm-fleet-prefetch.service ran for 20 s (17.8 s of CPU) beside cloud-init-local (9.3 s, against 7.4 s on the image before) and the store (13.6 s, against 10.8 s). warm-root.sh traced its only launch, which also boots the VM and exports the image into root's podman store, so the list held image layers no slot reads. On a leased g4dn.metal, the traced launch of a slot that restores the snapshot read 120 files (124 MiB). warm-root.sh now launches twice: the first takes the pre-start snapshot, the second runs under strace, must log a pre-start snapshot hit, and is what the list comes from. Test: fleet/ami/check.sh asserts the traced launch follows an untraced one and the hit is checked (fails against the previous warm-root.sh). the_ami_warm_up_launches_its_vm_as_a_slot_is_launched passes. --- fleet/ami/check.sh | 7 ++++++ fleet/ami/host/warm-root.sh | 45 ++++++++++++++++++++++++------------- 2 files changed, 36 insertions(+), 16 deletions(-) diff --git a/fleet/ami/check.sh b/fleet/ami/check.sh index 16aee022c..dcb28290a 100644 --- a/fleet/ami/check.sh +++ b/fleet/ami/check.sh @@ -233,6 +233,13 @@ grep -qx 'DefaultDependencies=no' fleet/ami/host/fcvm-fleet-prefetch.service && no "fcvm-fleet-prefetch.service must start once local file systems are up (DefaultDependencies=no)" sed -n '/^prep)/,/;;/p' fleet/ami/host/build.sh | grep -qE '^ systemctl enable .*fcvm-fleet-prefetch\.service' || no "host/build.sh prep does not enable fcvm-fleet-prefetch.service" +# warm-root.sh lists the prefetch from a launch that restores the snapshot (what a woken +# host's slots run), not from the first launch, which also boots and exports the image. +wr=fleet/ami/host/warm-root.sh +first=$(grep -n '^launch ||' "$wr" | head -1 | cut -d: -f1) +traced=$(grep -n '^launch trace ||' "$wr" | head -1 | cut -d: -f1) +[ -n "$first" ] && [ -n "$traced" ] && [ "$first" -lt "$traced" ] && grep -q "Pre-start snapshot hit" "$wr" || + no "warm-root.sh must list the prefetch from a second, traced launch that hits the first one's snapshot" # prefetch.sh reads every listed file in 1 MiB pieces (a file of 2 MiB and one byte is three # pieces) and skips a listed file the image lacks. pf=$(mktemp -d) diff --git a/fleet/ami/host/warm-root.sh b/fleet/ami/host/warm-root.sh index 90c76765d..6234f8640 100755 --- a/fleet/ami/host/warm-root.sh +++ b/fleet/ami/host/warm-root.sh @@ -39,23 +39,36 @@ P=$(curl -fsS -H "X-aws-ec2-metadata-token: $T" "http://169.254.169.254/latest/m [ -n "$P" ] || { echo "warm-root: this instance has no IPv6 prefix (build-ami.sh launch host gives it one)"; exit 1; } # The agent's slot address: the prefix with the GPU index plus two in its last group. A=$(python3 -c 'import ipaddress,sys; print(ipaddress.ip_network(sys.argv[1], strict=False).network_address + 2)' "$P") -t0=$(date +%s%N) -setsid strace -f -qq --seccomp-bpf -e trace=openat,execve -o /tmp/warm-root.strace \ - fcvm podman run --name warm-root --kernel-profile gpu --gpu "$G" --publish 127.0.0.1:20099:8080 \ - --network routed --ipv6-prefix "$P" --ipv6-address "$A" --publish 127.0.0.1:20098:443 \ - --map "$TLS_DIR":/run/fleet-tls:ro --env TLS_CERT_FILE=/run/fleet-tls/tls.json --env TLS_PORT=443 "$IMG" \ - > "$LOG" 2>&1 < /dev/null & -WP=$! -ok=0 -for _ in $(seq 1 1800); do - if curl -fsS -m 2 http://127.0.0.1:20099/health 2>/dev/null | jq -e '.ready == true and .frame > 0' >/dev/null 2>&1; then ok=1; break; fi - kill -0 $WP 2>/dev/null || break - sleep 1 -done -echo "warm-root: ok=$ok first_frame_ms=$(( ($(date +%s%N) - t0) / 1000000 )) gpu=$G" -pkill -TERM -x fcvm; wait $WP +# One launch, as the agent launches a slot; with "trace", under strace into /tmp/warm-root.strace. +launch() { + local trace=() + [ "${1:-}" = trace ] && trace=(strace -f -qq --seccomp-bpf -e "trace=openat,execve" -o /tmp/warm-root.strace) + local t0; t0=$(date +%s%N) + setsid "${trace[@]}" \ + fcvm podman run --name warm-root --kernel-profile gpu --gpu "$G" --publish 127.0.0.1:20099:8080 \ + --network routed --ipv6-prefix "$P" --ipv6-address "$A" --publish 127.0.0.1:20098:443 \ + --map "$TLS_DIR":/run/fleet-tls:ro --env TLS_CERT_FILE=/run/fleet-tls/tls.json --env TLS_PORT=443 "$IMG" \ + >> "$LOG" 2>&1 < /dev/null & + local wp=$! ok=0 + for _ in $(seq 1 1800); do + if curl -fsS -m 2 http://127.0.0.1:20099/health 2>/dev/null | jq -e '.ready == true and .frame > 0' >/dev/null 2>&1; then ok=1; break; fi + kill -0 $wp 2>/dev/null || break + sleep 1 + done + echo "warm-root: ${1:-launch} ok=$ok first_frame_ms=$(( ($(date +%s%N) - t0) / 1000000 )) gpu=$G" + pkill -TERM -x fcvm; wait $wp + [ $ok = 1 ] || { tail -20 "$LOG"; return 1; } +} +# The first launch boots the VM and takes the pre-start snapshot (and exports the image for +# root's podman store). The list comes from a second launch, which restores that snapshot +# as a woken host's slots do: listed from the first, it named 6163 files (334 MiB, mostly +# image layers the export read) that the prefetch then read for 20 s at every boot, beside +# cloud-init and the store (2026-10-27). +: > "$LOG" +launch || { rm -rf "$TLS_DIR"; exit 1; } +launch trace || { rm -rf "$TLS_DIR"; exit 1; } rm -rf "$TLS_DIR" -[ $ok = 1 ] || { tail -20 "$LOG"; exit 1; } +grep -q 'Pre-start snapshot hit' "$LOG" || { echo "warm-root: the second launch did not restore the first one's snapshot"; exit 1; } grep -oE '(openat\([^"]*|execve\()"[^"]+"' /tmp/warm-root.strace | sed -E 's/.*"([^"]+)"$/\1/' | grep '^/' | grep -vE '^/(proc|sys|dev|run|tmp|mnt/fcvm-btrfs)/' | sort -u | while read -r f; do [ -f "$f" ] && echo "$f"; done > "$LIST" From 8acd837c92f7972785eace41072a537715bddeb0 Mon Sep 17 00:00:00 2001 From: ejc3 Date: Tue, 27 Oct 2026 14:19:04 +0000 Subject: [PATCH 2/3] warm-root: launch at info so the snapshot hit is in the log fcvm's default filter is warn and it logs 'Pre-start snapshot hit' at info, so the hit check would fail every AMI build after two good launches (Codex, #1397). The launches set RUST_LOG=info. Test: fleet/ami/check.sh requires RUST_LOG=info on the launches (fails against 41cdc347). --- fleet/ami/check.sh | 4 +++- fleet/ami/host/warm-root.sh | 3 ++- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/fleet/ami/check.sh b/fleet/ami/check.sh index dcb28290a..deeab77ce 100644 --- a/fleet/ami/check.sh +++ b/fleet/ami/check.sh @@ -238,7 +238,9 @@ sed -n '/^prep)/,/;;/p' fleet/ami/host/build.sh | grep -qE '^ systemctl enable wr=fleet/ami/host/warm-root.sh first=$(grep -n '^launch ||' "$wr" | head -1 | cut -d: -f1) traced=$(grep -n '^launch trace ||' "$wr" | head -1 | cut -d: -f1) -[ -n "$first" ] && [ -n "$traced" ] && [ "$first" -lt "$traced" ] && grep -q "Pre-start snapshot hit" "$wr" || +# fcvm logs the hit at info and its default filter is warn: the launches set RUST_LOG. +[ -n "$first" ] && [ -n "$traced" ] && [ "$first" -lt "$traced" ] && grep -q "Pre-start snapshot hit" "$wr" && + grep -qE 'RUST_LOG=[^ ]*info[^ ]* +"\$\{trace\[@\]\}"|RUST_LOG=info' "$wr" || no "warm-root.sh must list the prefetch from a second, traced launch that hits the first one's snapshot" # prefetch.sh reads every listed file in 1 MiB pieces (a file of 2 MiB and one byte is three # pieces) and skips a listed file the image lacks. diff --git a/fleet/ami/host/warm-root.sh b/fleet/ami/host/warm-root.sh index 6234f8640..d2ff4dcfd 100755 --- a/fleet/ami/host/warm-root.sh +++ b/fleet/ami/host/warm-root.sh @@ -40,11 +40,12 @@ P=$(curl -fsS -H "X-aws-ec2-metadata-token: $T" "http://169.254.169.254/latest/m # The agent's slot address: the prefix with the GPU index plus two in its last group. A=$(python3 -c 'import ipaddress,sys; print(ipaddress.ip_network(sys.argv[1], strict=False).network_address + 2)' "$P") # One launch, as the agent launches a slot; with "trace", under strace into /tmp/warm-root.strace. +# At info, so the log says whether the launch restored a snapshot (fcvm defaults to warn). launch() { local trace=() [ "${1:-}" = trace ] && trace=(strace -f -qq --seccomp-bpf -e "trace=openat,execve" -o /tmp/warm-root.strace) local t0; t0=$(date +%s%N) - setsid "${trace[@]}" \ + RUST_LOG=info setsid "${trace[@]}" \ fcvm podman run --name warm-root --kernel-profile gpu --gpu "$G" --publish 127.0.0.1:20099:8080 \ --network routed --ipv6-prefix "$P" --ipv6-address "$A" --publish 127.0.0.1:20098:443 \ --map "$TLS_DIR":/run/fleet-tls:ro --env TLS_CERT_FILE=/run/fleet-tls/tls.json --env TLS_PORT=443 "$IMG" \ From 76eed0e81534cd41df4458e8ab64ba8956c6a31e Mon Sep 17 00:00:00 2001 From: ejc3 Date: Tue, 27 Oct 2026 14:40:07 +0000 Subject: [PATCH 3/3] warm-root: require the traced launch to restore, not fall back fcvm logs 'Pre-start snapshot hit' before it loads the snapshot, and a load that fails is logged as 'Snapshot miss' and cold-boots, which also reaches a first frame (Codex, #1397). Each launch now logs to its own file, and the traced launch's must hold the hit and no miss. Test: fleet/ami/check.sh requires that check (fails against 8acd837c). --- fleet/ami/check.sh | 5 ++++- fleet/ami/host/warm-root.sh | 12 ++++++++---- 2 files changed, 12 insertions(+), 5 deletions(-) diff --git a/fleet/ami/check.sh b/fleet/ami/check.sh index deeab77ce..d716ced23 100644 --- a/fleet/ami/check.sh +++ b/fleet/ami/check.sh @@ -239,7 +239,10 @@ wr=fleet/ami/host/warm-root.sh first=$(grep -n '^launch ||' "$wr" | head -1 | cut -d: -f1) traced=$(grep -n '^launch trace ||' "$wr" | head -1 | cut -d: -f1) # fcvm logs the hit at info and its default filter is warn: the launches set RUST_LOG. -[ -n "$first" ] && [ -n "$traced" ] && [ "$first" -lt "$traced" ] && grep -q "Pre-start snapshot hit" "$wr" && +# A hit is logged before the load, and a failed load falls back to a cold boot: the traced +# launch's own log must hold the hit and no miss. +[ -n "$first" ] && [ -n "$traced" ] && [ "$first" -lt "$traced" ] && + grep -qF "grep -q 'Pre-start snapshot hit' \"\$LOG.trace\" && ! grep -q 'Snapshot miss' \"\$LOG.trace\"" "$wr" && grep -qE 'RUST_LOG=[^ ]*info[^ ]* +"\$\{trace\[@\]\}"|RUST_LOG=info' "$wr" || no "warm-root.sh must list the prefetch from a second, traced launch that hits the first one's snapshot" # prefetch.sh reads every listed file in 1 MiB pieces (a file of 2 MiB and one byte is three diff --git a/fleet/ami/host/warm-root.sh b/fleet/ami/host/warm-root.sh index d2ff4dcfd..9fc594246 100755 --- a/fleet/ami/host/warm-root.sh +++ b/fleet/ami/host/warm-root.sh @@ -49,7 +49,7 @@ launch() { fcvm podman run --name warm-root --kernel-profile gpu --gpu "$G" --publish 127.0.0.1:20099:8080 \ --network routed --ipv6-prefix "$P" --ipv6-address "$A" --publish 127.0.0.1:20098:443 \ --map "$TLS_DIR":/run/fleet-tls:ro --env TLS_CERT_FILE=/run/fleet-tls/tls.json --env TLS_PORT=443 "$IMG" \ - >> "$LOG" 2>&1 < /dev/null & + > "$LOG.${1:-launch}" 2>&1 < /dev/null & local wp=$! ok=0 for _ in $(seq 1 1800); do if curl -fsS -m 2 http://127.0.0.1:20099/health 2>/dev/null | jq -e '.ready == true and .frame > 0' >/dev/null 2>&1; then ok=1; break; fi @@ -58,18 +58,22 @@ launch() { done echo "warm-root: ${1:-launch} ok=$ok first_frame_ms=$(( ($(date +%s%N) - t0) / 1000000 )) gpu=$G" pkill -TERM -x fcvm; wait $wp - [ $ok = 1 ] || { tail -20 "$LOG"; return 1; } + cat "$LOG.${1:-launch}" >> "$LOG" + [ $ok = 1 ] || { tail -20 "$LOG.${1:-launch}"; return 1; } } # The first launch boots the VM and takes the pre-start snapshot (and exports the image for # root's podman store). The list comes from a second launch, which restores that snapshot # as a woken host's slots do: listed from the first, it named 6163 files (334 MiB, mostly # image layers the export read) that the prefetch then read for 20 s at every boot, beside # cloud-init and the store (2026-10-27). -: > "$LOG" +: > "$LOG"; rm -f "$LOG.launch" "$LOG.trace" launch || { rm -rf "$TLS_DIR"; exit 1; } launch trace || { rm -rf "$TLS_DIR"; exit 1; } rm -rf "$TLS_DIR" -grep -q 'Pre-start snapshot hit' "$LOG" || { echo "warm-root: the second launch did not restore the first one's snapshot"; exit 1; } +# The traced launch must have restored the snapshot. fcvm logs the hit before it loads the +# snapshot, and a load that fails is logged as a miss and cold-boots instead. +{ grep -q 'Pre-start snapshot hit' "$LOG.trace" && ! grep -q 'Snapshot miss' "$LOG.trace"; } || + { echo "warm-root: the traced launch did not restore the first one's snapshot"; exit 1; } grep -oE '(openat\([^"]*|execve\()"[^"]+"' /tmp/warm-root.strace | sed -E 's/.*"([^"]+)"$/\1/' | grep '^/' | grep -vE '^/(proc|sys|dev|run|tmp|mnt/fcvm-btrfs)/' | sort -u | while read -r f; do [ -f "$f" ] && echo "$f"; done > "$LIST"