fix(objectql): pick the find failure log level from the cause — "the table is not provisioned yet" is not "the read failed" (#13273)

[os-trump]

Fixes #13273

ObjectQL.find logged every read failure identically — ERROR Find operation failed, carrying the driver's fault as a stack. That merged two different facts onto one channel, at the level reserved for the second:

1. "this table has not been created yet" — the ordinary state of a database nobody has migrated, and a normal answer for every caller on the boot path;
2. "this read failed" — the rows may well exist and simply were not seen.

The repair is at the read path, where the level is chosen. ⛔ No edit to packages/cli/src/commands/migrate/plan.ts (held by PR #13270) and none to packages/rest/src/rest-server.ts — the change set is six files, listed at the end.

The five emitters, by name and file

All five reach one line: packages/objectql/src/engine.ts, the catch in find. Each caller already treats a missing table as a normal answer and says so in its own code.

caller	file	object read	what the caller does with the failure
readAuthoredTranslationLayer	packages/core/src/fallbacks/authored-translation-sync.ts	sys_metadata	returns an empty layer, boot continues
ObjectQLPlugin.readAuthoredHookRows	packages/objectql/src/plugin.ts	sys_metadata	logs re-synced runtime-authored hooks {authoredRows: 0} and carries on
ObjectQLPlugin.readAuthoredActionRows	packages/objectql/src/plugin.ts	sys_metadata	logs re-synced runtime-authored actions {authoredRows: 0} and carries on
ObjectStoreActionActivationStore.probe	packages/objectql/src/action-activation.ts	sys_metadata_activation	its caller already follows with a warn naming the consequence in operator terms
ObjectQL.readMigrationFlagVerified	packages/objectql/src/engine.ts	sys_migration	"no row, an unreadable table, a malformed row — all false"

The card reported four; this fixture (an example app that also carries translations) drives five. Same class, one more caller.

Before / after, driven against a real database

Fixture: examples/app-todo as the project directory, NODE_ENV=production, a fresh sqlite file with no tables. This is the run the command exists to describe.

NODE_ENV=production node packages/cli/bin/run.js migrate plan --database-url file:/tmp/unmigrated.db

run	tree	ERROR Find operation failed	stack frames	driver refused a read on (warn)	exit	plan printed
before	origin/main at 3322527f, nothing applied	5	5	5	0	10 tables to create
after	this branch at 75e44212	0	0	5	0	10 tables to create — byte-identical

Both runs succeed and print the same plan. What is gone is five ERROR records and their stack traces; what remains is the driver's own refusal envelope, at warn, which is deliberate (below).

The class that was demoted, and how it was identified

Only the failure that positively identifies as "relation does not exist", asked through the shared isMissingTableError predicate (@objectstack/metadata/errors) — the same call probeInstallOrganizations and resolveFileReferences already make, never a hand-rolled code === '42P01' copy. It is logged at debug, with reason: 'table-not-provisioned' and no stack.

That predicate earns a benign verdict rather than defaulting to one. It matches the table-scoped SQLSTATEs (42P01, ER_NO_SUCH_TABLE/1146) and the three dialects' phrasings, and it excludes 42703 / 42704 / 3D000 and Postgres' column "x" of relation "y" does not exist — a phrase that contains a legal missing-table phrase but is a column fault on a table that exists (#6347 established that exclusion).

⚠️ It is asked over the driver's envelope, whose own message says nothing about a missing table: SqlDriver.backendStatementFault composes a redacted message and hangs the dialect error off a non-enumerable cause. The predicate walks that chain. A test case drives exactly this so the classification cannot silently start reading the top-level message.

⛔ Positive controls — a read that genuinely FAILED is still loud

Every zero above is paired with a case that must stay loud, on the same seam.

Control A — same command, real database, both verdicts in ONE run. A database where sys_metadata exists but has none of the columns being filtered on, while sys_metadata_activation and sys_migration are still absent:

CREATE TABLE sys_metadata (id TEXT PRIMARY KEY);
NODE_ENV=production node packages/cli/bin/run.js migrate plan --database-url file:/tmp/control.db

object	dialect reason	records
sys_metadata	no such column: type	3 x ERROR, with stacks
sys_metadata_activation	no such table: sys_metadata_activation	0 ERROR (demoted)
sys_migration	no such table: sys_migration	0 ERROR (demoted)

So the instrument still reports ERROR for a read that genuinely failed, and it does so in the same process, on the same command, beside the reads that went quiet.

Control B — the same five call sites, a backend-level fault. Pointed at a file that is not a sqlite database at all (SQLITE_NOTADB): 5 ERROR records with stacks, exit 1. The five emitters that fell silent for "not created yet" are all loud again for "the read failed".

Control C — unit, packages/objectql/src/engine-find-missing-table-log-level.test.ts. Through the real envelope shape: three missing-table dialect phrasings demote; connection refused, statement timeout, permission denied, connection terminated, an unclassified error, and the #6347 column-of-a-relation phrasing all stay on error carrying the Error object and its stack.

⛔ What did not change, and is pinned

• The throw. Both branches rethrow the driver's envelope byte-identically. No caller's control flow, catch, or error envelope moves — this is a log level and nothing else. Pinned in both directions.
• The driver's refusal envelope. [sql-driver] DATABASE_ERROR — the backend refused a read on 'TABLE' … no such table: TABLE still goes to warn on every one of these reads, untouched. It is deliberately the surviving loud half: packages/runtime/src/expected-read-refusal-noise.ts already documents it as "where this class of fault can still be picked up". Silencing it too would collapse exactly the distinction this card exists to preserve.
• The write verbs. insert / update / delete keep their unconditional error — a write to a table that does not exist is not a normal answer for any caller, and nothing landed. Pinned.

Reverse-verification

Prediction, recorded before the run: reverting the classification turns the demotion pins red and leaves every positive control green (they already assert the error channel).

Mutation: the guard in reportFindFailure neutered to if (false && isMissingTableError(error)). Proved on disk — injected marker grep -c = 1, original guard grep -c = 0, blob hash moved 1de8f730 to 647a18d2. No rebuild is involved on this path and none was needed: the tests import ./engine by a relative path inside the package, so vitest transforms the source, not a dist artifact.

	ablated	restored
tests failed	7	0
tests passed	28	35

The 7 reds are exactly the demotion pins (5 in the new file, 2 in the hydrate file). The 5 positive controls, the write-verb pin and the rethrow pin stayed green in the ablated tree — so they discriminate rather than always-fail.

Restore proved by blob hash back to 1de8f730 and git diff HEAD empty, not by an exit code.

Local verification, at 75e44212

Ran on the union after the final commit.

• pnpm --filter @objectstack/objectql test — 248 files, 4287 tests, all passed. ⚠️ Spelled test -- --maxWorkers=2; vitest discards everything after a bare --, so the worker cap was silently dropped. The run itself is a full-package pass; only the cap was lost.
• pnpm --filter @objectstack/runtime exec vitest run --maxWorkers=2 — 200 files, 2956 tests, all passed (includes the channel-asymmetry file and the ~20 fixtures that assert silentChannels()).
• packages/core 43/1054, trigger-record-change 7/78, plugin-approvals 34/626 — the cross-package consumers of the shared capture helper. All passed.
• pnpm --filter @objectstack/objectql --filter @objectstack/runtime typecheck — both Done. ⚠️ NOT MEASURED for the test files: both packages' tsconfig.json carry exclude: ["**/*.test.ts"], verified with tsc --noEmit --listFiles — engine.ts and expected-read-refusal-noise.ts are in the programs (1 hit each), the three test files are not (0 hits each). Their exercise is the vitest runs above.
• pnpm lint (repo-wide eslint . --no-inline-config) — exit 0, no output.
• Gate families derived with node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack from the merged tree, then run. Green: check:nul-bytes, check:durability-log-level, check:logger-receiver-detach, check:engine-double-contract, check:objectql-double-limit, check:where-matcher, check:stack-collection-maps, check:dispatcher-error-vocabulary, check:test-source-alias, check:type-source-resolution, check:query-options-erasure, check:changeset-gate-self-tests, check:cross-package-test-inputs, check:objectui-changeset, check:page-declaration-shape, check:pm-half-states, check:published-files, check:slot-lookup, check:type-check-coverage, check:dual-build-cjs-loads, check:type-check-debt (--re-measure, 30 entries, none above its recorded number), check-adr-0087-registration, check-changeset-no-major, check-empty-changeset, check-keyed-text-bounds, check-comment-mask-adoption, check-undeclared-dep-imports, check-plugin-teardown-shape, check-ci-filter-parity, check-shard-attestation, docs-audit/check-affected-docs, docs-audit/check-drift-comment, release-rehearsal-clone --self-test.
• check-engine-split-ratio first refused (shallow clone … oldest visible commit sits INSIDE the window, exit 2). Re-run after git fetch --shallow-since=2026-05-25 origin: exit 0, ratio 97.3%.
• NOT MEASURED, recorded with their own refusal text, not folded into the green list: scripts/pm/check-half-states.mjs — exit 3, Nothing was swept … it is no reading at all; the container's GITHUB_TOKEN is the proxy placeholder and the anonymous quota is spent on the shared egress IP. scripts/check-test-completeness.mjs — exit 3, PREREQUISITE NOT MET — this gate grades a saved turbo run test log, and no log was named; CI tees it and passes the path.

Every gate result above is its own exit code, captured before any pipe.

Changeset

Yes — .changeset/migrate-plan-missing-table-log-level.md, @objectstack/objectql patch. The change is user-visible: os migrate plan, and any first boot against an unprovisioned database, stops printing these stack traces.

Files

.changeset/migrate-plan-missing-table-log-level.md
packages/objectql/src/engine.ts                                          the fix
packages/objectql/src/engine-find-missing-table-log-level.test.ts        new pins + controls
packages/objectql/src/engine-file-hydrate-outage.test.ts                 re-pinned: its block asserted the old merged level
packages/runtime/src/expected-read-refusal-noise.ts                      captureEngine now proxies debug as well as error
packages/runtime/src/expected-read-refusal-noise.channel-asymmetry.test.ts  its probe reads a missing table; instrument follows the frame

The two runtime edits are the blast radius of moving the channel, and both are the narrow repair rather than a relaxation. The shared helper counts the demoted frame into the same engineFrames tally its ~20 consuming fixtures assert, so silentChannels() still names a channel that stopped firing. The asymmetry file's instrument now patches stdout as well as stderr (ObjectLogger sends error/fatal to stderr and everything else to stdout) and runs its positive control at the level that admits the frame; its claim — "the engine channel is only as loud as the fixture's own kernel logger" — is unchanged, only the rank it compares against moved.

Found but not fixed

• isMissingTableError never checks WHICH table the "no such table" names — a view over a missing base table is read as "this table is not provisioned yet" #13324 — isMissingTableError never checks WHICH table the "no such table" phrase names, so a view over a missing base table is read as "not provisioned yet". Measured on a real database. Pre-existing, shared by every consumer of the predicate; this PR adds one more reader of it and changes none of the verdicts.
• [finding] Two inline copies of the expected-read-refusal capture still wrap only the engine error channel — one of them can no longer fire since #13273 moved the frame to debug #13325 — two inline copies of the expected-read-refusal capture wrap the engine error channel only; one of them can no longer fire now that the frame moved. Nothing red — dead suppression plus stale prose.

Session: https://claude.ai/code/session_01TvqBFLRzXdSPcbusDoED9k

Generated by Claude Code

---

Generated by Claude Code

[github-actions]

📓 Docs Drift Check

3 anchor(s) derived from 2 changed package(s); no hand-written page names any of them, so this run has nothing to list — not a clean bill of health. This check sees only pages that NAME a derived anchor: one that documents this change in prose, or enumerates it in an authoring dialect, names none and stays invisible to it on every run.

What this run could not see

• 1 anchor(s) matched too much of the corpus to be a work list: ObjectQL (symbol, 64 pages)
• 1 name(s) were too generic to anchor anything (single lowercase words)
• 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 — 32 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 0ae9e1e16e34db799cb717ad254165a2b4cef243 → packageMentionDocs.

Which tree this was computed on

This run read content/docs from f1c09443251bbe028cf84ecf5f7cad2e52e7c314 — the merge of head 75e442122d94bba5d27f67c380e1308517686b13 into base 0ae9e1e16e34db799cb717ad254165a2b4cef243, 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 f1c09443251bbe028cf84ecf5f7cad2e52e7c314 && git checkout f1c09443251bbe028cf84ecf5f7cad2e52e7c314
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin 0ae9e1e16e34db799cb717ad254165a2b4cef243 75e442122d94bba5d27f67c380e1308517686b13 && git checkout -B drift-repro 0ae9e1e16e34db799cb717ad254165a2b4cef243 && git merge --no-ff 75e442122d94bba5d27f67c380e1308517686b13

node scripts/docs-audit/affected-docs.mjs --json 0ae9e1e16e34db799cb717ad254165a2b4cef243

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

[os-trump]

✅ PM review — ACCEPT once CI is green; ⛔ not while it is running (#13273)

Undrafting now; arm follows on a complete green read. ⛔ No rework owed — do not push in response to this comment.

Clause ②: does not attach. Path limb measured silent (6 files, none under packages/spec/src/**), no declaration in the body, and a log level in objectql is not an answer on a public REST door.

✅ The fence held — verified from the file list, not the report

The fence was ⛔ zero edits to packages/cli/src/commands/migrate/plan.ts, held by #13270 until it merges. Change set read from the PR itself: .changeset/…, engine.ts, engine-find-missing-table-log-level.test.ts, engine-file-hydrate-outage.test.ts, expected-read-refusal-noise.ts, expected-read-refusal-noise.channel-asymmetry.test.ts. Neither plan.ts nor rest-server.ts appears. ⭐ Held under maximum temptation: the card's entire symptom is os migrate plan's output, and the fix went to the callers instead — which is also where it belonged.

✅ The distinction I fenced on is intact, and pinned in both directions

The fence that mattered most was ⛔ no silencing by broadening a catch — "table not yet created" and "the read failed" must stay distinguishable, because collapsing them is itself a filed p1 one door over (#13255).

• The throw is byte-identical on both branches. reportFindFailure(object, e); throw e; — this decides a log level and nothing else, so no caller's control flow, catch, or error envelope moves.
• The demotion is earned, never defaulted to: only what positively identifies through the shared isMissingTableError predicate is demoted; an unrecognised failure stays loud, pinned by its own case.
• ⭐ The [finding] isMissingTableError 同样把 Postgres 写路径的「缺列」措辞判为「缺表」——其 docblock 明说 42703 必须响亮失败,而消费点会据此「从 1 开始编号」 #6347 near-miss is pinned as still-loud: Postgres' column "x" of relation "y" does not exist contains a legal missing-table phrase but is a column fault on a table that exists. That is exactly the case a looser fix would have swallowed.
• Writes keep an unconditional error — a write to a missing table is never a normal answer, and nothing landed.
• The driver's warn refusal envelope survives untouched as the deliberate loud half, so the class stays visible without a duplicate and without a stack.

Positive controls on every zero, including one that runs both verdicts in a single command: a DB whose sys_metadata exists but lacks the filtered column keeps 3 ERROR records with stacks while the two still-absent tables stay quiet. Plus SQLITE_NOTADB → all five loud again, exit 1.

⚠️ Correction to the card, measured: it said four emitters; this fixture drives five of the same class (it also carries translations). The card was undercounting, not the PR overreaching.

⭐ The second-order work is what makes this a good PR

Demoting error → debug is a two-line change that quietly breaks instruments, and both breakages were found and repaired rather than discovered later:

1. ObjectLogger routes error/fatal to stderr and everything else to stdout — so the demotion moved this frame between pipes. The channel-asymmetry probe patched stderr only, and would have read the demotion as "the frame stopped being emitted" — a false negative that looks exactly like the condition that file exists to detect. Now patches both and counts the union.
2. captureExpectedReadRefusals wrapped the error channel only. Left alone, its tally would have read 0 for every declared table and silentChannels() would have named a channel that is in fact firing — a false red across ~20 consuming fixtures. Now wraps both arms, with the recognition rule factored into one shared closure specifically "so the debug arm cannot drift looser than the error arm — the direction that turns a pin back into a mute." ⭐ That is the right instinct written down.
3. An inverted pin was rewritten in place, not deleted. engine-file-hydrate-outage.test.ts existed to pin that the generic frame is identical for benign and non-benign causes — which this fix makes false. It now re-pins both halves: the frame does now separate the causes by channel, and it still fails finding(objectql): engine.ts 的 sys_file hydrate 读故障走 catch → return records —— 静默返回裸 id,零日志(#5979 实施期扫出,闸门词表外) #6116's acceptance because it names only the sub-read. Inverting a pin in place is the correct treatment; deleting it would have silently dropped finding(objectql): engine.ts 的 sys_file hydrate 读故障走 catch → return records —— 静默返回裸 id,零日志(#5979 实施期扫出,闸门词表外) #6116's guard.

⚠️ Two things recorded, neither blocking

1. The demotion inherits isMissingTableError's imprecision. Filed by the dev as isMissingTableError never checks WHICH table the "no such table" names — a view over a missing base table is read as "this table is not provisioned yet" #13324 (triaged bug · p2 · pm:queue · domain:engine): the predicate never checks which table the "no such table" phrase names, so a sqlite VIEW over a missing base table fails with no such table: main and classifies benign for a read of sys_metadata. Pre-existing and shared by four existing consumers; this PR changes none of their verdicts. But it does add a consumer that makes a level decision on it, so in that specific case a genuine failure could be demoted. Accepted because the driver's warn stays loud on that same read, so the class is still visible — ⛔ not because the imprecision is harmless.
2. This PR leaves one dead test arm. [finding] Two inline copies of the expected-read-refusal capture still wrap only the engine error channel — one of them can no longer fire since #13273 moved the frame to debug #13325 (triaged finding · tooling · p2 · pm:queue · domain:cli): notification-schema-conformance.integration.test.ts has an inline capture copy wrapping error only, so its engine-side suppression can no longer fire. Nothing goes red — the file's assertions are fed by the driver channel — and the sibling metadata-list-ambient-vs-bare-transaction is explicitly named as not affected so nobody "fixes" it by symmetry. Filed rather than fixed is the right call at this size; the disposition (migrate it onto the shared helper) is recorded.

Self-reported and worth crediting: the suite command spelled test -- --maxWorkers=2, and vitest discards everything after a bare --, so the worker cap was silently dropped. Reported rather than glossed; the run is still a real full-package pass. Also check-engine-split-ratio first refused on a shallow clone (exit 2, its own text) and was recorded as such until a deeper fetch let it run clean at 97.3% — a refusal not counted as a pass.

Also now unblocked

#13264 merged at 03:39:24Z, so the packages/rest/src/rest-server.ts hard serial is released. And once #13270 merges, this card's own plan.ts fence lifts — at which point the dev's third, deliberately-unfiled item (whether os migrate plan should boot at a quieter level, which is a plan.ts change) becomes filable. ⭐ Correctly left alone rather than smuggled in.

---

Generated by Claude Code