Repository navigation
driver-sql: the boot widening's swallowed failure logs warn, but AGENTS.md's degradation rule names DDL-that-did-not-run as error #9609
Description
Activity
Claiming this card.
- session:
session_01XqDQYVU5smx29ts9pAErja - branch:
claude/issue-9609-widening-log-level
Declared file surface (initial):
packages/drivers/driver-sql/src/sql-driver.tsplus its test file, a.changeset/*.md, and — pending the gate measurement below — possiblyscripts/check-durability-degradation-log-level.mjs. Any addition to that surface will be posted as a follow-up comment on this card before it is edited.First action is the measurement the previous comment left open: run
node scripts/check-durability-degradation-log-level.mjsfrom a worktree with deps installed and determine whether the two call sites are (a) outside the gate's durability vocabulary, (b) baselined, or (c) unrecognised due to a matcher defect.Generated by Claude Code
Generated by Claude Code
- session:
os-dev-report
{ "issue": 9609, "status": "done", "branch": "claude/issue-9609-widening-log-level", "pr": "https://github.com/objectstack-ai/objectstack/pull/9665", "premise_still_valid": true, "summary": "Both boot-widening swallow logs now report at `error` and name the fix; control flow is untouched (the swallow stays, the flush keeps its refusal). H1 resolved to (a) by running the gate, not reasoning about it: `sql-driver.ts` IS scanned and IS NOT baselined, but `DURABILITY_CRITICAL_CALLEES` had no entry reaching the widening's DDL path — so `runWideningAlters` is declared there, measured to light up exactly the card's two sites and nothing else (27 seams before, 29 after). H2 confirmed from commit 8bbf45947's diff, with one refinement: before #9542 the guard read `if (!this.flushingDeferredDdl || !this.isMysql)`, so a metadata-lock-blocked boot ALTER waited MySQL's one-year default and never returned — but the catch was always reachable by NON-lock failures, so 'could not fire at all' holds for the lock-blocked path specifically, not for the catch in general. H3 confirmed: the messages named the consequence and not the fix; they now carry the same three moves the flush's refusal names (find the lock holder via SHOW PROCESSLIST / performance_schema.metadata_locks, end it, re-run `os migrate apply` or restart, the widening being idempotent). One unplanned finding drove a design choice: the file's own `(this.logger.error ?? this.logger.warn)(…)` idiom is INVISIBLE to the gate's `loggerLevel()` matcher (parenthesized callee), reporting both loud sites as 'catch swallows the failure with no log at all' — while the spelling the matcher does accept, `logger.error?.(…)`, prints nothing at all against a sink with no `error`. Both sites therefore call a named `logDurabilityFailure` helper that the gate follows transitively; the matcher defect is filed rather than patched.", "tests": "All at HEAD 042f406fa (the PR head), gate union re-run after the final commit. `pnpm --filter '@objectstack/driver-sql' test` -> 'Test Files 101 passed | 5 skipped (106) / Tests 1761 passed | 62 skipped (1823)'. `pnpm --filter '@objectstack/driver-sql' typecheck` -> clean (run unpiped; an earlier piped run masked a real TS2416/TS2322 behind tail's exit code, which is what the FakeLogSink annotation commit fixes). Targeted suite verbose -> 'Tests 15 passed (15)' including the 4 new pins. Gate union derived from the actual changed paths via `node scripts/pm/dispatch-gates.mjs`, all 15 PASS: check:durability-log-level, check:changeset-gate-self-tests, check:objectui-changeset, check:cross-package-test-inputs, check:test-source-alias, check:type-source-resolution, check:nul-bytes, check:engine-double-contract, check:where-matcher, check:query-options-erasure, check-adr-0087-registration, check-changeset-no-major, check-empty-changeset, check-cross-package-test-inputs, docs-audit/check-affected-docs. Checker --self-test -> 35 cases passed. Reverse verification, three ablations, each direction predicted before running and each landing as predicted, all run from the committed state and restored via `git checkout branch -- path` with an empty `git status` proving byte-identity: (1) datetime level back to `warn` -> test RED ('reports the un-run datetime widening at error, not warn') AND gate RED ('catch logs warn@8264 and does not rethrow'); (2) helper body -> `this.logger.error?.(msg, meta)` -> test RED ('still delivers the line at warn when the injected sink has no error') while the GATE STAYS GREEN — the load-bearing result, since it shows the gate alone would accept the harmful spelling; (3) fix clause stripped -> test RED ('names the FIX') plus the no-error-sink pin, which asserts that clause too. No dist/ ablation applies: these are vitest runs resolving `./sql-driver.js` to src, so no rebuild is involved. Dependency closure built first (`pnpm --filter '@objectstack/driver-sql^...' build`). Downstream check was targeted rather than a 48-package sweep, because the change adds one protected member and no public surface: `logDurabilityFailure` collides with no name repo-wide (grep), and both real `SqlDriver` subclasses typecheck clean — driver-sqlite-wasm, and driver-turso after building its own closure (a first attempt failed on an unbuilt `@objectstack/verify`, not on this change).", "open_questions": [], "out_of_scope_findings": [ "filed as #9657 (sub-issue of #8897): check-durability-degradation-log-level's `loggerLevel` cannot see the `(logger.error ?? logger.warn)(…)` fallback — a loud catch reads as `silent-swallow`, and the spelling it CAN see (`logger.error?.(…)`) prints nothing against a sink with no `error`, so the gate's cheapest satisfaction is actively harmful. 7 sites use the idiom (4 pre-existing in sql-driver.ts, 1 in turso-driver.ts with a third `.call()` spelling, 2 on this branch now routed through the helper); none is red on main because none is in the vocabulary yet. Three options with a weak preference recorded; deliberately not decided in this PR.", "recorded as a comment on #8897: its restart-when trigger ('any PR touches scripts/check-durability-degradation-log-level.mjs') fired, and #9657 upgrades that card's own 'latent, has cost nothing yet' analysis to a measured active misclassification on the call-shape half." ] }Generated by Claude Code
Generated by Claude Code
- added a commit that references this issue
on Aug 23, 2026 - added a commit that references this issue
on Oct 7, 2026
Found while documenting the metadata-lock bound for #9543 (docs PR #9608). Filed unassigned; not fixed in that PR — its declared file surface is
content/docs/data-modeling/drivers.mdx, andpackages/drivers/driver-sql/src/sql-driver.tsis outside it.The observation
Boot schema sync's MySQL widening logs its swallowed failure at
warn, on both twins (verified onorigin/main@ca2e020e4):sql-driver.ts:8222—this.logger.warn('[sql-driver] could not widen MySQL datetime columns on …; writes stay correct, but the 2038 ceiling and millisecond truncation remain')sql-driver.ts:8310—this.logger.warn('[sql-driver] could not widen MySQL time columns on …; fractional-second writes keep rounding to whole seconds')AGENTS.md's Degradation log levels section decides the level with one question:
and its
errorlimb names this case in its own example list: "A write that claims to persist does not, DDL that was supposed to run did not, persisted state and runtime state disagree."Both halves appear to hold here. After the swallow the platform boots, serves traffic and looks entirely normal; the DDL that was supposed to run did not; and the consequence the message itself states is silent — an un-widened
TIMESTAMPtruncates milliseconds, and an un-widenedTIMErounds fractional seconds away, whiledatetime's documented canonical storage format promises milliseconds are always present. Nothing else reports that the widening is outstanding.The counter-argument, stated fairly
runWideningAlters' own doc comment argues the opposite policy for the swallow, and that argument is sound: correctness never depended on the widening having run, aTIMESTAMPcolumn keeps accepting and returning the same UTC instants, and a migration must never take boot down. Triage's 2026-08-18 auto-adjudication on #9542 deliberately kept boot's swallow.But that reasoning is about throw vs swallow, not about
warnvserror— and the level was never separately adjudicated: these twologger.warncalls predate both #9354 and #9542, which changed the wait and the escape around them without revisiting the level. Raising the level keeps the swallow intact and changes only whether the line is visible to an operator's log alerting, which is the only signal there is.Note the level also governs how loud this gets now that the bound exists: before #9542, a blocked boot widening never returned, so this catch could not fire at all. It is newly reachable.
Not claimed here
Whether the maintainer's balance lands on
erroror on keepingwarnis a judgment call about a documented convention, so this is filed for triage rather than fixed. If the answer is thatwarnis correct, the useful outcome is a sentence at the call sites saying why this one is exempt from the rule's DDL limb — right now nothing there addresses it, so the next reader re-derives the same question.Related: #9354 and #9542 (the bound on each path) · #9543 / PR #9608 (the docs page that states the operator-visible consequence).
Generated by Claude Code