From 0526a7fe7f15e4767bdd4fb2efafc9dc6643f08e Mon Sep 17 00:00:00 2001 From: Yaraslau Tamashevich Date: Wed, 23 Sep 2026 04:56:34 +0200 Subject: [PATCH 1/4] ci: a pipeline's exit status is its left-hand side's, in every workflow (fixes #730) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The mutation campaign step ran bash scripts/mutation.sh "" | tee "mutation-.log" under `bash -e {0}` -- `-e` but not `-o pipefail` -- so the step's status was `tee`'s. scripts/mutation.sh takes deliberate care to exit 1 when mull-runner writes no report; that 1 was discarded, the step went green, and the failure surfaced one step later as check_mutation_regression.py failing to *open* build/mutation-core-forms/mutation-core-forms.txt. Two weeks of scheduled runs measured nothing and CI said so only as a missing file. Verified by driving the step's own shell fragment the way GitHub does, against a stub mutation.sh that fails the way run 35592789912 did: BEFORE: campaign step exit = 0 AFTER: campaign step exit = 1 AFTER (a campaign that prints nothing and exits 0): exit = 1 The third line is the `test -s` on the log: pipefail cannot see a script that prints nothing and exits 0, and an empty log is the same claim of success over nothing. ## The sweep, and why this closes the class rather than the instance #730 asked for an audit of every other `run:` block. Parsing all 169 of them across the seven workflow files found 13 pipelines, 6 of them unguarded: * mutation.yml:119 `scripts/mutation.sh | tee` -- this defect * ci.yml:1435,1898 `echo "$changed" | grep -qE` -- `echo` cannot fail * ci.yml:2627 `tr -cd '\0' < … | wc -c` -- the `-lt 100` guard already catches the vacuous case * ci.yml:2965 `find A B … | head -1` -- deliberate: the left side is *expected* to fail * wasm-ladder.yml:209 `find … | sort` -- prints nothing and exits 0 whether the tree is empty or absent Five are now guarded; the sixth carries `# pipefail-ok:` with its reason, which is the one morph#479's own comment already explains at length. scripts/check_workflow_pipefail.py makes that state the rule. Every pipeline in a bash `run:` block must be covered by a pipefail shell, a `set … pipefail` earlier in the block, or a `# pipefail-ok: ` marker -- and a marker that excuses nothing is an error, because it sits inert on a line ready to excuse whatever is written there next. Between morph#479 and morph#730 the same trap was guarded against by hand in three steps, and ci.yml:286 carries a comment about this exact hazard. The guard was known and applied inconsistently, which is what a gate is for. The gate is not vacuous on arrival: it found all six. Its self-test drives 13 cases, including the two that decide whether it measures anything -- a tree whose `run:` blocks it can no longer parse, and one whose pipelines it can no longer recognise, both of which it would otherwise pass while reading nothing. ok: the unmodified tree passes ok: caught: morph#730: the mutation campaign's pipefail removed ok: caught: morph#479: the clang-tidy step's pipefail removed ok: caught: a newly added unguarded pipeline ok: caught: the run-block syntax moved out from under the parser ok: caught: every pipeline rewritten out of the shape the gate reads ok: caught: an exemption with no reason ok: caught: an exemption left behind after its pipeline went away ok: accepted: a disjunction is not a pipeline ok: accepted: a quoted pipe character is not a pipeline ok: accepted: a GitHub expression containing || ok: accepted: a pipeline under an explicit shell: bash ok: accepted: a pipeline in a pwsh step The self-test's `edit()` helper checks three things the ten sibling self-tests' copy does not -- a `sed` that failed, a `sed` that emptied the file, and a `sed` that matched nothing. All three fired while this file was being written, and the first two produced passing cases over an empty workflow. Filed as morph#746 rather than fixed across the other ten here. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW --- .github/workflows/ci.yml | 66 +++- .github/workflows/mutation.yml | 23 +- .github/workflows/wasm-ladder.yml | 8 +- scripts/check_workflow_pipefail.py | 413 ++++++++++++++++++++++++ scripts/test_check_workflow_pipefail.sh | 229 +++++++++++++ 5 files changed, 735 insertions(+), 4 deletions(-) create mode 100644 scripts/check_workflow_pipefail.py create mode 100644 scripts/test_check_workflow_pipefail.sh diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 346d4ad67..ef5b4e279 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -1412,6 +1412,12 @@ jobs: - name: Determine whether the ladder needs to run id: filter run: | + # Not because `echo | grep` can lose a status today -- `echo` does + # not fail -- but because this block decides whether a whole job + # runs, and the next edit to it is the one that adds a pipeline + # that can (morph#730). scripts/check_workflow_pipefail.py enforces + # the same rule on every other `run:` block. + set -o pipefail if [ "${{ github.event_name }}" = "pull_request" ]; then base="${{ github.event.pull_request.base.sha }}" else @@ -1883,6 +1889,12 @@ jobs: - name: Determine whether the ladder needs to run id: filter run: | + # Not because `echo | grep` can lose a status today -- `echo` does + # not fail -- but because this block decides whether a whole job + # runs, and the next edit to it is the one that adds a pipeline + # that can (morph#730). scripts/check_workflow_pipefail.py enforces + # the same rule on every other `run:` block. + set -o pipefail if [ "${{ github.event_name }}" = "pull_request" ]; then base="${{ github.event.pull_request.base.sha }}" else @@ -2623,6 +2635,11 @@ jobs: - name: Check every tracked C++ file against .clang-format run: | + # Without pipefail the count below is `wc`'s status, not `tr`'s: a + # missing or unreadable cpp-files.z yields COUNT=0 rather than an + # error (morph#730). The `-lt 100` guard catches that particular + # case; pipefail is what keeps the *next* pipeline here honest. + set -o pipefail git ls-files -z '*.hpp' '*.cpp' > cpp-files.z COUNT=$(tr -cd '\0' < cpp-files.z | wc -c) # An empty or truncated file list would make this job pass while @@ -2961,8 +2978,14 @@ jobs: else BASE_SHA="${{ github.event.before }}" fi + # The left-hand side of the pipeline below is *expected* to fail: + # `find` exits non-zero when one of its two search roots is absent, + # and `head -1` closing the pipe SIGPIPEs it. The `-z` test is what + # reads the result. This is why the `set -o pipefail` further down is + # placed after this line rather than at the top of the step, and why + # the line carries the marker scripts/check_workflow_pipefail.py reads. CLANG_TIDY_DIFF="$(find /usr/lib/llvm-${{ env.CLANG_VERSION }}/share/clang /usr/share/clang \ - -name 'clang-tidy-diff.py' 2>/dev/null | head -1)" + -name 'clang-tidy-diff.py' 2>/dev/null | head -1)" # pipefail-ok: find's roots may be absent; head SIGPIPEs it; the -z test below reads the result if [ -z "$CLANG_TIDY_DIFF" ]; then echo "::error::clang-tidy-diff.py not found" exit 1 @@ -3372,6 +3395,47 @@ jobs: - name: Check every job named in a workflow comment exists run: python3 scripts/check_workflow_job_references.py . + # ── A workflow pipeline must read its left-hand side's status ───────── + # + # Its own job for the same reason banner-lint and job-reference-lint above + # are: it reads workflow text and builds nothing, so it answers in seconds + # rather than riding on a leg that takes 26-74 minutes to say the same thing. + # + # A `run:` block with no `shell:` key runs under `bash -e {0}` -- `-e` but + # not `-o pipefail` -- so `cmd | tee log` exits with `tee`'s status and a + # failing `cmd` is green. That has now cost this repository two gates: + # + # * morph#479: `clang-tidy-diff.py … | tee` could not fail on anything it + # found, for as long as it took someone to notice; + # * morph#730: `scripts/mutation.sh … | tee` reported success for a + # campaign that exited 1 having produced no report, so the mutation score + # went unmeasured for two weeks and the workflow said nothing. + # + # Between those, three steps set `pipefail` by hand and one carries a comment + # about this exact hazard. The guard was known and applied inconsistently, + # which is what a gate is for. `shell: bash` -- the explicit spelling -- is + # `bash --noprofile --norc -eo pipefail {0}` and does carry the guard; only + # the absent key does not, and that asymmetry is most of why this recurs. + # + # Not vacuous on arrival: it found six unguarded pipelines on the tree it + # landed against, one of which was morph#730 itself. + pipefail-lint: + name: Workflow pipelines read their exit status + runs-on: ubuntu-24.04 + steps: + - uses: actions/checkout@v4 + + # See scripts/test_check_workflow_pipefail.sh's own comment: this gate + # repairs the tree it guards in the same commit that adds it, so it + # passes on day one whether it parses a single `run:` block or none at + # all. The cases that decide whether it measures anything are the two + # vacuity ones, not the defects. + - name: Self-test the pipefail checker + run: bash scripts/test_check_workflow_pipefail.sh + + - name: Check every workflow pipeline reads its left-hand side's status + run: python3 scripts/check_workflow_pipefail.py . + # ── Install / export: find_package(morph CONFIG) must work ───────────── # # Its own job rather than a step on an existing leg. It configures, installs diff --git a/.github/workflows/mutation.yml b/.github/workflows/mutation.yml index 77e319d4c..fc751f100 100644 --- a/.github/workflows/mutation.yml +++ b/.github/workflows/mutation.yml @@ -115,8 +115,27 @@ jobs: env: CXX: clang++-${{ env.CLANG_VERSION }} run: | - bash scripts/mutation.sh "${{ inputs.scope || 'core-forms' }}" \ - | tee "mutation-${{ inputs.scope || 'core-forms' }}.log" + # `set -o pipefail`, and it is the whole point of this step + # (morph#730). A `run:` with no `shell:` key is `bash -e {0}` -- + # `-e` but NOT `-o pipefail` -- so this pipeline used to exit with + # `tee`'s status, which is 0 unless the disk fills. + # scripts/mutation.sh takes deliberate care to exit 1 when + # mull-runner writes no report, and that 1 was discarded: the step + # went green and the failure surfaced one step later as + # check_mutation_regression.py failing to *open* a file. Two weeks + # of scheduled runs measured nothing and nothing said so. The same + # trap cost morph#479 the clang-tidy gate; scripts/check_workflow_pipefail.py + # now fails on an unguarded pipeline in any workflow. + # + # `tee` stays: the Upload step below publishes the log it writes. + set -o pipefail + scope="${{ inputs.scope || 'core-forms' }}" + bash scripts/mutation.sh "$scope" | tee "mutation-${scope}.log" + # An empty log means the campaign produced no output at all, which + # `set -o pipefail` cannot see -- a script that prints nothing and + # exits 0 is a successful pipeline. Same reason the install steps + # above `test -s` what curl wrote (morph#681). + test -s "mutation-${scope}.log" - name: Check for a regression against the recorded baseline id: regression diff --git a/.github/workflows/wasm-ladder.yml b/.github/workflows/wasm-ladder.yml index a1942be9a..5bdaf12df 100644 --- a/.github/workflows/wasm-ladder.yml +++ b/.github/workflows/wasm-ladder.yml @@ -206,4 +206,10 @@ jobs: # Informational: the build steps above are the gate. Listed rather than # asserted by path, since where Qt drops a wasm bundle is Qt's business. - name: Show the produced artifacts - run: find build-wasm-ladder -name '*.wasm' -o -name '*.html' | sort + run: | + # pipefail because `find` over a build tree the previous step was + # supposed to fill is a claim worth failing on: without it this step + # prints nothing and exits 0 whether the directory is empty or absent + # (morph#730). + set -o pipefail + find build-wasm-ladder -name '*.wasm' -o -name '*.html' | sort diff --git a/scripts/check_workflow_pipefail.py b/scripts/check_workflow_pipefail.py new file mode 100644 index 000000000..fc7ce4166 --- /dev/null +++ b/scripts/check_workflow_pipefail.py @@ -0,0 +1,413 @@ +#!/usr/bin/env python3 +# SPDX-License-Identifier: Apache-2.0 +"""Usage: python3 scripts/check_workflow_pipefail.py [REPO_ROOT] + +Fails if a workflow `run:` block contains a shell pipeline whose exit status +nothing reads. + +## The mechanism, which is one line of shell and has cost this repository twice + +A `run:` block with no `shell:` key runs under `bash -e {0}` -- `-e` but **not** +`-o pipefail`. A pipeline's status is then its *last* command's, so + + bash scripts/mutation.sh core-forms | tee mutation-core-forms.log + +exits with `tee`'s status, which is 0 unless the disk fills. The script's +`exit 1` is discarded and the step is green. + +It is not a hypothetical and it is not a one-off: + + * morph#479: `clang-tidy-diff.py … | tee` -- the changed-lines lint could not + fail on anything it found. Fixed by `set -o pipefail` in that block. + * morph#730: `scripts/mutation.sh … | tee` -- a campaign that exited 1 having + produced no report left the step green, and the failure surfaced one step + later as `check_mutation_regression.py` failing to open a missing file. + Two weeks of scheduled runs measured nothing and nothing said so. + +Between those two, `pipefail` was set in three other steps by hand +(`spec-sync.yml`, `wasm-ladder.yml`, `ci.yml`). The guard was known and applied +inconsistently, which is the state a gate exists for: the next unguarded pipe is +written by someone who has not read any of those three. + +Note that `shell: bash` -- the explicit spelling -- *is* +`bash --noprofile --norc -eo pipefail {0}`, so it carries the guard. Only the +*default*, an absent `shell:` key, does not. That asymmetry is most of why this +keeps happening. + +## The rule + +For every `run:` block in `.github/workflows/*.yml` that runs under a +bash/sh-family shell, every pipeline in it must be covered by one of: + + 1. an effective shell that sets pipefail -- `shell: bash`, or an explicit + `shell: bash -e -o pipefail {0}`-style spelling, from the step, the job's + `defaults.run.shell` or the workflow's; + 2. a `set … pipefail` command earlier in the same block; + 3. a `# pipefail-ok: ` comment on the pipeline's line or on the line + above it. + +Rule 3 is not decoration. `find A B | head -1` is a pipeline whose left side is +*expected* to fail -- one search root absent, or `head` closing the pipe and +SIGPIPE-ing `find` -- and `ci.yml`'s clang-tidy step deliberately sets pipefail +*after* it for exactly that reason (morph#479's own comment says so). A gate +with no way to say "this one, and here is why" would be turned off within the +week. The reason is mandatory: an exemption without one records only that +somebody was annoyed. + +And it has to stay necessary. A marker that excuses no pipeline -- because the +line was rewritten, or because the block gained a `set -o pipefail` above it -- +is an error, not a harmless leftover: it sits inert on a line, ready to excuse +whatever pipeline is written there next, silently. That is the same shape as +the defect this gate is about. + +## What this gate does not see + +Stated rather than left to be discovered: + + * **Scope.** `set -o pipefail` is matched by line order within the block, so a + `set` inside an `if` branch or a `( … )` subshell is credited to the whole + block from that line down. Under-strict, never over-strict. + * **Quoting.** A pipe inside `bash -c "a | b"` is quoted, so it is not seen at + all. Also under-reporting. + * **Other shells.** `shell: pwsh` and `shell: python` blocks are skipped + entirely; `$?`-style semantics there are a different question. + * **Composite actions.** Only `.github/workflows/*.yml` is read. `run:` inside + an `action.yml` is out of scope, and there are none in this tree. + +## Anti-vacuity + +Two floors, both on what was *found* rather than on what failed, because a +parser that silently stops recognising `run:` blocks or pipelines would +otherwise report a clean tree: + + * fewer than `MIN_RUN_BLOCKS` run blocks parsed is an error; + * fewer than `MIN_PIPELINES` pipelines seen across the tree is an error. + +A gate that finds pipelines and clears them all is working. A gate that finds +none has stopped looking. + +Reads text only; compiles and runs nothing. No third-party imports, so it runs +on a bare runner in seconds. +""" + +from __future__ import annotations + +import re +import sys +from pathlib import Path + +# Floors for the anti-vacuity check. The tree this landed against carries 169 +# `run:` blocks and 6 pipelines; the floors sit far enough below both that +# ordinary editing does not trip them and a parser that has stopped parsing +# does. +MIN_RUN_BLOCKS = 100 +MIN_PIPELINES = 4 + +# `run: …` as a step key, either as the first key of a list item (`- run: …`) +# or a later one. group(1) is the indentation up to the `run` token. +RUN_RE = re.compile(r"^(\s*)(?:-\s+)?run:(.*)$") + +# A YAML block scalar introducer: `|`, `>`, with optional chomping/indent +# indicators. +BLOCK_SCALAR_RE = re.compile(r"^\s*[|>][-+]?\d*\s*(#.*)?$") + +SHELL_RE = re.compile(r"^\s*shell:\s*(.+?)\s*(?:#.*)?$") + +# `set -o pipefail`, `set -euo pipefail`, `set -eo pipefail`, … +SET_PIPEFAIL_RE = re.compile(r"^\s*set\s+[^#]*\bpipefail\b") + +EXEMPT_RE = re.compile(r"#\s*pipefail-ok:\s*(\S.*)$") + +# A GitHub expression. `${{ inputs.scope || 'core-forms' }}` carries a `||` that +# is not shell, and could carry a `|`; it is substituted before bash sees it. +EXPRESSION_RE = re.compile(r"\$\{\{.*?\}\}") + +SH_SHELLS = ("bash", "sh", "/bin/bash", "/bin/sh", "/usr/bin/bash") + + +def uses_pipefail_shell(shell: str | None) -> bool: + """Does this `shell:` spelling start bash with pipefail set? + + `shell: bash` is documented as `bash --noprofile --norc -eo pipefail {0}`. + An explicit command line counts only if it says so itself. + """ + if shell is None: + return False + stripped = shell.strip().strip("\"'") + if stripped == "bash": + return True + return "pipefail" in stripped + + +def is_sh_family(shell: str | None) -> bool: + """True for a shell this gate understands (bash/sh), or the default.""" + if shell is None: + return True # the default, `bash -e {0}` + first = shell.strip().strip("\"'").split()[0] if shell.strip() else "" + return first in SH_SHELLS + + +def strip_shell_quoting(line: str) -> str: + """Blank out quoted spans and the trailing comment. + + A `|` inside quotes is a literal character, not a pipeline; a `|` after `#` + is prose. Both are removed so the caller can scan what is left. + """ + out: list[str] = [] + quote: str | None = None + i = 0 + while i < len(line): + char = line[i] + if quote is not None: + if char == quote: + quote = None + i += 1 + continue + if char == "\\": + i += 2 + continue + if char in "'\"": + quote = char + i += 1 + continue + if char == "#": + break + out.append(char) + i += 1 + return "".join(out) + + +def has_pipeline(line: str) -> bool: + """Does this shell line contain a pipeline operator? + + `||` is a disjunction, `>|` is a clobbering redirection, and `|&` is a + pipeline that carries stderr too. + """ + text = strip_shell_quoting(EXPRESSION_RE.sub("EXPR", line)) + i = 0 + while i < len(text): + if text[i] != "|": + i += 1 + continue + if text[i : i + 2] == "||": + i += 2 + continue + if i > 0 and text[i - 1] == ">": + i += 1 + continue + return True + return False + + +def default_shell(lines: list[str], rel: str, fail) -> str | None: + """The workflow- or job-level `defaults.run.shell`, if there is one. + + Only the canonical three-line shape is understood. A `defaults:` block this + cannot read is an error rather than a silent "no default": mis-reading it + the other way would excuse, or wrongly accuse, every block in the file. + """ + found: str | None = None + for i, line in enumerate(lines): + match = re.match(r"^(\s*)defaults:\s*(#.*)?$", line) + if not match: + continue + indent = match.group(1) + if ( + i + 2 < len(lines) + and re.match(rf"^{indent} run:\s*(#.*)?$", lines[i + 1]) + and SHELL_RE.match(lines[i + 2]) + and lines[i + 2].startswith(indent + " shell:") + ): + found = SHELL_RE.match(lines[i + 2]).group(1) + continue + fail( + f"{rel}:{i + 1}: a `defaults:` block this gate cannot read. It " + f"understands only `defaults:` / `run:` / `shell: …` on three " + f"consecutive lines. Either write it that way or teach " + f"{Path(__file__).name} the shape -- guessing would excuse every " + f"block in the file." + ) + return found + + +def step_shell(lines: list[str], run_index: int, key_indent: int) -> str | None: + """The `shell:` key of the step that owns the `run:` at `run_index`.""" + item_indent = max(key_indent - 2, 0) + start = 0 + for i in range(run_index, -1, -1): + line = lines[i] + if re.match(rf"^ {{{item_indent}}}-\s", line): + start = i + break + end = len(lines) + for i in range(run_index + 1, len(lines)): + line = lines[i] + if not line.strip(): + continue + if re.match(rf"^ {{{item_indent}}}-\s", line) or ( + len(line) - len(line.lstrip()) < item_indent + ): + end = i + break + for i in range(start, end): + stripped = lines[i].strip() + if stripped.startswith("#"): + continue + indent = len(lines[i]) - len(lines[i].lstrip()) + if indent != key_indent: + continue + match = SHELL_RE.match(lines[i]) + if match: + return match.group(1) + return None + + +def run_blocks(lines: list[str]) -> list[tuple[int, int, list[str]]]: + """(run-key line index, key indent, body lines) for every `run:` in a file. + + The body of an inline `run: cmd` is that one line; the body of a block + scalar is every following line indented past the key. + """ + blocks: list[tuple[int, int, list[str]]] = [] + i = 0 + while i < len(lines): + match = RUN_RE.match(lines[i]) + if not match: + i += 1 + continue + key_indent = lines[i].index("run:") + rest = match.group(2) + if BLOCK_SCALAR_RE.match(rest) or not rest.strip(): + body: list[tuple[int, str]] = [] + j = i + 1 + while j < len(lines): + line = lines[j] + if line.strip() and (len(line) - len(line.lstrip())) <= key_indent: + break + body.append((j, line)) + j += 1 + blocks.append((i, key_indent, body)) + i = j + continue + blocks.append((i, key_indent, [(i, rest.strip())])) + i += 1 + return blocks + + +def main(argv: list[str]) -> int: + root = Path(argv[1] if len(argv) > 1 else Path(__file__).resolve().parent.parent) + workflows = sorted((root / ".github" / "workflows").glob("*.yml")) + if not workflows: + print(f"error: no workflows found under {root}/.github/workflows", file=sys.stderr) + return 1 + + failures = 0 + total_blocks = 0 + total_pipelines = 0 + # (file, 0-based line) for every `# pipefail-ok:` marker seen, and for + # every one that excused a pipeline. An exemption has to be necessary to be + # allowed to stay: a marker left behind after its pipeline was rewritten + # sits there inert, ready to excuse whatever pipeline is written on that + # line next -- silently, which is the shape of defect this whole gate is + # about. + markers: list[tuple[str, int, str]] = [] + used: set[tuple[str, int]] = set() + + def fail(msg: str) -> None: + nonlocal failures + print(f"error: {msg}", file=sys.stderr) + failures += 1 + + for path in workflows: + rel = str(path.relative_to(root)) + lines = path.read_text(encoding="utf-8").split("\n") + file_default = default_shell(lines, rel, fail) + + for run_index, key_indent, body in run_blocks(lines): + total_blocks += 1 + shell = step_shell(lines, run_index, key_indent) or file_default + if not is_sh_family(shell): + continue + shell_guards = uses_pipefail_shell(shell) + + set_at: int | None = None + for position, (line_no, line) in enumerate(body): + if set_at is None and SET_PIPEFAIL_RE.match(strip_shell_quoting(line)): + set_at = line_no + marker = EXEMPT_RE.search(line) + if marker is not None: + markers.append((rel, line_no, marker.group(1).strip())) + if not has_pipeline(line): + continue + total_pipelines += 1 + if shell_guards: + print(f"ok: {rel}:{line_no + 1}: pipeline under a pipefail shell") + continue + if set_at is not None and set_at < line_no: + print(f"ok: {rel}:{line_no + 1}: pipeline after `set … pipefail`") + continue + exempt, exempt_line = EXEMPT_RE.search(line), line_no + if exempt is None: + for prev_no, prev_line in reversed(body[:position]): + if prev_line.strip(): + exempt, exempt_line = EXEMPT_RE.search(prev_line), prev_no + break + if exempt is not None: + used.add((rel, exempt_line)) + print(f"ok: {rel}:{line_no + 1}: excused -- {exempt.group(1).strip()}") + continue + fail( + f"{rel}:{line_no + 1}: this pipeline's exit status is its " + f"last command's, and nothing sets pipefail before it.\n" + f" {line.strip()}\n" + f" A `run:` with no `shell:` key is `bash -e {{0}}`: `-e` " + f"but not `-o pipefail`, so a failing left-hand side is\n" + f" discarded (morph#479, morph#730). Add `set -o pipefail` " + f"above it, or -- if the left side is *expected* to fail --\n" + f" a `# pipefail-ok: ` comment on that line or the " + f"one before it." + ) + + # -- Exemption hygiene ---------------------------------------------------- + for rel, line_no, reason in markers: + if (rel, line_no) in used: + continue + fail( + f"{rel}:{line_no + 1}: a `# pipefail-ok:` marker that excuses " + f"nothing -- the line it sits on, and the line below it, carry no " + f"pipeline.\n" + f" Its reason was: {reason}\n" + f" Remove it. An exemption nothing needs is an exemption waiting " + f"to excuse the next pipeline written on that line." + ) + + # -- Anti-vacuity --------------------------------------------------------- + if total_blocks < MIN_RUN_BLOCKS: + fail( + f"only {total_blocks} `run:` block(s) parsed across " + f"{len(workflows)} workflow file(s), against a floor of " + f"{MIN_RUN_BLOCKS}. Either the workflows shrank drastically or this " + f"gate has stopped recognising `run:` blocks -- in which case it is " + f"reporting a clean tree it never read." + ) + if total_pipelines < MIN_PIPELINES: + fail( + f"only {total_pipelines} pipeline(s) found across " + f"{len(workflows)} workflow file(s), against a floor of " + f"{MIN_PIPELINES}. A gate that finds no pipelines is not a tree " + f"without pipes; it is a scanner that has stopped matching them." + ) + + if failures: + print(f"\n{failures} workflow pipefail check(s) failed", file=sys.stderr) + return 1 + + print( + f"\nok: all {total_pipelines} pipeline(s) in {total_blocks} `run:` " + f"block(s) read their left-hand side's status" + ) + return 0 + + +if __name__ == "__main__": + sys.exit(main(sys.argv)) diff --git a/scripts/test_check_workflow_pipefail.sh b/scripts/test_check_workflow_pipefail.sh new file mode 100644 index 000000000..ec52395f3 --- /dev/null +++ b/scripts/test_check_workflow_pipefail.sh @@ -0,0 +1,229 @@ +#!/usr/bin/env bash +# Usage: bash scripts/test_check_workflow_pipefail.sh +# +# Self-test for scripts/check_workflow_pipefail.py, the gate that keeps a +# workflow pipeline from discarding its left-hand side's exit status +# (morph#479, morph#730). +# +# A lint gate nobody tests reports green whether or not it still detects +# anything, and this one repairs the tree it guards in the same commit that +# adds it -- so it passes on day one whether it parses a single `run:` block or +# none at all. Its whole value is what it does to the pipeline someone writes +# next month. +# +# The cases below are three kinds: +# +# * the two defects it exists for, reintroduced verbatim -- morph#730's +# `mutation.sh | tee` and morph#479's `clang-tidy-diff.py | tee`; +# * the vacuity cases, which are what decide whether it measures anything: +# a tree where the parser no longer finds `run:` blocks, and one where it +# no longer recognises a pipeline, both of which it would otherwise pass +# while reading nothing; +# * the false-positive mirror. `||`, a quoted `|`, a YAML block scalar and a +# `${{ a || b }}` expression all contain the character and none is a +# pipeline. A gate that flagged them would be switched off within the day, +# so they are asserted rather than assumed. +# +# Every mutation is applied to a scratch copy of the tree, one at a time. +# Applied together, a single detection would mask every other. +set -euo pipefail + +readonly repo_root="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +readonly checker="scripts/check_workflow_pipefail.py" + +failures=0 + +note() { printf 'ok: %s\n' "$*"; } +fail() { printf 'error: %s\n' "$*" >&2; failures=$((failures + 1)); } + +scratch="$(mktemp -d)" +trap 'rm -rf "$scratch"' EXIT + +# The checker reads .github/workflows/*.yml and nothing else; a copy of those +# plus the script itself is the whole tree it needs. +readonly pristine="${scratch}/pristine" +mkdir -p "${pristine}/.github/workflows" "${pristine}/scripts" +cp "${repo_root}"/.github/workflows/*.yml "${pristine}/.github/workflows/" +cp "${repo_root}/${checker}" "${pristine}/scripts/" + +make_tree() { + local dest="$1" + rm -rf "$dest" + mkdir -p "$dest" + cp -R "${pristine}/." "$dest" +} + +# `sed -i` is not portable between GNU and BSD sed; edit through a temp file. +# +# Three checks the sibling self-tests' copy of this helper does not make, and +# each of them fired while this file was being written (morph#746): +# +# * a `sed` that *fails* still leaves the redirection's empty output behind, +# and `mv` then installs it -- so a mutator with a syntax error silently +# truncates the file it was editing, and an `expect_accepted` case passes +# over an empty workflow having asserted nothing; +# * a `sed` that succeeds while matching *nothing* leaves the file identical, +# and the case again passes having mutated nothing; +# * either of those is invisible, because the harness only reads the +# checker's exit status. +edit() { + local file="$1"; shift + if ! sed "$@" "$file" > "${file}.new"; then + rm -f "${file}.new" + printf 'edit: sed failed on %s\n' "$file" >&2 + return 1 + fi + if [ ! -s "${file}.new" ]; then + rm -f "${file}.new" + printf 'edit: sed emptied %s\n' "$file" >&2 + return 1 + fi + if cmp -s "${file}.new" "$file"; then + rm -f "${file}.new" + printf 'edit: expression matched nothing in %s\n' "$file" >&2 + return 1 + fi + mv "${file}.new" "$file" +} + +# Each mutation must be caught, and caught *for the stated reason*. `$expected` +# is a substring the diagnostic must contain; without it a mutation that broke +# the tree some unrelated way would count as a detection, and this self-test +# would report a dead gate as a working one. +expect_caught() { + local description="$1" mutator="$2" expected="$3" + local tree="${scratch}/case" output + make_tree "$tree" + if ! ( cd "$tree" && eval "$mutator" ); then + fail "mutator failed to apply: ${description}" + return + fi + if output="$( cd "$tree" && python3 "$checker" . 2>&1 )"; then + fail "NOT caught: ${description} -- the gate passed a tree it should reject" + printf '%s\n' "$output" >&2 + return + fi + if printf '%s' "$output" | grep -qF "$expected"; then + note "caught: ${description}" + else + fail "caught for the WRONG reason: ${description} -- no diagnostic containing '${expected}':" + printf '%s\n' "$output" >&2 + fi +} + +# The mirror, for false positives. A gate that rejected every tree would +# "catch" every case above while being worthless. +expect_accepted() { + local description="$1" mutator="$2" + local tree="${scratch}/case" output + make_tree "$tree" + if ! ( cd "$tree" && eval "$mutator" ); then + fail "mutator failed to apply: ${description}" + return + fi + if output="$( cd "$tree" && python3 "$checker" . 2>&1 )"; then + note "accepted: ${description}" + else + fail "FALSE POSITIVE: ${description} -- the gate rejected a tree it should accept:" + printf '%s\n' "$output" >&2 + fi +} + +# -- The unmodified tree must pass ------------------------------------------- +make_tree "${scratch}/clean" +if output="$( cd "${scratch}/clean" && python3 "$checker" . 2>&1 )"; then + note "the unmodified tree passes" +else + fail "the unmodified tree was rejected by the gate:" + printf '%s\n' "$output" >&2 +fi + +# -- The two defects this gate exists for ------------------------------------ +# morph#730 verbatim: drop the campaign step's guard and the `| tee` is back to +# reporting `tee`'s status for a script that exited 1. +expect_caught "morph#730: the mutation campaign's pipefail removed" \ + "edit .github/workflows/mutation.yml -e '/^ set -o pipefail$/d'" \ + "mutation.sh" + +# morph#479 verbatim: the clang-tidy gate's `set -o pipefail` sits *after* a +# deliberate `find | head`, so deleting it leaves the `| tee` below unguarded +# rather than removing a whole-step guard. +expect_caught "morph#479: the clang-tidy step's pipefail removed" \ + "python3 - <<'PY' +import pathlib +p = pathlib.Path('.github/workflows/ci.yml') +lines = p.read_text().split('\n') +anchor = next(i for i, l in enumerate(lines) if 'left this gate unable to fail' in l) +drop = next(i for i in range(anchor, len(lines)) if lines[i].strip() == 'set -o pipefail') +del lines[drop] +p.write_text('\n'.join(lines)) +PY" \ + "nothing sets pipefail before it" + +# The shape the next one will take: a new step, written by someone who has read +# none of the above, piping a fallible command into something that cannot fail. +expect_caught "a newly added unguarded pipeline" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Count the headers\n run: |\n find include -name \"*.hpp\" | wc -l\n\n - name: Install dependencies%'" \ + "this pipeline's exit status is its last command's" + +# -- The vacuity cases ------------------------------------------------------- +# These decide whether the gate measures anything. A checker that stops finding +# `run:` blocks reports a clean tree it never read. +expect_caught "the run-block syntax moved out from under the parser" \ + "for f in .github/workflows/*.yml; do edit \"\$f\" -e 's|^\\( *\\)\\(- \\)\\?run:|\\1\\2x-run:|'; done" \ + "\`run:\` block(s) parsed" + +# And one that stops recognising pipelines: every pipe in the tree becomes a +# `;`. Nothing is then wrong -- and nothing is being checked either. +expect_caught "every pipeline rewritten out of the shape the gate reads" \ + "python3 - <<'PY' +import pathlib, re +for p in pathlib.Path('.github/workflows').glob('*.yml'): + out = [] + for line in p.read_text().split('\n'): + if not line.rstrip().endswith('|'): + line = re.sub(r'(?])\|(?!\|)', ';', line) + out.append(line) + p.write_text('\n'.join(out)) +PY" \ + "pipeline(s) found across" + +# -- The exemption has to be necessary, and has to say why ------------------- +expect_caught "an exemption with no reason" \ + "edit .github/workflows/ci.yml -e 's|# pipefail-ok: find.*\$|# pipefail-ok:|'" \ + "nothing sets pipefail before it" + +expect_caught "an exemption left behind after its pipeline went away" \ + "edit .github/workflows/ci.yml -e 's|^ set -euo pipefail\$| set -euo pipefail # pipefail-ok: stale, excuses nothing|'" \ + "excuses nothing" + +# -- False positives --------------------------------------------------------- +# `||` is a disjunction. This tree is full of `cmd || fallback`, and flagging +# one would make the gate unusable. +expect_accepted "a disjunction is not a pipeline" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Probe\n run: |\n command -v doxygen || echo missing\n\n - name: Install dependencies%'" + +# A `|` inside quotes is a literal character. +expect_accepted "a quoted pipe character is not a pipeline" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Print\n run: echo \"a | b\"\n\n - name: Install dependencies%'" + +# `${{ a || b }}` is a GitHub expression, substituted before bash sees it. +expect_accepted "a GitHub expression containing ||" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Echo the ref\n run: echo \"\${{ github.head_ref || github.ref_name }}\"\n\n - name: Install dependencies%'" + +# `shell: bash` is documented as `bash --noprofile --norc -eo pipefail {0}`, so +# it carries the guard. Only the *absent* key does not, and that asymmetry is +# most of why this defect keeps recurring. +expect_accepted "a pipeline under an explicit shell: bash" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Count\n shell: bash\n run: find include -name \"*.hpp\" | wc -l\n\n - name: Install dependencies%'" + +# Other shells are a different question, and guessing at them would be noise. +expect_accepted "a pipeline in a pwsh step" \ + "edit .github/workflows/docs.yml -e 's%^ - name: Install dependencies% - name: Count\n shell: pwsh\n run: Get-ChildItem | Measure-Object\n\n - name: Install dependencies%'" + +if [ "$failures" -ne 0 ]; then + printf '\n%d case(s) failed.\n' "$failures" >&2 + exit 1 +fi + +printf '\nall cases passed.\n' From 7a6e588173819cb1f4c81e4d7a6dcc1c5b43c7bb Mon Sep 17 00:00:00 2001 From: Yaraslau Tamashevich Date: Wed, 23 Sep 2026 05:01:18 +0200 Subject: [PATCH 2/4] mutation: record the second failure in a scope instead of skipping it (fixes #731) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The "Open an issue on failure" step built a fixed title per scope and skipped when any issue carrying that title was open: title="Mutation campaign failed or regressed (scope: ${scope})" existing="$(gh issue list --state open --search "in:title \"${title}\"" …)" if [ "$existing" != "0" ]; then echo "An open issue already names this failure; not filing a duplicate." exit 0 fi The title carries the scope and nothing about the failure, so "already names this failure" was false whenever the failure was a different one. morph#517 was filed on 2026-09-14 for a survivor regression; the 2026-09-21 run, in which the campaign never ran at all (morph#732), printed that line and left no record outside its own run log. The dedup was right and is kept -- one thread per scope. What was missing is the other half: a suppressed run now lands as a comment on the issue that suppressed it, with the cause it was classified as and the tail of each log the run produced. The step's body moves to scripts/report_mutation_failure.sh, and that is the fix rather than a tidy-up. morph#731's acceptance condition is "force two different failures in one scope and confirm both are recorded", and the thing to confirm is an *absence* of a record -- no issue, no comment, no label, only a run log. There is nothing to inspect after the fact, so it has to be driven, and a dozen lines inside a `run:` block cannot be driven at all. scripts/test_report_mutation_failure.sh drives it against a stub `gh` that keeps issues in a directory and records every create/comment. The two failures are the two runs morph#731 cites, verbatim: ok: two different failures in one scope: the first opens the issue, the second comments on it ok: the comment carries the second failure's own log, not the first's ok: the comment names the cause it classified ok: the comment names the run it came from ok: the opening issue quotes the regression rather than paraphrasing it ok: an issue whose title merely contains the phrase is not commented on ok: a failure in a different scope opens its own thread ok: an unrecognised failure is reported as unclassified, with its log ok: a log the run never wrote is named as missing, and the report still lands ok: a failing search is fatal, and the failure still reaches the run log Shown failing on the old behaviour: reinstating the `exit 0` branch in a scratch copy gives error: both failures must be recorded. Transcript was: create 900 expected: create 900 comment 900 error: the comment does not quote the warm-up timeout it was reporting: error: the comment does not name the classified cause: error: the comment does not name run 2 4 case(s) failed. Three things that are not incidental: * **The title match is exact.** `--search 'in:title "…"'` is a text search, and morph#731 recorded its behaviour as unverified. The reply is filtered in shell, not in `--jq`, so the near-miss case is testable -- a filter inside jq is one only the real `gh` can run. * **A failing search is fatal**, not "no issue open". Reading an API error as "nothing is open" files a duplicate every week; the digest goes to the run log on the way out so the failure is not lost with it. * **The regression check now tees its verdict** to regression-.log, so the report can quote it rather than paraphrase it. That pipeline is guarded, which is #730. Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW --- .github/workflows/drift-guard.yml | 15 ++ .github/workflows/mutation.yml | 36 ++- scripts/report_mutation_failure.sh | 180 +++++++++++++++ scripts/test_report_mutation_failure.sh | 295 ++++++++++++++++++++++++ 4 files changed, 514 insertions(+), 12 deletions(-) create mode 100755 scripts/report_mutation_failure.sh create mode 100755 scripts/test_report_mutation_failure.sh diff --git a/.github/workflows/drift-guard.yml b/.github/workflows/drift-guard.yml index 5788e8f30..ecebc67a1 100644 --- a/.github/workflows/drift-guard.yml +++ b/.github/workflows/drift-guard.yml @@ -474,6 +474,21 @@ jobs: - name: Self-test the mutation-survivor citation gate run: python3 scripts/check_mutation_survivors.py --self-test + # scripts/report_mutation_failure.sh is the campaign's reporting half, + # and it runs only on a failed scheduled run -- i.e. a few times a year, + # on the day its output matters most. It is self-tested here, per-PR, + # against a stub `gh`, because the defect it fixes (morph#731) is the + # *absence* of a record: the old step skipped when any issue with the + # scope's title was open, so the second, different failure in a scope + # produced no issue, no comment and no label -- only a line in a run log. + # There is nothing to inspect afterwards, so it has to be driven. + # + # The self-test is morph#731's acceptance condition executed rather than + # argued: two different failures in one scope, both recorded, with the + # second record carrying the second failure's own evidence. + - name: Self-test the mutation-failure reporter + run: bash scripts/test_report_mutation_failure.sh + # ── Every line-cited allowlist's citations, resolved in one place ────── # Three files in this repository cite source lines by `{file, line, source}`: # scripts/branch_partial_allowlist.json, scripts/error_path_allowlist.json diff --git a/.github/workflows/mutation.yml b/.github/workflows/mutation.yml index fc751f100..fdf5185bd 100644 --- a/.github/workflows/mutation.yml +++ b/.github/workflows/mutation.yml @@ -140,9 +140,16 @@ jobs: - name: Check for a regression against the recorded baseline id: regression run: | + # Teed to a file for the same reason the campaign step is: the + # failure report below quotes the checker's own verdict rather than + # paraphrasing it, and a verdict that exists only in the run log is + # the state morph#731 describes. `set -o pipefail` first -- this is + # the pipeline morph#730 was about. + set -o pipefail scope="${{ inputs.scope || 'core-forms' }}" python3 scripts/check_mutation_regression.py \ - "build/mutation-${scope}/mutation-${scope}.txt" "$scope" + "build/mutation-${scope}/mutation-${scope}.txt" "$scope" \ + 2>&1 | tee "regression-${scope}.log" # scripts/check_mutation_regression.py updates scripts/mutation_baseline.json # in place on a first run or an improvement (never on a regression -- @@ -169,23 +176,27 @@ jobs: # have to be noticed by someone comparing by hand" gap # docs/spec/testing_charter.md names, closed: something now notices and # files it, instead of the campaign's own log being the only record. - - name: Open an issue on failure + # + # The body of this step is scripts/report_mutation_failure.sh, and that + # is morph#731's fix rather than a tidy-up. What used to be here built a + # fixed title per scope and *skipped* when any issue with that title was + # open, so the first failure in a scope silenced the report of every + # later, different one -- which is how morph#732 stayed invisible behind + # morph#517 for two weeks. The script comments on the open issue instead, + # and classifies the cause so the thread reads as distinct events. It + # lives in scripts/ because morph#731's acceptance condition is "force + # two different failures in one scope and confirm both are recorded", + # and a dozen lines inside a `run:` block cannot be driven at all -- + # scripts/test_report_mutation_failure.sh drives exactly that. + - name: Report the failure if: failure() env: GH_TOKEN: ${{ github.token }} RUN_URL: ${{ github.server_url }}/${{ github.repository }}/actions/runs/${{ github.run_id }} run: | scope="${{ inputs.scope || 'core-forms' }}" - title="Mutation campaign failed or regressed (scope: ${scope})" - existing="$(gh issue list --state open --search "in:title \"${title}\"" --json number --jq 'length')" - if [ "$existing" != "0" ]; then - echo "An open issue already names this failure; not filing a duplicate." - exit 0 - fi - body="The scheduled mutation campaign (.github/workflows/mutation.yml) failed or found a regression for scope \`${scope}\`." - body="${body}\n\nRun: ${RUN_URL}" - body="${body}\n\nSee \`scripts/check_mutation_regression.py\`'s own doc comment for what this compares, \`scripts/mutation_baseline.json\` for the recorded baseline, and \`scripts/mutation_survivors.json\` for the triage process for a genuine new survivor." - gh issue create --title "$title" --label "area: ci" --body "$(printf '%b' "$body")" + bash scripts/report_mutation_failure.sh "$scope" "$RUN_URL" \ + "mutation-${scope}.log" "regression-${scope}.log" - name: Upload the mutation report if: always() @@ -194,5 +205,6 @@ jobs: name: mutation-report-${{ inputs.scope || 'core-forms' }} path: | mutation-*.log + regression-*.log build/mutation-*/mutation-*.txt retention-days: 30 diff --git a/scripts/report_mutation_failure.sh b/scripts/report_mutation_failure.sh new file mode 100755 index 000000000..14e5b6cc8 --- /dev/null +++ b/scripts/report_mutation_failure.sh @@ -0,0 +1,180 @@ +#!/usr/bin/env bash +# Usage: bash scripts/report_mutation_failure.sh SCOPE RUN_URL [LOG...] +# +# Records one failed mutation-campaign run on GitHub: it opens the scope's +# issue if there is not one open, and comments on it if there is. Called from +# .github/workflows/mutation.yml's "Report the failure" step, and separated +# from it so that it can be driven by scripts/test_report_mutation_failure.sh +# against a stub `gh` -- the acceptance condition morph#731 asks for is "force +# two different failures in one scope and confirm both are recorded", and a +# dozen lines of shell inside a `run:` block cannot be driven at all. +# +# ── What this replaces, and why ────────────────────────────────────────────── +# +# The step used to build a fixed title per scope and *skip* when any issue +# carrying that title was open: +# +# title="Mutation campaign failed or regressed (scope: ${scope})" +# existing="$(gh issue list --state open --search "in:title \"${title}\"" …)" +# if [ "$existing" != "0" ]; then +# echo "An open issue already names this failure; not filing a duplicate." +# exit 0 +# fi +# +# The title carries the scope and nothing about the failure, so "an open issue +# already names this failure" was false whenever the failure was a different +# one. It happened immediately (morph#731): morph#517 was filed on 2026-09-14 +# for a genuine survivor regression, and the 2026-09-21 run -- in which the +# campaign never ran at all, mull's warm-up having timed out (morph#732) -- +# printed that line and left no record anywhere outside its own run log. +# +# The dedup itself was right: a hundred identical weekly failures should not be +# a hundred issues. What was missing is the other half, so the suppressed run +# now lands as a comment on the issue that suppressed it. One thread per scope, +# and the thread is the campaign's history. +# +# ── Two details that are not incidental ────────────────────────────────────── +# +# **The title match is exact.** `gh issue list --search 'in:title "…"'` is a +# text search, not an equality test: it matches an issue whose title merely +# contains the phrase, and GitHub's search also tokenises. morph#731 recorded +# that as unverified. Rather than verify it, the reply is filtered here with an +# exact string comparison, so a near-miss title opens a second thread instead of +# commenting on the wrong issue. +# +# **The cause is classified from the logs**, and appears in the comment's first +# line, so the thread reads as a sequence of distinct events rather than a pile +# of run links. The classification is a small fixed table; anything it does not +# recognise is reported as unclassified *with* the log excerpt, never dropped. +set -euo pipefail + +if [ "$#" -lt 2 ]; then + echo "usage: bash scripts/report_mutation_failure.sh SCOPE RUN_URL [LOG...]" >&2 + exit 2 +fi + +scope="$1"; shift +run_url="$1"; shift +readonly scope run_url + +readonly title="Mutation campaign failed or regressed (scope: ${scope})" + +# ── The cause, from whichever logs the run got far enough to write ─────────── +# +# Ordered from "the campaign never started" outwards, because an earlier +# failure makes every later symptom meaningless: a run whose warm-up timed out +# also has no report for the regression check to read, and reporting the second +# names the consequence rather than the cause -- which is how morph#732 spent +# two weeks looking like morph#517. +cause="unclassified failure" +for log in "$@"; do + [ -s "$log" ] || continue + if grep -q "Original test failed (warmup run)" "$log"; then + cause="the campaign could not run: mull's warm-up run of the unmutated suite failed or timed out" + break + fi + if grep -q "carries no .mull_mutants section" "$log"; then + cause="the campaign instrumented nothing: the binary carries no .mull_mutants section" + break + fi + if grep -q "wrote no report" "$log"; then + cause="the campaign errored: mull-runner exited non-zero and wrote no report" + break + fi + if grep -q "0 mutants for scope" "$log"; then + cause="the campaign produced an empty mutant population" + break + fi + if grep -q "survivors this run, up from a" "$log"; then + cause="survivors regressed against the recorded baseline" + break + fi +done +readonly cause + +# ── The evidence ───────────────────────────────────────────────────────────── +# +# The tail of each log the run produced, rather than a paraphrase of it. A +# report whose reader has to open the run to learn what happened is the state +# morph#731 describes. +evidence="$( + for log in "$@"; do + if [ ! -e "$log" ]; then + printf '### `%s`\n\n_not produced by this run._\n\n' "$log" + continue + fi + if [ ! -s "$log" ]; then + printf '### `%s`\n\n_empty._\n\n' "$log" + continue + fi + printf '### `%s` (last 30 lines)\n\n```\n' "$log" + tail -n 30 "$log" + printf '```\n\n' + done +)" + +digest="$(printf '**%s**\n\nRun: %s\n\n%s' "$cause" "$run_url" "$evidence")" + +# ── Open, or comment ───────────────────────────────────────────────────────── +# +# `--json number,title`, and the exact comparison is done *here* rather than in +# the `--jq` expression: see the header for why it has to be exact, and +# scripts/test_report_mutation_failure.sh for why it has to be in shell. A +# filter that lives inside jq is a filter only the real `gh` can run, which +# means the near-miss case cannot be tested at all. +# +# A search that *errors* must not be read as "no issue open" -- that would file +# a duplicate every week -- so it is fatal here, and the digest goes to the run +# log on the way out. A report step that fails is a report step that is seen; +# one that swallows the error is how this workflow got here. +listing="$(mktemp)" +trap 'rm -f "$listing" "${body_file:-}"' EXIT +if ! gh issue list --state open --limit 100 \ + --search "in:title \"${title}\"" \ + --json number,title \ + --jq '.[] | "\(.number)\t\(.title)"' > "$listing"; then + echo "report_mutation_failure.sh: 'gh issue list' failed -- refusing to guess" >&2 + echo " that no issue is open, which would file a duplicate every week." >&2 + echo " The failure this run was reporting:" >&2 + printf '%s\n' "$digest" >&2 + exit 1 +fi + +existing="" +while IFS=$'\t' read -r number found_title; do + [ -n "${number:-}" ] || continue + if [ "$found_title" = "$title" ]; then + existing="$number" + break + fi + echo "ignoring #${number}: its title contains the phrase but is not it -- ${found_title}" +done < "$listing" + +body_file="$(mktemp)" + +if [ -n "$existing" ]; then + { + printf 'The scheduled mutation campaign failed again for scope `%s`.\n\n' "$scope" + printf '%s\n' "$digest" + printf '\nFiled here rather than as a new issue: one thread per scope is\n' + printf 'deliberate (morph#731). If this cause is unrelated to the one this\n' + printf 'issue was opened for, split it out -- but it is recorded either way,\n' + printf 'which is what the previous behaviour did not do.\n' + } > "$body_file" + gh issue comment "$existing" --body-file "$body_file" + echo "recorded on existing issue #${existing}: ${cause}" + exit 0 +fi + +{ + printf 'The scheduled mutation campaign (.github/workflows/mutation.yml) failed for scope `%s`.\n\n' "$scope" + printf '%s\n' "$digest" + printf '\nSee `scripts/check_mutation_regression.py`'"'"'s own doc comment for what this\n' + printf 'compares, `scripts/mutation_baseline.json` for the recorded baseline, and\n' + printf '`scripts/mutation_survivors.json` for the triage process for a genuine new\n' + printf 'survivor.\n\n' + printf 'While this issue is open, every later failure in this scope is recorded as a\n' + printf 'comment here rather than as a new issue.\n' +} > "$body_file" +gh issue create --title "$title" --label "area: ci" --body-file "$body_file" +echo "opened a new issue: ${cause}" diff --git a/scripts/test_report_mutation_failure.sh b/scripts/test_report_mutation_failure.sh new file mode 100755 index 000000000..baf911e08 --- /dev/null +++ b/scripts/test_report_mutation_failure.sh @@ -0,0 +1,295 @@ +#!/usr/bin/env bash +# Usage: bash scripts/test_report_mutation_failure.sh +# +# Self-test for scripts/report_mutation_failure.sh -- morph#731's acceptance +# condition, executed rather than argued: **force two different failures in one +# scope and confirm both are recorded.** +# +# The failure it guards against is specific. The reporting step used to skip +# when any open issue carried the scope's title, so the second failure in a +# scope produced nothing anywhere: no issue, no comment, no label, only a line +# in a run log nobody reads. That is not a state a workflow run can be asked +# about afterwards -- it is the *absence* of a record -- so the only way to +# check it is to drive the reporter against a `gh` whose calls can be counted. +# +# So `gh` here is a stub on PATH. It keeps its issues in a directory, answers +# `issue list` from it, and appends `issue create` / `issue comment` calls to a +# transcript. The cases below assert on that transcript. +# +# The two failures are the real ones from the two runs morph#731 cites: +# +# * run 34836153375 (2026-09-14): a survivor regression, 203 up from 199 -- +# which opened morph#517; +# * run 35592789912 (2026-09-21): the campaign never ran, mull's warm-up +# timing out (morph#732) -- which was recorded nowhere. +set -euo pipefail + +readonly repo_root="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" +readonly reporter="${repo_root}/scripts/report_mutation_failure.sh" + +failures=0 +note() { printf 'ok: %s\n' "$*"; } +fail() { printf 'error: %s\n' "$*" >&2; failures=$((failures + 1)); } + +scratch="$(mktemp -d)" +trap 'rm -rf "$scratch"' EXIT + +# ── The stub `gh` ──────────────────────────────────────────────────────────── +# +# Deliberately not a mock of the whole CLI: it implements the three calls the +# reporter makes and refuses anything else loudly, so a reporter that starts +# calling something new fails this test rather than silently passing it. +mkdir -p "${scratch}/bin" +cat > "${scratch}/bin/gh" <<'STUB' +#!/usr/bin/env bash +set -euo pipefail +state="${GH_STUB_STATE:?}" +mkdir -p "${state}/issues" +transcript="${state}/transcript" + +subject="${1:-}"; verb="${2:-}"; shift 2 || true + +title=""; body_file=""; number=""; search="" +case "$verb" in + comment) number="${1:-}"; shift || true ;; +esac +while [ "$#" -gt 0 ]; do + case "$1" in + --title) title="$2"; shift 2 ;; + --body-file) body_file="$2"; shift 2 ;; + --search) search="$2"; shift 2 ;; + --state|--limit|--json|--jq|--label) shift 2 ;; + *) shift ;; + esac +done + +if [ "$subject" != "issue" ]; then + echo "gh stub: unexpected subject '${subject}'" >&2; exit 64 +fi + +case "$verb" in + list) + # Emits `\t` per matching issue -- what real `gh` plus + # the reporter's `--jq '.[] | "\(.number)\t\(.title)"'` produces. + # + # The match is a *substring* one, deliberately: `in:title "…"` is a + # text search, not an equality test, so an issue whose title merely + # contains the phrase comes back. Answering only exact matches here + # would hide the case the reporter's own filter exists for. + phrase="${search#in:title \"}"; phrase="${phrase%\"}" + for f in "${state}/issues"/*; do + [ -e "$f" ] || continue + recorded="$(head -n 1 "$f")" + case "$recorded" in + *"$phrase"*) printf '%s\t%s\n' "$(basename "$f")" "$recorded" ;; + esac + done + exit 0 + ;; + create) + n=$(( $(ls "${state}/issues" | wc -l) + 900 )) + { printf '%s\n' "$title"; cat "$body_file"; } > "${state}/issues/${n}" + printf 'create %s\n' "$n" >> "$transcript" + cp "$body_file" "${state}/body-create-${n}" + echo "https://github.com/LASTRADA-Software/morph/issues/${n}" + ;; + comment) + if [ ! -e "${state}/issues/${number}" ]; then + echo "gh stub: comment on a nonexistent issue ${number}" >&2; exit 65 + fi + printf 'comment %s\n' "$number" >> "$transcript" + cat "$body_file" >> "${state}/issues/${number}" + cp "$body_file" "${state}/body-comment-${number}-$(date +%s%N)" + ;; + *) + echo "gh stub: unexpected verb '${verb}'" >&2; exit 64 + ;; +esac +STUB +chmod +x "${scratch}/bin/gh" +export PATH="${scratch}/bin:${PATH}" + +# ── The two failures, verbatim from the runs morph#731 cites ───────────────── +mkdir -p "${scratch}/logs" + +cat > "${scratch}/logs/warmup-timeout.log" <<'LOG' +[info] Warm up run (threads: 1) + [################################] 1/1. Finished in 1m0.0s +[error] Original test failed (warmup run) +status: Timedout +stdout: '' +stderr: '' +[error] Error messages are treated as fatal errors. Exiting now. +scripts/mutation.sh: mull-runner exited 1 and wrote no + report at build/mutation-core-forms/mutation-core-forms.txt. +LOG + +cat > "${scratch}/logs/regression.log" <<'LOG' +error: regression for scope 'core-forms': 203 survivors this run, up from a +recorded baseline of 199 (784 mutants this run vs 773 baseline). A new survivor +means the suite stopped noticing a mutation it used to catch (or would have). +LOG + +run_reporter() { + local state="$1"; shift + GH_STUB_STATE="$state" bash "$reporter" "$@" +} + +transcript_of() { cat "${1}/transcript" 2>/dev/null || true; } + +# ── Case 1: two different failures in one scope, both recorded ─────────────── +state="${scratch}/case1" +mkdir -p "${state}/issues" + +if ! out1="$(run_reporter "$state" core-forms https://example/run/1 \ + "${scratch}/logs/regression.log" 2>&1)"; then + fail "the first failure was not reported at all: ${out1}" +fi + +if ! out2="$(run_reporter "$state" core-forms https://example/run/2 \ + "${scratch}/logs/warmup-timeout.log" 2>&1)"; then + fail "the second failure was not reported at all: ${out2}" +fi + +transcript="$(transcript_of "$state")" +expected="$(printf 'create 900\ncomment 900')" +if [ "$transcript" = "$expected" ]; then + note "two different failures in one scope: the first opens the issue, the second comments on it" +else + fail "both failures must be recorded. Transcript was: +${transcript} +expected: +${expected}" +fi + +# Recorded is not enough: the second record has to carry the *second* failure's +# evidence. A comment that repeated the first would be the same silence with +# extra steps. +comment_body="$(cat "${state}"/body-comment-900-* 2>/dev/null || true)" +if printf '%s' "$comment_body" | grep -q "Original test failed (warmup run)"; then + note "the comment carries the second failure's own log, not the first's" +else + fail "the comment does not quote the warm-up timeout it was reporting: +${comment_body}" +fi +if printf '%s' "$comment_body" | grep -q "warm-up run of the unmutated suite"; then + note "the comment names the cause it classified" +else + fail "the comment does not name the classified cause: +${comment_body}" +fi +if printf '%s' "$comment_body" | grep -q "https://example/run/2"; then + note "the comment names the run it came from" +else + fail "the comment does not name run 2" +fi + +# ── Case 2: the regression's own evidence in the opening issue ─────────────── +create_body="$(cat "${state}/body-create-900")" +if printf '%s' "$create_body" | grep -q "203 survivors this run"; then + note "the opening issue quotes the regression rather than paraphrasing it" +else + fail "the opening issue does not quote the regression: +${create_body}" +fi + +# ── Case 3: a near-miss title must not be commented on ────────────────────── +# +# `gh issue list --search 'in:title "…"'` is a text search, not equality -- +# morph#731 filed that as unverified. The reporter filters for an exact title, +# so an issue whose title merely *contains* the phrase gets a new thread rather +# than someone else's. +state="${scratch}/case3" +mkdir -p "${state}/issues" +printf 'Mutation campaign failed or regressed (scope: core-forms) -- triage notes\n' \ + > "${state}/issues/870" +run_reporter "$state" core-forms https://example/run/3 \ + "${scratch}/logs/regression.log" > /dev/null +transcript="$(transcript_of "$state")" +if [ "$transcript" = "create 901" ]; then + note "an issue whose title merely contains the phrase is not commented on" +else + fail "a near-miss title was treated as the scope's issue. Transcript was: +${transcript}" +fi + +# ── Case 4: two scopes are two threads ────────────────────────────────────── +state="${scratch}/case4" +mkdir -p "${state}/issues" +run_reporter "$state" core-forms https://example/run/4 "${scratch}/logs/regression.log" > /dev/null +run_reporter "$state" net https://example/run/5 "${scratch}/logs/regression.log" > /dev/null +transcript="$(transcript_of "$state")" +if [ "$transcript" = "$(printf 'create 900\ncreate 901')" ]; then + note "a failure in a different scope opens its own thread" +else + fail "scopes were not kept apart. Transcript was: +${transcript}" +fi + +# ── Case 5: an unclassifiable failure is still reported ───────────────────── +# +# The classification table is a convenience. A failure it does not recognise +# must be reported *with* its log, never dropped -- dropping it is the defect +# this script exists for, one level down. +state="${scratch}/case5" +mkdir -p "${state}/issues" +printf 'ninja: build stopped: subcommand failed.\n' > "${scratch}/logs/odd.log" +run_reporter "$state" core-forms https://example/run/6 "${scratch}/logs/odd.log" > /dev/null +body="$(cat "${state}/body-create-900")" +if printf '%s' "$body" | grep -q "unclassified failure" \ + && printf '%s' "$body" | grep -q "ninja: build stopped"; then + note "an unrecognised failure is reported as unclassified, with its log" +else + fail "an unrecognised failure lost its evidence: +${body}" +fi + +# ── Case 6: a log the run never produced ──────────────────────────────────── +# +# The campaign failing before the regression check means regression-<scope>.log +# does not exist. The reporter must still report, and must say which log is +# missing rather than exiting non-zero on the `tail`. +state="${scratch}/case6" +mkdir -p "${state}/issues" +if ! run_reporter "$state" core-forms https://example/run/7 \ + "${scratch}/logs/warmup-timeout.log" "${scratch}/logs/does-not-exist.log" > /dev/null 2>&1; then + fail "a missing log file made the reporter fail instead of report" +else + body="$(cat "${state}/body-create-900")" + if printf '%s' "$body" | grep -q "not produced by this run"; then + note "a log the run never wrote is named as missing, and the report still lands" + else + fail "the missing log was not named: +${body}" + fi +fi + +# ── Case 7: a failing search is fatal, not a silent duplicate ─────────────── +# +# If `gh issue list` errors, reading that as "no issue open" files a duplicate +# every week. The reporter must fail instead -- and must put the digest in the +# run log on its way out, so the failure is not lost with it. +state="${scratch}/case7" +mkdir -p "${state}/issues" +cat > "${scratch}/bin/gh" <<'STUB' +#!/usr/bin/env bash +echo "gh: could not connect to api.github.com" >&2 +exit 1 +STUB +chmod +x "${scratch}/bin/gh" +if out="$(run_reporter "$state" core-forms https://example/run/8 \ + "${scratch}/logs/warmup-timeout.log" 2>&1)"; then + fail "a failing search was treated as 'no issue open'" +elif printf '%s' "$out" | grep -q "Original test failed (warmup run)"; then + note "a failing search is fatal, and the failure still reaches the run log" +else + fail "a failing search took the evidence down with it: +${out}" +fi + +if [ "$failures" -ne 0 ]; then + printf '\n%d case(s) failed.\n' "$failures" >&2 + exit 1 +fi + +printf '\nall cases passed.\n' From 112913cb95b9aa8fa5050e0e00ebfc5d64450a86 Mon Sep 17 00:00:00 2001 From: Yaraslau Tamashevich <yaraslau.tamashevich@gmail.com> Date: Wed, 23 Sep 2026 05:06:00 +0200 Subject: [PATCH 3/4] mutation: derive the per-mutant timeout from a baseline measured on the runner (fixes #732) `--timeout 60000` was arithmetic done once -- 2.7x the 22s this suite takes on a 12-core workstation -- and the same number bounds mull's **warm-up** run of the *unmutated* suite. When the baseline goes over the cap mull does not slow down, it aborts before mutating anything: [info] Warm up run (threads: 1) [################################] 1/1. Finished in 1m0.0s [error] Original test failed (warmup run) status: Timedout ## The hosted-runner baseline, which nobody had #732 asked for it before changing the number. It is in the campaign's own logs: | run | date | warm-up (1 thread) | mutant phase | build | |--------------|------------|--------------------|----------------|--------| | 34349442137 | 2026-09-09 | completed | completed | -- | | 34836153375 | 2026-09-14 | **24.21s** | 121m13.7s /784 | ~14min | | 35592789912 | 2026-09-21 | **> 60s** (killed) | never started | ~29min | $ gh run view 34836153375 --log | grep -i "warm up" -A 2 [info] Warm up run (threads: 1) [################################] 1/1. Finished in 24.21s **This corrects the issue's premise, which was that a hosted runner is materially slower.** It is not: 24.21s against 22s is about 10%. What it is, is *variable*. The same job's instrumented build took 14 minutes on 09-14 and 29 on 09-21, and the baseline moved with it -- from 2.5x under the cap to over it. Two of the three hosted runs completed the campaign at the old cap, so "the campaign cannot complete on a hosted runner" is too strong; it completes on the machine you usually get and not on the one you sometimes get. That is why this derives rather than re-pins. A second constant chosen from 24.21s would have the same shape as the first and a cliff in a new place. ## What changed scripts/mutation.sh runs the unmutated suite once, single-threaded, exactly as mull's warm-up will, and sets `--timeout` to 2.7x what it measured -- floored at the old 60000 ms, which is what 22s x 2.7 comes to, so the machine the constant came from keeps the behaviour it had. `mull.yml`'s `timeout:` is appended after the measurement rather than written before the build: the frontend has read the file by then and does not consume `timeout`, and the runner -- which does -- has not started, so both halves see one number. Verified by driving the derivation lines as they appear in the script: baseline 1s -> --timeout 60000 ms (60.0x) <- the floor baseline 22s -> --timeout 60000 ms (2.7x) <- today's workstation, unchanged baseline 24s -> --timeout 64800 ms (2.7x) <- the measured hosted baseline baseline 60s -> --timeout 162000 ms (2.7x) <- the run that aborted would have proceeded baseline 150s -> --timeout 405000 ms (2.7x) baseline 150s with MULL_TIMEOUT_MS=99000 -> --timeout 99000 ms The measurement costs one suite run (~24s against a two-hour campaign) and is also the only place the unmutated suite's own output is ever seen -- mull reports a failing baseline as `Original test failed (warmup run)` with `stdout: ''`, `stderr: ''`. Against a stub binary that fails: refusal exit = 1 scripts/mutation.sh: the unmutated suite exited 1 after 0s. Every mutant is scored against this run, so a failing baseline makes the whole campaign meaningless. Mull reports this as 'Original test failed (warmup run)' with the suite's own output stripped out; here it is: test_outbox.cpp:412: FAILED: REQUIRE( queue.size() == 1 ) **Not verified:** no campaign was run. This box has no Mull install, and the campaign is ~76 minutes at best. What is measured is the derivation, the refusal, and the baseline figures above -- which come from CI's own logs, not from an estimate. The next scheduled run prints its own baseline into the log the workflow uploads, so the number stops being something anybody has to dig for. Consequence worth stating: **no mutation score since 2026-09-09.** This unblocks morph#517, which cannot be closed without a campaign run to triage its four survivors. And a runner as slow as 09-21's will now reach the mutant phase and is likely to hit `timeout-minutes: 240` instead -- ~242 min of mutants plus a ~29 min build, extrapolated from 09-14. Filed as morph#747 rather than folded in: it is a different constant and a different decision. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW --- .github/workflows/mutation.yml | 2 + scripts/mutation.sh | 103 +++++++++++++++++++++++++++++++-- 2 files changed, 99 insertions(+), 6 deletions(-) diff --git a/.github/workflows/mutation.yml b/.github/workflows/mutation.yml index fdf5185bd..ba8bb03e8 100644 --- a/.github/workflows/mutation.yml +++ b/.github/workflows/mutation.yml @@ -207,4 +207,6 @@ jobs: mutation-*.log regression-*.log build/mutation-*/mutation-*.txt + build/mutation-*/baseline-*.log + build/mutation-*/mull.yml retention-days: 30 diff --git a/scripts/mutation.sh b/scripts/mutation.sh index a752ff024..a6a74431f 100755 --- a/scripts/mutation.sh +++ b/scripts/mutation.sh @@ -116,12 +116,59 @@ # is max(baseline * 10, --minimum-timeout), which against a 22s baseline is 220s # -- so a mutant that makes the suite hang holds a worker for nearly four # minutes, and measured throughput was 6.7 mutants/minute on twelve workers -# instead of the ~33 the arithmetic predicts. Capping it at 60s (2.7x baseline) +# instead of the ~33 the arithmetic predicts. Capping it at 2.7x the baseline # recovers most of that. A mutant that outlives the cap is scored killed, which # is the standard reading and the right one here: nothing in morph_tests is # legitimately three times slower than the baseline, so an over-cap mutant has # changed the program's termination behaviour. # +# ── Why the cap is measured here and not written down (morph#732) ──────────── +# +# That 2.7x used to be a constant -- 60000 ms, arithmetic done once against the +# 22s this workstation takes -- and a constant derived on one machine and +# enforced on another is a threshold calibrated where the feature is cheap. The +# same timeout bounds mull's **warm-up** run of the *unmutated* suite, so when +# the baseline goes over the cap mull does not slow down, it aborts: +# +# [info] Warm up run (threads: 1) +# [################################] 1/1. Finished in 1m0.0s +# [error] Original test failed (warmup run) +# status: Timedout +# +# -- run 35592789912, 2026-09-21, ubuntu-26.04. No mutation score was produced +# for two weeks, and no one saw it because the workflow's own reporting was +# broken twice over (morph#730, morph#731). +# +# The numbers, from the campaign's own logs rather than from an estimate: +# +# | run | date | warm-up (1 thread) | mutant phase | +# |--------------|------------|--------------------|----------------| +# | 34349442137 | 2026-09-09 | completed | completed | +# | 34836153375 | 2026-09-14 | **24.21s** | 121m13.7s /784 | +# | 35592789912 | 2026-09-21 | **> 60s** (killed) | never started | +# +# So the hosted runner is not systematically slower than this workstation -- +# 24.21s against 22s is ~10%. What it is, is *variable*: the same job's +# instrumented build took 14 minutes on 09-14 and 29 minutes on 09-21, and the +# baseline moved with it, from 2.5x under the cap to over it. A fixed cap with +# no margin for a 2x machine is the defect; a second, larger constant would only +# move the cliff. +# +# So the baseline is measured on whatever machine is actually running, once, +# before mull is invoked, and the cap is 2.7x *that*. On this workstation that +# reproduces the old 60000 ms almost exactly (22s * 2.7 = 59.4s), which is why +# MULL_MIN_TIMEOUT_MS floors it at 60000: the ratio is what was measured, and +# the floor keeps a fast machine from deriving a cap too tight for a mutant that +# is merely slow. +# +# The measurement costs one extra run of the suite -- ~24s against a campaign of +# two hours -- and pays for itself twice over: it is also the only place the +# unmutated suite's own output is ever seen. Mull runs it too, and reports a +# failure as `Original test failed (warmup run)` with `stdout: ''`, `stderr: ''` +# -- a verdict with the evidence stripped out. Running it here first means a +# suite that does not pass says so in its own words, before two hours of mutants +# are scored against it. +# # One caveat on the number, in the direction of *over*-counting kills. # tests/test_outbox.cpp names its scratch file after the address of a # stack object, which is stable across processes, so twelve concurrent copies of @@ -238,10 +285,11 @@ mkdir -p "$build_dir" echo "excludePaths:" echo " - .*_deps.*" echo " - .*/tests/.*" - # Per-mutant timeout. morph_tests' own wall time is ~22s and several of its - # cases wait on real timeouts, so a mutant that merely makes the suite slow - # must not be scored as killed-by-timeout. - echo "timeout: 60000" + # No `timeout:` here. It is appended below, once the baseline it is derived + # from has been measured on this machine -- see "Why the cap is measured + # here and not written down". The frontend has read this file by then and + # does not consume `timeout` at all; only the runner does, and the runner + # has not started. } > "${build_dir}/mull.yml" # USE_COMPILER_CACHE=OFF: the objects carry mutation metadata keyed to this @@ -268,6 +316,49 @@ if ! readelf -SW "${build_dir}/${binary}" | grep -q '\.mull_mutants'; then exit 1 fi +# ── The baseline, measured on the machine that is about to run the campaign ── +# +# One unmutated run of the suite, single-threaded, exactly as mull's warm-up +# will run it. See "Why the cap is measured here and not written down" for what +# this replaces and the three runs that made it necessary (morph#732). +readonly baseline_log="${build_dir}/baseline-${scope}.log" +echo "scripts/mutation.sh: measuring the unmutated suite (mull runs it once, single-threaded, before any mutant)..." +baseline_start=${SECONDS} +set +e +"${build_dir}/${binary}" > "$baseline_log" 2>&1 +baseline_status=$? +set -e +readonly baseline_seconds=$(( SECONDS - baseline_start )) +readonly baseline_status + +if [ "$baseline_status" -ne 0 ]; then + echo "scripts/mutation.sh: the unmutated suite exited ${baseline_status} after ${baseline_seconds}s." >&2 + echo " Every mutant is scored against this run, so a failing baseline makes the" >&2 + echo " whole campaign meaningless. Mull reports this as 'Original test failed" >&2 + echo " (warmup run)' with the suite's own output stripped out; here it is:" >&2 + tail -n 30 "$baseline_log" >&2 + exit 1 +fi + +# 2.7x, floored. The ratio is what was measured on a 12-core workstation (22s +# baseline, 60s cap); the floor keeps a fast machine from deriving a cap too +# tight for a mutant that is merely slow, and reproduces the old constant +# exactly on the machine that constant came from. +readonly timeout_floor_ms="${MULL_MIN_TIMEOUT_MS:-60000}" +derived_timeout_ms=$(( baseline_seconds * 2700 )) +if [ "$derived_timeout_ms" -lt "$timeout_floor_ms" ]; then + derived_timeout_ms="$timeout_floor_ms" +fi +readonly timeout_ms="${MULL_TIMEOUT_MS:-$derived_timeout_ms}" +echo "scripts/mutation.sh: unmutated ${target} baseline: ${baseline_seconds}s on $(nproc) cores." +echo " per-mutant timeout: ${timeout_ms} ms (2.7x baseline, floored at ${timeout_floor_ms} ms${MULL_TIMEOUT_MS:+, overridden by MULL_TIMEOUT_MS})." + +# Appended now rather than written with the rest of the config: the frontend +# read mull.yml at compile time and does not consume `timeout`, and the runner +# -- which does -- has not started. Both halves therefore see one number, which +# is the property the "step that is easy to get wrong" section is about. +echo "timeout: ${timeout_ms}" >> "${build_dir}/mull.yml" + # IDE only. Mull's SQLite reporter aborts on this project -- # "Failed to write SQLite report: string or blob too big" -- and Mull treats a # reporter error as fatal, so it exits *after* the 46-minute run and *before* @@ -283,7 +374,7 @@ fi set +e MULL_CONFIG="${PWD}/${build_dir}/mull.yml" "$runner" \ --workers "${MULL_WORKERS:-$(nproc)}" \ - --timeout "${MULL_TIMEOUT_MS:-60000}" \ + --timeout "${timeout_ms}" \ --reporters IDE \ --report-dir "${build_dir}" \ --report-name "mutation-${scope}" \ From ef30b6a5df3fe4ac8db67b8fb9bb38f91f071ec4 Mon Sep 17 00:00:00 2001 From: Yaraslau Tamashevich <yaraslau.tamashevich@gmail.com> Date: Wed, 23 Sep 2026 05:11:30 +0200 Subject: [PATCH 4/4] ci+presets: TSan names where the already-held mutex was taken (fixes #736) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Both TSan sites in ci.yml, and CMakePresets.json's `clang-tsan` test preset, carried `suppressions=` and nothing else. Without `second_deadlock_stack=1` a lock-order inversion is reported with the cycle and one stack per acquisition, and the stacks that would name the *participants* are replaced by advice: Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get more informative warning message -- which nobody can take after the fact. morph#578 and morph#717 are both intermittent and neither has been reproduced; the run that fires is the only evidence that will ever exist, and the job cannot be re-run into the same interleaving. ## Measured, not assumed A two-mutex inversion, clang 22.1.8, `-fsanitize=thread -g -O1`: $ TSAN_OPTIONS="" ./deadlock; wc -l 36 $ TSAN_OPTIONS="second_deadlock_stack=1" ./deadlock; wc -l 55 $ grep -c "previously acquired by the same thread here" plain.txt 0 $ grep -c "previously acquired by the same thread here" sds.txt 2 The 19 extra lines are the two stacks, and they name the function and source line that took each already-held mutex: Mutex M0 previously acquired by the same thread here: #0 pthread_mutex_lock … #4 take_a_then_b() deadlock.cpp:11:33 #5 main deadlock.cpp:21:5 Mutex M1 previously acquired by the same thread here: … #4 take_b_then_a() deadlock.cpp:16:33 (morph#738's lane measured 47 -> 71 on a larger fixture; same two stacks, and that lane also disproved its own hypothesis that this was why morph#578's report was uninformative -- that was morph#578's own `grep -A 60 | head -70`.) ## The triage's own closing condition, measured > `invalid` if the option turns out to cost meaningful runtime on a green run -- > I have not measured that, and neither did the filing. 2M lock acquisitions across 4 threads over 16 mutexes under TSan, which is the worst case for an option that retains an acquisition stack per mutex: without: 0.275 0.275 0.242 with second_deadlock_stack=1: 0.263 0.273 0.278 No measurable difference. **Proxy, not the suite:** this is a lock-heavy microbenchmark, not morph_tests under the CI preset, which I did not run. ## Two things the change gets right rather than nearly right The option goes *into* the existing value, colon-separated. A second `TSAN_OPTIONS:` key would silently replace the first and drop the suppressions file -- morph#688's failure one spelling over: >>> yaml.safe_load("env:\n TSAN_OPTIONS: suppressions=/x/cmake/tsan.supp\n TSAN_OPTIONS: second_deadlock_stack=1\n") {'env': {'TSAN_OPTIONS': 'second_deadlock_stack=1'}} And `CMakePresets.json`'s `clang-tsan` test preset gets it too. That preset exists (morph#688) so a local run matches CI; CI gaining the option alone would make a local reproduction *less* informative than the run being reproduced, which is the asymmetry morph#688 was filed to remove. `cmake/tsan.supp` is untouched -- it is held by an open PR, and nothing here needs it. Three places now have to agree on one string and nothing checks that they do. Filed as morph#748 rather than folded in. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01VptDWG2fKr2vBnLSJcgzgW --- .github/workflows/ci.yml | 25 +++++++++++++++++++++++-- CMakePresets.json | 4 ++-- 2 files changed, 25 insertions(+), 4 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index ef5b4e279..17ceaf79b 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -598,7 +598,22 @@ jobs: # # Harmless on the clang-asan and clang-ubsan legs of this matrix: # neither runtime reads TSAN_OPTIONS. - TSAN_OPTIONS: suppressions=${{ github.workspace }}/cmake/tsan.supp + # + # `second_deadlock_stack=1` is colon-separated *into this value*, not + # a second `TSAN_OPTIONS:` key -- a second key silently replaces the + # first and drops the suppressions file, which is morph#688's failure + # one spelling over. It makes TSan print, for a lock-order inversion, + # the stacks where the *already-held* mutexes were taken. Measured on + # a two-mutex inversion under clang 22.1.8: 36 lines -> 55, the extra + # 19 being two `Mutex Mn previously acquired by the same thread here:` + # stacks that name the acquiring function and line. Without it TSan + # prints only `Hint: use TSAN_OPTIONS=second_deadlock_stack=1 to get + # more informative warning message` -- advice nobody can take after + # the fact, because morph#578 and morph#717 are intermittent and the + # run that fires is the only evidence that will ever exist. No + # measurable runtime cost: 2M lock acquisitions under TSan took a + # median 0.275s without and 0.273s with (morph#736). + TSAN_OPTIONS: suppressions=${{ github.workspace }}/cmake/tsan.supp:second_deadlock_stack=1 run: | # morph::testkit::OomInjector (tests/oom_injector.cpp) overrides # the process-wide operator new/delete to force std::bad_alloc on @@ -1027,7 +1042,13 @@ jobs: # Without it this leg is a coin toss on a false positive that the # other TSan leg already knows is one — and the failure mode of a # known false positive is that the next real one is waved past. - TSAN_OPTIONS: suppressions=${{ github.workspace }}/cmake/tsan.supp + # + # `second_deadlock_stack=1` for the reason the linux-sanitizers Test + # step above gives at length (morph#736), and appended to the same + # value rather than added as a second `TSAN_OPTIONS:` key, which + # would silently drop the suppressions file this leg was given in the + # first place. + TSAN_OPTIONS: suppressions=${{ github.workspace }}/cmake/tsan.supp:second_deadlock_stack=1 run: ctest --preset clang-tsan -L ladder-kanban -R ThreadSanitizer --output-on-failure # Cumulative hit/miss for this leg. Without it the cache is diff --git a/CMakePresets.json b/CMakePresets.json index 34c790901..5a14e71d4 100644 --- a/CMakePresets.json +++ b/CMakePresets.json @@ -251,9 +251,9 @@ "name": "clang-tsan", "configurePreset": "clang-tsan", "inherits": "base-test", - "description": "TSan test run. Two things it sets that a caller would otherwise have to know. (1) TSAN_OPTIONS points at cmake/tsan.supp through ${sourceDir}, i.e. absolutely, so it resolves from any working directory and cannot drift from the file it names. A relative 'suppressions=cmake/tsan.supp' does not survive test discovery: catch_discover_tests runs the binary with the working directory set to its own build directory, TSan then fails to open the file and exits with its default exitcode=66, and Catch2's CatchAddTests.cmake reports 'Result: 66 / Output:' with nothing in it -- the listing goes to a file via --out, so that error block is empty for every discovery failure -- attributed to whichever binary ctest enumerated first (examples/concepts), which is nowhere near the cause. (2) The OomInjector exclusion, for the reason spelled out on the clang-asan preset above.", + "description": "TSan test run. Three things it sets that a caller would otherwise have to know. (1) TSAN_OPTIONS points at cmake/tsan.supp through ${sourceDir}, i.e. absolutely, so it resolves from any working directory and cannot drift from the file it names. A relative 'suppressions=cmake/tsan.supp' does not survive test discovery: catch_discover_tests runs the binary with the working directory set to its own build directory, TSan then fails to open the file and exits with its default exitcode=66, and Catch2's CatchAddTests.cmake reports 'Result: 66 / Output:' with nothing in it -- the listing goes to a file via --out, so that error block is empty for every discovery failure -- attributed to whichever binary ctest enumerated first (examples/concepts), which is nowhere near the cause. (2) The OomInjector exclusion, for the reason spelled out on the clang-asan preset above. (3) second_deadlock_stack=1, colon-separated into the same value -- a second TSAN_OPTIONS key would replace the first and drop the suppressions file, which is this preset's own morph#688 failure one spelling over. It is what makes a lock-order inversion name where each already-held mutex was taken (36 report lines -> 55 on a two-mutex inversion, the extra 19 being two 'Mutex Mn previously acquired by the same thread here:' stacks); CI's two TSan legs pass it, and a local reproduction that did not would be less informative than the CI run it is reproducing -- the asymmetry morph#688 existed to remove (morph#736).", "environment": { - "TSAN_OPTIONS": "suppressions=${sourceDir}/cmake/tsan.supp" + "TSAN_OPTIONS": "suppressions=${sourceDir}/cmake/tsan.supp:second_deadlock_stack=1" }, "filter": { "exclude": { "name": "OomInjector|morph#108" } } },