Skip to content

fix(driver-sql): keep the logger receiver at the nine detach-then-call sites — a class-based host logger no longer turns a durability warning into a TypeError - #12821

Merged
os-zhuang merged 6 commits into
mainfrom
claude/issue-12792-driver-sql-detached-logger-receiver
Aug 28, 2026
Merged

fix(driver-sql): keep the logger receiver at the nine detach-then-call sites — a class-based host logger no longer turns a durability warning into a TypeError#12821
os-zhuang merged 6 commits into
mainfrom
claude/issue-12792-driver-sql-detached-logger-receiver

Conversation

@claude

@claudeclaudeBot commented Aug 28, 2026

Copy link
Copy Markdown
Contributor

Fixes#12792

Nine sites in packages/drivers/driver-sql/src/sql-driver.ts selected a log channel by extracting the method before calling it. a.b(…) passes a as the receiver; (a.b ?? c.d)(…) evaluates to the bare function first, so the call runs with this === undefined. Eight now call logDurabilityFailure() — the property-access helper this class already had, three lines from the docblock that explains it. The ninth reports a reconcile that succeeded, so it keeps its info level with an in-place property-access spelling instead of being escalated onto the durability channel.


⭐ The first deliverable was a measurement: what logger does SqlDriver actually get?

Nothing composes a logger into SqlDriver at all today. Measured on origin/main at 23843d3f4:

seamwhat it does with a logger
driver-sql/src/index.tsonEnabledestructures logger from the plugin context, uses it for its own two lines, and builds new SqlDriver(config)never passes it in
SqlDriver constructorstrips schemaMode/autoMigrate/sqliteJournalMode/sqliteAbsentFile and hands the rest to knex; reads no logger key
SqlDriver.logger fieldkeeps its class-property default: an object literal of arrow closures over console.warn / console.error
every driver.logger = … in the repo26 assignments, all in *.test.ts or in packages/runtime/src/expected-read-refusal-noise.ts, a testkit whose only importers are integration tests
SqliteWasmDriver constructorif (config.logger) this.logger = config.logger — inherited straight into this class. The one production seam that can install one; no caller passes it yet.

So these were latent, not live. ⛔ That was not treated as grounds to close: a call that runs with this === undefined is a defect whatever today's wiring tolerates, and SqliteWasmDriver's constructor is a one-line change away from making it live. The fix landed regardless, which is what the card asked for.

The receiver half was already settled from the other end and is re-confirmed here as an executable assertion: @objectstack/core's ObjectLogger dereferences this on every channel — error/fatal via this.writeErrorLike, debug/info/warn via this.write, declared as methods at logger.ts:401/405/409/413.

⚠️ The count, per instrument, with each instrument's blind spots stated

Both counts this card carried came from single-line regexes, so 9 was published as a floor. It was re-derived here with an AST instrument — comments are not nodes and line breaks are not syntax, so both of that instrument's blind spots are closed — and swept for the three shapes a parenthesized-callee regex cannot see at all.

