From f75ed95fad619e3ad5a8491470acdbb1759481bd Mon Sep 17 00:00:00 2001 From: Nikolai Emil Damm Date: Mon, 20 Jul 2026 00:33:45 +0200 Subject: [PATCH 1/5] feat(ai-engineer): split the sleep counter into foreground blocks, deferred watchers and unattributed Codex MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The raw sleep total could not answer the question it was used to answer. It scored a contract-COMPLIANT backgrounded watcher identically to a foreground busy-wait, and the improver's own runs arm several watchers per tick — so the metric polluted itself with the noise of the component reading it. Classification is structural (`run_in_background` on the tool call), so prose cannot fake it; the key is omitted when false, so absence reads as foreground. Codex is a STATED GAP, not a zero: 767 live exec_command calls carried `yield_time_ms` (an output-read timeout) and zero carried any background flag, so that runtime exposes no surface to classify. Its sleeps are counted but not attributed. One jq expression with a class filter rather than a second extractor — a parallel copy is how detector parity broke six times on the redactor — plus a sum check that warns when the classes stop summing to the total. This SHARPENS the measurement and removes nothing. Co-Authored-By: Claude Opus 4.8 (1M context) --- .claude/scripts/agent-telemetry.sh | 78 +++++++++++++++++++++-- .claude/scripts/agent-telemetry.test.sh | 63 ++++++++++++++++++ .claude/skills/agent-improvement/SKILL.md | 10 ++- 3 files changed, 143 insertions(+), 8 deletions(-) diff --git a/.claude/scripts/agent-telemetry.sh b/.claude/scripts/agent-telemetry.sh index 8130edd5..3b49beab 100755 --- a/.claude/scripts/agent-telemetry.sh +++ b/.claude/scripts/agent-telemetry.sh @@ -235,15 +235,35 @@ fi # schemas. Behavioural metrics must never be grepped from raw transcript text: # untrusted prose that merely mentions `sleep 60` would otherwise manufacture a # busy-wait pattern, and busy-wait counts are evidence the improver acts on. +# +# Optional $2 = BACKGROUND CLASS filter, so a caller can split the same commands +# by whether the agent blocked on them. Deliberately ONE jq expression with a +# filter rather than a second extractor: a parallel copy is how detector parity +# broke six times on the redactor, and here it would silently make the class +# counts stop summing to the total. +# FG Claude, foreground — run_in_background absent/false (the default; +# the key is OMITTED when false, so absence=FG) +# BG Claude, backgrounded — run_in_background:true +# CX Codex — UNCLASSIFIABLE: 767 live exec_command calls +# carried `yield_time_ms` (an output-read +# timeout) and ZERO carried a background flag, +# so no backgrounding surface exists to read. +# Reported as a stated gap, never folded into +# FG — a false coverage claim beats no claim. +# "" (default) every command, unchanged legacy behaviour. commands_in() { - local f="$1" - jq -r ' + local f="$1" cls="${2:-}" + jq -r --arg cls "$cls" ' .. | objects | ( # Claude: tool_use carrying a Bash command. - (select(.type=="tool_use") | .input?.command? // empty), + (select(.type=="tool_use") + | select($cls == "" or $cls == (if .input?.run_in_background == true + then "BG" else "FG" end)) + | .input?.command? // empty), # Codex, JSON-argument shape (function_call). (select(.type=="function_call") + | select($cls == "" or $cls == "CX") | .arguments? // empty | (try (fromjson | (.command? // .cmd? // empty)) catch empty)), # Codex, REAL observed shape: custom_tool_call name="exec" whose .input is @@ -252,6 +272,7 @@ commands_in() { # (An invented JSON fixture passed here for two rounds while this real # shape was silently unparsed — match the format that actually ships.) (select(.type=="custom_tool_call") + | select($cls == "" or $cls == "CX") | .input? // empty | select(type=="string") | [scan("cmd:\\s*\"((?:[^\"\\\\]|\\\\.)*)\"")] | .[]? | .[0]? @@ -527,14 +548,57 @@ if want efficiency; then # STRUCTURAL, not a text grep: only commands the agent actually ran count. # A grep would let untrusted prose that merely mentions `sleep 60` fabricate # a busy-wait pattern, and this metric is evidence for definition changes. - SLEEPS=$(printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' \ - | while IFS= read -r f; do commands_in "$f"; done \ - | strip_heredocs \ - | grep -cE '(^|[;&|(]|&&|\|\||[[:space:]](do|then|else)[[:space:]])[[:space:]]*sleep[[:space:]]+["'"'"']?[$0-9{]' || true) + # ONE definition of "this command sleeps", shared by the total and every + # class count below. Duplicating the regex is how the two would drift apart + # and stop summing. + count_sleeps() { + strip_heredocs \ + | grep -cE '(^|[;&|(]|&&|\|\||[[:space:]](do|then|else)[[:space:]])[[:space:]]*sleep[[:space:]]+["'"'"']?[$0-9{]' || true + } + sleeps_for_class() { # $1 = "" | FG | BG | CX + printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' \ + | while IFS= read -r f; do commands_in "$f" "$1"; done | count_sleeps + } + SLEEPS=$(sleeps_for_class "") + SLEEP_FG=$(sleeps_for_class FG) + SLEEP_BG=$(sleeps_for_class BG) + SLEEP_CX=$(sleeps_for_class CX) echo " [BOTH instances: ${SF_COUNT} Claude + ${CX_COUNT} Codex sessions]" echo " bash timeouts .............. ${TIMEOUTS} (each = a foreground block that produced nothing)" echo " interrupted tool calls ..... ${INTERRUPT}" echo " explicit sleep/poll calls .. ${SLEEPS} (contract: arm a watcher, never busy-wait)" + # The raw total above cannot answer the question the contract actually asks, + # because it scores a CONTRACT-COMPLIANT backgrounded watcher (`sleep N && + # check`, run_in_background) identically to a foreground busy-wait — and the + # improver's own runs emit several compliant watchers each, landing as + # self-noise in the very bucket used to judge the agents. These lines split + # the two. This SHARPENS the measurement; it removes nothing. + echo " ├ foreground block ....... ${SLEEP_FG} [Claude] ← the contract violation" + echo " ├ deferred watcher ....... ${SLEEP_BG} [Claude, backgrounded] ← COMPLIANT, not waste" + echo " └ unclassified ........... ${SLEEP_CX} [Codex — see gap note below]" + if [ "$((SLEEP_FG + SLEEP_BG + SLEEP_CX))" -ne "$SLEEPS" ]; then + echo " ⚠️ CLASS SUM $((SLEEP_FG + SLEEP_BG + SLEEP_CX)) != TOTAL ${SLEEPS} — the class" + echo " filter and the total have drifted; trust NEITHER until fixed." + fi + # Rates, because a raw total is not a rate. The window selects FILES by + # mtime, so session counts swing hard day to day and a raw count fell while + # the per-session rate ROSE (442→328 total, but 2.02→3.73/session). Every + # trend claim must name its denominator. + if [ "$SF_COUNT" -gt 0 ]; then + echo " per-session (Claude, n=${SF_COUNT}): foreground $(awk -v a="$SLEEP_FG" -v b="$SF_COUNT" 'BEGIN{printf "%.2f", a/b}')/session, deferred $(awk -v a="$SLEEP_BG" -v b="$SF_COUNT" 'BEGIN{printf "%.2f", a/b}')/session" + fi + if [ "$CX_COUNT" -gt 0 ]; then + echo " per-session (Codex, n=${CX_COUNT}): unclassified $(awk -v a="$SLEEP_CX" -v b="$CX_COUNT" 'BEGIN{printf "%.2f", a/b}')/session" + fi + echo " NOTE: the Claude split reads run_in_background on the tool call, so" + echo " it is STRUCTURAL — prose cannot fake it. The key is OMITTED" + echo " when false, so absence is correctly read as foreground." + echo " CODEX IS A STATED GAP, NOT A ZERO: 767 live exec_command" + echo " calls carried yield_time_ms (an output-read timeout) and" + echo " ZERO carried any background flag, so that runtime exposes no" + echo " backgrounding surface to classify. Codex sleeps are counted" + echo " but NOT attributed — never read 'unclassified' as compliant" + echo " or as a violation." echo echo " descriptions of commands that ACTUALLY timed out:" # Correlated by tool_use_id, not a bare grep over every description. The diff --git a/.claude/scripts/agent-telemetry.test.sh b/.claude/scripts/agent-telemetry.test.sh index 6a28125e..f5a941e7 100755 --- a/.claude/scripts/agent-telemetry.test.sh +++ b/.claude/scripts/agent-telemetry.test.sh @@ -1023,6 +1023,69 @@ check "the Codex denial gap stays disclosed" "$OUT" "CLAUDE-SCHEMA ONLY" OUT=$(run --section reliability) check "the mtime window bound is disclosed" "$OUT" "selects FILES by mtime" +# ── 6f. sleep background classification ─────────────────────────────────────── +echo +echo "sleep classification (foreground block vs deferred watcher)" + +# A BACKGROUNDED sleep is the contract's CHEAP WATCHER, not a busy-wait. Scoring +# it as waste is what made the raw total unusable as evidence — the improver's +# own runs arm several per tick, polluting the bucket used to judge the agents. +mkdir -p "$FIX/bgsleep" +cat > "$FIX/bgsleep/s.jsonl" <<'EOF' +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"b1","name":"Bash","input":{"command":"sleep 300 && gh pr checks 1","run_in_background":true}}]}} +EOF +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/bgsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'deferred watcher \.+ 1'; then + ok "a backgrounded sleep counts as a deferred watcher" +else bad "a backgrounded sleep counts as a deferred watcher" "$(printf '%s' "$OUT" | grep -E 'foreground|deferred|unclass')"; fi +if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 0'; then + ok "...and is NOT counted as a foreground block" +else bad "...and is NOT counted as a foreground block" "$(printf '%s' "$OUT" | grep -E 'foreground')"; fi + +# The key is OMITTED when false, so ABSENCE must read as foreground. If this +# regressed to "absent => unknown", every ordinary busy-wait would vanish. +mkdir -p "$FIX/fgsleep" +cat > "$FIX/fgsleep/s.jsonl" <<'EOF' +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"f1","name":"Bash","input":{"command":"sleep 60"}}]}} +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"f2","name":"Bash","input":{"command":"sleep 30","run_in_background":false}}]}} +EOF +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/fgsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 2'; then + ok "an omitted AND an explicit-false flag both read as foreground" +else bad "an omitted AND an explicit-false flag both read as foreground" "$(printf '%s' "$OUT" | grep -E 'foreground|deferred')"; fi + +# Codex exposes NO backgrounding surface (767 live exec calls: yield_time_ms +# only, zero background flags). Its sleeps must land in `unclassified` — folding +# them into foreground would invent an attribution the data cannot support. +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/empty" CODEX_HOME="$FIX/cxreal" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'unclassified \.+ 1'; then + ok "a Codex sleep is counted as unclassified" +else bad "a Codex sleep is counted as unclassified" "$(printf '%s' "$OUT" | grep -E 'unclass|foreground')"; fi +if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 0'; then + ok "...and is NOT attributed to foreground" +else bad "...and is NOT attributed to foreground" "$(printf '%s' "$OUT" | grep -E 'foreground')"; fi +check "the Codex classification gap is stated" "$OUT" "STATED GAP, NOT A ZERO" + +# The classes must SUM to the total, or a trend is read off a broken split. +# Mixed corpus: 2 Claude (1 fg + 1 bg) + 1 Codex = 3. +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/bgsleep" CODEX_HOME="$FIX/cxreal" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'sleep/poll calls \.\. 2' \ + && printf '%s' "$OUT" | grep -qE 'deferred watcher \.+ 1' \ + && printf '%s' "$OUT" | grep -qE 'unclassified \.+ 1'; then + ok "classes sum to the total across both instances" +else bad "classes sum to the total across both instances" "$(printf '%s' "$OUT" | grep -E 'sleep/poll|foreground|deferred|unclass')"; fi +if printf '%s' "$OUT" | grep -q 'CLASS SUM'; then + bad "no drift warning on a consistent split" "$(printf '%s' "$OUT" | grep 'CLASS SUM')" +else ok "no drift warning on a consistent split"; fi + +# Rates carry their denominator — a raw total is not a rate, and comparing one +# against the other is exactly how the 07-19 sleep reading was misread as a win. +check "per-session rate states its denominator" "$OUT" "per-session (Claude, n=" + # ── 7. robustness ───────────────────────────────────────────────────────────── echo echo "robustness" diff --git a/.claude/skills/agent-improvement/SKILL.md b/.claude/skills/agent-improvement/SKILL.md index b4a8fed8..754e7129 100644 --- a/.claude/skills/agent-improvement/SKILL.md +++ b/.claude/skills/agent-improvement/SKILL.md @@ -65,7 +65,8 @@ than absolute values, and only a recorded number can trend. date_utc, window_days reliability: tool_error_count, top_signatures[], timeout_count safety: blocked_actions[], near_misses[], credential_hits, injection_attempts_in_corpus -efficiency: sleep_poll_calls, timeouts, redundant_call_patterns[] +efficiency: sleep_poll_calls{total, fg_per_session, bg_per_session, codex_unclassified}, + timeouts, redundant_call_patterns[] quality: merged_prs, reverts, post_merge_red, review_findings_per_pr coordination: two_writer_races, push_collisions, duplicate_artifacts[] currency: loader_drift[], stale_memory[], unused_capabilities[] @@ -78,6 +79,13 @@ The `flow` row is the Kanban Kata's measurement surface ([monorepo#2271](https:/ it comes from `flow-scorecard.sh`, and its stated gaps (UI-only column limits, lifetime as a cycle-time proxy) are part of the record — never silently paper over them. +**Record sleeps as RATES, split by class — a raw total is not a rate.** The window selects files by +mtime, so session counts swing hard day to day: a raw sleep total once fell 442→328 while the +per-session rate *rose* 2.02→3.73, and the fall was read as a win. Always state the denominator, and +never compare a raw count against a per-session one. The classes are not interchangeable either — a +backgrounded `deferred watcher` is contract-COMPLIANT, and Codex's sleeps are **unattributed** (that +runtime exposes no backgrounding flag), so only `foreground block` is evidence of busy-waiting. + **A metric that moved the wrong way since yesterday outranks a new finding** — regression first. Verify any change from a previous run that is awaiting confirmation (step 5) before starting new work. From 5edf384647288dd5721a13c1bf19f9910b761c34 Mon Sep 17 00:00:00 2001 From: Nikolai Emil Damm Date: Mon, 20 Jul 2026 00:51:06 +0200 Subject: [PATCH 2/5] fix(ai-engineer): report sleep launch mode neutrally, count it atomically, exclude never-ran calls MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three review findings, all valid: 1. The labels claimed a compliance verdict the data does not support. run_in_background is LAUNCH MODE, not intent: the contract permits a foreground bare sleep as a local timer for a process the agent started, and a backgrounded sleep can still be a redundant poll. Labels are now neutral and the note says plainly that a foreground count is a candidate, not a violation, and a background count is not an exoneration. 2. Four independent scans of a LIVE corpus (the sibling writes transcripts while we read) could observe four different states and fire the drift warning spuriously. Each file is now snapshotted once and every class comes from that copy; the total is the SUM of the classes, so drift is impossible by construction rather than merely detected. The drift warning is dropped with it — over a derived sum it would be a vacuous guard. 3. A hook-blocked or permission-denied call never ran, so counting it as a foreground block reports waiting that never happened. Note on (3): keying the exclusion on is_error was too broad and the suite caught it. A TIMED-OUT sleep also carries is_error:true, but it ran — and it is the most expensive block in the corpus, so suppressing it would have hidden the worst case while claiming to measure it. The exclusion matches the two never-ran shapes explicitly, with a guard pinning the timeout case. 111/111 tests; the two new guards RED-proven by ablation. Co-Authored-By: Claude Opus 4.8 (1M context) --- .claude/scripts/agent-telemetry.sh | 87 +++++++++++++++++++------ .claude/scripts/agent-telemetry.test.sh | 66 ++++++++++++++----- 2 files changed, 116 insertions(+), 37 deletions(-) diff --git a/.claude/scripts/agent-telemetry.sh b/.claude/scripts/agent-telemetry.sh index 3b49beab..5a5f3a9a 100755 --- a/.claude/scripts/agent-telemetry.sh +++ b/.claude/scripts/agent-telemetry.sh @@ -252,14 +252,39 @@ fi # FG — a false coverage claim beats no claim. # "" (default) every command, unchanged legacy behaviour. commands_in() { - local f="$1" cls="${2:-}" - jq -r --arg cls "$cls" ' + local f="$1" cls="${2:-}" errs='[]' + # Exclude only calls that NEVER EXECUTED: the enforcement hook rejects + # `sleep N && ` and the permission layer denies a command, both leaving + # the tool_use in the transcript with no time spent. Counting those as blocks + # reports waiting that never happened, and inflates exactly the metric the + # hook exists to drive down. + # + # NOT keyed on is_error, which is far broader than "never ran" — a TIMED-OUT + # sleep carries is_error:true and is the single most expensive real block in + # the corpus. Suppressing it would hide the worst case while claiming to + # measure it. Match the two never-ran shapes explicitly instead. + if [ -n "$cls" ]; then + errs=$(jq -Rr 'select(length>0)|(try fromjson catch empty) + | select(.type=="user") | .message.content[]? + | select(.type=="tool_result" and .is_error==true) + | select((.content | tostring) + | test("Blocked:|^Permission to use|\\\"Permission to use")) + | .tool_use_id // empty' "$f" 2>/dev/null \ + | jq -Rs 'split("\n")|map(select(length>0))' 2>/dev/null) + [ -n "$errs" ] || errs='[]' + fi + jq -r --arg cls "$cls" --argjson errs "$errs" ' .. | objects | ( # Claude: tool_use carrying a Bash command. (select(.type=="tool_use") | select($cls == "" or $cls == (if .input?.run_in_background == true then "BG" else "FG" end)) + # $i is bound BEFORE index() so `.` is not rebound inside the test — + # `$arr | index(.)` there would compare the array against itself and + # match everything (a trap that has made a guard vacuous before). + | (.id? // "") as $i + | select($i == "" or (($errs | index($i)) | not)) | .input?.command? // empty), # Codex, JSON-argument shape (function_call). (select(.type=="function_call") @@ -555,14 +580,30 @@ if want efficiency; then strip_heredocs \ | grep -cE '(^|[;&|(]|&&|\|\||[[:space:]](do|then|else)[[:space:]])[[:space:]]*sleep[[:space:]]+["'"'"']?[$0-9{]' || true } - sleeps_for_class() { # $1 = "" | FG | BG | CX - printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' \ - | while IFS= read -r f; do commands_in "$f" "$1"; done | count_sleeps - } - SLEEPS=$(sleeps_for_class "") - SLEEP_FG=$(sleeps_for_class FG) - SLEEP_BG=$(sleeps_for_class BG) - SLEEP_CX=$(sleeps_for_class CX) + # The corpus is LIVE: the sibling instance writes transcripts while we read. + # Scanning once per class could observe a different corpus each time, so a + # sleep appended mid-run would make the classes disagree with a separately + # scanned total. Snapshot each file ONCE and derive every class from that + # copy, so the counts are mutually consistent by construction rather than + # merely checked afterwards. + SNAP=$(mktemp -d) || SNAP="" + : > "$SNAP/FG"; : > "$SNAP/BG"; : > "$SNAP/CX" + printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' | while IFS= read -r f; do + cp "$f" "$SNAP/cur" 2>/dev/null || continue + commands_in "$SNAP/cur" FG >> "$SNAP/FG" + commands_in "$SNAP/cur" BG >> "$SNAP/BG" + commands_in "$SNAP/cur" CX >> "$SNAP/CX" + done + SLEEP_FG=$(count_sleeps < "$SNAP/FG") + SLEEP_BG=$(count_sleeps < "$SNAP/BG") + SLEEP_CX=$(count_sleeps < "$SNAP/CX") + # The total is now the SUM of the classes, not a fourth independent scan. + # That makes class-vs-total drift impossible instead of detectable — and a + # drift warning over a sum would be a vacuous guard, which is worse than + # none. Classification is exhaustive by construction (a Claude tool_use is + # FG or BG; a Codex call is CX; there is no fourth command source). + SLEEPS=$((SLEEP_FG + SLEEP_BG + SLEEP_CX)) + rm -rf "$SNAP" 2>/dev/null echo " [BOTH instances: ${SF_COUNT} Claude + ${CX_COUNT} Codex sessions]" echo " bash timeouts .............. ${TIMEOUTS} (each = a foreground block that produced nothing)" echo " interrupted tool calls ..... ${INTERRUPT}" @@ -573,13 +614,9 @@ if want efficiency; then # improver's own runs emit several compliant watchers each, landing as # self-noise in the very bucket used to judge the agents. These lines split # the two. This SHARPENS the measurement; it removes nothing. - echo " ├ foreground block ....... ${SLEEP_FG} [Claude] ← the contract violation" - echo " ├ deferred watcher ....... ${SLEEP_BG} [Claude, backgrounded] ← COMPLIANT, not waste" - echo " └ unclassified ........... ${SLEEP_CX} [Codex — see gap note below]" - if [ "$((SLEEP_FG + SLEEP_BG + SLEEP_CX))" -ne "$SLEEPS" ]; then - echo " ⚠️ CLASS SUM $((SLEEP_FG + SLEEP_BG + SLEEP_CX)) != TOTAL ${SLEEPS} — the class" - echo " filter and the total have drifted; trust NEITHER until fixed." - fi + echo " ├ foreground launch ...... ${SLEEP_FG} [Claude, synchronous]" + echo " ├ background launch ...... ${SLEEP_BG} [Claude, run_in_background]" + echo " └ launch mode unknown .... ${SLEEP_CX} [Codex — see gap note below]" # Rates, because a raw total is not a rate. The window selects FILES by # mtime, so session counts swing hard day to day and a raw count fell while # the per-session rate ROSE (442→328 total, but 2.02→3.73/session). Every @@ -590,9 +627,19 @@ if want efficiency; then if [ "$CX_COUNT" -gt 0 ]; then echo " per-session (Codex, n=${CX_COUNT}): unclassified $(awk -v a="$SLEEP_CX" -v b="$CX_COUNT" 'BEGIN{printf "%.2f", a/b}')/session" fi - echo " NOTE: the Claude split reads run_in_background on the tool call, so" - echo " it is STRUCTURAL — prose cannot fake it. The key is OMITTED" - echo " when false, so absence is correctly read as foreground." + echo " NOTE: this splits LAUNCH MODE, which is NOT a compliance verdict." + echo " run_in_background says how Bash started the command, never" + echo " why the sleep exists. The contract permits a FOREGROUND bare" + echo " sleep as a local timer for a process the agent itself" + echo " started, and a BACKGROUND sleep can still be a redundant" + echo " poll alongside foreground polling. So a foreground count is" + echo " a busy-wait CANDIDATE, not a violation, and a background" + echo " count is not an exoneration — correlate with what was being" + echo " waited on before drawing a conclusion." + echo " The split is STRUCTURAL (read off the tool call), so prose" + echo " cannot fake it. The key is OMITTED when false, so absence is" + echo " correctly read as foreground. Calls whose RESULT errored are" + echo " excluded from these classes: a hook-rejected sleep never ran." echo " CODEX IS A STATED GAP, NOT A ZERO: 767 live exec_command" echo " calls carried yield_time_ms (an output-read timeout) and" echo " ZERO carried any background flag, so that runtime exposes no" diff --git a/.claude/scripts/agent-telemetry.test.sh b/.claude/scripts/agent-telemetry.test.sh index f5a941e7..6aeb9675 100755 --- a/.claude/scripts/agent-telemetry.test.sh +++ b/.claude/scripts/agent-telemetry.test.sh @@ -1025,7 +1025,7 @@ check "the mtime window bound is disclosed" "$OUT" "selects FILES by mtime" # ── 6f. sleep background classification ─────────────────────────────────────── echo -echo "sleep classification (foreground block vs deferred watcher)" +echo "sleep classification (launch mode: foreground vs background)" # A BACKGROUNDED sleep is the contract's CHEAP WATCHER, not a busy-wait. Scoring # it as waste is what made the raw total unusable as evidence — the improver's @@ -1036,12 +1036,12 @@ cat > "$FIX/bgsleep/s.jsonl" <<'EOF' EOF OUT=$(CLAUDE_PROJECTS_DIR="$FIX/bgsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ bash "$TARGET" --since-days 3650 --section efficiency 2>&1) -if printf '%s' "$OUT" | grep -qE 'deferred watcher \.+ 1'; then - ok "a backgrounded sleep counts as a deferred watcher" -else bad "a backgrounded sleep counts as a deferred watcher" "$(printf '%s' "$OUT" | grep -E 'foreground|deferred|unclass')"; fi -if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 0'; then - ok "...and is NOT counted as a foreground block" -else bad "...and is NOT counted as a foreground block" "$(printf '%s' "$OUT" | grep -E 'foreground')"; fi +if printf '%s' "$OUT" | grep -qE 'background launch \.+ 1'; then + ok "a backgrounded sleep is classified background-launch" +else bad "a backgrounded sleep is classified background-launch" "$(printf '%s' "$OUT" | grep -E 'foreground|deferred|unclass')"; fi +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 0'; then + ok "...and is NOT classified foreground-launch" +else bad "...and is NOT classified foreground-launch" "$(printf '%s' "$OUT" | grep -E 'foreground')"; fi # The key is OMITTED when false, so ABSENCE must read as foreground. If this # regressed to "absent => unknown", every ordinary busy-wait would vanish. @@ -1052,7 +1052,7 @@ cat > "$FIX/fgsleep/s.jsonl" <<'EOF' EOF OUT=$(CLAUDE_PROJECTS_DIR="$FIX/fgsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ bash "$TARGET" --since-days 3650 --section efficiency 2>&1) -if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 2'; then +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 2'; then ok "an omitted AND an explicit-false flag both read as foreground" else bad "an omitted AND an explicit-false flag both read as foreground" "$(printf '%s' "$OUT" | grep -E 'foreground|deferred')"; fi @@ -1061,31 +1061,63 @@ else bad "an omitted AND an explicit-false flag both read as foreground" "$(prin # them into foreground would invent an attribution the data cannot support. OUT=$(CLAUDE_PROJECTS_DIR="$FIX/empty" CODEX_HOME="$FIX/cxreal" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ bash "$TARGET" --since-days 3650 --section efficiency 2>&1) -if printf '%s' "$OUT" | grep -qE 'unclassified \.+ 1'; then - ok "a Codex sleep is counted as unclassified" -else bad "a Codex sleep is counted as unclassified" "$(printf '%s' "$OUT" | grep -E 'unclass|foreground')"; fi -if printf '%s' "$OUT" | grep -qE 'foreground block \.+ 0'; then +if printf '%s' "$OUT" | grep -qE 'launch mode unknown \.+ 1'; then + ok "a Codex sleep has unknown launch mode" +else bad "a Codex sleep has unknown launch mode" "$(printf '%s' "$OUT" | grep -E 'unclass|foreground')"; fi +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 0'; then ok "...and is NOT attributed to foreground" else bad "...and is NOT attributed to foreground" "$(printf '%s' "$OUT" | grep -E 'foreground')"; fi check "the Codex classification gap is stated" "$OUT" "STATED GAP, NOT A ZERO" +check "launch mode is not presented as a compliance verdict" "$OUT" "NOT a compliance verdict" # The classes must SUM to the total, or a trend is read off a broken split. # Mixed corpus: 2 Claude (1 fg + 1 bg) + 1 Codex = 3. OUT=$(CLAUDE_PROJECTS_DIR="$FIX/bgsleep" CODEX_HOME="$FIX/cxreal" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ bash "$TARGET" --since-days 3650 --section efficiency 2>&1) if printf '%s' "$OUT" | grep -qE 'sleep/poll calls \.\. 2' \ - && printf '%s' "$OUT" | grep -qE 'deferred watcher \.+ 1' \ - && printf '%s' "$OUT" | grep -qE 'unclassified \.+ 1'; then + && printf '%s' "$OUT" | grep -qE 'background launch \.+ 1' \ + && printf '%s' "$OUT" | grep -qE 'launch mode unknown \.+ 1'; then ok "classes sum to the total across both instances" else bad "classes sum to the total across both instances" "$(printf '%s' "$OUT" | grep -E 'sleep/poll|foreground|deferred|unclass')"; fi -if printf '%s' "$OUT" | grep -q 'CLASS SUM'; then - bad "no drift warning on a consistent split" "$(printf '%s' "$OUT" | grep 'CLASS SUM')" -else ok "no drift warning on a consistent split"; fi +# The total is DERIVED from the classes now, so a drift warning would be a +# vacuous guard. Exhaustiveness is what must hold instead: every counted sleep +# lands in exactly one class, which the sum check above asserts directly. # Rates carry their denominator — a raw total is not a rate, and comparing one # against the other is exactly how the 07-19 sleep reading was misread as a win. check "per-session rate states its denominator" "$OUT" "per-session (Claude, n=" +# A sleep the enforcement hook REJECTED never ran. Counting it as a foreground +# block reports time the agent never spent blocking, and inflates precisely the +# metric the hook exists to drive down. +mkdir -p "$FIX/blockedsleep" +cat > "$FIX/blockedsleep/s.jsonl" <<'EOF' +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"blk1","name":"Bash","input":{"command":"sleep 60 && gh pr checks 1"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"blk1","is_error":true,"content":"Blocked: sleep 60 followed by: gh pr checks 1"}]}} +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"ok1","name":"Bash","input":{"command":"sleep 5"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"ok1","is_error":false,"content":"done"}]}} +EOF +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/blockedsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 1'; then + ok "a hook-BLOCKED sleep is excluded; the executed one still counts" +else bad "a hook-BLOCKED sleep is excluded; the executed one still counts" "$(printf '%s' "$OUT" | grep -E 'foreground|sleep/poll')"; fi + +# A TIMED-OUT sleep also carries is_error:true, but it RAN — and it is the most +# expensive block in the corpus. Excluding it (by keying on is_error rather than +# on the never-ran shapes) would hide the worst case while claiming to measure +# busy-waiting. This guard exists because that regression was written and caught. +mkdir -p "$FIX/timedoutsleep" +cat > "$FIX/timedoutsleep/s.jsonl" <<'EOF' +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"to1","name":"Bash","input":{"command":"sleep 600"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"to1","is_error":true,"content":[{"type":"text","text":"Command timed out after 2m 0s"}]}]}} +EOF +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/timedoutsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 1'; then + ok "a TIMED-OUT sleep still counts (it ran; is_error is not 'never ran')" +else bad "a TIMED-OUT sleep still counts (it ran; is_error is not 'never ran')" "$(printf '%s' "$OUT" | grep -E 'foreground|sleep/poll')"; fi + # ── 7. robustness ───────────────────────────────────────────────────────────── echo echo "robustness" From c2b612f662028452914e776e4cef8fe08a0215ce Mon Sep 17 00:00:00 2001 From: Nikolai Emil Damm Date: Mon, 20 Jul 2026 01:13:44 +0200 Subject: [PATCH 3/5] fix(ai-engineer): clean the snapshot on signals, share one never-ran regex, halve the parse passes MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Four review findings, all valid: P1 — the snapshot directory holds an UNREDACTED transcript copy and extracted command text, either of which can carry inline credentials, and it was not in the signal traps. A scheduler SIGTERM could leave that material in /tmp. It is now registered with both traps BEFORE it is populated, and deregistered when removed. The never-ran shapes were a SECOND hand-maintained copy of a list the safety detector already had, so a permission-DENIED sleep still counted as a foreground launch while a hook-blocked one did not. Both now read one NEVER_RAN_RE constant — two copies of a shape list is exactly how detector parity broke six times on the redactor. Denial ids are resolved once per file instead of once per class, cutting six full jq passes per transcript to two. The report note claimed every errored result was excluded, which contradicted both the code and the timeout regression test. Narrowed to the never-ran cases. On the signal-cleanup test: an end-to-end kill test was attempted twice and was VACUOUS both times (it passed with SNAP deliberately removed from the traps). Replaced with a deterministic structural assertion, with the residual gap stated in the test rather than hidden behind a green tick. 114/114; the new guards RED-proven by ablation. Co-Authored-By: Claude Opus 4.8 (1M context) --- .claude/scripts/agent-telemetry.sh | 79 ++++++++++++++++--------- .claude/scripts/agent-telemetry.test.sh | 36 +++++++++++ 2 files changed, 86 insertions(+), 29 deletions(-) diff --git a/.claude/scripts/agent-telemetry.sh b/.claude/scripts/agent-telemetry.sh index 5a5f3a9a..fd681bef 100755 --- a/.claude/scripts/agent-telemetry.sh +++ b/.claude/scripts/agent-telemetry.sh @@ -251,28 +251,34 @@ fi # Reported as a stated gap, never folded into # FG — a false coverage claim beats no claim. # "" (default) every command, unchanged legacy behaviour. +# The ONE definition of "this tool call never executed", shared by the safety +# section's denial detector and the sleep classifier. Kept as a single constant +# because two hand-maintained copies of a shape list is exactly how detector +# parity broke six times on the redactor: the sleep classifier originally +# matched a narrower subset, so a permission-DENIED sleep still counted as a +# foreground launch. +# +# Deliberately NOT `is_error`, which is far broader than "never ran" — a +# TIMED-OUT sleep carries is_error:true and is the single most expensive real +# block in the corpus, so suppressing it would hide the worst case while +# claiming to measure it. +NEVER_RAN_RE='[[:space:]]*Blocked:|^[[:space:]]*Permission to use [A-Za-z_]+ with command|"Permission to use [A-Za-z_]+ with command|Claude requested permissions to use|approval (denied|required) for tool' + +# tool_use ids whose result shows the call never ran. Computed ONCE per file and +# passed into commands_in: recomputing it per class made every transcript parsed +# six times instead of two, which on a 400-session corpus is real scheduled +# latency, not a micro-optimisation. +denied_ids() { + jq -Rr --arg re "$NEVER_RAN_RE" 'select(length>0)|(try fromjson catch empty) + | select(.type=="user") | .message.content[]? + | select(.type=="tool_result" and .is_error==true) + | select((.content | tostring) | test($re)) + | .tool_use_id // empty' "$1" 2>/dev/null \ + | jq -Rs 'split("\n")|map(select(length>0))' 2>/dev/null +} + commands_in() { - local f="$1" cls="${2:-}" errs='[]' - # Exclude only calls that NEVER EXECUTED: the enforcement hook rejects - # `sleep N && ` and the permission layer denies a command, both leaving - # the tool_use in the transcript with no time spent. Counting those as blocks - # reports waiting that never happened, and inflates exactly the metric the - # hook exists to drive down. - # - # NOT keyed on is_error, which is far broader than "never ran" — a TIMED-OUT - # sleep carries is_error:true and is the single most expensive real block in - # the corpus. Suppressing it would hide the worst case while claiming to - # measure it. Match the two never-ran shapes explicitly instead. - if [ -n "$cls" ]; then - errs=$(jq -Rr 'select(length>0)|(try fromjson catch empty) - | select(.type=="user") | .message.content[]? - | select(.type=="tool_result" and .is_error==true) - | select((.content | tostring) - | test("Blocked:|^Permission to use|\\\"Permission to use")) - | .tool_use_id // empty' "$f" 2>/dev/null \ - | jq -Rs 'split("\n")|map(select(length>0))' 2>/dev/null) - [ -n "$errs" ] || errs='[]' - fi + local f="$1" cls="${2:-}" errs="${3:-[]}" jq -r --arg cls "$cls" --argjson errs "$errs" ' .. | objects | ( @@ -586,13 +592,22 @@ if want efficiency; then # scanned total. Snapshot each file ONCE and derive every class from that # copy, so the counts are mutually consistent by construction rather than # merely checked afterwards. - SNAP=$(mktemp -d) || SNAP="" + # SNAP holds an UNREDACTED transcript copy plus extracted command text, both + # of which can contain inline credentials — so it is registered with the + # signal traps BEFORE it is populated. A scheduler SIGTERM between here and + # the cleanup below would otherwise leave that material in /tmp. + SNAP=$(mktemp -d "${TMPDIR:-/tmp}/.agtel_snap.XXXXXXXX") || { echo "cannot create temp dir" >&2; exit 3; } + trap 'rm -f "$ERRTMP" "$INJTMP"; rm -rf "$SNAP"' EXIT + trap 'rm -f "$ERRTMP" "$INJTMP"; rm -rf "$SNAP"; trap - HUP INT TERM; kill -s INT $$' HUP INT TERM : > "$SNAP/FG"; : > "$SNAP/BG"; : > "$SNAP/CX" printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' | while IFS= read -r f; do cp "$f" "$SNAP/cur" 2>/dev/null || continue - commands_in "$SNAP/cur" FG >> "$SNAP/FG" - commands_in "$SNAP/cur" BG >> "$SNAP/BG" - commands_in "$SNAP/cur" CX >> "$SNAP/CX" + # Denial ids resolved ONCE per file, then reused for all three classes: + # recomputing per class parsed every transcript six times instead of two. + d=$(denied_ids "$SNAP/cur"); [ -n "$d" ] || d='[]' + commands_in "$SNAP/cur" FG "$d" >> "$SNAP/FG" + commands_in "$SNAP/cur" BG "$d" >> "$SNAP/BG" + commands_in "$SNAP/cur" CX "$d" >> "$SNAP/CX" done SLEEP_FG=$(count_sleeps < "$SNAP/FG") SLEEP_BG=$(count_sleeps < "$SNAP/BG") @@ -604,6 +619,9 @@ if want efficiency; then # FG or BG; a Codex call is CX; there is no fourth command source). SLEEPS=$((SLEEP_FG + SLEEP_BG + SLEEP_CX)) rm -rf "$SNAP" 2>/dev/null + SNAP="" + trap 'rm -f "$ERRTMP" "$INJTMP"' EXIT + trap 'rm -f "$ERRTMP" "$INJTMP"; trap - HUP INT TERM; kill -s INT $$' HUP INT TERM echo " [BOTH instances: ${SF_COUNT} Claude + ${CX_COUNT} Codex sessions]" echo " bash timeouts .............. ${TIMEOUTS} (each = a foreground block that produced nothing)" echo " interrupted tool calls ..... ${INTERRUPT}" @@ -638,8 +656,11 @@ if want efficiency; then echo " waited on before drawing a conclusion." echo " The split is STRUCTURAL (read off the tool call), so prose" echo " cannot fake it. The key is OMITTED when false, so absence is" - echo " correctly read as foreground. Calls whose RESULT errored are" - echo " excluded from these classes: a hook-rejected sleep never ran." + echo " correctly read as foreground. HOOK-REJECTED and" + echo " PERMISSION-DENIED calls are excluded from these classes" + echo " because they never ran; a call that ran and FAILED still" + echo " counts, including a TIMED-OUT sleep — that one blocked" + echo " longest and is the last thing to hide." echo " CODEX IS A STATED GAP, NOT A ZERO: 767 live exec_command" echo " calls carried yield_time_ms (an output-read timeout) and" echo " ZERO carried any background flag, so that runtime exposes no" @@ -702,7 +723,7 @@ if want safety; then # counts decide guard-vs-agent, so inflating them argues for loosening a # guard that never actually fired. printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' | while IFS= read -r f; do - jq -r ' + jq -r --arg never_ran "$NEVER_RAN_RE" ' .. | objects | ( (select(.type=="tool_result" and .is_error==true) @@ -721,7 +742,7 @@ if want safety; then elif type=="string" then . else empty end) ) | select(type=="string") - | select(test("[[:space:]]*Blocked:|^[[:space:]]*Permission to use [A-Za-z_]+ with command|Claude requested permissions to use|approval (denied|required) for tool")) + | select(test($never_ran)) | .[0:80] ' "$f" 2>/dev/null done | redact | sed -E 's/[0-9]+//g' | sort | uniq -c | sort -rn | head -10 | sed 's/^/ /' diff --git a/.claude/scripts/agent-telemetry.test.sh b/.claude/scripts/agent-telemetry.test.sh index 6aeb9675..07986766 100755 --- a/.claude/scripts/agent-telemetry.test.sh +++ b/.claude/scripts/agent-telemetry.test.sh @@ -1118,6 +1118,42 @@ if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 1'; then ok "a TIMED-OUT sleep still counts (it ran; is_error is not 'never ran')" else bad "a TIMED-OUT sleep still counts (it ran; is_error is not 'never ran')" "$(printf '%s' "$OUT" | grep -E 'foreground|sleep/poll')"; fi +# EVERY recognised never-ran shape must be excluded, not just the hook's. The +# sleep classifier and the safety detector share ONE regex constant precisely so +# a shape recognised by one cannot be missed by the other. +mkdir -p "$FIX/deniedsleep" +cat > "$FIX/deniedsleep/s.jsonl" <<'EOF' +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"d1","name":"Bash","input":{"command":"sleep 60"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d1","is_error":true,"content":"Claude requested permissions to use Bash, but you have not granted it yet"}]}} +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"d2","name":"Bash","input":{"command":"sleep 45"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d2","is_error":true,"content":"approval denied for tool Bash"}]}} +EOF +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/deniedsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 0'; then + ok "permission-denied sleeps are excluded too, not just hook-blocked ones" +else bad "permission-denied sleeps are excluded too, not just hook-blocked ones" "$(printf '%s' "$OUT" | grep -E 'foreground|sleep/poll')"; fi + +# The snapshot holds an UNREDACTED transcript copy plus extracted command text, +# so a signal must not leave it in /tmp. +# +# STRUCTURAL check, and the limitation is stated rather than papered over: an +# end-to-end "kill the miner mid-snapshot" test was attempted TWICE and was +# VACUOUS both times — first the run finished before the signal landed, then the +# signal landed before the snapshot was created, and on a corpus large enough to +# widen the window the miner still self-cleaned before the TERM arrived. Both +# versions passed with SNAP deliberately removed from the traps, which is the +# definition of a guard that cannot fail. A deterministic assertion that the +# signal traps actually cover SNAP is worth more than a green test that proves +# nothing; the residual gap is that this reads the registration, not the effect. +TRAPS=$(grep -c "rm -rf \"\$SNAP\"" "$TARGET" || true) +if [ "${TRAPS:-0}" -ge 2 ]; then + ok "SNAP is registered in BOTH the EXIT and HUP/INT/TERM traps" +else bad "SNAP is registered in BOTH the EXIT and HUP/INT/TERM traps" "occurrences=$TRAPS (expected >=2: EXIT + signal trap)"; fi +if grep -q "trap 'rm -f \"\$ERRTMP\" \"\$INJTMP\"; rm -rf \"\$SNAP\"; trap - HUP INT TERM" "$TARGET"; then + ok "the signal trap (not just EXIT) removes the unredacted snapshot" +else bad "the signal trap (not just EXIT) removes the unredacted snapshot" "signal trap does not cover SNAP"; fi + # ── 7. robustness ───────────────────────────────────────────────────────────── echo echo "robustness" From af7531e4ae0ce1e37eee8e4ab6dcec69473b3d34 Mon Sep 17 00:00:00 2001 From: Nikolai Emil Damm Date: Mon, 20 Jul 2026 01:30:06 +0200 Subject: [PATCH 4/5] refactor(ai-engineer): delete the transcript snapshot; classify in one tagged pass MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Round 3 raised four findings and three clustered on the snapshot added in round 2 — which is the signal that the snapshot was the defect, not something to harden. Removing it closes all three at once and leaves the script smaller. The P1 was unfixable in place: `main` is the left side of `main | redact`, so it runs in a pipeline subshell and a trap set there never fires when the scheduler signals the top-level PID. The snapshot existed only to keep the class counts consistent — a single tagged pass gives that for free, writes no unredacted copy to disk, and needs no cleanup at all. Four transcript traversals become one. Each line of a command carries a control-character class tag, so multi-line commands keep their structure and untrusted command text cannot forge a tag and move itself between classes (guarded). Also: the never-ran match is now anchored to the harness denial envelope, so an executed command that fails while printing "approval denied for tool" in its own output is no longer treated as never-run and silently removed from every class; and the skill's guidance no longer calls a background launch "compliant", which contradicted the report's own warning and would have produced exactly the false verdict that warning exists to prevent. Classification now lives in one function, so there is no second classifier to drift from the first. 115/115; live runtime 21.5s -> 17.8s. Co-Authored-By: Claude Opus 4.8 (1M context) --- .claude/scripts/agent-telemetry.sh | 131 ++++++++++++---------- .claude/scripts/agent-telemetry.test.sh | 33 ++++-- .claude/skills/agent-improvement/SKILL.md | 13 ++- 3 files changed, 107 insertions(+), 70 deletions(-) diff --git a/.claude/scripts/agent-telemetry.sh b/.claude/scripts/agent-telemetry.sh index fd681bef..7dfa210a 100755 --- a/.claude/scripts/agent-telemetry.sh +++ b/.claude/scripts/agent-telemetry.sh @@ -236,21 +236,8 @@ fi # untrusted prose that merely mentions `sleep 60` would otherwise manufacture a # busy-wait pattern, and busy-wait counts are evidence the improver acts on. # -# Optional $2 = BACKGROUND CLASS filter, so a caller can split the same commands -# by whether the agent blocked on them. Deliberately ONE jq expression with a -# filter rather than a second extractor: a parallel copy is how detector parity -# broke six times on the redactor, and here it would silently make the class -# counts stop summing to the total. -# FG Claude, foreground — run_in_background absent/false (the default; -# the key is OMITTED when false, so absence=FG) -# BG Claude, backgrounded — run_in_background:true -# CX Codex — UNCLASSIFIABLE: 767 live exec_command calls -# carried `yield_time_ms` (an output-read -# timeout) and ZERO carried a background flag, -# so no backgrounding surface exists to read. -# Reported as a stated gap, never folded into -# FG — a false coverage claim beats no claim. -# "" (default) every command, unchanged legacy behaviour. +# Every command, unclassified. Launch-mode classification lives ONLY in +# tagged_commands_in — one classifier, so there is no second copy to drift. # The ONE definition of "this tool call never executed", shared by the safety # section's denial detector and the sleep classifier. Kept as a single constant # because two hand-maintained copies of a shape list is exactly how detector @@ -262,12 +249,16 @@ fi # TIMED-OUT sleep carries is_error:true and is the single most expensive real # block in the corpus, so suppressing it would hide the worst case while # claiming to measure it. -NEVER_RAN_RE='[[:space:]]*Blocked:|^[[:space:]]*Permission to use [A-Za-z_]+ with command|"Permission to use [A-Za-z_]+ with command|Claude requested permissions to use|approval (denied|required) for tool' +# +# ANCHORED to the harness's denial envelope, not searched anywhere in the text. +# An executed command that sleeps and later fails while printing application or +# test output containing "approval denied for tool" would otherwise be treated +# as never-run and removed from every class — silently deleting a real block, +# which is the same failure mode as the is_error over-match this replaced. +NEVER_RAN_SHAPES='Blocked:|Permission to use [A-Za-z_]+ with command|Claude requested permissions to use|approval (denied|required) for tool' +NEVER_RAN_RE='^[[:space:]]*("|\[)?[[:space:]]*()?[[:space:]]*('"$NEVER_RAN_SHAPES"')' -# tool_use ids whose result shows the call never ran. Computed ONCE per file and -# passed into commands_in: recomputing it per class made every transcript parsed -# six times instead of two, which on a 400-session corpus is real scheduled -# latency, not a micro-optimisation. +# tool_use ids whose result shows the call never ran, resolved once per file. denied_ids() { jq -Rr --arg re "$NEVER_RAN_RE" 'select(length>0)|(try fromjson catch empty) | select(.type=="user") | .message.content[]? @@ -277,24 +268,49 @@ denied_ids() { | jq -Rs 'split("\n")|map(select(length>0))' 2>/dev/null } -commands_in() { - local f="$1" cls="${2:-}" errs="${3:-[]}" - jq -r --arg cls "$cls" --argjson errs "$errs" ' +# ONE traversal per transcript emitting EVERY command tagged with its launch +# class, so the three class counts come from a single consistent read instead of +# one re-parse per class. Each LINE of a command is prefixed \001\002 so a +# multi-line command survives intact; control characters are used because no +# real shell command line starts with one, which keeps untrusted command text +# from forging a tag and moving itself between classes. +tagged_commands_in() { + local f="$1" errs + errs=$(denied_ids "$f"); [ -n "$errs" ] || errs='[]' + jq -r --argjson errs "$errs" ' .. | objects | ( - # Claude: tool_use carrying a Bash command. (select(.type=="tool_use") - | select($cls == "" or $cls == (if .input?.run_in_background == true - then "BG" else "FG" end)) - # $i is bound BEFORE index() so `.` is not rebound inside the test — - # `$arr | index(.)` there would compare the array against itself and - # match everything (a trap that has made a guard vacuous before). + | ((if .input?.run_in_background == true then "BG" else "FG" end)) as $c | (.id? // "") as $i | select($i == "" or (($errs | index($i)) | not)) + | (.input?.command? // empty) | select(type=="string") | select(length>0) + | split("\n") | map("\u0001" + $c + "\u0002" + .) | .[]), + (select(.type=="function_call") + | (.arguments? // empty) + | (try (fromjson | (.command? // .cmd? // empty)) catch empty) + | select(type=="string") | select(length>0) + | split("\n") | map("\u0001CX\u0002" + .) | .[]), + (select(.type=="custom_tool_call") + | .input? // empty | select(type=="string") + | [scan("cmd:\\s*\"((?:[^\"\\\\]|\\\\.)*)\"")] | .[]? | .[0]? + | select(type=="string") | select(length>0) + | gsub("\\\\n"; "\n") | gsub("\\\\t"; " ") | gsub("\\\\\""; "\"") + | split("\n") | map("\u0001CX\u0002" + .) | .[]) + ) + ' "$f" 2>/dev/null +} + +commands_in() { + local f="$1" + jq -r ' + .. | objects + | ( + # Claude: tool_use carrying a Bash command. + (select(.type=="tool_use") | .input?.command? // empty), # Codex, JSON-argument shape (function_call). (select(.type=="function_call") - | select($cls == "" or $cls == "CX") | .arguments? // empty | (try (fromjson | (.command? // .cmd? // empty)) catch empty)), # Codex, REAL observed shape: custom_tool_call name="exec" whose .input is @@ -303,7 +319,6 @@ commands_in() { # (An invented JSON fixture passed here for two rounds while this real # shape was silently unparsed — match the format that actually ships.) (select(.type=="custom_tool_call") - | select($cls == "" or $cls == "CX") | .input? // empty | select(type=="string") | [scan("cmd:\\s*\"((?:[^\"\\\\]|\\\\.)*)\"")] | .[]? | .[0]? @@ -592,36 +607,32 @@ if want efficiency; then # scanned total. Snapshot each file ONCE and derive every class from that # copy, so the counts are mutually consistent by construction rather than # merely checked afterwards. - # SNAP holds an UNREDACTED transcript copy plus extracted command text, both - # of which can contain inline credentials — so it is registered with the - # signal traps BEFORE it is populated. A scheduler SIGTERM between here and - # the cleanup below would otherwise leave that material in /tmp. - SNAP=$(mktemp -d "${TMPDIR:-/tmp}/.agtel_snap.XXXXXXXX") || { echo "cannot create temp dir" >&2; exit 3; } - trap 'rm -f "$ERRTMP" "$INJTMP"; rm -rf "$SNAP"' EXIT - trap 'rm -f "$ERRTMP" "$INJTMP"; rm -rf "$SNAP"; trap - HUP INT TERM; kill -s INT $$' HUP INT TERM - : > "$SNAP/FG"; : > "$SNAP/BG"; : > "$SNAP/CX" - printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' | while IFS= read -r f; do - cp "$f" "$SNAP/cur" 2>/dev/null || continue - # Denial ids resolved ONCE per file, then reused for all three classes: - # recomputing per class parsed every transcript six times instead of two. - d=$(denied_ids "$SNAP/cur"); [ -n "$d" ] || d='[]' - commands_in "$SNAP/cur" FG "$d" >> "$SNAP/FG" - commands_in "$SNAP/cur" BG "$d" >> "$SNAP/BG" - commands_in "$SNAP/cur" CX "$d" >> "$SNAP/CX" - done - SLEEP_FG=$(count_sleeps < "$SNAP/FG") - SLEEP_BG=$(count_sleeps < "$SNAP/BG") - SLEEP_CX=$(count_sleeps < "$SNAP/CX") - # The total is now the SUM of the classes, not a fourth independent scan. - # That makes class-vs-total drift impossible instead of detectable — and a - # drift warning over a sum would be a vacuous guard, which is worse than - # none. Classification is exhaustive by construction (a Claude tool_use is - # FG or BG; a Codex call is CX; there is no fourth command source). + # ONE tagged pass per transcript, held in memory — no temp copy. + # + # The earlier design copied each transcript to a temp dir so the classes + # could not disagree. That copy was an UNREDACTED transcript holding + # potential credentials, and protecting it turned out to be unfixable in + # place: `main` is the left side of `main | redact`, so it runs in a + # pipeline SUBSHELL and a trap set here never fires when the scheduler + # signals the top-level PID. Rather than harden the copy, the copy is gone — + # a single pass is inherently self-consistent, needs no snapshot, and cannot + # leave anything on disk to clean up. + TAGGED=$(printf '%s\n%s\n' "$SF_CACHE" "$CX_CACHE" | grep -v '^$' \ + | while IFS= read -r f; do tagged_commands_in "$f"; done) + # Each LINE of a command carries its class tag, so multi-line commands keep + # their structure and their order within a class — which the separator- + # anchored sleep regex and the heredoc stripper both depend on. + class_lines() { printf '%s\n' "$TAGGED" | awk -v c="$1" ' + index($0, "\001" c "\002")==1 { print substr($0, length(c)+3) }'; } + SLEEP_FG=$(class_lines FG | count_sleeps) + SLEEP_BG=$(class_lines BG | count_sleeps) + SLEEP_CX=$(class_lines CX | count_sleeps) + # The total is the SUM of the classes, not a separate scan. That makes + # class-vs-total drift impossible instead of detectable — and a drift + # warning over a sum would be a vacuous guard, which is worse than none. + # Classification is exhaustive by construction (a Claude tool_use is FG or + # BG; a Codex call is CX; there is no fourth command source). SLEEPS=$((SLEEP_FG + SLEEP_BG + SLEEP_CX)) - rm -rf "$SNAP" 2>/dev/null - SNAP="" - trap 'rm -f "$ERRTMP" "$INJTMP"' EXIT - trap 'rm -f "$ERRTMP" "$INJTMP"; trap - HUP INT TERM; kill -s INT $$' HUP INT TERM echo " [BOTH instances: ${SF_COUNT} Claude + ${CX_COUNT} Codex sessions]" echo " bash timeouts .............. ${TIMEOUTS} (each = a foreground block that produced nothing)" echo " interrupted tool calls ..... ${INTERRUPT}" diff --git a/.claude/scripts/agent-telemetry.test.sh b/.claude/scripts/agent-telemetry.test.sh index 07986766..8d6a1d58 100755 --- a/.claude/scripts/agent-telemetry.test.sh +++ b/.claude/scripts/agent-telemetry.test.sh @@ -1146,13 +1146,32 @@ else bad "permission-denied sleeps are excluded too, not just hook-blocked ones" # definition of a guard that cannot fail. A deterministic assertion that the # signal traps actually cover SNAP is worth more than a green test that proves # nothing; the residual gap is that this reads the registration, not the effect. -TRAPS=$(grep -c "rm -rf \"\$SNAP\"" "$TARGET" || true) -if [ "${TRAPS:-0}" -ge 2 ]; then - ok "SNAP is registered in BOTH the EXIT and HUP/INT/TERM traps" -else bad "SNAP is registered in BOTH the EXIT and HUP/INT/TERM traps" "occurrences=$TRAPS (expected >=2: EXIT + signal trap)"; fi -if grep -q "trap 'rm -f \"\$ERRTMP\" \"\$INJTMP\"; rm -rf \"\$SNAP\"; trap - HUP INT TERM" "$TARGET"; then - ok "the signal trap (not just EXIT) removes the unredacted snapshot" -else bad "the signal trap (not just EXIT) removes the unredacted snapshot" "signal trap does not cover SNAP"; fi +# The classifier must never write an unredacted transcript copy to disk. An +# earlier revision snapshotted each transcript to a temp dir to keep the class +# counts consistent, which put credential-bearing content in /tmp — and it could +# not be protected in place, because `main` runs in a pipeline subshell so a trap +# set there never fires when the scheduler signals the top-level PID. The copy +# was removed rather than hardened; this guard stops it coming back. +SNAPLEFT=$(ls -d "${TMPDIR:-/tmp}"/.agtel_snap.* 2>/dev/null | wc -l | tr -d ' ') +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/projects" CODEX_HOME="$FIX/codex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +SNAPNOW=$(ls -d "${TMPDIR:-/tmp}"/.agtel_snap.* 2>/dev/null | wc -l | tr -d ' ') +if [ "$SNAPNOW" -le "$SNAPLEFT" ]; then + ok "no transcript snapshot directory is left on disk" +else bad "no transcript snapshot directory is left on disk" "before=$SNAPLEFT after=$SNAPNOW"; fi +if grep -q 'cp "$f" "$SNAP/cur"' "$TARGET"; then + bad "the classifier does not copy raw transcripts to a temp dir" "found a raw transcript cp" +else ok "the classifier does not copy raw transcripts to a temp dir"; fi + +# A command's own text must not be able to forge a class tag and move itself +# between classes — the tag is control-character delimited for exactly this. +mkdir -p "$FIX/forgetag" +printf '%s\n' '{"type":"assistant","message":{"content":[{"type":"tool_use","id":"x1","name":"Bash","input":{"command":"echo BGnot-a-real-tag\nsleep 60"}}]}}' > "$FIX/forgetag/s.jsonl" +OUT=$(CLAUDE_PROJECTS_DIR="$FIX/forgetag" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ + bash "$TARGET" --since-days 3650 --section efficiency 2>&1) +if printf '%s' "$OUT" | grep -qE 'foreground launch \.+ 1' && printf '%s' "$OUT" | grep -qE 'background launch \.+ 0'; then + ok "command text cannot forge a class tag" +else bad "command text cannot forge a class tag" "$(printf '%s' "$OUT" | grep -E 'foreground|background')"; fi # ── 7. robustness ───────────────────────────────────────────────────────────── echo diff --git a/.claude/skills/agent-improvement/SKILL.md b/.claude/skills/agent-improvement/SKILL.md index 754e7129..b2db6e34 100644 --- a/.claude/skills/agent-improvement/SKILL.md +++ b/.claude/skills/agent-improvement/SKILL.md @@ -82,9 +82,16 @@ cycle-time proxy) are part of the record — never silently paper over them. **Record sleeps as RATES, split by class — a raw total is not a rate.** The window selects files by mtime, so session counts swing hard day to day: a raw sleep total once fell 442→328 while the per-session rate *rose* 2.02→3.73, and the fall was read as a win. Always state the denominator, and -never compare a raw count against a per-session one. The classes are not interchangeable either — a -backgrounded `deferred watcher` is contract-COMPLIANT, and Codex's sleeps are **unattributed** (that -runtime exposes no backgrounding flag), so only `foreground block` is evidence of busy-waiting. +never compare a raw count against a per-session one. + +**The class is a LAUNCH MODE, never a compliance verdict.** `foreground launch` and `background +launch` say only how the command was started. The contract permits a foreground bare sleep as a +local timer for a process the agent itself started, and a backgrounded sleep can still be a +redundant poll running alongside foreground polling — so a foreground count is a busy-wait +*candidate* to investigate, not a violation to report, and a background count is not an +exoneration. Correlate with what was actually being waited on before drawing any conclusion. Codex's +sleeps carry no launch mode at all (that runtime exposes no backgrounding flag) and are +**unattributed** — never fold them into either class. **A metric that moved the wrong way since yesterday outranks a new finding** — regression first. Verify any change from a previous run that is awaiting confirmation (step 5) before starting new work. From 690282122bb43ad7f4305c41763da910ff49fd20 Mon Sep 17 00:00:00 2001 From: Nikolai Emil Damm Date: Mon, 20 Jul 2026 01:40:40 +0200 Subject: [PATCH 5/5] fix(ai-engineer): normalize tool_result content before matching the denial envelope MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A tool_result carries `content` either as a plain string or as the array-of-text-blocks shape. Anchoring the never-ran match (previous commit) without normalising meant `tostring` produced `[{"type":"text"...` for the array form, so the pattern never reached the denial text and a call that never ran was counted as an executed foreground launch. Normalised the same way the safety detector already does. Every denial fixture in the suite used string content, which is why anchoring looked correct — the array shape is now covered explicitly, RED-proven by ablation. 115/115. Co-Authored-By: Claude Opus 4.8 (1M context) --- .claude/scripts/agent-telemetry.sh | 14 ++++++++++++-- .claude/scripts/agent-telemetry.test.sh | 9 ++++++++- 2 files changed, 20 insertions(+), 3 deletions(-) diff --git a/.claude/scripts/agent-telemetry.sh b/.claude/scripts/agent-telemetry.sh index 7dfa210a..eba932cf 100755 --- a/.claude/scripts/agent-telemetry.sh +++ b/.claude/scripts/agent-telemetry.sh @@ -256,14 +256,24 @@ fi # as never-run and removed from every class — silently deleting a real block, # which is the same failure mode as the is_error over-match this replaced. NEVER_RAN_SHAPES='Blocked:|Permission to use [A-Za-z_]+ with command|Claude requested permissions to use|approval (denied|required) for tool' -NEVER_RAN_RE='^[[:space:]]*("|\[)?[[:space:]]*()?[[:space:]]*('"$NEVER_RAN_SHAPES"')' +NEVER_RAN_RE='^[[:space:]]*()?[[:space:]]*('"$NEVER_RAN_SHAPES"')' # tool_use ids whose result shows the call never ran, resolved once per file. +# +# The content is NORMALISED to its text before matching, exactly as the safety +# detector does. A tool_result may carry `content` as a plain string OR as the +# array-of-text-blocks shape; `tostring` on the array yields `[{"type":"text"…`, +# so an anchored pattern never reaches the denial text and the call is counted +# as an executed foreground launch even though it never ran. Anchoring without +# normalising is precisely that bug. denied_ids() { jq -Rr --arg re "$NEVER_RAN_RE" 'select(length>0)|(try fromjson catch empty) | select(.type=="user") | .message.content[]? | select(.type=="tool_result" and .is_error==true) - | select((.content | tostring) | test($re)) + | select((.content + | if type=="array" then (map(select(.type=="text").text // empty)|join(" ")) + elif type=="string" then . else tostring end) + | test($re)) | .tool_use_id // empty' "$1" 2>/dev/null \ | jq -Rs 'split("\n")|map(select(length>0))' 2>/dev/null } diff --git a/.claude/scripts/agent-telemetry.test.sh b/.claude/scripts/agent-telemetry.test.sh index 8d6a1d58..75e31d4a 100755 --- a/.claude/scripts/agent-telemetry.test.sh +++ b/.claude/scripts/agent-telemetry.test.sh @@ -1121,12 +1121,19 @@ else bad "a TIMED-OUT sleep still counts (it ran; is_error is not 'never ran')" # EVERY recognised never-ran shape must be excluded, not just the hook's. The # sleep classifier and the safety detector share ONE regex constant precisely so # a shape recognised by one cannot be missed by the other. +# NOTE the two content SHAPES here: a plain string and the array-of-text-blocks +# form. Both are supported by the harness, and an anchored pattern applied to +# `tostring` of the array sees `[{"type":"text"…` and never reaches the denial +# text — so the array case must be covered explicitly or the anchoring silently +# counts a never-run sleep as an executed foreground launch. mkdir -p "$FIX/deniedsleep" cat > "$FIX/deniedsleep/s.jsonl" <<'EOF' {"type":"assistant","message":{"content":[{"type":"tool_use","id":"d1","name":"Bash","input":{"command":"sleep 60"}}]}} {"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d1","is_error":true,"content":"Claude requested permissions to use Bash, but you have not granted it yet"}]}} {"type":"assistant","message":{"content":[{"type":"tool_use","id":"d2","name":"Bash","input":{"command":"sleep 45"}}]}} -{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d2","is_error":true,"content":"approval denied for tool Bash"}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d2","is_error":true,"content":[{"type":"text","text":"approval denied for tool Bash"}]}]}} +{"type":"assistant","message":{"content":[{"type":"tool_use","id":"d3","name":"Bash","input":{"command":"sleep 30"}}]}} +{"type":"user","message":{"content":[{"type":"tool_result","tool_use_id":"d3","is_error":true,"content":[{"type":"text","text":"Blocked: sleep 30 followed by: gh pr checks"}]}]}} EOF OUT=$(CLAUDE_PROJECTS_DIR="$FIX/deniedsleep" CODEX_HOME="$FIX/nocodex" MONOREPO_DIR="$FIX/monorepo" HOME="$FIX" \ bash "$TARGET" --since-days 3650 --section efficiency 2>&1)