From b2262e5dc658b2fcdf3ec74adb3db4d85843e720 Mon Sep 17 00:00:00 2001 From: igneum-labs <337424239+igneum-labs@users.noreply.github.com> Date: Tue, 6 Oct 2026 21:40:07 +0000 Subject: [PATCH] Build box: every red run classified and kept, pre-flight before the slot, one run per worktree, box reds in the red-run file, a 09:00 UK digest The box's 34 red rows of 6 October classified (docs/analysis/ci-failures-2026-10-06.md section 6): 22 iterations, 12 in three real classes (instant deaths with nothing kept, a shared worktree directory, an unread dry run). remote-run.sh now: pre-flight (subcommand, manifest, -p package, --features) refuses in a second with exit 3 and a class; the last 400 lines of every run kept in /srv/builds/_log/runs; a class on every row (compile-error, link-error, test-failure, instant, no-test-matched, slot-timeout, no-dir, preflight-*); a cargo test whose filter matched no test exits 3; a per-worktree lock in checkout and run mode; every red row appended to /srv/ci-red/red.jsonl as source box. red-watch.mjs never posts a box row alone and sends one digest a day (counts per class with each class's guard); the timer runs tick. Shared group cired on the box so the runner and build append to one file. Shown in a sandbox on the box: pass, failing test, empty filter, bad package, bad feature, missing subcommand, compile error, broken manifest, two concurrent runs of one worktree. Co-Authored-By: Claude Fable 5.1 --- docs/analysis/ci-failures-2026-10-06.md | 46 ++++++- .../build-server/ci-red/igneum-ci-red.service | 6 +- infra/build-server/ci-red/install.sh | 7 +- infra/build-server/provision.sh | 9 +- infra/build-server/remote-run.sh | 122 +++++++++++++++++- tools/ci/red-watch.mjs | 112 +++++++++++++++- 6 files changed, 282 insertions(+), 20 deletions(-) diff --git a/docs/analysis/ci-failures-2026-10-06.md b/docs/analysis/ci-failures-2026-10-06.md index 26f19e40..324a5053 100644 --- a/docs/analysis/ci-failures-2026-10-06.md +++ b/docs/analysis/ci-failures-2026-10-06.md @@ -109,8 +109,52 @@ run drops from about three minutes to about one. The hosted runner then serves o pipeline (MSVC, WebView2, Inno Setup, PowerShell 5.1, which a Linux box cannot provide). The flip is main's call after the 0.3.15 cut, per build-server.md section 7.1. -## 6. What belongs on another branch +## 6. The build box's own red rows (the project lead, 22:3x UK: "also make sure we are fixing and learning from all the errors here") + +Source: `/srv/builds/_log/builds.jsonl` on igneum-build-1, 139 rows from the first build at 18:38 UK to 22:11 UK on +6 October; 34 with a non-zero exit. Until this change the box kept no output of a run (it streamed to the agent's terminal), +so a red row could not be read afterwards; the classes below are from exit code, duration, compile count and what the next +row of the same worktree did. Times UK. "Iteration" = the same worktree and kind green inside ten minutes. + +| Time | Worktree, kind | Exit, secs, compiles | What it was | Kind | Would a local pre-check have saved the round trip | Guard now | +|---|---|---|---|---|---|---| +| 18:49:12 | build-server, suite `--lib jobbuild` on app/igneum-app | 101, 0 s, 0 | Instant death: `--lib` on a crate whose tests live in the bin (the next row, `--bin`, was green the same minute) | real class: instant | Yes, one second | pre-flight and the kept run log; class `instant` on the row and in the red-run file | +| 19:22:14, 19:51:09 | ship0314 then ship0315, prove `--features igneum-prove-host/cuda` | 101, 0 s, 0 (twice) | Instant death, the same command twice on two branches: the feature name (nothing on the box kept the message) | real class: failed the same way twice, instant | Yes | pre-flight refuses a feature the package does not have (`preflight-feature`, exit 3, before the slot) | +| 19:26:01 | master, check `-p igneum-prove-core` | 101, 0 s, 0 | Instant death: the package name (no such member) | real class: instant | Yes | pre-flight refuses a `-p` that names nothing (`preflight-package`) | +| 19:27:26, 19:27:54 | master, prove | 101, 0 s, 0; then 101, 55 s, 605 | An instant death, then a compile error; green 4 min later | iteration (with one instant) | The instant one, yes | as above; `compile-error` class with the run log kept | +| 19:35:56, 19:42:36, 19:48:37, 19:58:12, 21:02:56, 21:47:14 | ship0315, suite and node-linux | 101, 19 to 66 s, 44 to 724 compiles | The shipper's 0.3.15 node fixes: compile and test failures, each green within 1 to 8 min | iteration | No: a Mac check takes 12 to 18 min, the box IS the pre-check | run log kept; class `compile-error` or `test-failure` | +| 19:51:09 | ship0315, suite | 2, no duration | `no-dir`: the crate directory was not there, because a second run of the same worktree started in the same second and its checkout was replacing the tree | real class: a shared resource (one worktree directory, two runs) | n/a | one run per worktree directory at a time: `remote-run.sh` takes a per-worktree lock in checkout and run mode and waits (shown: the second of two concurrent runs waited and both finished) | +| 19:50:57, 19:52:50 | ca3-v4-node, suite | 101, 12 s and 7 s | Test failures while fixing; green 2 min and 0 min later | iteration | No | run log kept | +| 20:45:55 | box-work, night battery dry run | 1, 234 s | The night battery's dry-run subset failed in the box-work agent's hands; its output was on that agent's side | one-off, unread | n/a | the run log is kept from now on; the night battery writes its own report | +| 21:01:12 | build-server, `self-test-repro` | 1, 0 s | The repro self-test's first version; green 1 min later | iteration | n/a | none needed | +| 21:17:57 | ca3-v4-node, `cargo audit` | 2, 0 s, 0 | Instant death: cargo-audit is not installed on the box | real class: a missing tool, instant | Yes | pre-flight refuses a cargo subcommand the box does not have (`preflight-subcommand`); the install belongs in provision.sh (open: add cargo-audit there, the night battery runs it) | +| 21:17:58 to 21:26:42 | finality-pause, two suites alternating | 101, 4 to 26 s | Six reds, the same two commands three times each while the finality pause tests were being fixed; green 2 to 11 min after each | iteration (the first pair outside ten minutes) | No | run log kept; the digest counts the class | +| 21:45:13, 21:46:06 | box-capacity, node-linux p2p-probe | 101, 39 s and 3 s | Compile errors; green 1 min and 0 min later | iteration | No | run log kept | +| 21:58:26 | ca3-v4-node, check | 101, 12 s | Compile error; green 1 min later | iteration | No | run log kept | +| 22:00:08, 22:06:11, 22:08:16 | ca3-v4-node, suite (`finality`, then `clock_rule_v3 a_pause_carries ...`) | 101, 24, 13, 12 s, 22 compiles | The clock rule v3 tests failing while being fixed; green at 22:10 | iteration | No | run log kept | +| 22:08:52, 22:08:55, 22:08:57 | ca3-v4-node, three suites in five seconds | 101, 0 s, 0 (three times) | Three instant deaths in a row with nothing compiled: cargo refused before building (a manifest or lock the overlay carried mid-edit, or a name); the three commands were green one minute later, so the tree was fixed under them | real class: instant, failed the same way three times | Yes, one second each | pre-flight (manifest, package, feature, subcommand) before the slot; class `instant` flagged; the run log kept so the next one is read, not guessed | +| 22:11:38 | ca3-v4-node, check `--tests` | 101, 49 s, 844 | A compile error in the test targets; still red when the log was read | iteration, open | No | run log kept | + +Sum: 34 red rows. 22 are iteration (an agent taking a red to green inside ten minutes, the box doing the compile the Mac +cannot do in time). 12 are real classes, in three families: instant deaths (8 rows: a feature, a package, a target, a +tool, and three unread), a shared worktree directory (1 row), and the night battery's unread dry run (1 row, plus two +instant ones inside iterations). Every real class now has a guard in `infra/build-server/remote-run.sh`, shown on the box +in a sandbox (a pass, a failing test, an empty filter, a missing package, a missing feature, a missing subcommand, a compile +error, a broken manifest, two concurrent runs of one worktree): + +| Guard | What it does | Class it stops | +|---|---|---| +| pre-flight | before the slot's time is spent: `cargo ` exists, the manifest parses (`cargo metadata --no-deps`), every `-p` is a member or a dependency, every `--features pkg/feat` exists; a refusal is exit 3 in about a second with the reason | instant (manifest, package, feature, tool) | +| kept output | the last 400 lines of every run in `/srv/builds/_log/runs/.log`, named in the row (`run_log`) | every unread class | +| class on the row | `class` in builds.jsonl: compile-error, link-error, test-failure, instant, slot-timeout, no-dir, no-test-matched, preflight-*, other | the digest can count what kind of red it was | +| no-test-matched | a `cargo test` with a filter that ran 0 tests in every binary exits 3 instead of a green "0 tests" | a wasted round trip that read as ok | +| one run per worktree | a per-worktree lock in checkout and run mode; the second waits up to 2 h and says so | no-dir, the half-replaced tree | +| the red-run file | every red row is appended to `/srv/ci-red/red.jsonl` (the file the CI watcher writes), `"source":"box"`; not posted alone | | +| the daily digest | at the first pass at or after 09:00 London, one line to the updates channel: reds in 24 h, CI and box, per class, with each class's guard | the learning, read once a day | + +## 7. What belongs on another branch | Branch | One-line change | |---|---| +| build-server (provision.sh) | install cargo-audit for the build user (the night battery and the ca3 lane call it; pre-flight now refuses it with a clear line instead of a 0-second exit 2) | | release-0.3.15 | take master (or cherry-pick 2bd3bec): `infra/build-server/repro/rebuild-on-box.sh` re-stamps its clones, else the copied-sources step fails again at the next push. Its own `tools/ci/windows-paths-check.sh` (c25a3ca) is superseded by master's: on merge keep master's file and drop the extra ci.yml step, the gate runs it | diff --git a/infra/build-server/ci-red/igneum-ci-red.service b/infra/build-server/ci-red/igneum-ci-red.service index 79b8700d..56d08aed 100644 --- a/infra/build-server/ci-red/igneum-ci-red.service +++ b/infra/build-server/ci-red/igneum-ci-red.service @@ -2,7 +2,9 @@ # The workflow's `red` job (ci.yml, windows.yml; runs on this box's runner after a failed master or release-* run) appends # one JSON line per run to /srv/ci-red/red.jsonl as the runner user. This pass, as build, posts every line not yet posted # to the hidden updates channel (DISCORD_WEBHOOK_UPDATES in /srv/discord-hooks/env) and records the run id in -# /srv/discord-hooks/ci-red-posted.json. One line per run, however many passes. `journalctl -u igneum-ci-red -n 30`. +# /srv/discord-hooks/ci-red-posted.json. One line per run, however many passes. Box rows (remote-run.sh, "source":"box") +# are never posted alone; the first pass at or after 09:00 London posts the day's digest (counts per class with each class's +# guard). `journalctl -u igneum-ci-red -n 30`. # Installed by infra/build-server/ci-red/install.sh. [Unit] Description=Igneum CI red watcher (post failed master and release runs to the updates channel) @@ -18,7 +20,7 @@ Environment=PATH=/usr/local/bin:/usr/bin:/bin Environment=IGNEUM_DISCORD_ENV=/srv/discord-hooks/env Environment=IGNEUM_CI_RED_STATE=/srv/discord-hooks/ci-red-posted.json WorkingDirectory=/srv/discord-hooks -ExecStart=/usr/local/bin/node /srv/discord-hooks/bin/red-watch.mjs post --file /srv/ci-red/red.jsonl --live +ExecStart=/usr/local/bin/node /srv/discord-hooks/bin/red-watch.mjs tick --file /srv/ci-red/red.jsonl --live TimeoutStartSec=50 Nice=10 # the unit reads one secret file; nothing else on the box may diff --git a/infra/build-server/ci-red/install.sh b/infra/build-server/ci-red/install.sh index 7e111eca..a1bb7bc5 100644 --- a/infra/build-server/ci-red/install.sh +++ b/infra/build-server/ci-red/install.sh @@ -2,8 +2,9 @@ # Install or refresh the CI red watcher's poster on igneum-build-1 from this Mac. # infra/build-server/ci-red/install.sh (re-run whenever tools/ci/red-watch.mjs or the units change) # Copies tools/ci/red-watch.mjs to /srv/discord-hooks/bin (beside the Discord scheduler, which already holds the webhook -# file), creates /srv/ci-red (owner runner, 755: the workflow's `red` job writes red.jsonl there as the runner user, the -# poster and anyone on the box read it), installs the two units and enables the timer. No secret moves here: the poster +# file), creates /srv/ci-red with the shared group `cired` (runner and build; the workflow's `red` job appends CI rows as +# runner, remote-run.sh appends box rows as build, the file is 664 in a 2775 directory), installs the two units and enables +# the timer (one `tick` a minute: post new CI rows, then the 09:00 London digest). No secret moves here: the poster # reads the webhook file the Discord scheduler's install.sh already placed (DISCORD_WEBHOOK_UPDATES is the key it needs; # until that key is in ~/.config/igneum/discord and that install.sh is re-run, every pass logs the missing key by name # and the lines wait in red.jsonl). Needs root over ssh (root@ with ~/.ssh/igneum_ed25519); the host ip comes from @@ -16,7 +17,7 @@ IP="${HOST_LINE#*@}"; [ -n "$IP" ] || { echo "no build server in ~/.config/igneu node "$ROOT/tools/ci/red-watch.mjs" --self-test >/dev/null || { echo "red-watch.mjs fails its own self-test; not installing" >&2; exit 1; } SSH=(ssh -i "$KEY" -o BatchMode=yes -o StrictHostKeyChecking=accept-new -o ConnectTimeout=10) -"${SSH[@]}" "root@$IP" 'install -d -o build -g build -m 750 /srv/discord-hooks /srv/discord-hooks/bin && install -d -o runner -g runner -m 755 /srv/ci-red && [ -f /srv/ci-red/red.jsonl ] || install -o runner -g runner -m 644 /dev/null /srv/ci-red/red.jsonl' +"${SSH[@]}" "root@$IP" 'install -d -o build -g build -m 750 /srv/discord-hooks /srv/discord-hooks/bin; getent group cired >/dev/null || groupadd cired; usermod -aG cired runner; usermod -aG cired build; install -d -o root -g cired -m 2775 /srv/ci-red; [ -f /srv/ci-red/red.jsonl ] || install -o root -g cired -m 664 /dev/null /srv/ci-red/red.jsonl; chgrp cired /srv/ci-red/red.jsonl; chmod 664 /srv/ci-red/red.jsonl' scp -q -i "$KEY" "$ROOT/tools/ci/red-watch.mjs" "build@$IP:/srv/discord-hooks/bin/" scp -q -i "$KEY" "$HERE/igneum-ci-red.service" "$HERE/igneum-ci-red.timer" "root@$IP:/etc/systemd/system/" "${SSH[@]}" "root@$IP" 'systemctl daemon-reload && systemctl enable --now igneum-ci-red.timer >/dev/null 2>&1; systemctl is-active igneum-ci-red.timer; systemctl list-timers igneum-ci-red.timer --no-pager | sed -n 2p' diff --git a/infra/build-server/provision.sh b/infra/build-server/provision.sh index daf45bd8..945b128d 100755 --- a/infra/build-server/provision.sh +++ b/infra/build-server/provision.sh @@ -484,8 +484,13 @@ step_runner() { as_runner "git config --global --get safe.directory >/dev/null 2>&1 || git config --global --add safe.directory '*'" # the mirrors are owned by build # 3b. the CI red watcher's record file: the workflow's `red` job appends one line per failed master or release run here # (tools/ci/red-watch.mjs record); the poster (infra/build-server/ci-red) reads it as build - if [ ! -d /srv/ci-red ]; then install -d -o "$RUNNER_USER" -g "$RUNNER_USER" -m 755 /srv/ci-red; any=1; fi - [ -f /srv/ci-red/red.jsonl ] || { install -o "$RUNNER_USER" -g "$RUNNER_USER" -m 644 /dev/null /srv/ci-red/red.jsonl; any=1; } + # (tools/ci/red-watch.mjs record); remote-run.sh appends the box's own red rows as build; the shared group `cired` lets + # both write one file (664 in a 2775 directory), and the poster (infra/build-server/ci-red) reads it as build + getent group cired >/dev/null || { groupadd cired; any=1; } + id -nG "$RUNNER_USER" | tr ' ' '\n' | grep -qx cired || { usermod -aG cired "$RUNNER_USER"; any=1; } + id -nG "$BUILD_USER" | tr ' ' '\n' | grep -qx cired || { usermod -aG cired "$BUILD_USER"; any=1; } + if [ ! -d /srv/ci-red ]; then install -d -o root -g cired -m 2775 /srv/ci-red; any=1; fi + [ -f /srv/ci-red/red.jsonl ] || { install -o root -g cired -m 664 /dev/null /srv/ci-red/red.jsonl; any=1; } # 4. sccache: the build user's binary copied system-wide (the runner cannot read /home/build), a read-only view of /srv/sccache if [ ! -x /usr/local/bin/sccache ] || ! cmp -s "$BUILD_HOME/.cargo/bin/sccache" /usr/local/bin/sccache; then install -m 755 "$BUILD_HOME/.cargo/bin/sccache" /usr/local/bin/sccache; any=1 diff --git a/infra/build-server/remote-run.sh b/infra/build-server/remote-run.sh index c292badd..b78b4b65 100755 --- a/infra/build-server/remote-run.sh +++ b/infra/build-server/remote-run.sh @@ -23,7 +23,19 @@ # 3. Appends one JSON line to /srv/builds/_log/builds.jsonl (the worker dashboard reads it; asked for by main on 6 October # 2026): on success, on failure and on the slot give-up. UTC ISO 8601 Z times, numbers unquoted, unknown fields omitted, # artefacts with bytes and sha256 only when the run succeeded (a failed build would list the previous build's files), -# the line kept under 4 KB. +# the line kept under 4 KB. Since the evening of 6 October 2026 (the project lead: "make sure we are fixing and learning from all the +# errors here") the line also carries "class" and "run_log": +# - PRE-FLIGHT before cargo runs: the manifest must parse (cargo metadata --no-deps) and every `-p` package must exist +# (a workspace member, else cargo pkgid --offline); a refusal is exit 3, class preflight-manifest or preflight-package, +# and costs a second instead of a slot. The instant-death class: three suite runs on 6 October died in 0 s with exit +# 101 and no compile, and nothing on the box had kept the reason. +# - the run's output is kept: the last 400 lines in /srv/builds/_log/runs/.log, so a red row can be read after the +# agent's terminal is gone. +# - CLASS of a red run from that output: instant (under 3 s, nothing compiled), compile-error (error[E...] or "could not +# compile"), link-error, test-failure ("test result: FAILED"), slot-timeout (75), no-dir (2), other. +# - a `cargo test` with a filter that ran 0 tests everywhere is a wasted round trip: exit 3, class no-test-matched. +# - every red row is also appended to the shared red-run file (/srv/ci-red/red.jsonl, $IGNEUM_CI_RED_FILE), the file +# tools/ci/red-watch.mjs posts from; box rows are not posted one by one, the 09:00 UK digest counts them per class. # Modes (BR_MODE, default run): `checkout` resets the box's tree and checks the branch out at the commit (lib.sh # bs_push_and_checkout: BR_CO_DIR, BR_CO_MIRROR, BR_CO_BRANCH, BR_CO_SHA, BR_CO_WT); `--self-test` (first argument) builds a # scratch mirror and clone, dirties the clone the way a build's overlay does, moves the mirror one commit on, and shows the @@ -141,14 +153,29 @@ if [ "${1:-}" = --self-test-slots ]; then echo "self-test-slots: two concurrent builds 45 each, a lone build 90, a measure blocks a build, a build blocks a measure, a probe keeps the holder line, the log carries jobs and measure"; exit 0 fi +# One run per worktree directory at a time (6 October 2026, 19:51:09 UK: two runs of one worktree started in the same second; +# one found no crate directory while the other's checkout was replacing the tree, exit 2). The checkout and the run each take +# the worktree's lock (append mode, held to exit) and wait up to 2 h for it instead of dying; the wait is said on stderr. +wt_lock() { # + local name="${1//\//_}" fd + [ -n "$name" ] || return 0 + mkdir -p "$IGNEUM_BUILD_SLOTS_DIR" 2>/dev/null || return 0 + exec {fd}>>"$IGNEUM_BUILD_SLOTS_DIR/wt-$name.lock" || return 0 + if ! flock -n "$fd"; then + echo "build-remote: another run holds worktree $1 on this box, waiting for it (up to 2 h)" >&2 + flock -w 7200 "$fd" || { echo "build-remote: gave up waiting for worktree $1 after 2 h" >&2; exit 75; } + fi +} if [ "${BR_MODE:-run}" = checkout ]; then : "${BR_CO_DIR:?}" "${BR_CO_MIRROR:?}" "${BR_CO_BRANCH:?}" "${BR_CO_SHA:?}" + wt_lock "${BR_CO_WT:-$(basename "$BR_CO_DIR")}" checkout_tree "$BR_CO_DIR" "$BR_CO_MIRROR" "$BR_CO_BRANCH" "$BR_CO_SHA" "${BR_CO_WT:-}"; exit $? fi : "${BR_DIR:?}" "${BR_CMD:?}" "${BR_LABEL:?}" "${BR_TOOL:?}" "${BR_KIND:?}" BR_HOST=$(hostname); BR_PID=$$; BR_T0=$(date +%s) export BR_HOST BR_PID BR_T0 +wt_lock "${BR_WT:-}" LOG_DIR="${IGNEUM_BUILD_LOG_DIR:-/srv/builds/_log}"; mkdir -p "$LOG_DIR" # jsonlog @@ -170,6 +197,7 @@ d = { "start": iso(e['BR_START']), "end": iso(e['BR_END']), "secs": num(e['BR_SECS']), "exit": num(e['BR_EXIT']), "compiles": num(e['BR_COMPILES']), "jobs": num(e.get('BR_JOBS')), "measure": (e.get('BR_MEASURE') == '1') or None, "source_date_epoch": num(e.get('BR_SDE')), + "class": e.get('BR_CLASS') or None, "run_log": e.get('BR_RUN_LOG') or None, } sc = {k: num(e[v]) for k, v in (("hits", "BR_HITS"), ("misses", "BR_MISSES"), ("hits_total", "BR_HITS_T"), ("misses_total", "BR_MISSES_T"))} sc = {k: v for k, v in sc.items() if v is not None} @@ -200,13 +228,34 @@ with open(e['BR_LOG'], 'a') as f: PY } +# redlog : one line in the shape tools/ci/red-watch.mjs reads (source "box"; the digest counts it) +redlog() { + local f="${IGNEUM_CI_RED_FILE:-/srv/ci-red/red.jsonl}" + [ -w "$f" ] || [ -w "$(dirname "$f")" ] || { echo "build-remote: note: $f is not writable, the red row is in builds.jsonl only" >&2; return 0; } + BR_EXIT="$1" BR_SECS="$2" BR_CLASS="$3" BR_RED="$f" python3 - <<'PY' || echo "build-remote: WARNING the red-run line was not written" >&2 +import json, os, time +e = os.environ +line = { + "source": "box", "run_id": f"{e['BR_HOST']}-{e['BR_T0']}-{e['BR_PID']}", "attempt": 1, "workflow": f"box:{e['BR_KIND']}", + "branch": e.get('BR_BRANCH') or '', "sha": (e.get('BR_SHA') or '')[:7], "event": e.get('BR_TOOL') or '', + "url": "", "at": time.strftime('%Y-%m-%dT%H:%M:%SZ', time.gmtime()), "title": (e.get('BR_COMMAND') or '')[:100], + "failed": [{"job": f"{e.get('BR_WT') or ''}/{e.get('BR_CRATE') or ''}", "conclusion": "failure", + "step": f"{e['BR_CLASS']}: exit {e['BR_EXIT']} after {e['BR_SECS'] or 0} s"}], + "class": e['BR_CLASS'], "agent": e.get('BR_AGENT') or '', "run_log": e.get('BR_RUN_LOG') or '', "note": "", +} +with open(e['BR_RED'], 'a') as f: + f.write(json.dumps(line, separators=(',', ':')) + "\n") +PY +} + SLOTS_DIR="$IGNEUM_BUILD_SLOTS_DIR" slots=$(cat "$SLOTS_DIR/slots" 2>/dev/null || echo 1); [ "$slots" -ge 1 ] 2>/dev/null || slots=1 JOBS_ALONE="${JOBS_ALONE:-90}"; JOBS_SHARED="${JOBS_SHARED:-45}" holder_line() { printf 'pid %s since %sZ waited %s s: %s\n' "$BR_PID" "$(date -u +%H:%M:%S)" "$1" "$BR_LABEL"; } give_up() { # echo "build-remote: gave up waiting for $1 after 2 h" >&2 - jsonlog 75 0 $(( $(date +%s) - BR_T0 )) "" "$(date +%s)" "" "" "" "" "" "" + BR_CLASS=slot-timeout jsonlog 75 0 $(( $(date +%s) - BR_T0 )) "" "$(date +%s)" "" "" "" "" "" "" + redlog 75 $(( $(date +%s) - BR_T0 )) slot-timeout rm -f "$waitfile"; exit 75 } waitfile="$SLOTS_DIR/wait-$BR_PID" @@ -263,7 +312,43 @@ else echo "build-remote: holding build-$got on $BR_HOST (waited $waited s; $held of $slots slots held, CARGO_BUILD_JOBS=$BR_JOBS)" >&2 fi -cd "$BR_DIR" || { jsonlog 2 "$got" "$waited" "" "$(date +%s)" "" "" "" "" "" ""; exit 2; } +release_slot() { if [ "$got" = measure ]; then : > "$SLOTS_DIR/measure"; else : > "$SLOTS_DIR/build-$got"; fi; } +cd "$BR_DIR" || { BR_CLASS=no-dir jsonlog 2 "$got" "$waited" "" "$(date +%s)" "" "" "" "" "" ""; redlog 2 0 no-dir; release_slot; exit 2; } + +# PRE-FLIGHT for a cargo command (the instant-death class, 6 October 2026): the manifest parses and every -p package exists, +# answered in about a second from the workspace metadata (no network), before any compile time is spent +if [[ "$BR_CMD" =~ ^cargo[[:space:]] ]]; then + pf_class=""; pf_msg="" + sub=$(printf '%s\n' "$BR_CMD" | awk '{print $2}') + if ! cargo --list 2>/dev/null | awk 'NR>1 {print $1}' | grep -qx -- "$sub"; then + pf_class=preflight-subcommand; pf_msg="cargo has no '$sub' subcommand on this box (cargo audit at 21:17 UK on 6 October died this way: install it in provision.sh)" + elif ! pf_meta=$(cargo metadata --no-deps --format-version 1 2>&1 >/tmp/br-meta-$BR_PID.json); then + pf_class=preflight-manifest; pf_msg="$pf_meta" + else + members=$(python3 -c 'import json,sys; d=json.load(open(sys.argv[1])); print("\n".join(p["name"] for p in d["packages"]))' "/tmp/br-meta-$BR_PID.json" 2>/dev/null || true) + for pkg in $(printf '%s\n' "$BR_CMD" | grep -oE '(^|[[:space:]])(-p|--package)[[:space:]=]+[A-Za-z0-9_.@:-]+' | awk '{print $NF}' | sed -E 's/^(-p|--package)=?//'); do + grep -qx "$pkg" <<<"$members" && continue + cargo pkgid --offline -p "$pkg" >/dev/null 2>&1 && continue + pf_class=preflight-package; pf_msg="package '$pkg' is not in this workspace (and not a dependency): the -p argument names nothing"; break + done + # --features pkg/feat (or -F): the feature must exist on that member (the shipper's prove build died in 0 s twice on + # 6 October, 19:22 and 19:51 UK, with a feature name; nothing kept the message) + if [ -z "$pf_class" ]; then + for spec in $(printf '%s\n' "$BR_CMD" | grep -oE '(^|[[:space:]])(-F|--features)[[:space:]=]+[A-Za-z0-9_./@:,-]+' | awk '{print $NF}' | sed -E 's/^(-F|--features)=?//' | tr ',' '\n'); do + case "$spec" in */*) fpkg="${spec%%/*}"; feat="${spec#*/}" ;; *) continue ;; esac + has=$(python3 -c 'import json,sys; d=json.load(open(sys.argv[1])); m=[p for p in d["packages"] if p["name"]==sys.argv[2]]; print("member" if not m else ("yes" if sys.argv[3] in m[0]["features"] else "no"))' "/tmp/br-meta-$BR_PID.json" "$fpkg" "$feat" 2>/dev/null || echo yes) + if [ "$has" = no ]; then pf_class=preflight-feature; pf_msg="package '$fpkg' has no feature '$feat'"; break; fi + done + fi + fi + rm -f "/tmp/br-meta-$BR_PID.json" + if [ -n "$pf_class" ]; then + echo "build-remote: PRE-FLIGHT REFUSED ($pf_class): $pf_msg" >&2 + printf 'build-remote: RESULT rc=3 secs=0 compiles=0 class=%s\n' "$pf_class" + BR_CLASS=$pf_class jsonlog 3 "$([ "$got" = measure ] && echo "" || echo "$got")" "$waited" "$(date +%s)" "$(date +%s)" 0 0 "" "" "" "" + redlog 3 0 "$pf_class"; release_slot; exit 3 + fi +fi # reproducible builds (main, 6 October 2026, the 0.3.14 repro): the commit's author time as SOURCE_DATE_EPOCH (mimalloc's # __DATE__/__TIME__), UTC; the target dir is fixed per target by the caller (prost's generated code embeds OUT_DIR) if [ -n "${BR_SDE:-}" ]; then export SOURCE_DATE_EPOCH="$BR_SDE" TZ=UTC; echo "build-remote: SOURCE_DATE_EPOCH=$BR_SDE TZ=UTC" >&2; fi @@ -273,13 +358,36 @@ exec_before=$(stat_field "Compile requests executed"); hits_before=$(stat_field t1=$(date +%s) # in a subshell: a command string that carries `set -e` or `exit` ends only the subshell, never this runner (6 October 2026, # workers-remote.sh: both workers built, then the leaked set -e killed the runner before its RESULT line, reported as rc 101) -( eval "$BR_CMD" ) +# the output is kept on the box (the last 400 lines) so a red row can be read after the agent's terminal is gone; both +# streams stay where they were for the Mac (stdout to stdout, stderr to stderr), each teed into the run log +RUN_LOG_DIR="$LOG_DIR/runs"; mkdir -p "$RUN_LOG_DIR" +BR_RUN_LOG="$RUN_LOG_DIR/$BR_HOST-$BR_T0-$BR_PID.log"; export BR_RUN_LOG +( eval "$BR_CMD" ) > >(tee -a "$BR_RUN_LOG") 2> >(tee -a "$BR_RUN_LOG" >&2) rc=$? +wait t2=$(date +%s); secs=$(( t2 - t1 )) exec_after=$(stat_field "Compile requests executed"); hits_after=$(stat_field "Cache hits "); misses_after=$(stat_field "Cache misses ") compiles=$(( ${exec_after:-0} - ${exec_before:-0} )); hits=$(( ${hits_after:-0} - ${hits_before:-0} )); misses=$(( ${misses_after:-0} - ${misses_before:-0} )) -printf 'build-remote: RESULT rc=%s secs=%s compiles=%s sccache_hits=%s sccache_misses=%s sccache_hits_total=%s sccache_misses_total=%s jobs=%s load=%s\n' \ - "$rc" "$secs" "$compiles" "$hits" "$misses" "${hits_after:-?}" "${misses_after:-?}" "${BR_JOBS:-measure}" "$(cut -d' ' -f1-3 /proc/loadavg)" +tail -n 400 "$BR_RUN_LOG" > "$BR_RUN_LOG.tmp" 2>/dev/null && mv -f "$BR_RUN_LOG.tmp" "$BR_RUN_LOG" +# the class of the run, from its exit, its duration and its output +BR_CLASS="" +if [ "$rc" != 0 ]; then + # what the output says first (a failing test in a tiny crate also runs in under 3 s); instant is the rest + if grep -qE '^(error\[E[0-9]+\]|error: could not compile)' "$BR_RUN_LOG"; then BR_CLASS=compile-error + elif grep -qE 'error: linking with|undefined reference to' "$BR_RUN_LOG"; then BR_CLASS=link-error + elif grep -q 'test result: FAILED' "$BR_RUN_LOG"; then BR_CLASS=test-failure + elif [ "$secs" -le 2 ] && [ "${compiles:-0}" -le 0 ]; then BR_CLASS=instant + else BR_CLASS=other; fi +elif [[ "$BR_CMD" == cargo\ test* ]] && { [[ "$BR_CMD" == *" -- "* ]] || grep -qE -- '--(lib|tests|bins|all-targets)[[:space:]]+[^-[:space:]]' <<<"$BR_CMD"; } \ + && grep -q '^running 0 tests' "$BR_RUN_LOG" && ! grep -qE '^running [1-9][0-9]* tests?' "$BR_RUN_LOG"; then + # a filter that matched no test anywhere: the run was a wasted round trip, and the agent would have read "ok" + BR_CLASS=no-test-matched; rc=3 + echo "build-remote: REFUSED after the run: the test filter matched no test in any binary (every 'running 0 tests'); check the name" >&2 +fi +export BR_CLASS +printf 'build-remote: RESULT rc=%s secs=%s compiles=%s sccache_hits=%s sccache_misses=%s sccache_hits_total=%s sccache_misses_total=%s jobs=%s load=%s class=%s\n' \ + "$rc" "$secs" "$compiles" "$hits" "$misses" "${hits_after:-?}" "${misses_after:-?}" "${BR_JOBS:-measure}" "$(cut -d' ' -f1-3 /proc/loadavg)" "${BR_CLASS:-ok}" jsonlog "$rc" "$([ "$got" = measure ] && echo "" || echo "$got")" "$waited" "$t1" "$t2" "$secs" "$compiles" "$hits" "$misses" "${hits_after:-}" "${misses_after:-}" -if [ "$got" = measure ]; then : > "$SLOTS_DIR/measure"; else : > "$SLOTS_DIR/build-$got"; fi +[ "$rc" = 0 ] || redlog "$rc" "$secs" "$BR_CLASS" +release_slot exit "$rc" diff --git a/tools/ci/red-watch.mjs b/tools/ci/red-watch.mjs index 1dc6714e..3f367735 100755 --- a/tools/ci/red-watch.mjs +++ b/tools/ci/red-watch.mjs @@ -11,7 +11,18 @@ // hidden updates channel (DISCORD_WEBHOOK_UPDATES in the // credentials file), then is marked posted in the state file; // without --live the line is printed, not sent -// node tools/ci/red-watch.mjs --self-test record twice = one line; post = one send; post again = none +// node tools/ci/red-watch.mjs digest --file [--live] [--now] +// the daily line: at the first pass at or after 09:00 London +// (or at once with --now), one line to the updates channel +// counting the last 24 h of red rows, CI and box, per class, +// with the guard each class has; once per London day +// node tools/ci/red-watch.mjs tick --file [--live] post, then digest (what igneum-ci-red.timer runs every minute) +// node tools/ci/red-watch.mjs --self-test record twice = one line; post = one send; post again = none; +// a box row is counted, never posted alone; the digest once a day +// +// Box rows: infra/build-server/remote-run.sh appends a line with "source":"box" for every red build, suite or check on +// igneum-build-1 (class instant, compile-error, test-failure, no-test-matched, preflight-*, slot-timeout, no-dir, other). +// Those are not posted one by one (an agent iterating red to green would flood the channel); the digest counts them. // // Files: the record file is written by the runner user (one object per line: run_id, workflow, branch, sha, title, failed, // url, at); the poster's state (which run ids were posted, when) is $IGNEUM_CI_RED_STATE, default @@ -28,6 +39,22 @@ const has = (name) => args.includes(name); const CRED_FILE = process.env.IGNEUM_DISCORD_ENV || path.join(os.homedir(), '.config', 'igneum', 'discord'); const STATE_FILE = process.env.IGNEUM_CI_RED_STATE || path.join(os.homedir(), '.config', 'igneum', 'ci-red-posted.json'); const WEBHOOK_KEY = 'DISCORD_WEBHOOK_UPDATES'; +// what stops each class now (named in the digest so the line teaches, not just counts); docs/analysis/ci-failures-2026-10-06.md +export const GUARDS = { + 'ci': 'the pre-push gate (tools/ci/pre-push.sh, the same checks CI runs, before any push to master or release-*)', + 'instant': 'pre-flight in remote-run.sh (manifest, -p package, feature, subcommand checked in a second) and the kept run log', + 'preflight-manifest': 'refused before the slot: the manifest did not parse', + 'preflight-package': 'refused before the slot: the -p package does not exist', + 'preflight-feature': 'refused before the slot: the feature does not exist on that package', + 'preflight-subcommand': 'refused before the slot: cargo has no such subcommand on the box (provision.sh installs it)', + 'no-test-matched': 'refused after the run: the test filter matched nothing (exit 3 instead of a green "0 tests")', + 'compile-error': 'iteration: the box is the pre-check (a Mac check takes 12 to 18 min); the run log is kept on the box', + 'link-error': 'iteration; the run log is kept on the box', + 'test-failure': 'iteration; the run log is kept on the box', + 'slot-timeout': 'two slots since 20:3x UK on 6 October; the queue is visible on the workers page', + 'no-dir': 'one run per worktree at a time (the per-worktree lock in remote-run.sh)', + 'other': 'read the kept run log (/srv/builds/_log/runs/.log)', +}; export function readLines(file) { if (!fs.existsSync(file)) return []; @@ -108,8 +135,9 @@ function writeState(file, state) { fs.mkdirSync(path.dirname(file), { recursive: export async function post(file, { live = false, stateFile = STATE_FILE, credFile = CRED_FILE, fetchImpl = fetch, log = console.log } = {}) { const lines = readLines(file); const state = readState(stateFile); - const pending = lines.filter((l) => !state.posted[`${l.run_id}.${l.attempt || 1}`]); - if (!pending.length) { log(`ci-red: nothing to post (${lines.length} recorded, all posted)`); return { sent: 0, pending: 0 }; } + const pending = lines.filter((l) => l.source !== 'box' && !state.posted[`${l.run_id}.${l.attempt || 1}`]); + const boxRows = lines.filter((l) => l.source === 'box').length; + if (!pending.length) { log(`ci-red: nothing to post (${lines.length} recorded, ${boxRows} box rows for the digest, the rest posted)`); return { sent: 0, pending: 0 }; } const creds = readCredentials(credFile); const hook = creds[WEBHOOK_KEY]; let sent = 0; @@ -131,6 +159,51 @@ export async function post(file, { live = false, stateFile = STATE_FILE, credFil return { sent, pending: pending.length - sent }; } +// The London day of a Date (YYYY-MM-DD) and its hour, without a time zone library +function london(d) { + const parts = new Intl.DateTimeFormat('en-GB', { timeZone: 'Europe/London', year: 'numeric', month: '2-digit', day: '2-digit', hour: '2-digit', hour12: false }).formatToParts(d); + const get = (t) => parts.find((p) => p.type === t).value; + return { day: `${get('year')}-${get('month')}-${get('day')}`, hour: Number(get('hour')) % 24 }; +} + +export function digestText(lines, now = new Date()) { + const since = now.getTime() - 24 * 3600 * 1000; + const recent = lines.filter((l) => Date.parse(l.at) >= since); + const ci = recent.filter((l) => l.source !== 'box'); const box = recent.filter((l) => l.source === 'box'); + const byClass = {}; + for (const l of box) byClass[l.class || 'other'] = (byClass[l.class || 'other'] || 0) + 1; + const ciSteps = {}; + for (const l of ci) for (const f of (l.failed || [])) ciSteps[f.step] = (ciSteps[f.step] || 0) + 1; + const parts = [`CI red digest, last 24 h: ${recent.length} red run(s): ${ci.length} CI, ${box.length} on the box.`]; + if (ci.length) parts.push('CI: ' + Object.entries(ciSteps).sort((a, b) => b[1] - a[1]).map(([k, v]) => `${v} x "${k}"`).join(', ') + ` (guard: ${GUARDS.ci}).`); + if (box.length) parts.push('Box, by class: ' + Object.entries(byClass).sort((a, b) => b[1] - a[1]).map(([k, v]) => `${v} ${k} (${GUARDS[k] || GUARDS.other})`).join('; ') + '.'); + if (!recent.length) parts.push('Nothing was red.'); + return parts.join(' ').slice(0, 1900); +} + +export async function digest(file, { live = false, now = new Date(), force = false, stateFile = STATE_FILE, credFile = CRED_FILE, fetchImpl = fetch, log = console.log } = {}) { + const state = readState(stateFile); + const { day, hour } = london(now); + if (!force) { + if (hour < 9) return { sent: false, why: 'before 09:00 London' }; + if (state.digest_day === day) return { sent: false, why: 'already sent today' }; + } + const text = digestText(readLines(file), now); + if (!live) { log(`ci-red digest (dry run, not sent): ${text}`); return { sent: false, why: 'dry run', text }; } + const hook = readCredentials(credFile)[WEBHOOK_KEY]; + if (!hook) { log(`ci-red digest: ${WEBHOOK_KEY} is not in the credentials file; the digest waits`); return { sent: false, why: 'no key', text }; } + try { + const r = await fetchImpl(hook, { method: 'POST', headers: { 'Content-Type': 'application/json', 'User-Agent': 'igneum-red-watch' }, + body: JSON.stringify({ username: 'Igneum CI', content: text, allowed_mentions: { parse: [] } }) }); + if (!r.ok && r.status !== 204) { log(`ci-red digest: the webhook answered ${r.status}; retried next pass`); return { sent: false, why: `webhook ${r.status}`, text }; } + } catch (e) { + log(`ci-red digest: send failed: ${e.message.replace(/https?:\/\/\S+/g, '')}; retried next pass`); return { sent: false, why: 'send failed', text }; + } + state.digest_day = day; writeState(stateFile, state); + log(`ci-red digest: posted for ${day}`); + return { sent: true, text }; +} + async function selfTest() { const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'red-watch-')); const file = path.join(dir, 'red.jsonl'); const stateFile = path.join(dir, 'posted.json'); const credFile = path.join(dir, 'discord'); @@ -179,9 +252,29 @@ async function selfTest() { const badFetch = async () => ({ ok: false, status: 500 }); const r3 = await post(file, { live: true, stateFile, credFile, fetchImpl: badFetch, log }); if (r3.sent !== 0 || r3.pending !== 1) fails.push('post: a 500 from the webhook did not keep the run pending'); + // a box row (remote-run.sh's shape) is never posted alone, and the digest counts it per class with its guard + const boxLine = { source: 'box', run_id: 'igneum-build-1-1-1', attempt: 1, workflow: 'box:suite', branch: 'x', sha: 'abc1234', url: '', at: new Date().toISOString(), + title: 'cargo test --release -p kaspa-consensus --lib finality', failed: [{ job: 'wt/crate', conclusion: 'failure', step: 'instant: exit 101 after 0 s' }], class: 'instant', note: '' }; + fs.appendFileSync(file, JSON.stringify(boxLine) + '\n'); + const before = sends.length; + const r4 = await post(file, { live: true, stateFile, credFile, fetchImpl: hookFetch, log }); + // the pending CI run 424243 goes now (one send), the box row does not + if (sends.length !== before + 1 || r4.pending !== 0 || !sends[sends.length - 1].body.content.includes('actions/runs/424243')) fails.push('post: a box row was posted alone or the pending CI run was not'); + const text2 = digestText(readLines(file), new Date()); + if (!/3 red run\(s\): 2 CI, 1 on the box/.test(text2) || !text2.includes('1 instant (pre-flight')) fails.push(`digest text: ${text2}`); + const at0830 = new Date('2026-10-07T07:30:00Z'); // 08:30 London (BST) + const d0 = await digest(file, { live: true, now: at0830, stateFile, credFile, fetchImpl: hookFetch, log }); + if (d0.sent || d0.why !== 'before 09:00 London') fails.push(`digest: sent before 09:00 London (${d0.why})`); + const at0905 = new Date('2026-10-07T08:05:00Z'); // 09:05 London + const d1 = await digest(file, { live: true, now: at0905, stateFile, credFile, fetchImpl: hookFetch, log }); + if (!d1.sent || sends[sends.length - 1].body.content !== d1.text) fails.push('digest: not sent at 09:05 London or the text differs'); + const d2 = await digest(file, { live: true, now: new Date('2026-10-07T15:00:00Z'), stateFile, credFile, fetchImpl: hookFetch, log }); + if (d2.sent || d2.why !== 'already sent today') fails.push('digest: sent twice in one London day'); + const d3 = await digest(file, { live: true, now: new Date('2026-10-08T08:05:00Z'), stateFile, credFile, fetchImpl: hookFetch, log }); + if (!d3.sent) fails.push('digest: not sent the next day'); fs.rmSync(dir, { recursive: true, force: true }); if (fails.length) { for (const f of fails) console.error(`self-test failed: ${f}`); process.exit(1); } - console.log('self-test passed: one line per run however often record runs; the dry run sends nothing; a missing key is named, never a URL; one live send per run; a webhook error keeps the run pending'); + console.log('self-test passed: one line per run however often record runs; the dry run sends nothing; a missing key is named, never a URL; one live send per run; a webhook error keeps the run pending; a box row is counted, never posted alone; the digest goes once per London day, at or after 09:00'); } const cmd = args[0]; @@ -194,6 +287,15 @@ if (cmd === '--self-test') { } else if (cmd === 'post') { const file = flag('--file'); if (!file) { console.error('post: --file is required'); process.exit(2); } await post(file, { live: has('--live') }); +} else if (cmd === 'digest') { + const file = flag('--file'); if (!file) { console.error('digest: --file is required'); process.exit(2); } + const r = await digest(file, { live: has('--live'), force: has('--now') }); + if (!r.sent && r.why !== 'dry run') console.log(`ci-red digest: not sent (${r.why})`); +} else if (cmd === 'tick') { + const file = flag('--file'); if (!file) { console.error('tick: --file is required'); process.exit(2); } + await post(file, { live: has('--live') }); + const r = await digest(file, { live: has('--live') }); + if (!r.sent && r.why !== 'dry run' && r.why !== 'before 09:00 London' && r.why !== 'already sent today') console.log(`ci-red digest: not sent (${r.why})`); } else { - console.error('usage: red-watch.mjs record --file | post --file [--live] | --self-test'); process.exit(2); + console.error('usage: red-watch.mjs record --file | post --file [--live] | digest --file [--live] [--now] | tick --file [--live] | --self-test'); process.exit(2); }