Skip to content

test: a timeout is a check result, and these records had no major (#965) - #1109

Merged
jdatcmd merged 1 commit into
commandprompt:mainfrom
OffgridwithJD:test/965-timeout-paths-record
Sep 18, 2026
Merged

jdatcmd merged 1 commit into
commandprompt:mainfrom
OffgridwithJD:test/965-timeout-paths-record

Conversation

@OffgridwithJD

Copy link
Copy Markdown
Collaborator

Takes the timeout half of #965 — the part its own text says has to be decided rather than substituted.

The defect: an aggregate that balances while asserting zero failures

Eleven bounded waits across concurrency.sh, unique_conc.sh and update_conc.sh printed FAIL timeout waiting for ..., set the suite-local fail and returned, touching neither PGC_CHECKS nor the record stream.

Induced on unmodified main as the control — all four wait bounds lowered from 1200 to 1, with the rewritten count asserted before the run:

main / induced timeout       rc=1
  verdict line          : CONCURRENCY TEST FAILED
  human FAIL lines      : 1
  RESULT records total  : 7
  RESULT records w/ FAIL: 0      <- the failure is recorded nowhere
  checks run:           : 7

Records and total agree, so nothing refuses that log — on a run that printed a FAIL and exited 1. This was never a false green (the suite derives its verdict from the local fail and exits 1), but a figure that reconciles is worse than one that is missing: a missing number gets noticed.

After

branch / induced timeout     rc=1
  RESULT records w/ FAIL: 2
  RESULT records total  : 9
  checks run:           : 9

FAIL  a bounded wait for a command's sentinel completed (timed out waiting for s1/a_del)
RESULT	concurrency	concurrency	a bounded wait for a command's sentinel completed	FAIL	18	s1/a_del

Green runs are unchanged, which is the other half of the claim:

main / green      rc=0   7 records, checks run: 7
branch / green    rc=0   7 records, checks run: 7

The two decisions #965 said were not mechanical

The name. Fixed per wait kind, with the session and sentinel in pgc_record's REASON field — which is what that field is for. Interpolating "$name/$label" into a ledger keyed on (suite, part, name) would mint rows nobody can enumerate and therefore nobody can seed. Four kinds: a command's sentinel, a standalone sentinel, a session blocking, a session reaching idle-in-transaction.

It cannot be proved by running the suite. None of these lines execute on a green run, so every count is identical whether the conversion is right, wrong, or absent. The proof is the induced timeout above, with main as the control in the same table.

A second finding, fixed here because it is what makes the records usable

Every record these three suites emit named major=unknown — including the ones already on main:

=== majors on the GREEN branch run, before the fix ===
      7   PASS  major=unknown

pgc_record reads ${PGC_MAJOR:-unknown}, and PGC_MAJOR is set by pgc_setup, which these three never call — they carry their own harness. A ledger row claiming to hold on unknown matches no run, so none of these checks could ever have been seeded, which is part of why suites_not_covered has a floor here (#965) and why the major dimension matters (#1071).

One line each, from the PG_CONFIG they already resolve. After:

concurrency   7 records   all major 18   checks run: 7    rc=0
unique_conc  31 records   all major 18   checks run: 31   rc=0
update_conc  25 records   all major 18   checks run: 25   rc=0

This predates the change and I am not claiming otherwise — it is fixed here because recording a timeout into a row nothing can seed would have been half a fix.

Scope

Not the other half of #965: the 58 checks still going through eq_on_off, assert_plan, expect_error and friends, and audit.sh:313's ungated echo. Those are a separate mechanical pass, and this one is the part that needed a decision and an induced fixture.

The three suites hold no ledger rows, so nothing moves in check_ledger.tsv and suites_not_covered is unchanged. Every mutation restored byte-exact; bash -n and shellcheck -S error clean on all three.

🤖 Generated with Claude Code

https://claude.ai/code/session_012RSw4qMHS7ByE7PY8Ns4cs

@jdatcmd jdatcmd 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. I reproduced both halves on PG17 rather than reading your table, and the control on main is what settles it.

The defect, reproduced on unmodified main

main 9caec4c, all four wait bounds 1200 -> 1
  rc=1
  verdict line          : CONCURRENCY TEST FAILED
  human FAIL lines      : 3
  RESULT records total  : 7
  RESULT records w/FAIL : 0      <- the failure is recorded nowhere
  checks run:           : 7
  majors                : unknown

Records and total agree at 7, so nothing refuses that log, on a run that printed three FAIL lines and exited 1. Your point that a figure which reconciles is worse than one that is missing is the right way to put it.

(I saw three human FAIL lines where you saw one. That is the induced scenario reaching more waits on a different major, not a disagreement — the load-bearing numbers, 7 records with 0 FAIL against checks run: 7, match yours exactly.)

The fix, same mutation on your branch

629b560, same 1200 -> 1
  rc=1
  RESULT records total  : 9
  RESULT records w/FAIL : 2
  checks run:           : 9

RESULT	concurrency	concurrency	a bounded wait for a command's sentinel completed	FAIL	17	s1/a_begin
RESULT	concurrency	concurrency	a bounded wait for a command's sentinel completed	FAIL	17	s1/a_del

Identical to your PG18 numbers. And the green half, which is the other side of the claim:

629b560 green   rc=0   7 records   major=17   checks run: 7
                wait_timeout records on a green run: 0

So the record stream is unchanged when nothing times out, and major is no longer unknown.

The name decision is right, and I checked it is actually fixed

wait_timeout takes the name as $1, so the property lives at the call sites rather than in the helper. Enumerated across all three suites:

concurrency   4   command's sentinel / standalone sentinel / session blocking / idle-in-transaction
unique_conc   4   the same four
update_conc   3   no idle-in-transaction arm
                                                          = 11 call sites

Eleven, matching the issue, every one a fixed literal, with the session and sentinel going to pgc_record's reason field — s1/a_del lands in field 6, not in the name. So the ledger key set is enumerable at eleven and seedable. Interpolating the label would have minted rows nobody could enumerate, and you were right to refuse it.

The major finding

Confirmed at the source rather than from your description:

lib.sh:1201        "${PGC_MAJOR:-unknown}"
lib.sh:1186        "PGC_MAJOR is set in pgc_setup, and 14 suites need no ..."
concurrency.sh     pgc_setup: 0 occurrences
unique_conc.sh     pgc_setup: 0
update_conc.sh     pgc_setup: 0

And main printing majors: unknown above is the live confirmation. A row claiming to hold on unknown matches no run, so these checks could never have been seeded. Fixing it here rather than filing it is the right call — recording a timeout into a row nothing can seed would have been half a fix.

Ledger

None of the three suites is covered (0 rows each), so the eleven new names need no rows and the gate has nothing to refuse. Worth stating in the PR, since a reader who knows the gate will ask.

Two notes, neither blocking

You will need a rebase. #1106 merged a few minutes ago and this is now CONFLICTING on the CHANGELOG.md anchor — #996 collecting its toll again, which is the argument for #1108 and not a fault of this branch.

No pytest twin. The house rule asks for both harnesses, and these three suites have none — there is no test_concurrency.py to extend, and they carry their own harness rather than lib.sh's. I do not think that blocks this: building twins for three concurrency suites is #432's job, not this fix's. Flagging it so the decision is recorded rather than passed over silently.

Good change. The part I value most is that you said plainly it cannot be proved by running the suite, then built the control that can.

@OffgridwithJD
OffgridwithJD force-pushed the test/965-timeout-paths-record branch from 629b560 to b856bae Compare September 18, 2026 01:33
…mmandprompt#965)

ELEVEN TIMEOUT PATHS RECORDED NOTHING. concurrency.sh, unique_conc.sh and
update_conc.sh bound every wait; on a timeout each printed `FAIL  timeout waiting
for ...`, set the suite-local `fail` and returned, touching neither PGC_CHECKS nor
the record stream. The suite still exited 1, so this was never a false green. It
was worse than a missing number:

    main, timeout induced     rc=1, CONCURRENCY TEST FAILED
      human FAIL lines          1
      RESULT records with FAIL  0
      RESULT records total      7
      checks run:               7

Records and total agree, so nothing refuses the log -- on a run that failed. A
missing figure can be noticed; a reconciling one cannot.

Each path now records through pgc_record. Same induced timeout: 2 FAIL records,
9 records, checks run: 9.

THE NAME IS FIXED PER WAIT KIND, the session and sentinel going to the REASON
field, because the ledger is keyed on (suite, part, name) and interpolating
"$name/$label" would mint rows nobody can enumerate or seed.

It cannot be proved by a green run -- none of these lines execute on one, so every
count is identical whether the conversion is right, wrong or absent. Proved by
lowering all four wait bounds from 1200 to 1 in a scratch tree, asserting the
rewritten count first, with unmodified main as the control. Green runs unchanged:
7 records and checks run: 7 before and after, rc=0.

AND EVERY RECORD SAID major=unknown. pgc_record reads ${PGC_MAJOR:-unknown};
PGC_MAJOR is set by pgc_setup, which these three do not call. A row claiming
"unknown" matches no run, so none of these checks could ever be seeded. One line
each, from the PG_CONFIG they already resolve. Now concurrency 7, unique_conc 31,
update_conc 25 records, all major 18, each reconciling with its own checks run:.

The three suites hold no ledger rows, so no rows move.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012RSw4qMHS7ByE7PY8Ns4cs
@OffgridwithJD
OffgridwithJD force-pushed the test/965-timeout-paths-record branch from b856bae to d38c00d Compare September 18, 2026 01:50
@jdatcmd
jdatcmd merged commit f4d7836 into commandprompt:main Sep 18, 2026
14 checks passed
OffgridwithJD pushed a commit to OffgridwithJD/pgcolumnar that referenced this pull request Sep 18, 2026
…dprompt#1014)

merge --mutation refused any run in which more than one check failed. The guard is
right about the hazard and wrong about the remedy: a mutation with TWO GENUINE
targets is ordinary, and for it the only permitted merge was --reds-are-real, which
writes `-` in the mutation column. So the catalogue that column exists to become
could never hold the entry it most exists for -- the one saying WHICH CHECKS SHARE A
CAUSE.

--target CHECK, repeatable, makes the caller assert the attribution, exactly as
--reds-are-real makes them assert that a red is real. Teeth in both directions: a
red not named is refused and named; a target that did not fail is refused, because
the claim is wrong; --target without --mutation is refused; one red and no --target
merges, as every existing caller does.

THE TWO ROWS ARE BACK-FILLED, with the mutation re-run rather than recalled. Two
wrong attempts on the way, and the reason is a PostgreSQL fact worth writing down
because it is not the obvious one.

Mutating only the C initializer is INERT -- 46 checks, 0 failed --  because
DefineCustomBoolVariable assigns the boot value to the variable at registration, so
for a bool GUC the initializer decides nothing at run time.

Mutating only the boot value will not start:

    LOG:  GUC (PGC_BOOL) pgcolumnar.enable_join_runtime_filter, boot_val=0, C-var=1
    TRAP: failed Assert("check_GUC_init(variable)"), guc.c:4944

check_GUC_init does NOT require the two to agree. Read at the source rather than
inferred from the trap, src/backend/utils/misc/guc.c:

    case PGC_BOOL:
        if (*conf->variable && !conf->boot_val)   /* traps: C-var true, boot false */

Asymmetric: a C variable left true against a false boot value traps; a false
initializer against a true boot value is accepted silently. PGC_INT and PGC_REAL
apply the same asymmetry against zero; PGC_ENUM requires equality unconditionally.

So the mutation is two lines, but not because they must match -- because one alone
does nothing and the other alone will not boot. The third attempt changed both,
fingerprinted the .so before and after to prove the build took (53c3f626889c ->
7f67e077f26c), reddened exactly two checks, and restored byte-exact with the .so
back to 53c3f626889c.

Census unchanged: both rows were already ever-red, so checks_never_observed_red
stays 1277 and the ledger stays 1285 rows, all carrying 15;16;17;18;19.

Both harnesses, independently: nine arms in selftest/410 and six in
test_mutation_ledger.py, own fixtures and own names. EVERY REFUSAL ARM GREPS ITS
MESSAGE, not just its status: --target did not exist before, so argparse exited 2
for an unknown flag and three status-only arms passed against the absent feature.
Measured before implementing, which is why they are written the other way.

harness_selftest 986 checks 0 failed; pytest guard half 347 passed, 909 checks,
0 failed.

LEDGER ROWS FOR THE NINE NEW ARMS. selftest/410 is part of harness_selftest, which
IS a covered suite, so the gate correctly refused the run on every major: "has a
check the ledger has never seen". I had checked "does this suite hold rows" for
commandprompt#1109, where the answer was zero, and carried that conclusion to a different suite
instead of asking the question the gate asks -- "does this RUN emit a key the ledger
lacks".

Seeded from five majors on ONE FROZEN SNAPSHOT, copied once and not edited during
the loop, after jdatcmd hit a phantom PG19-only failure that was a mid-loop edit:

    PG15..PG19  rc=0  records=1018  FAILs=0
    namehash     e3eb4ac2ded6 on all five
    verdicthash  75397ca861ae on all five

Both hashes, not just names: a name hash is exactly what stayed identical while the
legs disagreed in that incident, because only the verdict moved.

    ledger 1317 -> 1327 rows, all carrying 15;16;17;18;19, 0 duplicate keys
    census RE-DERIVED by counting, 1309 -> 1319
    guard_tests RE-DERIVED by collection, 356 (355 + 1; 347 + 9 also reaches 356,
      which is the coincidence expected_tests.txt warns about three times)
    gate against a real PG18 log: rc=0, census agrees, ceiling 249 does not rise

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012RSw4qMHS7ByE7PY8Ns4cs
OffgridwithJD pushed a commit to OffgridwithJD/pgcolumnar that referenced this pull request Sep 18, 2026
orphan-scan refuses a ledger row that no record in its own part matches. A row whose
check was ADDED after the log was written produces exactly that signal, and nothing
in a RESULT record dates it against a tree.

Measured when filed: replaying a log from one tree against the ledger one commit
later reported two orphans, and both were checks that tree had just GAINED -- one
step from a defect report against a tool merged an hour earlier.

Nothing needed inventing. test/lib.sh already writes the source fingerprint into
every log, from the one implementation in test/pgc_fingerprint.py. It needed READING.
--expect-source FINGERPRINT refuses a log not carrying the one the caller names, on
orphan-scan and on merge -- and on merge it matters more, because a misread orphan is
recoverable by looking again and a stale log stamped into the ledger persists.

Reproduced end to end, with the control that makes the refusal mean anything:

    without the flag        orphan: demo part1 one added since   rc=1
                            (reported DELETED; it was ADDED)
    --expect-source <new>   refused, naming both fingerprints     rc=2
    a log FROM that tree    read, and the orphan STILL REPORTED   rc=1
    a log naming none       refused: "does not disagree" is how an opt-in check
                            reports success having asked nothing

OPT-IN deliberately. A hand caller may not know the build its log came from, and a
flag that refused every hand invocation is a flag nobody passes. Today's runner is
safe by CONSTRUCTION -- it passes the logs from the run it just finished -- which is
an argument for stating the guarantee, not for assuming the next caller inherits it.
The runner now passes --expect-source from the same stamp it wrote, so the flag is
exercised in production and not only in its own arms: lib.sh and pgc_fingerprint.py
both give c9e65b1b35ba on this tree.

Both harnesses independently: thirteen arms in selftest/410, nine in
test_mutation_ledger.py, own fixtures and own names.

A fixture error on the way, recorded because it looked like a code defect: the first
end-to-end run used a fingerprint that was not hexadecimal, so the tool said "names
no source fingerprint" where a mismatch was expected. The format check was right and
the fixture was wrong.

harness_selftest 985 checks 0 failed; pytest guard half 347 passed, 907 checks,
0 failed. guard_tests re-derived by collection, 346 -> 347.

LEDGER ROWS FOR THE THIRTEEN NEW ARMS. selftest/410 is part of harness_selftest,
which IS a covered suite, so arms with no rows are "a check the ledger has never
seen" and the gate refuses every major. Seeded from five majors on ONE FROZEN
SNAPSHOT, copied once and not edited during the loop:

    PG15..PG19  rc=0  records=1017  FAILs=0
    namehash     68e3fa930101 on all five
    verdicthash  8e059ec65b3d on all five

Both hashes, because a name hash is what stays identical when only a verdict moves.

    ledger 1317 -> 1326 rows, all carrying 15;16;17;18;19, 0 duplicate keys
    census RE-DERIVED by counting, 1309 -> 1318
    guard_tests RE-DERIVED by collection, 356
    gate against a real PG18 log: rc=0

AN EMPTY EXPECTATION EXPECTS NOTHING, and the runner could pass one.
pgc_source_fingerprint returns EMPTY with status 0 on both failure paths -- no
python3, or the module erroring -- so a box with broken freshness machinery would
have the runner pass --expect-source "" and the opt-in rule would skip the check.
That is "does not disagree" satisfying a guard, moved from the log to the
expectation. Reported by jdatcmd.

    pgc_source_fingerprint /nonexistent/tree   -> value=[] rc=0
    PATH=/nonexistent pgc_source_fingerprint   -> value=[] rc=0

The runner refuses rather than scanning: an empty fingerprint sets the broken flag
and the loop does not run, so it cannot report clean. Three arms, two of which
redden when the guard is removed.

Re-seeded after those three arms: five majors on one frozen snapshot, records 1036,
namehash e7dc4d1a1861 and verdicthash 193222e22fa1 identical across all five legs.
Ledger 1345 rows all at 15;16;17;18;19, 0 duplicate keys, census re-derived 1337,
gate rc=0.

THE RUNNER STAMPS, NOT THE SUITES. The first version leaned on pgc_setup to write
`-- source:`, and 28 files in test/ never call it -- they carry their own harness,
deliberately, which is the population commandprompt#1109 exists for. Fourteen REGISTERED suites
among them produced logs that could not satisfy the flag, and CI refused every
major. "Safe by construction" was true of PROVENANCE and not of STAMPING. Reported
by jdatcmd off CI.

One helper, three sites, nothing asked of any suite. The stamp is written FIRST and
the suite APPENDS: _log_source_fingerprint returns the first match, so a suite that
also stamps gets one answer, and a `>` where a `>>` belongs would erase it.

COUNTED ON CALLS, NOT MENTIONS: `grep -l pgc_setup` says 20, because six of the
fourteen name it only in a comment saying they skip it deliberately.

Verified on a full one-major matrix run alone: 0 suite FAILs, 0 `command not
found`, 0 `names no source fingerprint`, 0 `came from a different tree`, 0 `source
fingerprint could not be computed`, 256 of 258 ran.

AND A DEFINITION-ORDER DEFECT FOUND BY RUNNING IT: the helper was first defined
below its call sites, so bash printed `command not found` once per suite AND THE
LOOP RAN ANYWAY -- every log unstamped while the run looked normal. An arm now
compares the definition's line number to the first call's, since no behavioural arm
can see it.

selftest/390 re-anchored, not changed in substance: it pinned the skip branch on a
literal `>` that had to become `>>`.

Re-seeded: five majors on one frozen snapshot, records 1048, namehash 85d97e787e2a
and verdicthash 4a2a406245b5 identical across all five. Ledger 1357 rows all at
15;16;17;18;19, 0 duplicate keys, census re-derived 1349, gate rc=0.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_012RSw4qMHS7ByE7PY8Ns4cs
jdatcmd pushed a commit that referenced this pull request Sep 18, 2026
Eleven suites recorded every check against the literal string `unknown`.
`pgc_record` writes `${PGC_MAJOR:-unknown}` and PGC_MAJOR is set inside
`pgc_setup`, which none of them calls.

A ledger row claiming `unknown` matches no run: the gate considers a row
only where its majors intersect the majors the run observed, and no run
ever observes it. So these checks were structurally unseedable.

    smoke 9   audit 31   objstore_stash_recovery 17   phase2 42
    phase3 32   phase4 38   phase5 36   phase6 43
    decode_interrupts 29   hilbert_curve 184   wal_envelope 20
    ---- 481 of 481 records named no major ----

Same one-line fix as #1109, which reached concurrency, unique_conc and
update_conc.

THE THREE THAT TAKE NO PG_CONFIG read `$1`. The runner passes the pg_config
to every suite, including those needing no cluster, and `pgc_major_of`
yields empty on a path it cannot run -- so a bad path degrades to today's
`unknown` rather than to a WRONG major. A guessed major would seed a row
claiming a major the check was never observed on.

And a static sweep in selftest 400 over the REGISTERED suites, carrying both
wrong pattern spellings as fixtures:

    .*lib\.sh      matches portlib.sh -- false positives
    .*/lib\.sh"?$  misses `. ".../lib.sh" || {` -- false negative, 184 records
    .*/lib\.sh"    correct

Both failures silent, in opposite directions, from one character.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NhwXKAgSmYDUjteWkfajHK
jdatcmd pushed a commit that referenced this pull request Sep 18, 2026
Eleven suites recorded every check against the literal string `unknown`.
`pgc_record` writes `${PGC_MAJOR:-unknown}` and PGC_MAJOR is set inside
`pgc_setup`, which none of them calls.

A ledger row claiming `unknown` matches no run: the gate considers a row
only where its majors intersect the majors the run observed, and no run
ever observes it. So these checks were structurally unseedable.

    smoke 9   audit 31   objstore_stash_recovery 17   phase2 42
    phase3 32   phase4 38   phase5 36   phase6 43
    decode_interrupts 29   hilbert_curve 184   wal_envelope 20
    ---- 481 of 481 records named no major ----

Same one-line fix as #1109, which reached concurrency, unique_conc and
update_conc.

THE THREE THAT TAKE NO PG_CONFIG read `$1`. The runner passes the pg_config
to every suite, including those needing no cluster, and `pgc_major_of`
yields empty on a path it cannot run -- so a bad path degrades to today's
`unknown` rather than to a WRONG major. A guessed major would seed a row
claiming a major the check was never observed on.

And a static sweep in selftest 400 over the REGISTERED suites, carrying both
wrong pattern spellings as fixtures:

    .*lib\.sh      matches portlib.sh -- false positives
    .*/lib\.sh"?$  misses `. ".../lib.sh" || {` -- false negative, 184 records
    .*/lib\.sh"    correct

Both failures silent, in opposite directions, from one character.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NhwXKAgSmYDUjteWkfajHK
jdatcmd pushed a commit that referenced this pull request Sep 18, 2026
Eleven suites recorded every check against the literal string `unknown`.
`pgc_record` writes `${PGC_MAJOR:-unknown}` and PGC_MAJOR is set inside
`pgc_setup`, which none of them calls.

A ledger row claiming `unknown` matches no run: the gate considers a row
only where its majors intersect the majors the run observed, and no run
ever observes it. So these checks were structurally unseedable.

    smoke 9   audit 31   objstore_stash_recovery 17   phase2 42
    phase3 32   phase4 38   phase5 36   phase6 43
    decode_interrupts 29   hilbert_curve 184   wal_envelope 20
    ---- 481 of 481 records named no major ----

Same one-line fix as #1109, which reached concurrency, unique_conc and
update_conc.

THE THREE THAT TAKE NO PG_CONFIG read `$1`. The runner passes the pg_config
to every suite, including those needing no cluster, and `pgc_major_of`
yields empty on a path it cannot run -- so a bad path degrades to today's
`unknown` rather than to a WRONG major. A guessed major would seed a row
claiming a major the check was never observed on.

And a static sweep in selftest 400 over the REGISTERED suites, carrying both
wrong pattern spellings as fixtures:

    .*lib\.sh      matches portlib.sh -- false positives
    .*/lib\.sh"?$  misses `. ".../lib.sh" || {` -- false negative, 184 records
    .*/lib\.sh"    correct

Both failures silent, in opposite directions, from one character.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NhwXKAgSmYDUjteWkfajHK
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.

2 participants