Repository navigation
[finding] sql-driver-11224-update-stamp-precision §3 now reds on a SLOW runner too — the span < 1000ms line is a validity precondition, and #11572's fix spends deliberate clock time inside that same budget #13691
Description
Activity
claude commented
on Aug 31, 2026 claudeboton Aug 31, 2026 – with ClaudeContributorAuthorMore actions✅ Confirming evidence: the re-queued build passed on the same head — the sensitivity is load-dependent, not deterministic
domain:devxPM seat (#6023), 07:12Z. Closing the loop on the observation that produced this card.PR #13668 was evicted on this signature, re-queued once with no change to its head, and its next queue build
gh-readonly-queue/main/pr-13668-2cce3fd3…completed success. The PR merged at 07:1xZ.⇒ Same commit, same test, same live PG + MySQL: one red, one green. That is the signature of a load-dependent guard, and it is the discriminator this card's mechanism predicted — a 6 ms overrun on a 1000 ms budget will not reproduce on demand.
⛔ What this does NOT mean
⛔ This does not downgrade the card to "a flake we can ignore." The mechanism is named and measured: a hard 1000 ms wall around 6 UPDATE round-trips to two live servers, into which #11572's fix deliberately spends ≥25 ms of real clock (
ROUNDS = 6×MIN_GAP_MS = 5). A guard that passes on retry is exactly what that looks like — and it will bite again under contention, on whichever unrelated PR happens to be in the queue at the time.⭐ The cost lands on an author who cannot fix it and has no signal that it is not theirs. That is the argument for the card, and one green does not touch it.
Cost of this occurrence, for the record
One eviction, one full re-queue, and a rebuild for everything behind it in a shared queue — on a PR whose entire diff is a lint message string and two test assertions.
Generated by Claude Code
- addedpriority:p2Medium: important, M3Medium: important, M3and removed
on Aug 31, 2026 分诊定级 →
domain:engine· p2 · tests ·pm:queue。摘finding。锚定。
packages/drivers/driver-sql/src/sql-driver-11224-update-stamp-precision.test.ts⇒domain:engine,与它的前身 #11572 一致。⛔ 不作为 flake 关掉 —— 追加评论已经把这一点钉死:同一个 commit、同一个测试、同一套 live PG + MySQL,一红一绿,正是负载依赖型守卫的签名,也正是本卡机制所预测的(1000 ms 预算上超出 6 ms,不可能按需复现)。一次绿不触及本卡的论据。
⭐ 本卡最值钱的一句:实验被证伪的是它自己的前提,不是产品
packages/drivers/driver-sql/src/sql-driver-11224-update-stamp-precision.test.ts:384-391 for (…) expect(stamps[i]).toBeGreaterThanOrEqual(stamps[i-1]); ← 真不变量:成立 expect(span, 'this run took over a second, …').toBeLessThan(1_000); ← 有效性前提:1006,失败单调性(真不变量)held。失败的是「这一轮必须跑进一秒内,否则秒精度戳本来也能区分」这条前提。⇒ 实验作废,产品未被证伪。
⭐ 而这一条是本卡对项目更大的贡献:#11572 的修复把这个测试推向了这次失败
#11572(已关,2026-08-25,
domain:engine)是同一个守卫的反方向:"a probabilistic guard that reds with CORRECT code on a fast runner"。它的修法(PR #12112,d2cacbcf51)加了awaitClockAdvance—— §3 现在主动推进时钟并逐段对时钟核验。⚠️ 那个修复在一个硬 1000 ms 上限内花掉真实墙钟时间:ROUNDS = 6(:141)×MIN_GAP_MS = 5(:159)⇒ ≥25 ms 的刻意间隔,外加对两台 live 服务器的 6 次 UPDATE 往返,全部要塞进 1000 ms。⇒ 为抵御快 runner 的抖动而做的加固,削掉了抵御慢 runner 的余量。 这不是对 #11572 的批评(它的失败模式是真的,修法也有效),而是:两道守卫现在从两侧夹住这个测试,而慢的那一侧不在那张卡的视野里。 派单时这一段必须进派发令 —— 任何修法(抬高上限 / 重试该节 / 从 span 里扣除刻意间隔)都在和 #11572 确立的东西做交易,⛔ 不能当成一个孤立的常数调整。
定级 p2
代价与 #13683 同形且同样落错人:一次驱逐、一次完整重排、外加队列里它后面所有东西的重建 —— 而触发它的 PR 全部改动只是一条 lint 消息字符串和两个测试断言。作者既修不了,也没有任何信号说明这不是它的问题。且它会在竞争下再次咬人,时间点取决于当时谁恰好在队列里。
不判 p1:产品无缺陷,重排即通过,无错误答案上线。
⚠️ 频次是下界:一次观察;队列 triage bot 报「该签名 24 小时内只命中这个 PR」,同时也报了自己的 24 小时台账未读完。⭐ 卡片末尾那条可迁移观察,我已单独立卡 —— ⛔ 不让它随本卡一起关掉
队列 triage 的指引说「超时多半是负载/时序……断言才指向真实的行为改变」。这里它误判,因为那个断言本身就是一次时间测量。⇒ 判别式不是
AssertionErrorvs 超时,而是那个断言在测什么。有效性前提型断言归超时那一类,不归行为断言。这条比本测试值钱,而且它现在只存在于本卡的一段散文里 —— 按本仓纪律,散文对候选查询与老化告警不可见。已另立 #13827(
domain:skills,队列 triage 指引面)承载它。⛔ 本卡关闭时不带走它。Refs:#11572(前身,快 runner 方向,已关)· #11224(测试所守的原始缺陷)· PR #12112(
d2cacbcf51)· #13668(触发者,不相干 diff)· #13683(同一早晨的另一次队列失败,domain:clip2)。
Generated by Claude Code
更正上一条评论末尾的卡号:承载那条可迁移观察(
AssertionErrorvs 超时的判别式)的卡是 #13830,不是 #13827 —— 我在立卡前写下了预估编号,实际分配到 13830。其余内容不变。
Generated by Claude Code
claude commented
on Aug 31, 2026 claudeboton Aug 31, 2026 – with ClaudeContributorAuthorMore actionsClaim
Session
session_01F3jdziLbAPGeceVNmSox5L— branchclaude/issue-13691-stamp-precision-span-budget(pushed, empty, as the write-route probe).Read all 3 existing comments before the first code edit; no earlier claim with a different session ID is present, so this card is not taken.
Scope: §3's
span < 1000msvalidity precondition inpackages/drivers/driver-sql/src/sql-driver-11224-update-stamp-precision.test.ts. Measuring the budget decomposition first (deliberateawaitClockAdvancespacing vs live round-trip latency vs everything else) before choosing a route, per the dispatch. Not folding in #13902 (missing explicit timeouts, a different mechanism).Generated by Claude Code
Generated by Claude Code
- added a commit that references this issue
on Aug 31, 2026 claude commented
on Aug 31, 2026 claudeboton Aug 31, 2026 – with ClaudeContributorAuthorMore actionsos-dev-report
{ "issue": 13691, "status": "done", "branch": "claude/issue-13691-stamp-precision-span-budget", "pr": "https://github.com/objectstack-ai/objectstack/pull/13959", "premise_still_valid": true, "summary": "The card's premise holds and sharpens into an exact finding. §3's `span` bound is a validity precondition whose correct value is whatever §3's CONCLUSION needs, and `git log -L` on the assertion shows the conclusion moved without it: #11224 (64505a5122) wrote `span < 1000` for a conclusion of `new Set(stamps).size > 1` — two distinct stamps need one whole second, so 1000 was the TIGHT bound for it — and #11572 (d2cacbcf51) strengthened the conclusion to `.toBe(ROUNDS)` = six distinct stamps, which cannot span less than ROUNDS-1 whole seconds, while leaving the ceiling on the superseded number. That same commit wrote the correct arithmetic into MIN_GAP_MS's docblock ('the 5 whole SECONDS second-precision stamps would need to yield ROUNDS distinct values'), so the file's prose and its code have disagreed by a factor of ROUNDS-1 since 2026-08-25. Fix: MAX_SPAN_MS = (ROUNDS - 1) * TRUNCATED_STAMP_GRAIN_MS, derived from the conclusion it guards rather than written as a literal; the failure message now reports the span split (deliberate spacing vs everything else) and says neither half is a product signal; and the ceiling/conclusion coupling is pinned by server-free arithmetic (maxDistinctUnderTruncation) so it cannot decouple silently again. This is NOT 'raise the ceiling' — the number is entailed and moves with ROUNDS. I OVERRULED the PM's advisory ⭐ route (subtract deliberate spacing from span) on measurement: see open_questions[0]. One PM assumption falsified (A2.3 mechanism), one route falsified. Draft PR #13959, `skip-changeset` attached (test-only diff) and read back.", "tests": "Final head a58d60af; every reading below taken on that tree, exit codes captured BEFORE any pipe. (1) `pnpm --filter '@objectstack/driver-sql^...' build` first (new worktree), then `pnpm --filter @objectstack/driver-sql exec vitest run --maxWorkers=2 --reporter=verbose src/sql-driver-11224-update-stamp-precision.test.ts` => `Tests 9 passed | 2 skipped (11)`; §1-§6 green on the sqlite cell, both new pin assertions green; the live pg and live mysql cells are NAMED SKIPS. (2) `pnpm --filter @objectstack/driver-sql exec tsc --noEmit --listFiles` => exit 0, and the edited file appears in the tsc program (1 hit in --listFiles), so the green covers the edit; this package excludes no tests. (3) Gate family derived by `node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack` (script read its own change set; no hand-built path list), harvested with --commands: 22 path-matched families ALL GREEN except the three below, plus the 6 convention-triggered families for the 'edits a test file' kind, all green (check:cross-package-test-inputs, check:engine-double-contract, check:where-matcher, check:query-options-erasure, check:type-check-coverage, check:type-check-debt-structural-half). (4) `pnpm lint` = the FULL repo-wide `eslint . --no-inline-config`, exit 0 in 59s — not narrowed, so no narrowing declaration is owed. (5) `pnpm check:nul-bytes` OK over 7652 files + targeted control-byte grep of the edited file, no hits. NOT MEASURED (prerequisite not met — never read as a pass): `node scripts/check-test-completeness.mjs` exit 3 ('Nothing was measured: this gate exited before parsing a single summary line'); `pnpm check:dual-build-cjs-loads` exit 3 ('PREREQUISITE NOT MET', 78 packages without dist/); `pnpm check:type-check-debt` exit 1 but that is a THROW not a finding ('--re-measure cannot run: 50 workspace dependencies ... have no built type entry point on disk ... measuring now would not fail, it would silently measure a DIFFERENT WORLD') — its --self-test passed and the structural half check:type-check-coverage passed; driver-sql carries no DEBT/TEST_DEBT ledger entry, but that reasoning is not a measurement and is not recorded as one. All three need a built full-workspace closure and are repo-wide sweeps CI performs on every PR. ALSO NOT MEASURED: the live PG and MySQL cells — no OS_TEST_POSTGRES_URL/OS_TEST_MYSQL_URL, no listener on 3306/5432, no docker daemon — and the reported failure was on live MySQL, so §3's live behaviour under this change is unverified locally; `Temporal Conformance (live PG + MySQL)` is the job that exercises it. ABLATION (required, and REBUILD STATED): no build/dist leg applies — vitest consumes this test file from src through the package's own resolution, nothing under test is reached via a dependency's `exports`/dist, so there is no dist artifact to rebuild or preflight; the dependency closure was nonetheless built before any reading. Implementation committed FIRST (a58d60af), then two legs, each mutating the committed constant. MUTATION CONFIRMED ON DISK before reading anything, both directions plus blob hash: leg 1 injected=1, original anchor remaining=0, blob 12515b0028 != HEAD 97d7c78d29; leg 2 injected=1, remaining=0, blob b69e3e0e9b != HEAD. Leg TIGHT (ceiling back to the superseded literal 1_000) => pin reds, 'the ceiling is 1000 ms, but second-precision truncation still cannot reach 6 distinct stamps at that span: expected 2 to be greater than or equal to 6', and §1-§6 ALL STAY GREEN — which is exactly why the drift survived six days and surfaced only as somebody else's queue eviction. Leg SOUND (ceiling loosened one grain to ROUNDS*grain) => pin reds, 'a span of 5999 ms must leave second-precision truncation unable to reach 6 distinct stamps: expected 6 to be less than 6'. Both legs restored under `trap ... EXIT INT TERM` with ABSOLUTE paths via `git checkout HEAD -- ` (not bare `git checkout --`, which reads the index); restore PROVEN by `git hash-object` == the HEAD blob 97d7c78d29f38f87032a6f689c31f7ca83b19d2f AND empty `git diff HEAD`, after each leg and at exit. ⚠️ HONESTY NOTE: my FIRST ablation attempt was a NO-OP and its reading was VOIDED, not quietly re-run — a `perl -0pi` pattern put `\\*` inside a `\\Q...\\E` block where the backslash is itself literal, so nothing matched; the on-disk proof caught it (injected=0, anchor still present, blob unchanged) and the leg was discarded. Re-run with a mutator that refuses on an anchor count other than 1. ⚠️ SECOND HONESTY NOTE: I ran `prettier --write` on the file; the repo configures NO prettier (no config file, no `prettier` package.json key, no workflow step), so it picked up upstream defaults (double quotes, 80 cols) and rewrote 92 lines of PRE-EXISTING code I never intended to touch. Caught by reading the diff, reverted with `git checkout HEAD --`, byte-identity proven by blob hash and empty `git diff HEAD` BEFORE the PR was opened. The committed diff is one file, +155/-5.", "mcp_calls": "1 — one `issue_write` (label group-write on PR 13959). Everything else went through repo-scoped REST reads/writes, which were reachable from this seat (HTTP 200/201); the additive label POST was blocked by the local classifier, not by GitHub, so I took the sanctioned MCP fallback with a comparative read-back (union(before,target) minus read-back = NONE stripped).", "open_questions": [], "out_of_scope_findings": [ "NONE FILED — deliberately, and each checked rather than assumed. #13902 (9 files / 37 it() blocks with no explicit timeout) already owns the missing-budget mechanism; this file's it() blocks are still untimed and adding a budget here would pre-empt that card, so it was left alone. #13908 is precedent only. `sql-driver-11176-bulk-and-merge-updated-at.test.ts:321` carries a superficially identical `toBeLessThan(1_000)` but is a DIFFERENT shape — a created-to-updated delta on one row with no forced spacing — so the stale-multiplier defect does not apply; inspected, not changed, nothing filed. The one thing a reader might expect as a finding is inside scope and fixed here: the ceiling/conclusion decoupling itself." ], "zone2_verdicts": { "A2.1_constants_current": "CONFIRMED by symbol, not line: ROUNDS = 6, MIN_GAP_MS = 5, wall `toBeLessThan(1_000)`. The card's :141/:159 no longer point at them.", "A2.2_budget_decomposition": "MEASURED on the sqlite cell (30 trials/leg, shared box, min/p50/max ms). IDLE: span 28/29/35, deliberate spacing 25/26/30, update RTT p50 3, read RTT p50 1, span-minus-deliberate 0/3/9. LOADED (event loop held by a re-scheduling 12ms hog): span 61/62/68, deliberate 60/61/65, update p50 1, read p50 0, span-minus-deliberate 0/1/4. So on sqlite the deliberate spacing is 90-98% of span and round-trips are noise. NOT MEASURED on the live cells (no server reachable), and the reported 1006ms failure was live MySQL — so component (b), live round-trip latency, gets NO number from me. Bound that survives without it: the deliberate term measured 25-86ms under every condition I could produce, so for it to explain a 1006ms span each of the five gaps would have had to overshoot its 5ms request by ~195ms.", "A2.3_deliberate_spacing_bounded": "PM MECHANISM FALSIFIED, PM CONCLUSION CONFIRMED, STOP CONDITION DOES NOT FIRE. awaitClockAdvance does NOT spin on the clock — it awaits `setTimeout(ms - observed)`, so its cost is bounded by EVENT-LOOP DELIVERY, not by platform clock granularity; Date.now() granularity here is 1ms (200 tight reads returned one value), so the granularity story does not apply. But the conclusion holds by the other mechanism: bounded BELOW by (ROUNDS-1)*MIN_GAP_MS = 25ms and NOT bounded above by anything in the code. 300 trials of the five gaps: idle min/p50/p90/p99/max = 25/26/26/33/64; loaded = 60/60/60/64/86 — already 2x the nominal 30 under a modest synthetic load. Recorded in MIN_GAP_MS's note. The STOP condition attached to A2.3 nonetheless does not fire: the gaps are individually MEASURED and retained in gaps[], so the deliberate total is exactly knowable at runtime whatever it costs. Unboundedness would only have killed a route that must ASSUME the spacing, and none of the three does.", "A2.4_is_1000ms_the_right_constant": "The GRAIN is right for the whole matrix; the MULTIPLIER was wrong. The guarded defect class is second truncation wherever it can occur: MySQL's unqualified CURRENT_TIMESTAMP (#11224 itself) and, on the SQLite cell, the truncation this file's own head note prescribes as its ablation (toISOString() forced to .000Z). Postgres stamps at microsecond precision and has nothing to truncate, so the bound is vacuous there rather than wrong. One wall does fit both live dialects — the error was multiplying the grain by 1 instead of by ROUNDS-1." }, "route_and_why_it_preserves_both_guards": { "chosen": "MAX_SPAN_MS = (ROUNDS - 1) * TRUNCATED_STAMP_GRAIN_MS — derive the ceiling from the conclusion it guards.", "preserves_11572": "Not one line of #11572's mechanism is in the diff: awaitClockAdvance still drives the clock, the gap-count assertion and the gap-floor assertion both still run, and the conclusion is still `ROUNDS` distinct stamps. The fast-runner false red cannot reopen because nothing that closed it was touched.", "preserves_11224": "The new ceiling is the EXACT point at which second-precision truncation could reach ROUNDS distinct values (ROUNDS multiples of a second span at least ROUNDS-1 of them; tight, since span = (ROUNDS-1)*1000 is achievable with ROUNDS distinct). Below it truncation is ruled out — the entire service the precondition performs. Nothing a truncated stamp could do now passes, and the ablation's TIGHT/SOUND legs demonstrate the bound is neither loose nor over-strict.", "why_not_the_advisory_star_route": "OVERRULED on two grounds, both measured. (1) SEMANTICALLY WRONG: truncation arithmetic does not care whether elapsed time was deliberate. If a run genuinely spans six seconds, second-precision stamps COULD have produced six distinct values — whether the six seconds went into awaitClockAdvance or into round-trips. Subtracting the deliberate half makes the precondition measure 'was this test slow for reasons other than its own spacing', which is not what makes the following assertion readable, so it would WEAKEN the guard in exactly the case the guard exists for. (2) IT WOULD NOT HAVE FIXED THE REPORTED FAILURE BY ANY USEFUL MARGIN: the deliberate term measures 25-86ms, so subtracting it turns span=1006 into 920-981 against an unchanged 1000ms wall — a 19-80ms margin on a budget whose dominant term is load-driven and unbounded. It buys one build.", "note_on_the_decomposition": "The A2.2 decomposition is reported because it was asked for and is now in the failure message, but it did NOT decide the route. The route follows from the arithmetic relating the ceiling to the conclusion, which holds whichever budget term dominates — that is what makes it a fix rather than a headroom adjustment.", "other_two_moves_declined": "Raising the ceiling to a CHOSEN number leaves the same disconnect one constant further out; retrying the section adds nondeterminism to a cell whose entire point since #11572 is that it is deterministic." }, "clause_2_contract_review": "BOTH LIMBS NO, self-declared from the actual diff and stated in a dedicated PR-body section. PATH: the diff is exactly one file, packages/drivers/driver-sql/src/sql-driver-11224-update-stamp-precision.test.ts — nothing under packages/spec/src/**. CONTENT: a *.test.ts in no package entry point (check:published-files green); nothing touches updatedAtStamp(), stampUpsertUpdatedAt(), emitted SQL or any schema — §4 and §5, which pin the emitted expression per dialect, are unmodified; the new symbols are file-local consts and one file-local function, no export added. Per the 不预挂 rule (maintainer 2026-08-28), `needs:contract-review` was NOT attached.", "landing": "Draft, per dispatch. NOT flipped ready, no auto-merge armed, nothing queued. `skip-changeset` attached (test-only diff: the closed list is docs/adr + .claude + scripts/pm + tests/workflow + comments) and read back comparatively — nothing stripped." }Generated by Claude Code
Generated by Claude Code
- added a commit that references this issue
on Sep 1, 2026
Filed unassigned by the
domain:devx @ objectstackexecution seat (seat post #6023, sessionsession_01Pk26oZ12t5N1hwGW1m1MgC), surfaced by a merge-queue build on an unrelated lint-message PR (#13668). ⛔ Ungraded, ⛔ unclaimed, ⛔ nodomain:*— an execution seat does not produce routing labels. Likely destination:domain:engine(packages/drivers/driver-sql), matching its predecessor #11572.The failure
Temporal Conformance (live PG + MySQL), queue build 33364345029:⭐ The assertion is a validity precondition, not a claim about the product
packages/drivers/driver-sql/src/sql-driver-11224-update-stamp-precision.test.ts:384-391:The run must fit inside one second so that a truncated second-precision stamp could not have distinguished the updates — which is what gives the following distinctness assertion its meaning. At
span = 1006the test correctly reports that its own premise failed, by 6 ms. The real invariant (monotonicity, the line above) held.⇒ The experiment was invalidated. The product was not falsified.
⭐ The sharp part: #11572's fix moved this test TOWARD this failure
#11572 (closed completed 2026-08-25,
domain:engine) is this same guard, in the opposite direction: "a probabilistic guard that reds with CORRECT code on a fast runner — and its failure is byte-identical to the defect it guards against." Its fix (PR #12112,d2cacbcf51) addedawaitClockAdvance: §3 now drives the clock and verifies each gap against the clock rather than trusting a timer.ROUNDS = 6(:141),MIN_GAP_MS = 5(:159) ⇒ ≥25 ms of deliberate spacing, plus 6 UPDATE round-trips against two live servers, all inside 1000 ms.⇒ Hardening against the fast-runner flake reduced the headroom against the slow-runner flake. Not a criticism of #11572 — its failure mode was real and its fix works — but the two guards now bound the test from both sides, and the slow side was not part of that card's frame.
What is NOT established
sql-driver-11224-update-stamp-precision§3 is a probabilistic guard that reds with CORRECT code on a fast runner — and its failure is byte-identical to the defect it guards against #11572 established, and pricing that is the owning lane's call, ⛔ not this seat's.The merge-queue triage comment instructs readers: 「超时多半是负载/时序…断言(
AssertionError: …)才指向真实的行为改变」.That heuristic is sound in general — this seat used it earlier today to refuse a flake reading on a different failure. Here it misfires, because the assertion is a timing measurement. ⇒ The discriminator is not
AssertionErrorvs timeout; it is what the assertion measures. A validity-precondition assertion belongs with timeouts, not with behaviour assertions.⭐ That is a cheap, generalisable addition to the triage guidance, and worth more than this single test.
Refs: #11572 (predecessor, fast-runner direction, closed) · #11224 (the original defect the test guards) · PR #12112 (
d2cacbcf51, theawaitClockAdvancefix) · #13668 (surfaced it; unrelated diff) · #13683 (the other queue failure this morning, different test).Generated by Claude Code