instrumentwhat it can seewhat it is blind tocount in driver-sql
single-line regex (both prior counts)(a.x ?? a.y)( on one linecomments · multi-line fallbacks · every other shape10 lines → 9 sites (the 10th is the docblock quoting the shape in prose)
① AST: call whose callee is a parenthesized expressionthe same shape, at any line breaking, never in a commenta detach that never parenthesizes9
② AST: two-step local — const fn = a.x ?? a.y;fn(…)the shape that grew the sibling card's family from 1 to 3a local escaping its declaring scope0 (3 non-log candidates, triaged below)
③ AST: destructured channel — const { error } = this.loggerreceiver lost at the bindinga rename through an intermediate object0
④ AST: channel handed on as a bare callback argumentrun(this.logger.warn)a channel wrapped in a closure first (which is safe anyway)0

The three ② candidates, read rather than counted: hostAfterCreate = pool.afterCreate twice (a host-supplied knex pool hook — a plain config callback, not a method with a receiver contract) and runner = trx ?? this.knex (a knex instance is a callable object designed to be invoked standalone). None is a log channel.

Zero-hit discipline. A zero from ②③④ is only a reading if the instrument fires, so it was proven twice on real code: against the pre-fix blobs of the sibling card (git show 26deb31a0^:…) it reports ① at auth-manager.ts:3610 and ② at reconcile-membership.ts:161 and adopt-membership.ts:239 — exactly the three that card found, including the two its regex could not see. A synthetic control carrying all four shapes plus a multi-line fallback is checked into the pin as its own test case (§3), where the regex finds 1 and the AST finds 2.

Swept repo-wide too, over 5,096 tracked .ts files: outside driver-sql and the already-landed plugin-auth fix there is no further live instance. The 2 remaining ① sites are on console (bound in Node and in browsers), and the 25 remaining ② sites are the idiomatic options-callback shape — a caller-supplied plain function with a console default (opts.warn, opts.info), not a method lifted off a receiver-sensitive class. Filed as an observation — see below.

⚠️ The gate hypothesis was tested, and it does NOT hold

The triage's hypothesis was that converting the nine would close two axes at once: the receiver bug and nine false silent-swallow sources for check:durability-degradation-log-level. Verified against the gate rather than asserted, before and after:

before: ✓ 29 durability-critical catch seam(s), all loud, rethrowing or propagating (4 propagating, declared)
UNRECOGNISED: 0 of 29
after : byte-identical audit output

The reason is measurable: none of the nine sits inside a catch guarding a DURABILITY_CRITICAL_CALLEES operation, so the checker never discovered them and they produced no findings to begin with. The two driver seams it does discover (runWideningAlters, at :9952 / :10057 before this diff) already reached logDurabilityFailure and are still classified recovers on one branch, loud (error@… via logDurabilityFailure()) after it — --list differs only in the line numbers the docblock rewrite shifted. Reason ② is why the helper exists; it is not what this conversion bought.

The docblock at :4290 needed rewriting, and was rewritten

Its closing paragraph explained why the inline sites were left alone — prose that would now sit next to code that no longer uses that shape, which is exactly the fossil this repo keeps paying for. It now carries three reasons instead of two, with the receiver as the load-bearing one, and records three things a future reader would otherwise have to re-derive: that the eight were converted and why they had been left (the receiver question was not in scope then, not that they were judged safe); that the ninth must not be converted, because escalating a functional report onto the durability channel is the over-application AGENTS.md names; and that reason ② was measured not to improve, so nobody re-litigates it.

Tests

packages/drivers/driver-sql/src/logger-receiver-detach.test.ts — 11 cases, 3 sections.

  • §0 non-vacuity. The doubles are classes whose channels dispatch through this, and §0 asserts that directly — plus that a closure double survives the same detachment, which is why this defect had no red test in the first place. It also asserts that @objectstack/core's realObjectLogger throws on every detached channel, which is the link that makes this card a defect rather than a style preference.
  • §1 the info site, driven through the real dev auto-reconcile: real SQLite table, real differ, real DDL, autoMigrate: 'safe'. Asserts the whole log transcript, because the second half of the defect is a line that must not be there.
  • §2 the durability sites, driven through the real declared-index sync with real duplicate rows, so it is the real CREATE UNIQUE INDEX that refuses. Run against a class-based logger, against a warn-only one (the fallback leg is held to the same standard), and against the platform's real ObjectLogger.
  • §3 a structural pin: the AST sweep above, run over sql-driver.ts itself, with the control sample as its own preceding test case so a green §3 can never mean "the scanner stopped working".

Ablation, both channels, prediction committed first

Each prediction is an empty commit made before the mutation (79a297735, 64fd23506), so it cannot have been written to fit the result. Every leg proved the mutation on disk with anchored greps in both directions before running, and proved the restore with git hash-object against the HEAD blob plus an empty git diff HEAD; the mutation scripts carry trap … EXIT INT TERM with absolute paths.

A — the durability site (syncDeclaredIndexes), reverted to (this.logger.error ?? this.logger.warn)(. Predicted red on §2's three cases and §3; §0 and §1 green. Observed exactly that:

AssertionError: promise rejected "TypeError: Cannot read properties of unde…" instead of resolving
Caused by: TypeError: Cannot read properties of undefined (reading 'record')
❯ error src/logger-receiver-detach.test.ts:95:10
❯ SqlDriver.syncDeclaredIndexes src/sql-driver.ts:11470:45
Caused by: TypeError: Cannot read properties of undefined (reading 'writeErrorLike')
❯ error ../../core/src/logger.ts:414:14
❯ SqlDriver.syncDeclaredIndexes src/sql-driver.ts:11470:45

The second frame is the production failure this card describes, reproduced against the platform's own logger.

B — the info site, reverted the same way. Predicted red in a different shape: that site sits inside the reconcile's own try, so the throw is caught, not propagated. Observed exactly that — no rejection, and a transcript that is worse than an empty one:

- StringContaining "info: [schema-drift] auto-reconciled",
+ "warn: [schema-drift] dev auto-reconcile failed for 'os12792_info' — falling back to warning",
+ "warn: [schema-drift] os12792_info: metadata declares index 'idx_os12792_info_code' (code) but the
database has no such index — run \"os migrate apply\" to create it.",

⭐ Both lines are false. The reconcile succeeded — the index was created before the log call — and the throw skipped the post-reconcile re-detect, so the driver reports a successful reconcile as a failure and then tells the operator to run os migrate apply for an index that already exists. That third harm was not in the prediction; it is the loop shape #11722 documents, reached from a different direction.

⚠️ No dist/ is involved in either ablation, and the stack frames prove it: they name src/sql-driver.ts and ../../core/src/logger.ts. The pin imports the driver relatively and this package's vitest config aliases @objectstack/core to core/src/index.ts, so both sides of the measurement are the source that was mutated.

Gates run locally, at this exact tree (7d64433d8)

Green: check:nul-bytes · check:changeset-gate-self-tests · check:cross-package-test-inputs · check:driver-conformance · check:objectql-double-limit · check:objectui-changeset · check:page-declaration-shape · check:pm-half-states · check:published-files · check:slot-lookup · check:test-source-alias · check:type-source-resolution · check:engine-double-contract · check:where-matcher · check:query-options-erasure · check:type-check-coverage · check:durability-log-level · check:type-check-debt (--re-measure, 31 entries, after building the closure exactly as lint.yml does) · check-adr-0087-registration · check-changeset-no-major · check-ci-filter-parity · check-comment-mask-adoption · check-empty-changeset · check-plugin-teardown-shape · release-rehearsal-clone --self-test.

Package suites: @objectstack/driver-sql144 files / 2206 tests passed, 8 files / 129 skipped; @objectstack/driver-sqlite-wasm (the one subclass) 26 files / 439 tests passed; @objectstack/driver-sql typecheck clean, and tsc --listFiles confirms the new pin is one of the 152 test files inside that program rather than excluded from it.

NOT MEASURED, not red:scripts/pm/check-half-states.mjs refused with PREREQUISITE NOT MET — the token in the environment is not a valid GitHub credential (exit 3, its own distinct code). Nothing was swept, so it is no reading at all; it needs a real credential and CI has one.

Declared narrowing: the repo-wide pnpm lint sweep was not run here — CI runs the farm exactly once regardless. Everything above is the affected package plus the derived families, re-derived from the actual diff on this head with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack (3 paths, 22 path-matched families plus the convention-triggered ones), not from a list carried in the brief.

Out of scope, filed not fixed

The repo-wide sweep above turned up no live sibling defect, but it did establish that this class has now been fixed card-by-card three times with no guard behind it, each round finding the next round's population by hand with a weaker instrument than the last. Recorded in #12820 — filed unassigned and labelled finding, ungraded, with the measured population (2 benign console sites, 25 legitimate options-callback sites, 0 live) and an explicit note that no gate is proposed because the false-positive surface has not been measured. #12820 is not addressed here. Routing is triage's.


Generated by Claude Code

…l sites
`(this.logger.error ?? this.logger.warn)(…)` evaluates to the bare function
and then calls it, so the call runs with `this === undefined`. The eight
`error ?? warn` sites now call `logDurabilityFailure()` — the property-access
helper this class already had three lines from the docblock that explained it.
The ninth is `info ?? warn` and reports a reconcile that SUCCEEDED, so it keeps
its level with an in-place property-access spelling rather than being escalated
to the durability channel.
The `:4290` docblock is rewritten: its closing paragraph explained why the
inline sites were left alone, next to code that no longer uses that shape.
Part of #12792
…d a shape scan
Three sections. ⓪ asserts the doubles — and `@objectstack/core`'s real
`ObjectLogger` — are receiver-sensitive, and that a closure double is not, so
the file cannot go quietly decorative. ①/② drive the real reconcile and the
real declared-index sync (real sqlite, real duplicate rows) against a
class-based logger and against a warn-only one. ③ is a structural pin over
`sql-driver.ts`: an AST walk for all four detach shapes, with a control sample
proving it fires — including on a fallback split across lines, which the two
single-line counts on this card could not see.
Part of #12792
…ns red
Prediction, committed before the mutation so it cannot be written after the
fact. Reverting the durability site in `syncDeclaredIndexes` to
`(this.logger.error ?? this.logger.warn)(…)` must produce, against the
class-based double:
① §2 red — the detached call throws `TypeError: Cannot read properties of
undefined (reading 'record')`, escaping `syncDeclaredIndexes`, so the
`resolves.toBeUndefined()` assertion rejects instead. The mirror of the
production shape, where `ObjectLogger.error` reaches `this.writeErrorLike`.
② §2's warn-only case red for the same reason (the FALLBACK leg detaches too).
③ §2's real-ObjectLogger case red — the platform logger, same path.
④ §3 red — the structural scan reports one `parenthesized-callee` finding.
⑤ §0 and §1 stay GREEN: they do not touch this site, so a red there would
mean the mutation was not the thing measured.
Direction: RED. Not "fewer diagnostics" and not a reversal — the assertions
are behavioural and the scan is a direct count of the shape.
Part of #12792
…t shape
The second ablation, because §1's assertions are about a different site on a
different channel and the first one does not cover them.
Reverting the `info` site in `reconcileAndWarnDrift` to
`(this.logger.info ?? this.logger.warn)(…)` must produce:
① §1 red — but NOT as an escaping TypeError. That site sits inside the
reconcile's own `try`, so the throw is CAUGHT and re-reported as
`[schema-drift] dev auto-reconcile failed … — falling back to warning`.
So the failure is `infos` empty AND a bogus failure line present: a
reconcile that really happened, announced as a failure.
② §1's warn-only case red the same way (the fallback leg detaches too).
③ §3 red — one more `parenthesized-callee` finding.
④ §0 and §2 stay GREEN.
Direction: RED, via SWALLOW-AND-MISLABEL rather than a propagating throw.
That asymmetry is the point of running this one separately.
Part of #12792
…st the line wanted
The info site's defect has two halves and the second one is a line that must
NOT be present: the site sits inside the reconcile's own `try`, so a detached
call is caught and re-reported as `dev auto-reconcile failed`. Asserting the
full transcript puts both halves in one diff instead of hiding the mislabel
behind an earlier expectation that fails first.
Part of #12792
@github-actions

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

This PR changes 1 package(s): @objectstack/driver-sql, touching 8 documentable anchor(s).

6 hand-written doc(s) NAME something this change touched and may need an implementation-accuracy re-verification:

  • content/docs/data-modeling/drivers.mdx(via SqlDriver (symbol))
  • content/docs/data-modeling/index.mdx(via SqlDriver (symbol))
  • content/docs/plugins/packages.mdx(via SqlDriver (symbol))
  • content/docs/protocol/kernel/index.mdx(via SqlDriver (symbol))
  • content/docs/protocol/kernel/lifecycle.mdx(via SqlDriver (symbol))
  • content/docs/protocol/objectql/query-syntax.mdx(via SqlDriver (symbol))

1 release-owned page(s) also name something this change touched. These are read-only:

  • content/docs/releases/v17.mdx(via SqlDriver (symbol))

content/docs/releases/ is RELEASE-OWNED (AGENTS.md "Documentation Guardrails"): release
notes are written centrally at release time, and a code PR that edits them is the exact PR
that guardrail exists to stop. They are still audited — read-only. If one of them is actually
wrong, file an issue or open a dedicated docs-only PR; do not edit it here.

What this run could not see
  • the SDK route bridge reached 47 of 219 client-bound route-ledger rows — the other 172 have no registrar path: tail to select them, so pages documenting THEIR client methods cannot appear above, on this or any run. Of those 172: 14 are remediable by widening that discovery convention (an in-repo file declares the path; the convention did not scan it); 56 are structural — on a ledger where NOT ONE row is declared in-repo, so no discovery change reaches them at any price; 102 are undecided (no in-repo declaration, on a ledger that has other in-repo registrars — absence and an unreadable spelling are not distinguishable here). The rows themselves: node scripts/docs-audit/affected-docs.mjs --bridge-coverage
  • a page that states a rule by its inputs shares no identifier with the emitter that implements the rule, so an emitter-only diff cannot list it — not on this run and not on any run. Measured on fix(driver-sql): emit varchar(maxLength) for a text field a declared index keys on #11430: content/docs/protocol/objectql/types.mdx documents the text-family column mapping by the ObjectQL type names it maps FROM (text / textarea / html) while the diff changed createColumn; it went unlisted, and it was the page that diff falsified, in four places. No shared token exists to detect this on, so a rule your change carries has to be re-read by hand in the pages that restate it.

Coarse fallback — 9 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json 632e862d14497e882885e0a75f5c31cc61c5186dpackageMentionDocs.

Which tree this was computed on

This run read content/docs from 48e4840648a583d0c6fc110eb0f20a3b6053c9f7 — the merge of head 7d64433d83d22ff7785caf70effbab76d1cec93c into base 632e862d14497e882885e0a75f5c31cc61c5186d, which is what actions/checkout gives a pull_request run. Not the PR head.

A worktree cut from an older main holds a different content/docs, so re-deriving there can legitimately return a different list — that is a different tree, not a wrong row. To answer on the same tree:

# while this PR is open — GitHub drops the merge commit once it closes
git fetch origin 48e4840648a583d0c6fc110eb0f20a3b6053c9f7 && git checkout 48e4840648a583d0c6fc110eb0f20a3b6053c9f7
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin 632e862d14497e882885e0a75f5c31cc61c5186d 7d64433d83d22ff7785caf70effbab76d1cec93c && git checkout -B drift-repro 632e862d14497e882885e0a75f5c31cc61c5186d && git merge --no-ff 7d64433d83d22ff7785caf70effbab76d1cec93c
node scripts/docs-audit/affected-docs.mjs --json 632e862d14497e882885e0a75f5c31cc61c5186d

⚠️ That checkout carried uncommitted changes, so the commit above does not fully identify what was read.

Advisory only, and a precision-first one (#9192): a page is listed because it names a
symbol, wire route or SDK method this diff touched — not because it mentions a changed
package. Each row says which anchor put it there, so a wrong row is reportable rather than
merely annoying. To re-verify, run the docs-accuracy-audit workflow scoped to these files:
node scripts/docs-audit/affected-docs.mjs 632e862d14497e882885e0a75f5c31cc61c5186d → pass the list as
args.docs, on the commit named under Which tree this was computed on.

@github-actionsgithub-actionsBot added documentation Improvements or additions to documentation tests tooling labels Aug 28, 2026
@os-zhuangClaude

Copy link
Copy Markdown
Contributor

Reviewer-of-record notes. Three things, one of which is a correction to my own dispatch brief.

1. The release-owned page, audited (read-only, but the check says audit it)

content/docs/releases/v17.mdx:2727 is the one line on that page bearing on this change: "costs durability logs error, not warn, with a gate enforcing the rule."

Not falsified — repaired. Before this PR, those sites handed a receiver-sensitive logger logged neithererror nor warn: they threw. The sentence was true about the gate's intent while the runtime did not deliver it in that composition. Nothing to file, nothing to fix.

The page's other four SqlDriver mentions (:1090 window functions, :1811 the removed findOne, :2377 capability bits, :2887distinct) are untouched by this diff.

2. The six hand-written rows are coarse-anchor noise, and the check invites saying so

Every row was matched on the anchor SqlDriver (symbol) — the bare class name — not on anything this diff changed. Since the conversion preserves every level exactly (8 sites keep error-with-warn-fallback via logDurabilityFailure; the 9th keeps info-with-warn-fallback in place), this PR has no observable behaviour change beyond the calls no longer crashing. So no claim on any of those pages can be falsified by it.

This is the mirror of the failure mode the check documents at length. It reasons carefully about pages it cannot see; a whole-class anchor is the case where it sees far too many. Recording it as the check asks — a wrong row is reportable rather than merely annoying.

3. ⭐ The nine sites are not one shape, and my dispatch brief said they were

My brief said "convert the 9 to the named helper", carrying the triage's framing without questioning it. That was wrong, and the seat caught it: eight are error ?? warn durability failures, but the ninth is info ?? warn — the ADR-0120 line reporting a reconcile that succeeded.

Routing that one through the durability channel would have escalated a functional report from info to error. That is a behaviour change wearing a refactor's clothes, and the cost is the one AGENTS.md names: over-applied error trains everyone to skim error. The seat fixed it in place instead — receiver repaired, level and fallback both preserved — and did not add a sibling helper to do it.

The ablation makes the distinction executable rather than asserted: two predictions, committed empty before either mutation, predicting failure in different shapes. Reverting a durability site rejects; reverting the info site is swallowed by the reconcile's own try and instead prints two false lines — a successful reconcile reported as a failure, followed by advice to migrate an index that already exists. That third harm was not in the prediction and is reported as an unpredicted observation rather than folded in.

4. The gate hypothesis came back NEGATIVE, which is the valuable outcome

Triage's both-axes hypothesis — that converting the 9 also closes false silent-swallow sources for check-durability-degradation-log-level.mjsdoes not hold. Before and after audit output byte-identical; none of the 9 sits inside a catch guarding a durability-critical callee, so the checker never discovered them and there was nothing to close. Tested rather than asserted, per the brief, and written into the rewritten docblock so nobody re-litigates it as a benefit of this conversion.

⭐ Also worth naming: the instrument's zero-hits are proven twice — the same AST scanner run over historical plugin-auth blobs reproduces exactly the 3 sites the sibling card found, including the 2 its regex could not see, and a synthetic all-four-shapes sample is checked into the pin as its own case, so a green structural pin can never quietly mean the scanner stopped working. And the first repo-wide sweep died at the foreground cap (exit 143, the walker descended into node_modules) — reported as NOT MEASURED, not as a zero, and re-run over git ls-files.


Generated by Claude Code

@os-zhuang
os-zhuang marked this pull request as ready for review August 28, 2026 00:28
@os-zhuang
os-zhuang enabled auto-merge August 28, 2026 00:28
@os-zhuang
os-zhuang added this pull request to the merge queueAug 28, 2026
Merged via the queue into main with commit 3f42920Aug 28, 2026
34 checks passed
@os-zhuang
os-zhuang deleted the claude/issue-12792-driver-sql-detached-logger-receiver branch August 28, 2026 00:47
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentationImprovements or additions to documentationsize/lteststooling

Projects

None yet

2 participants

@os-zhuang@claude