From 6a94f9d82d9637ed485a539676423daa3643a572 Mon Sep 17 00:00:00 2001 From: zackees Date: Thu, 2 Jul 2026 06:24:58 -0700 Subject: [PATCH 1/5] feat(ci): Docker Linux profiling harness for NightDriverStrip builds Phase 0 of the profiling-driven performance burndown. Adds ci/docker-profile/: ubuntu:24.04 image with soldr, perf, bpftrace and FlameGraph plus a sha-pinned NightDriverStrip checkout; an in-container scenario loop (cold / warm / hot cache, N iterations) that captures wall clock, FBUILD_PERF_LOG phase timelines, on-CPU cpu-clock flamegraphs and off-CPU sched_switch wait profiles; and a uv-run host orchestrator owning image build, named harness volumes and the summary table. ~/.fbuild is deliberately kept off all volumes so cold-cache runs are genuinely cold. Part of #942 Co-Authored-By: Claude Fable 5 --- .gitignore | 4 + ci/docker-profile/Dockerfile | 85 +++++++++++++ ci/docker-profile/README.md | 81 ++++++++++++ ci/docker-profile/offcpu.bt | 30 +++++ ci/docker-profile/profile_entry.sh | 197 +++++++++++++++++++++++++++++ ci/docker-profile/run_profile.py | 189 +++++++++++++++++++++++++++ 6 files changed, 586 insertions(+) create mode 100644 ci/docker-profile/Dockerfile create mode 100644 ci/docker-profile/README.md create mode 100644 ci/docker-profile/offcpu.bt create mode 100644 ci/docker-profile/profile_entry.sh create mode 100644 ci/docker-profile/run_profile.py diff --git a/.gitignore b/.gitignore index 54022d6a..14af1826 100644 --- a/.gitignore +++ b/.gitignore @@ -99,3 +99,7 @@ tasks/loop-runs/ # the captures are local-only and should never be checked in. port_scan_stderr*.txt port_scan_stdout*.txt + +# Profiling harness artifacts (FastLED/fbuild#942) - local-only measurement +# output: flamegraphs, perf.data, daemon logs, timing tables. +ci/docker-profile/out/ diff --git a/ci/docker-profile/Dockerfile b/ci/docker-profile/Dockerfile new file mode 100644 index 00000000..815326e6 --- /dev/null +++ b/ci/docker-profile/Dockerfile @@ -0,0 +1,85 @@ +# Linux profiling harness for fbuild builds of NightDriverStrip +# (FastLED/fbuild#942 Phase 0). +# +# The image carries the *tooling* only: soldr (which bootstraps the +# pinned Rust toolchain on first run), perf, bpftrace, FlameGraph, and +# a pinned NightDriverStrip checkout. fbuild itself is built at run +# time from the bind-mounted source tree so the harness always profiles +# the current working copy — no COPY of fbuild source here. +# +# Caching contract (see README.md): +# * PERSISTED across runs via named volumes: /work/target, ~/.cargo, +# ~/.rustup, ~/.soldr — these only make the *harness* fast. +# * NEVER persisted: ~/.fbuild (and ~/.platformio) — the system under +# test. It lives in the container filesystem and dies with the +# `--rm` container, so "cold cache" is genuinely cold. +# +# Build (from repo root): +# docker build -f ci/docker-profile/Dockerfile -t fbuild-profile-linux ci/docker-profile +# +# Run: use `uv run python ci/docker-profile/run_profile.py` — it owns +# the volume flags and privileged-mode setup. Don't hand-type them. + +# ubuntu:24.04 for the same reason as ci/docker-mac-cross: the +# published soldr linux-gnu binary requires glibc 2.39, and 24.04 +# matches the GHA `ubuntu-latest` runners. +FROM ubuntu:24.04 + +ENV DEBIAN_FRONTEND=noninteractive + +# Tooling set = docker-mac-cross baseline + profiling additions: +# linux-tools-generic → perf (invoked via /usr/lib/linux-tools-*/perf; +# the /usr/bin/perf wrapper refuses to run when +# `uname -r` doesn't match an installed linux-tools, +# which is always the case on WSL2 kernels) +# bpftrace → off-CPU wait profiling (sched_switch sums) +# time → /usr/bin/time -v resource capture per build +# procps → pkill for daemon teardown between scenarios +# perl → FlameGraph stackcollapse/flamegraph scripts +RUN apt-get update \ + && apt-get install -y --no-install-recommends \ + ca-certificates curl git xz-utils bzip2 zstd \ + python3 python3-pip python3-venv \ + build-essential pkg-config file \ + linux-tools-generic bpftrace time procps perl \ + && rm -rf /var/lib/apt/lists/* + +# uv for python ops (CLAUDE.md mandate). +RUN curl -LsSf https://astral.sh/uv/install.sh | sh \ + && cp /root/.local/bin/uv /usr/local/bin/ + +# Soldr binary tarball from GitHub Releases — same rationale and pin as +# ci/docker-mac-cross/Dockerfile (pip wheel is manylinux_2_39-tagged and +# falls back to a squatted placeholder on older glibc). +ARG SOLDR_VERSION=0.7.98 +RUN mkdir -p /opt/soldr-bin \ + && curl -fsSL \ + "https://github.com/zackees/soldr/releases/download/v${SOLDR_VERSION}/soldr-v${SOLDR_VERSION}-x86_64-unknown-linux-gnu.tar.zst" \ + | zstd -d --stdout \ + | tar -xf - -C /opt/soldr-bin \ + && for bin in soldr soldr-clang-shim cargo-chef crgx; do \ + [ -f "/opt/soldr-bin/$bin" ] && cp "/opt/soldr-bin/$bin" "/usr/local/bin/$bin" && chmod +x "/usr/local/bin/$bin"; \ + done \ + && soldr --version + +# Brendan Gregg's FlameGraph scripts (stackcollapse-perf.pl, +# stackcollapse-bpftrace.pl, flamegraph.pl). Shallow clone of master — +# these scripts have been stable for years and the repo is untagged. +RUN git clone --depth 1 https://github.com/brendangregg/FlameGraph.git /opt/FlameGraph + +# Benchmark workload: NightDriverStrip pinned to a fixed upstream sha so +# every profile run builds the identical source. env:demo is the target +# (esp32dev / registry espressif32@^6.12.0, WiFi+audio disabled). +# The checkout is a pristine template; profile_entry.sh copies it to a +# throwaway per-run directory so build output never contaminates it. +ARG NIGHTDRIVER_SHA=59113319200a62ffd39c91f7372b47e86df38bcc +RUN git clone https://github.com/PlummersSoftwareLLC/NightDriverStrip.git /opt/nightdriver \ + && git -C /opt/nightdriver checkout --detach "${NIGHTDRIVER_SHA}" \ + && rm -rf /opt/nightdriver/.git + +ENV HOME=/root \ + SOLDR_TRUST_MODE=permissive \ + CARGO_TERM_COLOR=always + +WORKDIR /work +CMD ["bash", "ci/docker-profile/profile_entry.sh"] diff --git a/ci/docker-profile/README.md b/ci/docker-profile/README.md new file mode 100644 index 00000000..23ecbd92 --- /dev/null +++ b/ci/docker-profile/README.md @@ -0,0 +1,81 @@ +# Docker profiling harness (FastLED/fbuild#942) + +Reproducible Linux profiling of `fbuild build` against a pinned +[NightDriverStrip](https://github.com/PlummersSoftwareLLC/NightDriverStrip) +checkout (`env:demo`, esp32dev). Produces wall-clock timings, on-CPU and +off-CPU flamegraphs, and `FBUILD_PERF_LOG` phase timelines for cold-, +warm-, and hot-cache builds. + +## Usage + +```bash +# from repo root — full matrix: cold+warm+hot, 3 iterations each +uv run python ci/docker-profile/run_profile.py + +# quick single cold run +uv run python ci/docker-profile/run_profile.py -n 1 --scenarios cold + +# housekeeping +uv run python ci/docker-profile/run_profile.py --status # harness volumes +uv run python ci/docker-profile/run_profile.py --wipe # drop them (next run rebuilds fbuild from scratch) +``` + +Artifacts land in `ci/docker-profile/out//` (gitignored): +`timings.jsonl` + `summary.md` (median wall clock per scenario), and per +run `oncpu.svg` / `offcpu.svg` flamegraphs, `.folded` stacks, raw +`perf.data` files, CLI logs, `daemon.log`, and extracted +`perf-log-lines.txt`. + +## Scenarios + +| scenario | fbuild cache (`~/.fbuild`) | project dir | measures | +|---|---|---|---| +| `cold` | wiped (+ `~/.platformio`), daemon killed | fresh copy | downloads, installs, full compile | +| `warm` | intact, daemon running | fresh copy | first build of a new project with a hot global cache — uncached work shows up here | +| `hot` | intact, daemon running | unchanged | no-op rebuild / fast-path overhead | + +Scenarios run in the order given per iteration; `warm`/`hot` assume +`cold` ran first in the same sequence (the default `cold,warm,hot` does +this per iteration). + +## Caching contract + +- **Persisted across runs** (named Docker volumes; only make the + *harness* fast): `/work/target`, `~/.cargo`, `~/.rustup`, `~/.soldr`. + Named volumes, not bind mounts, because Windows/WSL2 bind mounts + rewrite mtimes on every container start and bust cargo fingerprints. +- **Never persisted** (the system under test): `~/.fbuild` and + `~/.platformio` live in the container filesystem and die with the + `--rm` container. Cold means genuinely cold — fresh downloads. + +fbuild + fbuild-daemon are built inside the container from the +bind-mounted working copy with +`RUSTFLAGS="-C force-frame-pointers=yes -C debuginfo=2"` (clean perf +stacks; firmware compile flags are untouched — see the #942 constraint +that compile settings stay stock). + +## Profilers + +- **On-CPU**: `perf record -F 99 -e cpu-clock -g --call-graph fp -a` + (software clock event — WSL2 exposes no hardware PMU), rendered with + [FlameGraph](https://github.com/brendangregg/FlameGraph). +- **Off-CPU**: `offcpu.bt` (bpftrace, sums blocked µs per stack via + `sched:sched_switch`) rendered as `offcpu.svg`; plus a concurrent raw + `perf record -e sched:sched_switch` capture as fallback for WSL2 + kernels where bpftrace stack lookups come back empty. +- **Phase timeline**: `FBUILD_PERF_LOG=1` — summaries are emitted by + the daemon, so the harness harvests + `~/.fbuild/prod/daemon/daemon.log` per run. + +The container runs `--privileged` (perf_event_open + BPF on Docker +Desktop) and relaxes `kernel.perf_event_paranoid` best-effort. + +## Files + +- `Dockerfile` — ubuntu:24.04 + soldr (pinned release tarball, same + rationale as `ci/docker-mac-cross`), perf/bpftrace/FlameGraph, and + the NightDriverStrip checkout pinned to a fixed sha. +- `profile_entry.sh` — in-container scenario loop + samplers. +- `offcpu.bt` — bpftrace off-CPU program. +- `run_profile.py` — host orchestrator (image build, volumes, + `docker run`, summary table). diff --git a/ci/docker-profile/offcpu.bt b/ci/docker-profile/offcpu.bt new file mode 100644 index 00000000..efa71375 --- /dev/null +++ b/ci/docker-profile/offcpu.bt @@ -0,0 +1,30 @@ +// Off-CPU wait-time profiler (FastLED/fbuild#942). +// +// Sums microseconds each thread spends blocked (not runnable), keyed by +// comm + kernel/user stack at the point it went to sleep. Output feeds +// FlameGraph's stackcollapse-bpftrace.pl → offcpu.svg. +// +// prev_state != 0 filters to genuine blocking (D/S states); preemptions +// of still-runnable threads (state 0 / TASK_RUNNING) are excluded so the +// graph shows waiting, not scheduler churn. +// +// Best effort on WSL2 kernels: stack-id lookups can come back empty +// there, in which case profile_entry.sh falls back to the raw +// `perf -e sched:sched_switch` recording taken concurrently. + +tracepoint:sched:sched_switch +{ + if (args->prev_state != 0) { + @sleep_start[args->prev_pid] = nsecs; + } + $start = @sleep_start[args->next_pid]; + if ($start) { + @usecs[comm, kstack, ustack] = sum((nsecs - $start) / 1000); + delete(@sleep_start[args->next_pid]); + } +} + +END +{ + clear(@sleep_start); +} diff --git a/ci/docker-profile/profile_entry.sh b/ci/docker-profile/profile_entry.sh new file mode 100644 index 00000000..13cc029e --- /dev/null +++ b/ci/docker-profile/profile_entry.sh @@ -0,0 +1,197 @@ +#!/usr/bin/env bash +# In-container entry point for the fbuild profiling harness +# (FastLED/fbuild#942). Runs inside the fbuild-profile-linux image with +# the fbuild source bind-mounted at /work and an artifact dir at /out. +# +# Scenarios (each iterated FBUILD_PROFILE_ITERS times, default 3): +# cold — ~/.fbuild + ~/.platformio wiped, daemon killed, fresh +# project copy. Measures downloads + installs + full compile. +# warm — global cache intact, daemon running, but a FRESH project +# copy. Measures how much of a first build the global cache +# actually saves (uncached work shows up here). +# hot — immediate no-change rebuild of the same project copy. +# Measures fingerprint/fast-path overhead. +# +# Per scenario-iteration this captures: +# * wall clock + /usr/bin/time -v resource stats +# * full CLI stdout/stderr +# * ~/.fbuild/prod/daemon/daemon.log (FBUILD_PERF_LOG phase summaries +# are emitted by the daemon, not the CLI) +# * on-CPU: perf record -F 99 cpu-clock, system-wide, → flamegraph +# * off-CPU: bpftrace sched_switch wait-time sums (best effort on +# WSL2 kernels) + raw `perf -e sched:sched_switch` fallback data +set -uo pipefail + +ITERS="${FBUILD_PROFILE_ITERS:-3}" +SCENARIOS="${FBUILD_PROFILE_SCENARIOS:-cold,warm,hot}" +ENV_NAME="${FBUILD_PROFILE_ENV:-demo}" +BUILD_TIMEOUT="${FBUILD_PROFILE_BUILD_TIMEOUT:-5400}" +OUT=/out +TEMPLATE=/opt/nightdriver +PROJ=/tmp/nightdriver +FG=/opt/FlameGraph + +# Ubuntu's /usr/bin/perf wrapper refuses to run under a WSL2 kernel +# string; call the real binary directly. +PERF="$(ls -d /usr/lib/linux-tools-*/perf 2>/dev/null | head -1)" +if [[ -z "$PERF" ]]; then + echo "FATAL: no perf binary found under /usr/lib/linux-tools-*" >&2 + exit 1 +fi + +log() { echo "[profile $(date -u +%H:%M:%S)] $*"; } + +# ---------------------------------------------------------------- setup +log "relaxing perf/bpf restrictions (best effort)" +sysctl -qw kernel.perf_event_paranoid=-1 2>/dev/null || log "WARN: could not set perf_event_paranoid" +sysctl -qw kernel.kptr_restrict=0 2>/dev/null || true +mount -t debugfs debugfs /sys/kernel/debug 2>/dev/null || true + +log "building fbuild + fbuild-daemon from /work (soldr cargo, frame pointers on)" +cd /work +# Frame pointers + debuginfo make perf's fp unwinder produce clean +# stacks on WSL2 (dwarf unwinding there is unreliable). This changes +# fbuild's OWN build only — firmware compile flags are untouched. +export RUSTFLAGS="-C force-frame-pointers=yes -C debuginfo=2" +soldr cargo build --release -p fbuild-cli -p fbuild-daemon 2>&1 | tail -20 +build_rc=${PIPESTATUS[0]} +if [[ $build_rc -ne 0 ]]; then + echo "FATAL: fbuild build failed (rc=$build_rc)" >&2 + exit "$build_rc" +fi +unset RUSTFLAGS + +export PATH="/work/target/release:$PATH" +command -v fbuild >/dev/null || { echo "FATAL: fbuild not on PATH" >&2; exit 1; } +command -v fbuild-daemon >/dev/null || { echo "FATAL: fbuild-daemon not on PATH" >&2; exit 1; } +log "fbuild: $(fbuild --version 2>&1 | head -1)" + +# Everything the system-under-test caches must die with this container. +export FBUILD_PERF_LOG=1 +export RUST_LOG="${RUST_LOG:-info}" + +DAEMON_LOG="$HOME/.fbuild/prod/daemon/daemon.log" + +kill_daemon() { + pkill -f fbuild-daemon 2>/dev/null && sleep 1 || true +} + +wipe_fbuild_state() { + kill_daemon + rm -rf "$HOME/.fbuild" "$HOME/.platformio" +} + +fresh_project() { + rm -rf "$PROJ" + cp -r "$TEMPLATE" "$PROJ" +} + +git_sha() { git -C /work rev-parse --short HEAD 2>/dev/null || echo unknown; } + +mkdir -p "$OUT" +cat > "$OUT/meta.json" < "$OUT/timings.jsonl" + +# --------------------------------------------------------- one profiled run +run_one() { + local scenario="$1" iter="$2" + local dir="$OUT/${scenario}-${iter}" + mkdir -p "$dir" + log "=== $scenario iter $iter ===" + + # On-CPU sampler: system-wide so daemon + compiler subprocesses are + # all visible. cpu-clock because WSL2 exposes no hardware PMU. + "$PERF" record -F 99 -e cpu-clock -g --call-graph fp -a \ + -o "$dir/oncpu.data" -- sleep "$BUILD_TIMEOUT" &>/dev/null & + local oncpu_pid=$! + + # Off-CPU sampler #1: bpftrace sched_switch wait-time sums. Known + # to fail on some WSL2 kernels — best effort, fallback below. + bpftrace ci/docker-profile/offcpu.bt > "$dir/offcpu-bpftrace.txt" 2> "$dir/offcpu-bpftrace.err" & + local bpf_pid=$! + + # Off-CPU sampler #2 (fallback): raw sched_switch events via perf. + "$PERF" record -e sched:sched_switch -g --call-graph fp -a \ + -o "$dir/offcpu-sched.data" -- sleep "$BUILD_TIMEOUT" &>/dev/null & + local sched_pid=$! + + sleep 1 # let samplers attach + + local t0 t1 rc + t0=$(date +%s.%N) + timeout "$BUILD_TIMEOUT" /usr/bin/time -v -o "$dir/time-v.txt" \ + fbuild build "$PROJ" -e "$ENV_NAME" \ + > "$dir/cli-stdout.log" 2> "$dir/cli-stderr.log" + rc=$? + t1=$(date +%s.%N) + + # Stop samplers (perf flushes its file on SIGINT/SIGTERM). + kill -INT "$oncpu_pid" "$sched_pid" 2>/dev/null + kill -INT "$bpf_pid" 2>/dev/null + wait "$oncpu_pid" "$sched_pid" "$bpf_pid" 2>/dev/null + + local wall + wall=$(echo "$t1 $t0" | awk '{printf "%.2f", $1 - $2}') + echo "{\"scenario\": \"$scenario\", \"iter\": $iter, \"wall_s\": $wall, \"exit\": $rc}" >> "$OUT/timings.jsonl" + log "$scenario iter $iter: ${wall}s (exit $rc)" + + # The FBUILD_PERF_LOG phase summary is emitted by whichever process + # owns the timer — usually the daemon → daemon.log. + [[ -f "$DAEMON_LOG" ]] && cp "$DAEMON_LOG" "$dir/daemon.log" + grep -h "perf-log" "$dir/cli-stderr.log" "$dir/daemon.log" 2>/dev/null > "$dir/perf-log-lines.txt" || true + + # Flamegraphs (best effort — never fail the run over rendering). + ( + cd "$dir" + "$PERF" script -i oncpu.data 2>/dev/null \ + | "$FG/stackcollapse-perf.pl" > oncpu.folded 2>/dev/null + [[ -s oncpu.folded ]] && "$FG/flamegraph.pl" --title "$scenario-$iter on-CPU" \ + oncpu.folded > oncpu.svg 2>/dev/null + if [[ -s offcpu-bpftrace.txt ]]; then + "$FG/stackcollapse-bpftrace.pl" offcpu-bpftrace.txt > offcpu.folded 2>/dev/null + [[ -s offcpu.folded ]] && "$FG/flamegraph.pl" --color=io --countname=us \ + --title "$scenario-$iter off-CPU" offcpu.folded > offcpu.svg 2>/dev/null + fi + # Raw sched data is kept for offline analysis; a rendered + # flamegraph from switch counts alone would be misleading. + rm -f oncpu.data.old + ) || true + + return "$rc" +} + +# ------------------------------------------------------------- main loop +overall_rc=0 +IFS=',' read -ra WANT <<< "$SCENARIOS" +for iter in $(seq 1 "$ITERS"); do + for scenario in "${WANT[@]}"; do + case "$scenario" in + cold) + wipe_fbuild_state + fresh_project + ;; + warm) + fresh_project + ;; + hot) + # no-op rebuild: same project, same cache, daemon up. + # Guard for a hot-only invocation with no prior copy. + [[ -d "$PROJ" ]] || fresh_project + ;; + *) + log "unknown scenario '$scenario', skipping" + continue + ;; + esac + run_one "$scenario" "$iter" || overall_rc=1 + done +done + +kill_daemon +log "done. artifacts in $OUT (timings.jsonl, per-run dirs)" +cat "$OUT/timings.jsonl" +exit "$overall_rc" diff --git a/ci/docker-profile/run_profile.py b/ci/docker-profile/run_profile.py new file mode 100644 index 00000000..c3bc2cc2 --- /dev/null +++ b/ci/docker-profile/run_profile.py @@ -0,0 +1,189 @@ +#!/usr/bin/env python3 +"""Host orchestrator for the fbuild Docker profiling harness (FastLED/fbuild#942). + +Builds the fbuild-profile-linux image, wires up the named volumes that +keep the *harness* fast across runs (cargo/rustup/soldr homes and the +fbuild target dir), and runs the profiled build scenarios in a +privileged Linux container. The system under test's own cache +(~/.fbuild inside the container) is deliberately NOT on any volume, so +every container start is a genuinely cold fbuild cache. + +Usage (from repo root): + uv run python ci/docker-profile/run_profile.py # cold+warm+hot, 3 iters + uv run python ci/docker-profile/run_profile.py --iterations 1 --scenarios cold + uv run python ci/docker-profile/run_profile.py --wipe # drop harness volumes + uv run python ci/docker-profile/run_profile.py --status # show volumes + +Artifacts land in ci/docker-profile/out// (gitignored): +timings.jsonl, per-run flamegraphs (oncpu.svg / offcpu.svg), folded +stacks, daemon logs, FBUILD_PERF_LOG phase lines, and summary.md. +""" + +from __future__ import annotations + +import argparse +import datetime as _dt +import json +import os +import statistics +import subprocess +import sys +from pathlib import Path + +IMAGE = "fbuild-profile-linux" +REPO_ROOT = Path(__file__).resolve().parent.parent.parent +HARNESS_DIR = Path(__file__).resolve().parent + +# Named volumes: build-state caches for the HARNESS ONLY (never the +# fbuild cache under test). Host bind mounts are not an option for +# these on Windows/WSL2 — the 9P layer rewrites mtimes on every +# container start, busting cargo's fingerprints and forcing full +# rebuilds of fbuild itself. +VOLUMES = { + "fbuild-profile-target": "/work/target", + "fbuild-profile-cargo-home": "/root/.cargo", + "fbuild-profile-rustup-home": "/root/.rustup", + "fbuild-profile-soldr-home": "/root/.soldr", +} + + +def run(cmd: list[str], **kw) -> subprocess.CompletedProcess: + print(f"$ {' '.join(cmd)}", flush=True) + return subprocess.run(cmd, **kw) + + +def docker_env() -> dict[str, str]: + env = os.environ.copy() + # Stop Git-Bash from rewriting /work into a Windows path before + # docker sees it. + env.setdefault("MSYS_NO_PATHCONV", "1") + return env + + +def build_image(rebuild: bool) -> None: + cmd = ["docker", "build", "-f", str(HARNESS_DIR / "Dockerfile"), "-t", IMAGE] + if rebuild: + cmd.append("--no-cache") + cmd.append(str(HARNESS_DIR)) + rc = run(cmd, env=docker_env()).returncode + if rc != 0: + sys.exit(rc) + + +def ensure_volumes() -> None: + for name in VOLUMES: + run(["docker", "volume", "create", name], env=docker_env(), + stdout=subprocess.DEVNULL) + + +def wipe_volumes() -> None: + for name in VOLUMES: + run(["docker", "volume", "rm", "--force", name], env=docker_env()) + + +def show_status() -> None: + for name, mount in VOLUMES.items(): + r = run(["docker", "volume", "inspect", name, "--format", + "{{.Name}} -> {{.Mountpoint}}"], + env=docker_env(), capture_output=True, text=True) + state = r.stdout.strip() if r.returncode == 0 else "(absent)" + print(f" {name} @ {mount}: {state}") + + +def run_container(out_dir: Path, iterations: int, scenarios: str, + env_name: str) -> int: + cmd = [ + "docker", "run", "--rm", "--init", + # perf_event_open + BPF need privileged on Docker Desktop/WSL2. + "--privileged", + "-v", f"{REPO_ROOT}:/work", + "-v", f"{out_dir}:/out", + ] + for name, mount in VOLUMES.items(): + cmd += ["-v", f"{name}:{mount}"] + cmd += [ + "-e", f"FBUILD_PROFILE_ITERS={iterations}", + "-e", f"FBUILD_PROFILE_SCENARIOS={scenarios}", + "-e", f"FBUILD_PROFILE_ENV={env_name}", + "-w", "/work", + IMAGE, + "bash", "ci/docker-profile/profile_entry.sh", + ] + # No -t: mintty/Git-Bash fools isatty() and docker then errors with + # "the input device is not a TTY". + return run(cmd, env=docker_env()).returncode + + +def summarize(out_dir: Path) -> None: + timings = out_dir / "timings.jsonl" + if not timings.exists(): + print("no timings.jsonl produced — container failed early?") + return + by_scenario: dict[str, list[float]] = {} + failures: dict[str, int] = {} + for line in timings.read_text().splitlines(): + if not line.strip(): + continue + rec = json.loads(line) + by_scenario.setdefault(rec["scenario"], []).append(rec["wall_s"]) + if rec["exit"] != 0: + failures[rec["scenario"]] = failures.get(rec["scenario"], 0) + 1 + + lines = ["# fbuild profile summary", ""] + meta = out_dir / "meta.json" + if meta.exists(): + lines += [f"```json\n{meta.read_text().strip()}\n```", ""] + lines += ["| scenario | runs | median s | min s | max s | failures |", + "|---|---|---|---|---|---|"] + for scenario, walls in by_scenario.items(): + lines.append( + f"| {scenario} | {len(walls)} | {statistics.median(walls):.1f} " + f"| {min(walls):.1f} | {max(walls):.1f} " + f"| {failures.get(scenario, 0)} |") + text = "\n".join(lines) + "\n" + (out_dir / "summary.md").write_text(text) + print(text) + + +def main() -> int: + ap = argparse.ArgumentParser(description=__doc__.splitlines()[0]) + ap.add_argument("--iterations", "-n", type=int, default=3) + ap.add_argument("--scenarios", default="cold,warm,hot", + help="comma list of cold,warm,hot") + ap.add_argument("--env", dest="env_name", default="demo", + help="platformio env to build (default: demo)") + ap.add_argument("--out", type=Path, default=None, + help="artifact dir (default ci/docker-profile/out/)") + ap.add_argument("--rebuild-image", action="store_true", + help="docker build --no-cache") + ap.add_argument("--skip-image", action="store_true", + help="reuse existing image without rebuilding layers") + ap.add_argument("--wipe", action="store_true", + help="remove harness volumes and exit") + ap.add_argument("--status", action="store_true", + help="show harness volume state and exit") + args = ap.parse_args() + + if args.wipe: + wipe_volumes() + return 0 + if args.status: + show_status() + return 0 + + out_dir = args.out or (HARNESS_DIR / "out" / + _dt.datetime.now().strftime("%Y%m%d-%H%M%S")) + out_dir.mkdir(parents=True, exist_ok=True) + + if not args.skip_image: + build_image(args.rebuild_image) + ensure_volumes() + rc = run_container(out_dir.resolve(), args.iterations, args.scenarios, + args.env_name) + summarize(out_dir) + print(f"artifacts: {out_dir}") + return rc + + +if __name__ == "__main__": + sys.exit(main()) From 8d9c26fa53af155c26367dd6c3428de23acdd0d6 Mon Sep 17 00:00:00 2001 From: zackees Date: Thu, 2 Jul 2026 12:05:03 -0700 Subject: [PATCH 2/5] fix(ci): harden profile harness bootstrap (toolchain ensure, OOM retry, hot-only guard) soldr's 60s no-output watchdog killed the first-run rustup toolchain download, and full-parallel rustc with debuginfo=2 can OOM small Docker VMs; ensure the toolchain explicitly, raise the watchdog, and resume with -j2 on build failure. Also make a hot-only invocation create its project copy instead of failing. Part of #942 Co-Authored-By: Claude Fable 5 --- ci/docker-profile/profile_entry.sh | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/ci/docker-profile/profile_entry.sh b/ci/docker-profile/profile_entry.sh index 13cc029e..82e54c12 100644 --- a/ci/docker-profile/profile_entry.sh +++ b/ci/docker-profile/profile_entry.sh @@ -47,14 +47,28 @@ sysctl -qw kernel.perf_event_paranoid=-1 2>/dev/null || log "WARN: could not set sysctl -qw kernel.kptr_restrict=0 2>/dev/null || true mount -t debugfs debugfs /sys/kernel/debug 2>/dev/null || true -log "building fbuild + fbuild-daemon from /work (soldr cargo, frame pointers on)" +# The pinned toolchain download can exceed soldr's default 60s +# no-output watchdog on first run; ensure it explicitly (same pattern +# as ci/docker-mac-cross/build.sh) with a generous timeout. +export SOLDR_COMMAND_OUTPUT_TIMEOUT_SECS="${SOLDR_COMMAND_OUTPUT_TIMEOUT_SECS:-1800}" cd /work +log "ensuring rust toolchain (soldr toolchain ensure)" +soldr toolchain ensure 2>&1 | tail -5 + +log "building fbuild + fbuild-daemon from /work (soldr cargo, frame pointers on)" # Frame pointers + debuginfo make perf's fp unwinder produce clean # stacks on WSL2 (dwarf unwinding there is unreliable). This changes # fbuild's OWN build only — firmware compile flags are untouched. export RUSTFLAGS="-C force-frame-pointers=yes -C debuginfo=2" soldr cargo build --release -p fbuild-cli -p fbuild-daemon 2>&1 | tail -20 build_rc=${PIPESTATUS[0]} +if [[ $build_rc -ne 0 ]]; then + # Full-parallel rustc with debuginfo=2 can OOM small Docker VMs; + # a -j2 resume finishes the survivors instead of aborting the run. + log "fbuild build failed (rc=$build_rc), retrying with -j2" + soldr cargo build --release -j 2 -p fbuild-cli -p fbuild-daemon 2>&1 | tail -20 + build_rc=${PIPESTATUS[0]} +fi if [[ $build_rc -ne 0 ]]; then echo "FATAL: fbuild build failed (rc=$build_rc)" >&2 exit "$build_rc" From f848f8c2c43b139b62d68696698a9bf92c652ec1 Mon Sep 17 00:00:00 2001 From: zackees Date: Thu, 2 Jul 2026 13:37:36 -0700 Subject: [PATCH 3/5] fix(ci): add esptool + machine-id to profiling image The demo build's elf2image step shells out to esptool (not yet a managed fbuild package), and the running-process broker wants a machine id for user identity; provide both in the image. Part of #942 Co-Authored-By: Claude Fable 5 --- ci/docker-profile/Dockerfile | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/ci/docker-profile/Dockerfile b/ci/docker-profile/Dockerfile index 815326e6..cf9e0a68 100644 --- a/ci/docker-profile/Dockerfile +++ b/ci/docker-profile/Dockerfile @@ -48,6 +48,17 @@ RUN apt-get update \ RUN curl -LsSf https://astral.sh/uv/install.sh | sh \ && cp /root/.local/bin/uv /usr/local/bin/ +# esptool: fbuild's ESP32 path shells out to it for elf2image (it is not +# yet a managed fbuild package — see #942 findings). uv-managed install +# with the console script linked onto PATH. +RUN uv tool install esptool \ + && ln -s /root/.local/bin/esptool* /usr/local/bin/ \ + && esptool version | head -1 + +# The running-process broker derives user identity from the machine id; +# containers have none by default and fbuild logs a fallback warning. +RUN test -f /etc/machine-id || cat /proc/sys/kernel/random/uuid | tr -d '-\n' > /etc/machine-id + # Soldr binary tarball from GitHub Releases — same rationale and pin as # ci/docker-mac-cross/Dockerfile (pip wheel is manylinux_2_39-tagged and # falls back to a squatted placeholder on older glibc). From de659ecc1cafa38e9cf775ccf0c27d744249a593 Mon Sep 17 00:00:00 2001 From: zackees Date: Thu, 2 Jul 2026 16:02:25 -0700 Subject: [PATCH 4/5] fix(ci): record perf data to container-local scratch, not the 9P bind mount perf record dies with 'failed to write perf data: Bad address' when its mmap-backed output file lives on the Windows bind mount, which silently zeroed every on-CPU capture in the first baseline. Record to /tmp scratch, render flamegraphs there, and copy only the folded stacks, SVGs, a gzipped sched excerpt, and sampler stderr to /out. Part of #942 Co-Authored-By: Claude Fable 5 --- ci/docker-profile/README.md | 9 ++++++--- ci/docker-profile/profile_entry.sh | 30 +++++++++++++++++++++--------- 2 files changed, 27 insertions(+), 12 deletions(-) diff --git a/ci/docker-profile/README.md b/ci/docker-profile/README.md index 23ecbd92..e162ed8b 100644 --- a/ci/docker-profile/README.md +++ b/ci/docker-profile/README.md @@ -22,9 +22,12 @@ uv run python ci/docker-profile/run_profile.py --wipe # drop them (next run Artifacts land in `ci/docker-profile/out//` (gitignored): `timings.jsonl` + `summary.md` (median wall clock per scenario), and per -run `oncpu.svg` / `offcpu.svg` flamegraphs, `.folded` stacks, raw -`perf.data` files, CLI logs, `daemon.log`, and extracted -`perf-log-lines.txt`. +run `oncpu.svg` / `offcpu.svg` flamegraphs, `.folded` stacks, a gzipped +`perf script` excerpt of the sched capture, CLI logs, `daemon.log`, and +extracted `perf-log-lines.txt`. Raw `perf.data` files stay inside the +container (perf cannot write its mmap-backed output onto the 9P Windows +bind mount, and they run to hundreds of MB — the folded stacks carry +the analysis-relevant content). ## Scenarios diff --git a/ci/docker-profile/profile_entry.sh b/ci/docker-profile/profile_entry.sh index 82e54c12..05fc4637 100644 --- a/ci/docker-profile/profile_entry.sh +++ b/ci/docker-profile/profile_entry.sh @@ -114,13 +114,18 @@ EOF run_one() { local scenario="$1" iter="$2" local dir="$OUT/${scenario}-${iter}" - mkdir -p "$dir" + # perf record cannot write its mmap-backed data file onto the 9P + # Windows bind mount ("failed to write perf data, error: Bad + # address") — record into container-local scratch and copy the + # rendered products to /out afterwards. + local scratch="/tmp/prof-${scenario}-${iter}" + mkdir -p "$dir" "$scratch" log "=== $scenario iter $iter ===" # On-CPU sampler: system-wide so daemon + compiler subprocesses are # all visible. cpu-clock because WSL2 exposes no hardware PMU. "$PERF" record -F 99 -e cpu-clock -g --call-graph fp -a \ - -o "$dir/oncpu.data" -- sleep "$BUILD_TIMEOUT" &>/dev/null & + -o "$scratch/oncpu.data" -- sleep "$BUILD_TIMEOUT" > "$dir/oncpu.perf.err" 2>&1 & local oncpu_pid=$! # Off-CPU sampler #1: bpftrace sched_switch wait-time sums. Known @@ -130,7 +135,7 @@ run_one() { # Off-CPU sampler #2 (fallback): raw sched_switch events via perf. "$PERF" record -e sched:sched_switch -g --call-graph fp -a \ - -o "$dir/offcpu-sched.data" -- sleep "$BUILD_TIMEOUT" &>/dev/null & + -o "$scratch/offcpu-sched.data" -- sleep "$BUILD_TIMEOUT" > "$dir/offcpu-sched.perf.err" 2>&1 & local sched_pid=$! sleep 1 # let samplers attach @@ -159,21 +164,28 @@ run_one() { grep -h "perf-log" "$dir/cli-stderr.log" "$dir/daemon.log" 2>/dev/null > "$dir/perf-log-lines.txt" || true # Flamegraphs (best effort — never fail the run over rendering). + # Render in scratch, copy products to /out; the raw perf.data files + # stay in the container (they can reach hundreds of MB per run and + # the folded stacks carry the analysis-relevant content). ( - cd "$dir" + cd "$scratch" "$PERF" script -i oncpu.data 2>/dev/null \ | "$FG/stackcollapse-perf.pl" > oncpu.folded 2>/dev/null [[ -s oncpu.folded ]] && "$FG/flamegraph.pl" --title "$scenario-$iter on-CPU" \ oncpu.folded > oncpu.svg 2>/dev/null - if [[ -s offcpu-bpftrace.txt ]]; then - "$FG/stackcollapse-bpftrace.pl" offcpu-bpftrace.txt > offcpu.folded 2>/dev/null + if [[ -s "$dir/offcpu-bpftrace.txt" ]]; then + "$FG/stackcollapse-bpftrace.pl" "$dir/offcpu-bpftrace.txt" > offcpu.folded 2>/dev/null [[ -s offcpu.folded ]] && "$FG/flamegraph.pl" --color=io --countname=us \ --title "$scenario-$iter off-CPU" offcpu.folded > offcpu.svg 2>/dev/null fi - # Raw sched data is kept for offline analysis; a rendered - # flamegraph from switch counts alone would be misleading. - rm -f oncpu.data.old + "$PERF" script -i offcpu-sched.data 2>/dev/null | head -200000 \ + | gzip > sched-script.txt.gz 2>/dev/null + for f in oncpu.folded oncpu.svg offcpu.folded offcpu.svg sched-script.txt.gz; do + [[ -s "$f" ]] && cp "$f" "$dir/" + done + true ) || true + rm -rf "$scratch" return "$rc" } From 26d317be9891a7eb9940fe073ccb2c5c56203b7b Mon Sep 17 00:00:00 2001 From: zackees Date: Thu, 2 Jul 2026 16:36:32 -0700 Subject: [PATCH 5/5] fix(ci): attribute off-CPU time to the sleeping task's own stack; guard cd /work CodeRabbit review: comm/kstack/ustack were read at wakeup time, so blocked intervals were bucketed under the waker's context. Capture them when the task goes to sleep (prev side of sched_switch, where current context IS the sleeper) and key the sum with the stored values. Also fail fast if /work is missing. Co-Authored-By: Claude Fable 5 --- ci/docker-profile/offcpu.bt | 20 +++++++++++++++++--- ci/docker-profile/profile_entry.sh | 2 +- 2 files changed, 18 insertions(+), 4 deletions(-) diff --git a/ci/docker-profile/offcpu.bt b/ci/docker-profile/offcpu.bt index efa71375..3f00fafe 100644 --- a/ci/docker-profile/offcpu.bt +++ b/ci/docker-profile/offcpu.bt @@ -1,8 +1,11 @@ // Off-CPU wait-time profiler (FastLED/fbuild#942). // // Sums microseconds each thread spends blocked (not runnable), keyed by -// comm + kernel/user stack at the point it went to sleep. Output feeds -// FlameGraph's stackcollapse-bpftrace.pl → offcpu.svg. +// comm + kernel/user stack captured AT THE POINT IT WENT TO SLEEP (at +// sched_switch the current context is the outgoing prev task, so that +// is where its sleep-site stack is visible; the wakeup edge only knows +// the waker's context). Output feeds stackcollapse-bpftrace.pl → +// offcpu.svg. // // prev_state != 0 filters to genuine blocking (D/S states); preemptions // of still-runnable threads (state 0 / TASK_RUNNING) are excluded so the @@ -16,15 +19,26 @@ tracepoint:sched:sched_switch { if (args->prev_state != 0) { @sleep_start[args->prev_pid] = nsecs; + @sleep_comm[args->prev_pid] = comm; + @sleep_kstack[args->prev_pid] = kstack; + @sleep_ustack[args->prev_pid] = ustack; } $start = @sleep_start[args->next_pid]; if ($start) { - @usecs[comm, kstack, ustack] = sum((nsecs - $start) / 1000); + @usecs[@sleep_comm[args->next_pid], + @sleep_kstack[args->next_pid], + @sleep_ustack[args->next_pid]] = sum((nsecs - $start) / 1000); delete(@sleep_start[args->next_pid]); + delete(@sleep_comm[args->next_pid]); + delete(@sleep_kstack[args->next_pid]); + delete(@sleep_ustack[args->next_pid]); } } END { clear(@sleep_start); + clear(@sleep_comm); + clear(@sleep_kstack); + clear(@sleep_ustack); } diff --git a/ci/docker-profile/profile_entry.sh b/ci/docker-profile/profile_entry.sh index 05fc4637..dd3cd1c8 100644 --- a/ci/docker-profile/profile_entry.sh +++ b/ci/docker-profile/profile_entry.sh @@ -51,7 +51,7 @@ mount -t debugfs debugfs /sys/kernel/debug 2>/dev/null || true # no-output watchdog on first run; ensure it explicitly (same pattern # as ci/docker-mac-cross/build.sh) with a generous timeout. export SOLDR_COMMAND_OUTPUT_TIMEOUT_SECS="${SOLDR_COMMAND_OUTPUT_TIMEOUT_SECS:-1800}" -cd /work +cd /work || { echo "FATAL: could not cd to /work" >&2; exit 1; } log "ensuring rust toolchain (soldr toolchain ensure)" soldr toolchain ensure 2>&1 | tail -5