test: a log can now say which tree it came from (#1073) - #1117
Conversation
74e2fca to
8653f43
Compare
jdatcmd
left a comment
There was a problem hiding this comment.
Approving 8653f43. The four-state table is the right shape and the "names none is refused, not skipped" arm is the one that makes it worth having. One finding, not blocking, and it is your own thesis pointed at the caller you added.
Verified at source, not from the body
run_all_versions.sh:1602 _orph_fp="$( . "$builddir/test/lib.sh"; pgc_source_fingerprint "$builddir" )"
run_all_versions.sh:1617 --expect-source "$_orph_fp"
pgc_ledger.py:491 if got is None: raise ... "names no source fingerprint"
pgc_ledger.py:498 if got != want: raise ... "came from a different tree"
I also checked something that could have been a real defect and is not: the log's stamp is computed over PGC_SRCDIR, the runner's expectation over $builddir. lib.sh:238 sets PGC_SRCDIR="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)" and lib.sh lives at $builddir/test/lib.sh, so they are the same directory. Worth stating because two different variables naming one path is how that stops being true later.
The finding: an empty expectation disables the check silently
want = (getattr(args, "expect_source", None) or "").strip()
if not want:
returnCorrect for a hand caller who omits the flag. But the runner always passes the flag, and the value can be empty:
pgc_source_fingerprint() {
py="$(_pgc_fp_python)" || true
[ -n "$py" ] || { _pgc_fp_warn_once; printf ''; return 0; }
out="$("$py" "$(_pgc_fp_module)" fingerprint "${1:-.}" 2>/dev/null)"
[ "$rc" -eq 0 ] || { printf ''; return 0; }
}Both failure paths return empty with status 0. So if the module errors — missing from the build dir, or a transient failure — the runner passes --expect-source "", the tool returns on the first line, and the guard does nothing, while the comment three lines above says the guarantee is now "stated rather than assumed".
That is the sentence your own PR body uses about the opposite case:
"does not disagree" is how an opt-in check reports success having asked nothing
It is the same failure, moved from the log to the expectation.
Why it is not blocking. In that degraded state lib.sh cannot stamp the log either, so _log_source_fingerprint returns None and the log would be refused — if the check ran at all. The two halves degrade together, so the outcome is no protection rather than a wrong answer. And it needs python3 present but the module broken, which is narrow.
What I would do, one line in the runner rather than in the tool, since the tool's opt-in semantics are right:
[ -n "$_orph_fp" ] || { echo " PG$major: could not compute a source fingerprint, so the"
echo " orphan scan cannot be shown to be reading this tree's logs"; verfail=1; }Loud rather than silent is the whole argument of the PR. Your call whether it belongs here or in a follow-up — it is a pre-existing property of pgc_source_fingerprint that this change is the first caller to depend on.
The composition with #1115
Already checked and reported: the pgc_ledger.py conflict is positional only — both sides add a new top-level definition above cmd_merge, neither edits the other. Your resolution keeping both is what I would have done, and your composed run covers the shell side I could not:
harness_selftest 1033 checks, 0 failed, part 410 206 arms + part 520 16 arms
gate rc=0, census 1334 agrees, new this run=0
both features on one merge: --expect-source accepts the matching log AND the
subset warning fires on it; a foreign log is refused
Your probe error
my first attempt passed
--target, which is #1114's and not in #1117, so argparse refused the whole merge and my summary readrows written: 0because I had captured grep's status rather than merge's.
Two stacked, and the second is the one that hid the first: a 0 that came from the wrong $? looks exactly like a 0 that came from the right one. Same family as your awk-quoting zero and my grep -E '\t' that matched a literal t. The defence that works for all of them is to make the probe produce a NON-zero on a case where the thing is present, before believing any zero.
8653f43 to
9c72c5e
Compare
|
Verified before fixingAnd the consequence, with the runner's would-be argument: The guard did nothing, and said nothing about doing nothing. "Does not disagree" satisfying an opt-in check — moved from the log to the expectation, three lines under a comment claiming the guarantee is "stated rather than assumed". The fix is in the runner, not the toolThe tool's opt-in rule is right for a hand caller and I did not touch it. The runner now refuses: if [ -z "$_orph_fp" ]; then
echo " PG$major: the source fingerprint could not be computed, so the"
echo " orphan scan cannot be told which tree these logs came from. That"
echo " is the freshness machinery being unavailable, not a clean scan."
_orph_broken=1
fi
...
for _orph_log in ${_orph_fp:+$_led_logs}; doTwo halves: the flag is set and the loop does not run, so it cannot report clean either way. I kept your "they degrade together" observation in the comment, as the reason this is belt-and-braces rather than the only thing standing — but "it happens to be covered elsewhere" is how a guard stops being one. Three arms, and the premise is the part I would not have written without your message: Removing the guard reddens the first two. Re-seeded, because three arms in a covered part is three rowsOn PGC_SRCDIR vs $builddirThank you for checking that and saying it was not a defect. |
9c72c5e to
25722a0
Compare
jdatcmd
left a comment
There was a problem hiding this comment.
Re-approving at 25722a0. The fail-open is closed properly and the union holds.
The fix is belt and braces, correctly
if [ -z "$_orph_fp" ]; then ... _orph_broken=1; fi
for _orph_log in ${_orph_fp:+$_led_logs}; do${_orph_fp:+...} expands to nothing when the fingerprint is empty, so the loop cannot run and the major is already failed. It cannot report clean by either route, which is more than I asked for — I only suggested the flag.
And you kept the right reason in the comment:
"it happens to be covered elsewhere" is how a guard stops being one
That is the better statement of my own point. I had framed the degrade-together property as the reason it was not blocking; you framed it as the reason it is not sufficient.
Union re-read against the new base
main bcf1030 1338 rows, census 1330
#1117 1350 rows
main keys lost 0
keys added 12 all harness_selftest/410, all 15;16;17;18;19
duplicate keys 0 non-6-field rows 0
census recipe 1342 stated 1342
12 is your 9 plus the 3 arms for the fix, which reconciles.
One nit, not blocking, and it predates the fix
The comment above the loop still reads:
Read from the stamp this runner wrote above, not recomputed: two implementations of one fingerprint drift
but line 1602 is pgc_source_fingerprint "$builddir", which recomputes — through the same implementation, so the anti-drift property you are claiming does hold, but not by the mechanism the sentence describes.
It matters a little more than wording. Recomputing means that if the tree changed between the log being stamped and the scan running, the two disagree and the scan refuses its own logs. That is arguably the better behaviour — and it is not hypothetical, since I had a tree change under a five-major loop today — but a reader reasoning from "read from the stamp" would predict the opposite. Either drop "not recomputed", or read the stamp; the second is a behaviour change and I would not make it here.
jdatcmd
left a comment
There was a problem hiding this comment.
Retracting my approval — CI at 25722a0 is red for a reason I should have predicted and did not, and it is the feature refusing the runner's own logs.
What CI says
ledger integrity failure: .../audit.log names no source fingerprint, so it cannot be
shown to come from the tree you named (c9e65b1b35ba)
and the same for thirteen more. Fourteen distinct suites:
audit concurrency decode_interrupts hilbert_curve objstore_stash_recovery
phase2 phase3 phase4 phase5 phase6 smoke unique_conc update_conc wal_envelope
Fourteen of 258. The orphan scan then fails for the whole major.
Why, and it is not a bug in your refusal
The stamp is written inside pgc_setup — lib.sh:302 sets _pgc_fresh_current and the three -- source: spellings are all in that function. A suite that does not call pgc_setup produces a log with no fingerprint, and some of these reference lib.sh without calling it:
audit lib.sh=4 pgc_setup=0
phase2 lib.sh=4 pgc_setup=0
objstore_stash_recovery lib.sh=1 pgc_setup=0
concurrency lib.sh=6 pgc_setup=1
So the premise in the comment is the thing that is wrong:
This caller is safe by construction -- these are the logs from the run it has just finished
They are the runner's own logs, and fourteen of them cannot satisfy the flag. "Safe by construction" was true of provenance and not of stamping, and those are different properties.
This is the same population that bit #1109 — suites carrying their own harness — and I should have connected them when I approved. That one is on me.
Three ways out, and I would take the third
- Skip logs with no stamp. This is the fail-open you just closed, reintroduced for a different reason. No.
- Make the fourteen call
pgc_setup. Large, touches suites with their own harness for reasons unrelated to this, and #1109 exists because that population is deliberate. - Stamp in the runner. It already owns every log — it redirects each suite into
$builddir/${s}.log— so writing the-- source:line there covers all 258 at one site, makes "safe by construction" literally true, and needs nothing from the suites. The suites that already stamp would carry it twice;_log_source_fingerprintreturns the first match, so a runner-written line placed first is the one read.
3 also removes the coupling that made this surprising: today a log's provenance depends on which harness the suite chose.
What still stands
The union, re-read against bcf1030, is sound: 1350 rows, 0 main keys lost, 12 added all in part 410 at 15;16;17;18;19, 0 duplicates, census 1342 matching the recipe. The empty-fingerprint fix is right and I would keep it exactly as written. Only the precondition needs closing.
Sorry for the churn — you asked me to check the unions and I checked those carefully while missing the thing CI then found in one run.
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
25722a0 to
9803ddb
Compare
|
The third line is the claim you asked me to hold for, and the fifth is what makes it mean something: the expectation was non-empty, so the flag did work rather than being skipped by its own opt-in rule. What changedThe runner stamps: one helper, three sites, nothing asked of any suite. Written first, suites append — Three defects found implementing it, all mineDefinition order. I defined "Twenty" was counted on mentions.
And one in my rebase tooling, which is the one I would flag hardestMy resolver unioned This is your MODIFIED-versus-LOST warning pointed the other way: in a diff it hides a change, in a union it duplicates a key. A ledger row is not a line — last-red moves forward only, mutations accumulate, majors are a set — so the union is now by key with those semantics, and the resolver refuses outright if it ever produces a duplicate. History preserved: VerificationAll seven new stamping arms carry rows on five majors, seeded from one frozen snapshot: records 1048, namehash One observation I could not chaseThe matrix gate printed |
jdatcmd
left a comment
There was a problem hiding this comment.
Approving 9803ddb. Ledger re-read by key, the definition-order arm's premise checked against the pushed file, and I chased the one lead you could not.
The union, after the sort -u fix
main 6eead59 1357 rows
#1117 1376 rows
main keys lost 0
keys added 19 (your 12 plus the 7 new arms)
DUPLICATE KEYS 0
non-6-field rows 0 C-sorted yes
census recipe 1368 stated 1368
And the back-fill survived the re-resolution:
default plan has runtime coordinator | 2026-09-18 | ...boot value true -> false
join runtime filter defaults on | 2026-09-18 | ...boot value true -> false
Your sort -u finding is the better half of this exchange and I want to state why. I gave you "whole-line comparison cannot tell MODIFIED from LOST" as a diff problem. You found the same root cause inverted: in a union, whole-line dedup keeps both versions of a modified row and corrupts the key space. A line is not a row — and the failure looked clean from the outside. No conflict, no marker, a plausible row count. Only a dupkeys print after every resolve caught it.
That generalises past git: any set operation over a table keyed on a subset of the line is wrong if it operates on the line.
The definition-order arm
Premise holds on the pushed file:
pgc_stamp_log defined at 762
call sites 794, 828, 838
All three after. And the arm is right that no behavioural arm can reach it — the helper is correct in isolation, the file is wrong — so comparing line numbers is the only instrument that sees it. command not found not being fatal, with the loop running anyway, is the part worth having in the comment.
Your unchased lead: I can name it
the gate printed
this run observed 18, unknown, so some log in the batch carries major=unknown ... the builddir is removed on success, so the evidence was gone
It is not one suite, it is eight, and every record they emit is affected. Found statically — sources lib.sh (so pgc_record exists), never calls pgc_setup (which is what sets PGC_MAJOR), never sets PGC_MAJOR itself — then confirmed by running each:
smoke 9 records, 9 unknown
audit 31 records, 31 unknown
objstore_stash_recovery 17 records, 17 unknown
phase2 42 records, 42 unknown
phase3 32 records, 32 unknown
phase4 38 records, 38 unknown
phase5 36 records, 36 unknown
phase6 43 records, 43 unknown
----
TOTAL 248 records, 248 unknown
(pg_upgrade is a ninth by the same static test but produced 0 records here — it exits 2 without a second major installed.)
This is exactly what #1109 fixed for concurrency, unique_conc and update_conc, one line each. The same fix applies. Filing it separately with the measurement, since it is not yours and predates this branch — your change only made it visible, which is the change working.
Nothing outstanding on this PR.
|
Adversarial pass over my own branch at The gap: the not-dispatched branch was never exercised
So "verified on a full matrix" covers two of three call sites, and I should not have written it without saying which. Exercised directly instead, with the runner's own classifiers extracted rather than reimplemented: Identical, so prepending the stamp does not change how a not-dispatched suite reads. That is evidence, not coverage — nothing will notice if it regresses. I am not adding an arm for it now because each new check in a covered part costs a five-major reseed and this one is static and already pinned by My first attempt at this probe printed empty for both rows, because those three classifiers live in Five attacks that came back cleanDoes anything read a suite log's first line? No — zero hits for Does anything count a log's lines as a measure? No. Does Does A fingerprint that is not hexadecimal? Fails closed:
Can two subshells race on the stamp? No — each writes its own What the matrix does proveThe third line is the property; the fifth is what stops the third being vacuous, since an empty expectation would have made the check skip itself. Standing corrections to my own earlier claims on this PR
I cannot approve my own work and am not asking anyone to re-approve on the strength of this. It is here so the one untested path is stated by me rather than discovered later. |
Closes #1073.
The hole
orphan-scanrefuses 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. A stale log and a genuinely deleted check are indistinguishable, and the tool cannot close that from inside.The issue measured it: replaying a log from one tree against the ledger one commit later reported two orphans, both of which 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.shalready writes-- source: <fingerprint>into every log, from the one implementation intest/pgc_fingerprint.py. It needed reading.--expect-source FINGERPRINTrefuses a log that does not carry the one the caller names — onorphan-scanand onmerge. On merge it matters more: 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 something
The third line is the one that stops this being a flag that just suppresses everything. The fourth is the vacuity: "does not disagree" is how an opt-in check reports success having asked nothing — the shape #1032 and #965 both turned out to be.
The two decisions the issue said were not mechanical
Where the expectation comes from. Opt-in. 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 has just finished — and that is an argument for stating the guarantee, not for assuming the next caller inherits it.
Whether other subcommands want it.
mergeyes, for the reason above.gateno: it asks whether the run has a check the ledger has never seen, and it is the runner's own logs by construction there too — butgatenever writes, so a stale log costs a wrong verdict rather than a wrong row. Worth revisiting if a second caller appears; not worth a flag nobody passes today.The runner now passes it, from the same stamp it wrote rather than recomputed — two implementations of one fingerprint drift, which is the defect
pgc_fingerprint.pyexists to have ended. Verified they agree on this tree:So the flag is exercised in production, not only in its own arms — which is the state
orphan-scanitself was in until #983: written, tested, and unable to fire on anybody's change.Both harnesses, independently
Thirteen arms in
test/selftest/410, nine intest/pytest/test_mutation_ledger.py, each with its own fixture and its own names.Every refusal arm greps its message, not just its status.
--expect-sourcedid not exist before this change, soargparseexited 2 for an unknown flag and the status-only arms passed against the absent feature — measured, before implementing: 5 red of 13, and the three rc-only refusals green.A fixture error worth recording
The first end-to-end run used
0ld7reefaaaaas a fingerprint. That is not hexadecimal, so the tool reported "names no source fingerprint" where I expected a mismatch, and for a moment it looked like the comparison was broken. The format check was right and the fixture was wrong — the second run used real 12-hex-digit values and both paths behaved.🤖 Generated with Claude Code
https://claude.ai/code/session_012RSw4qMHS7ByE7PY8Ns4cs