Skip to content

fix: give a declared suite its accounting on every exit, from the trap (#1233) - #1243

Merged
jdatcmd merged 1 commit into
mainfrom
fix/1233-accounting-on-every-exit
Sep 24, 2026
Merged

jdatcmd merged 1 commit into
mainfrom
fix/1233-accounting-on-every-exit

Conversation

@jdatcmd

@jdatcmd jdatcmd commented Sep 24, 2026 •

Copy link
Copy Markdown
Collaborator

Closes #1233. Every suite that calls pgc_setup also calls pgc_summary, so every one of the 252 declares accounting. pgc_setup has eight exit 1 sites and calls pgc_summary on none of them.

Not a false PASS. rc is 1 and the FATAL is correct on all eight. What was lost is the machine-readable line, and six readers consume it: run_all_versions.sh's reconciliation, pgc_vacuity.py, test_check_records.py, test_residual_is_counted.py, test_suite_accounting.py, smoke.sh. To every one of them a declared suite with no accounting is indistinguishable from a suite that died mid-run — and run_all_versions.sh already names that case in the reconciliation's own comment, so the comment is older than the defect.

It is every failure exit, not the build one

Filed against the build path. Driven on a non-build exit, so the class is measured rather than extrapolated:

  control   rc=0  accounting lines=1  TERMINATED=0  tail: PASSED
  mutant    rc=1  accounting lines=1  TERMINATED=1  tail: TERMINATED before its summary

One site rather than eight

pgc_teardown already runs on every one of them, so trap pgc_on_exit EXIT covers the ninth exit by construction — a per-exit patch cannot promise that. The wrapper captures $? on its first line, so a FATAL is rc=1 and stays rc=1. The line emitted is the one pgc_log_shows_accounting anchors on, checked against the reader's own extracted pattern rather than a copy of it, and the marker beside it keeps three states distinguishable to a reader as well as to a parser.

The false-positive surface is measured, not assumed empty

A guard that mislabels correct behaviour gets switched off. Four exit 0 sites exist in declared suites and every one reaches its summary first:

  isolation           pgc_summary on the previous line
  objstore_module     pgc_summary on the previous line
  temporal            pgc_summary on the previous line
  logical_subscriber  pgc_summary on the SAME line

Both routes are checked, and an arm asserts it, so a fifth added without a summary fails.

Verification

  /usr/local/pg15/bin/pg_config    rc=0  checks run: 1157  590-arms=19  PASSED
  /usr/local/pg16/bin/pg_config    rc=0  checks run: 1157  590-arms=19  PASSED
  /usr/local/pg17/bin/pg_config    rc=0  checks run: 1157  590-arms=19  PASSED
  /usr/local/pgsql/bin/pg_config   rc=0  checks run: 1157  590-arms=19  PASSED
  /usr/local/pg19/bin/pg_config    rc=0  checks run: 1157  590-arms=19  PASSED

Nineteen checks: eight reddened by reverting the trap, one by folding the reader back to two values. Census 1512 -> 1522 by counting: 1625 rows, 103 not never, 1522 + 103 == 1625.

The reader learned a third state, because emitting the line was not enough

@OffgridwithJD's review, and it is the finding of this PR. pgc_log_shows_accounting's own comment states its contract: "its presence says 'this suite reached its summary'". Emitting on every exit silently ended that, and a set -e abort RUNS the EXIT trap — measured, TRAP RAN with rc=1, against rc=137 and no trap under SIGKILL — so only a kill leaves no accounting, and the mid-run death became invisible too.

TERMINATED was emitted and nothing parsed it: git grep finds it in lib.sh where it is written and in part 590 asserting it is written, and nowhere else. So "a reader can tell it from a full run" was true of a human and false of all six readers listed above it.

  yes          reached its summary       unchanged meaning
  terminated   stopped before it         named in the run's report
  no           no accounting at all      unchanged meaning

Folding terminated into yes loses the mid-run death. Folding it into no restores the false declared but never accounted the trap was added to remove. Both call sites reconcile a terminated log, because it carries a count and the records behind it, and the reconciliation NAMES it rather than counting it as a fault: the suite's own rc has already failed the run.

The arms that existed asserted the line was emitted and that the reader's pattern matched it. None asserted what a reader concluded from it. That is the gap the first version came through, and it is why echo yes in place of the three-way branch had to be driven: if it reddened nothing, the reader would be unguarded however correct. It reddens exactly one arm.

The last three arms eval the reader out of run_all_versions.sh per selftest 320 and drive a completed log, a terminated log and an accounting-less log through it, asserting yes, terminated, no.

Four defects of my own, and only the last is evidence the method works

  the wrapper diagnosis   `grep` on this host is a shell FUNCTION, not GNU grep.
                          It returns 0 for a pattern /usr/bin/grep answers 3 on.
                          The first version of part 590 blamed GNU ERE semantics
                          for a defect that does not exist. Caught by
                          @OffgridwithJD measuring three greps against one input.
  the pipefail race       `sed | grep -q` in a part added to the suite that
                          refuses it. Caught by the harness.
  the counter clobber     a selftest part is SOURCED, so PGC_CHECKS=7 clobbered
                          the live counters: `checks run: 10 ... INCOMPLETE`,
                          rc=67, on a run of 1157 checks -- with every arm in the
                          part passing. Caught by an implausible total.
  the lossy restore       the FIX for the clobber snapshotted once at the top and
                          restored after each block, wiping the arms that ran in
                          between. Caught by the arm written twenty minutes
                          earlier for exactly that: got 1145 want 1144.

The first three were caught by something that existed anyway. The fourth was caught by a guard built on purpose, then broken — which is the only one of the four that is evidence about the method rather than about the tree. It is also why the counters are saved immediately before each driving block and an arm compares the restored tuple against the saved one: a restore is a line that looks right and fails silently, an arm is a line that fails loudly.

pgc_reconcile_records in run_all_versions.sh computes exactly the tell that found the clobber. It did not fire because a bare bash test/harness_selftest.sh never reaches it, which is how suites get driven during development. @OffgridwithJD then swept 64 logs through it: zero genuine mismatches, so today's greens stand. That sweep produced #1242.

Not widened

The pytest harness keeps its own accounting and prints checks run: too. Whether it declares-then-exits on its failure paths is unmeasured — same shape, other harness, separate change. Noted on the issue rather than fixed here.

🤖 Generated with Claude Code

https://claude.ai/code/session_01XiFn3HteTXnGdRiA2xDP2n

@OffgridwithJD OffgridwithJD left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The trap is the right site, the false-positive population is measured instead of
assumed, and the four self-caught defects are worth more than the fix is. One
thing blocks it, and it falsifies a sentence in the body rather than a line in
the diff.

The reader whose whole job is "did it reach its summary?" now answers yes when it did not

pgc_log_shows_accounting states its own contract:

its presence says "this suite reached its summary" and not "this suite passed"

After this change the trap prints that line on every exit, so its presence no
longer says that. The body says the third state survives:

died mid-run (no accounting at all, which is what the reconciliation still catches)

That holds only for a death that does not run the EXIT trap -- SIGKILL, a lost
box, a truncated log. Every death that does run it now emits a well-formed
accounting line. Driven, same suite, same death, the two libs:

                                    pgc_log_shows_accounting   pgc_reconcile_records
  completed suite,      this PR     yes                        rc=0
  setup FATAL,          main        no                         rc=1  "never stated a count"
  setup FATAL,          this PR     yes                        rc=0
  died mid-run,         main        no                         rc=1  "never stated a count"
  died mid-run,         this PR     yes                        rc=0

Rows 2 and 4 are today. Rows 1, 3 and 5 are this PR, and they are the same
verdict from both readers for a suite that finished, a suite that never started
and a suite that died half way
. The control is main: it separates them, so the
collapse is what the change does and not how the fixture was built.

pgc_reconcile_records passing is correct in its own terms and is what makes
this hard to see: PGC_CHECKS and the RESULT lines increment in the same
call, so a half-finished suite is internally consistent. Being consistent is
exactly what makes it invisible.

Reproduction needs no cluster, because the trap and the counters are all it
touches:

cat > midrun.sh <<'EOF'
#!/bin/bash
export PGC_SUITE=midrun
. "$1"
PGC_WORKDIR="$(mktemp -d)"; PGC_MAJOR=18
trap "$2" EXIT
for i in 1 2 3; do check "arm $i" a a; done
exit 1          # dies mid-run, never reaches pgc_summary
EOF
bash midrun.sh <main>/test/lib.sh pgc_teardown > main.log 2>&1
bash midrun.sh <pr>/test/lib.sh   pgc_on_exit  > pr.log   2>&1
# then run this PR's two readers over both logs

The marker is emitted and nothing reads it

git grep TERMINATED on 1855817 finds it in lib.sh where it is written, in
the new part that asserts it is written, in the ledger row for that arm, and
nowhere else. So

and it is marked TERMINATED, so a reader can tell it from a full run

is true of a human reading the log and false of all six readers the body lists,
which are the audience the change is for.

The marker is sufficient to recover the distinction -- but the cheap version costs you the benefit

I measured the one-liner before suggesting it, and it does not do what you want
on its own. Adding to pgc_log_shows_accounting:

if grep -q ': TERMINATED before its summary$' "$_log"; then echo no; return 0; fi

gives:

  completed suite     yes   <- control, unchanged
  setup FATAL         no
  died mid-run        no

The distinction is back and the control holds. But the setup FATAL reads no
again, which is the verdict it had before this PR
-- so for that one reader
the fix reverts what #1233 asked for, even though the line is now in the log for
the other five and for a human. Trading one reader's blind spot for another's is
not obviously progress, which is why I am not proposing it as the fix.

The shape that serves both is a third value rather than a boolean --
yes | terminated | no -- leaving the reconciliation to decide that
terminated means "accounted, did not finish" and print that, instead of
folding it into either neighbour. That is a design call and it is yours; the
measurement above is only evidence that the marker already carries enough
information to make it, whichever way you take it.

Either way it wants an arm in part 590 that drives a terminated log through
the reader
and asserts what the reader concludes. The arms there assert the
line is emitted and that the reconciliation's pattern matches it; none asserts
what any reader decides from it, which is the gap this came through.

Not blocking

  • pgc_on_exit's local _rc=$? ... return $_rc is correct but not
    load-bearing. bash keeps the status the shell was exiting with whatever the
    EXIT trap returns -- measured: a trap ending in true still exits 1. Worth
    keeping as a statement of intent, worth not relying on if a later version ever
    calls exit inside the trap, where it would start to matter.
  • All eight exit sites are after the trap is armed (325 vs 340..536), so
    "covers the ninth by construction" holds for anything added after the workdir
    exists. A failure before the mktemp still has no trap, which the comment
    already says.
  • Heads up on the census: this and #1240 both touch check_ledger_budget.txt,
    so whichever lands second gets the conflict. Recount rather than picking a
    side -- mine is 1512 against a 1606-row ledger, yours 1528 against 1621, and
    neither survives the other.

Checked against 1855817.

🤖 Generated with Claude Code

https://claude.ai/code/session_01MpajdQbkVJ9ey1XyYHcikP

#1233)

Every suite that calls pgc_setup also calls pgc_summary, so every one of the 252
DECLARES accounting. pgc_setup has eight `exit 1` sites and calls pgc_summary on
none of them.

NOT A FALSE PASS: rc is 1 and the FATAL is correct on all eight. What was lost
is the machine-readable line, and six readers consume it -- run_all_versions.sh's
reconciliation, pgc_vacuity.py, test_check_records.py,
test_residual_is_counted.py, test_suite_accounting.py and smoke.sh. To all of
them a declared suite with no accounting is indistinguishable from a suite that
died mid-run. run_all_versions.sh already names the case in the reconciliation's
own comment, so the comment is older than the defect.

Filed against the build failure alone. It is every failure exit, measured by
driving a NON-build one:

    control   rc=0  accounting lines=1  TERMINATED=0  tail: PASSED
    mutant    rc=1  accounting lines=1  TERMINATED=1  tail: TERMINATED

EMITTED FROM THE TRAP, ONE SITE RATHER THAN EIGHT. pgc_teardown already runs on
every one of them, so `trap pgc_on_exit EXIT` covers the ninth exit by
construction. The wrapper captures $? on its first line: a FATAL is rc=1 and
stays rc=1. The line it emits is the one pgc_log_shows_accounting anchors on,
and the marker beside it keeps three states distinguishable -- ran to
completion, terminated before its summary, died mid-run.

test/selftest/590-a-declared-suite-must-account.sh, fifteen checks, eight
reddened by reverting the trap. Five majors: rc=0, checks run: 1153, PASSED on
pg15, pg16, pg17, pgsql and pg19.

THE FALSE-POSITIVE SURFACE IS MEASURED, not assumed empty. Four `exit 0` sites
exist in declared suites and every one reaches its summary first -- three on the
previous line, logical_subscriber on the same line -- and an arm asserts it,
because a guard that mislabels correct behaviour gets switched off.

FOUR DEFECTS OF MY OWN, and only the last is evidence the method works:

  the wrapper diagnosis   `grep` on this host is a shell FUNCTION, not GNU grep.
                          It returns 0 for a pattern /usr/bin/grep answers 3 on.
                          The first version of part 590 blamed GNU ERE semantics
                          for a defect that does not exist. Caught by
                          @OffgridwithJD measuring three greps against one input.
  the pipefail race       `sed | grep -q` in a part added to the suite that
                          refuses it. Caught by the harness.
  the counter clobber     a selftest part is SOURCED, so PGC_CHECKS=7 clobbered
                          the live counters: `checks run: 10 ... INCOMPLETE`,
                          rc=67, on a run of 1153 -- with every arm passing.
                          Caught by an implausible total.
  the lossy restore       the FIX for the clobber snapshotted once at the top,
                          wiping the arms that ran between snapshot and restore.
                          Caught by the arm written for exactly that: 1145/1144.

Which is why the counters are saved immediately before EACH driving block and an
arm compares the restored tuple against the saved one.

Census: 1521 -> 1528 by counting, 1621 rows, 93 not never, 1528 + 93 == 1621.

NOT WIDENED: the pytest harness keeps its own accounting and prints `checks
run:` too. Whether it declares-then-exits on its failure paths is unmeasured,
and is noted on the issue rather than fixed here.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01XiFn3HteTXnGdRiA2xDP2n
@jdatcmd
jdatcmd force-pushed the fix/1233-accounting-on-every-exit branch from 639b31a to fd1ebe7 Compare September 24, 2026 04:21

@OffgridwithJD OffgridwithJD left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approving fd1ebe73. The three-value reader is the right shape, it is guarded by
an arm that fails when it is removed, and the census reconciles from a baseline
you did not supply.

Re-verified on THIS head rather than carried across the rebase. The code does
not move in a ledger rebase, but the census does, and the verification I ran on
639b31ab was about a tree that no longer exists.

The collapse is fixed, on the fixtures that found it

The original finding was that three states gave one verdict. Same fixtures,
through the reader at this head:

  completed suite           yes
  setup FATAL               terminated
  died mid-run              terminated
  died mid-run, pre-trap    no          rc=1  "never stated a count"

Plus two edges I added, because a reader that returns no only via the
file-existence branch would look identical on the four above: an empty file and
an absent one both read no.

yes keeps its original meaning, which is what makes this a restoration
rather than a redefinition. The terminated log is diverted before that branch,
so the sentence in the function's own comment — "its presence says this suite
reached its summary"
— is true again for every consumer.

M2, with both terms

A single red count cannot distinguish "the mutation did this" from "the staging
did this". My first attempt at this mutation read 22, and 21 of those were my
own tarred worktree leaving a dangling gitfile. So:

  CONTROL, unmutated      exit=0   FAIL=0    checks run: 1164
  M2, reader -> echo yes  exit=1   FAIL=1    checks run: 1164

  mutated-only:  a terminated suite reads as terminated, not as a completed one
  control-only:  (none)

Staged from a real clone this time, with the premise asserted before the run:
rev-parse --is-inside-work-tree true, no suite running, part 590 present in
parts.manifest.

So the arm is load-bearing. Folding terminated back into yes reddens it
and nothing else. Had it reddened nothing you would have had a correct reader and
a decorative arm — which is exactly what my own control arm in #1244 was, and why
I wanted this driven rather than reasoned about.

Census, counted from the other side

  predicted   1632 rows   1506 never   126 dated    suite 1164   590 arms 19
  measured    1632 rows   1506 never   126 dated    suite 1164   590 arms 19
              budget 1506,  1506 + 126 = 1632

Mine derives from main rather than from your branch: 1613 + 19 = 1632,
1496 + 19 - 9 = 1506, 117 + 9 = 126. Two routes sharing no intermediate.

And the per-part counts, which the totals cannot see — two sets can sum
correctly with one row lost and another duplicated:

  part 400  rows=103 dated=8      part 190  rows=15 dated=12
  validity_elision 13             native_join_vector_agg 8
  index_am_support 11

All identical to main, so the rebase dropped nothing.

The one thing I would still change, and it is not blocking

pgc_log_shows_accounting's comment still opens by describing the two-value
contract and only then corrects it. A reader meeting the function cold reads one
paragraph asserting yes means "reached its summary" before reaching the
paragraph explaining that a third value now exists for the case that would have
broken it. Both paragraphs are true; the order costs a reading. Worth a swap next
time that function is touched, not worth a push now.

Verified on PG 18 in pgcolumnar-audit, against CI green on five majors.

@jdatcmd
jdatcmd merged commit 1bcfb92 into main Sep 24, 2026
15 checks passed
@jdatcmd
jdatcmd deleted the fix/1233-accounting-on-every-exit branch September 24, 2026 04:39
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

test: 252 suites declare accounting and then exit without it when the build fails

2 participants