Skip to content

fix(objectql): report a refused write at warn, not error — the caller was already told - #17211

Merged
os-bill merged 4 commits into
mainfrom
claude/issue-17052-insert-failure-log-level
Sep 10, 2026
Merged

os-bill merged 4 commits into
mainfrom
claude/issue-17052-insert-failure-log-level

Conversation

@os-bill

@os-bill os-bill commented Sep 9, 2026 •

Copy link
Copy Markdown
Collaborator

Fixes #17052

Clause-②: no — this PR puts no new key on any published payload. It narrows what the three write doors claim at error; writeFailureLogMeta() is module-local and unexported, no name was added to any repo-wide list, and no schema, error code or accept set moved. Re-declared from the DELIVERED diff by the reviewing seat, not inherited from the claim. The patch grading below therefore stands.

insert, update and delete each end their catch with throw e, and logged
the failure at ERROR one statement earlier. AGENTS.md → Degradation log levels
names that exact shape and forbids it: "a failure handed to the CALLER is not
a degradation at all … Do not bolt a logger.error onto such a site."
The
requester is told, on every path, by the loudest means available. The three
doors now report at warn, carrying the same diagnosis.

⭐ Zone 2 first: the premise, verified before anything was written

The ruling was hung on "the propagation checker can structurally prove every
path out of these catches delivers". Measured, both halves:

The substance holds — every path delivers. Each catch body's only exit is
the unconditional throw e; there is no branch, no early return, no loop. The
checker's own model agrees: in catchDeliversFailure(), analyzeStmt on a
ThrowStatement returns { delivered: true, terminates: true } under the
comment "A rethrow IS delivery — the loudest kind." So the fork the dispatch
told me to stop for — some path exits without telling the caller — did not
occur
, and shape 1 lands.

The mechanism named in the ruling is unavailable, and that is measured, not
argued.
FAILURE_PROPAGATION_SITES cannot be used here. I probed it rather
than reasoning about it — added packages/objectql/src/engine.ts::insert to the
map, ran the gate, restored (restore verified by git hash-object against the
HEAD blob, 87a4b61… == 87a4b61…):

✗ 1 stale entr(ies) in FAILURE_PROPAGATION_SITES — the declaration excuses nothing, so delete it
  packages/objectql/src/engine.ts::insert
GATE EXIT=1

Two independent structural reasons:

  1. The catch is never a seam of that rule. analyzeSourceFile's step 1
    (collectGuardedCalls) returns empty — the raw ObjectQL verbs are
    deliberately not in DURABILITY_CRITICAL_CALLEES, and the checker's own
    header says why (The durability log-level gate cannot see the catch { return null; } seeder family — 15 files outside #12923's five, and neither widening path is cheap #12981: declaring them repo-wide drags in 36 quiet
    degradations). --list confirms it: of the log-level rule's 29 seams the
    only engine.ts entry is syncSchema()@14484.
  2. Even as a seam it would not attach. catchDeliversFailure() requires
    evidence — a declared propagation call. A bare throw e leaves
    evidence undefined, so the function returns undefined and the site is
    excused by the rethrow limb (propagatesAlways), never by a declaration.

⇒ A declaration here is stale by construction and turns pnpm check:durability-log-level red. ⛔ I did not weaken the checker to make it fit;
the correct reading is that the checker already proves delivery for this shape
by the route it reserves for rethrows. pnpm check:durability-log-level is
green on the delivered tree (29 seams, 63 self-test cases).

⛔ How I verified the two earlier rulings survived (#8682, #14095)

This is the part that nearly went wrong, and the trap is worth naming: the
Logger contract gives an Error slot to error/fatal only.
warn(message, meta?) has two parameters. And Error.message/Error.stack are
non-enumerable, so handing the error to warn as meta does not merely lose
the slot — it serialises {} and destroys the diagnosis one level down, which
is precisely the loss #14095 refused.

So the doors build the bag ObjectLogger.write() builds from the slot
({ …meta, error: { message, stack } }), via a module-local
writeFailureLogMeta(). Measured against the real platform logger — before
(old error call) vs after (new warn call), plus the naive move as a negative
control:

BEFORE: …Z ERROR Insert operation failed {"object":"sys_oauth_resource","error":{"message":"UNIQUE constraint failed: doc.identifier [statement and bound values redacted]","stack":"Error: …\n    at Database.prepare (…)"}}
AFTER : …Z WARN  Insert operation failed {"object":"sys_oauth_resource","error":{"message":"UNIQUE constraint failed: doc.identifier [statement and bound values redacted]","stack":"Error: …\n    at Database.prepare (…)"}}
REMAINDER IDENTICAL (level word stripped): true

NAIVE  (Error handed to warn as meta) : {"object":"sys_oauth_resource","error":{}}
NAIVE2 (Error spread flat into meta)  : {"object":"sys_oauth_resource"}
diagnosis present in NAIVE2: false

The sweep the card marked NOT MEASURED

AST matcher over packages/objectql/src (145 files carrying a catch),
following same-file helper calls one frame — the same visibility
collectLoggedLevels() has — and discriminating by path: an error log counts
only when it is on the same path as the rethrow.

verdict site
in class engine.ts:9710 → Find operation failed (via reportFindFailure)
in class engine.ts:11010 → Insert operation failed ⭐ positive control
in class engine.ts:12382 → Update operation failed ⭐ positive control
in class engine.ts:13832 → Delete operation failed
discriminated out hook-wrappers.ts:418 → logs at ERROR only on the branch that suppresses (onError:'log', then return); its rethrow branch logs nothing

Positive control: the matcher finds both sites the card established, by name.
Negative control: hook-wrappers.ts is a real ERROR-and-rethrow-in-one-catch
and is still classified out, so the path limb is exercised rather than vacuous —
and it is correct as it stands, because on the branch that logs, the caller is
not told.

Repaired: 3 of 4 — insert, update, delete. The write doors are one
shape in one file, and delete is the same defect the card describes.

Scoped out and filed: find. Its level was set deliberately by a separate
ruling (reportFindFailure's docblock weighs the driver's own surviving warn
against a second line) whose scope note explicitly reasoned about the write
verbs. Moving it is a decision, not a repair, so it is a card rather than a rider
— see out_of_scope_findings. Both stale prose rulings that would otherwise have
been left contradicting the code are corrected here: reportFindFailure's
"insert/update/delete keep their unconditional error", and
driver-fault-redaction.ts's specimen line and its "not to lower the level"
sentence (whose ⛔ was about this exposure's remedy and stays).

Consumers surveyed before moving the level

Every mention of the three messages, repo-wide (29 hits, 18 files), classified:

Depends on the level (4):

  • scripts/publish-smoke.sh — ⭐ the consumer that made this a release problem.
    SMOKE_ERROR_LOG_PATTERN fails a boot on any error-level line. Its own header
    rules the direction this change relies on: "⛔ The severity is NOT the
    predicate. Widening the error scan to WARN is the obvious repair and it is the
    wrong one: warn is where this repo deliberately puts functional degradation …
    so a healthy boot HAS warn lines"
    . So warn is the level this gate is built
    to tolerate, and no gate change is owed.
  • engine-strict-readonly-warning-truthful.test.ts (⭐ positive control — the pin
    the dispatch named), engine-find-missing-table-log-level.test.ts,
    driver-fault-redaction.test.ts, engine-update-duplicate-record.test.ts.
    All four moved, not deleted — each now asserts the level the door takes,
    and three gained an assertion that nothing is emitted at error any more, so
    the move cannot be read as a copy.

Does not depend on the level (7 runtime prose references): plugin-security
(×4), cli/src/utils/schema-migration-plugins.ts, and two test comments all
point operators at "the query engine's 'Insert operation failed' / 'Update
operation failed' entries"
— they name the message, never the level, so they
stay true. Verified by reading each string, not by grepping for a level word.

Level choice: warn, not debug

The card allowed either. debug is refused by evidence, not taste:
engine-find-missing-table-log-level.test.ts already pinned that this line must
not land at debug (its toHaveLength(0) assertion is untouched by this PR
and still passes), and the platform default level is info — at debug the
diagnosis #8682 and #14095 fought to keep would be invisible in production,
which Zone 1 rule 4 forbids. warn keeps it on by default and off the channel
publish-smoke reads.

Gates

62 derived families from dispatch-gates.mjs --commands, exit codes captured to
disk before any pipe, reconciled with --ran:
✓ dispatch-gates --ran: 62 derived famil(ies) accounted for — 62 run, 0 NOT-MEASURED.

  • 57 green, including check:durability-log-level (the neighbouring gate the
    card asks about — it stays green, and its rule was never the one firing here:
    it fires on a catch logging below error without rethrowing, the opposite
    direction), check:nul-bytes, check:published-files, check:doc-authoring,
    check:test-source-alias, check:type-check-coverage.
  • 5 initially exit 3 = PREREQUISITE NOT MET (they read a built tree). After
    pnpm --filter '@objectstack/objectql...' build, three of them are green:
    check:dts-closure (78/78 declaration files across 15 built packages),
    check:lean-entry-closure, check:sourcemap-no-sources-content.
  • 2 remain exit 3, and both want a WHOLE-TREE build — check:dual-build-cjs-loads
    (47 more packages unbuilt) and check:type-check-debt (its --re-measure half
    needs 17 more dependency closures, and it refuses to measure a different world).
    Recorded NOT MEASURED — neither pass nor failure — and left to CI, which builds
    the farm.

Tests — measured

pnpm --filter @objectstack/objectql test → 289/289 files, 4865/4865 tests
passing
. pnpm --filter @objectstack/objectql typecheck → OK.

⚠️ These took five acquisition windows: the container's shared heavy-verify lock
was held continuously by another seat's run (issue-8772/final.sh, pid 5749) for
~37 minutes, and four calls returned VERDICT queue-timeout (exit 99) · never acquired before the lock freed. The place was kept via OS_VERIFY_LOCK_SLOT
throughout, and nothing was recorded as a red on the strength of an unacquired
lock.

Running the WHOLE package rather than the message-matched files paid for
itself
— it found one consumer no grep could have reached, and two defects in
my own rig:

  • engine-delete-restricted-locale.test.ts — DELETE_RESTRICTED (409) message is shown verbatim to end users: English-only, leaks API names, and contains developer-facing advice #7307's pin that the delete door's
    developerMessage reaches the server log. It monkey-patches the logger method
    and reads the meta by argument position, so it never mentions Delete operation failed and the message survey could not see it. warn(message, meta)
    has no Error slot, so the meta moved from the third argument to the second.
    It now captures both levels and takes meta from the right position for each,
    which makes it a statement about the log rather than about one method.
  • engine-strict-readonly-warning-truthful.test.ts — warns collected every
    warn-level message, so the door's entry turned each strip assertion into a
    count of 2. The message isolation this suite already performed in
    stripLineLevels() now backs warns too, which is where the strip assertions
    actually read. (This is the accessor half of the isolation its docblock always
    described.)
  • engine-write-failure-log-level.test.ts — my new rig drove the delete door with
    an unrecognised id option, so the engine refused the call before the driver
    and the door logged nothing at all. Addressed through where, which is what
    [P2] A direct engine call silently drops sort/select/skip/populate — declared query contract, zero enforcement #4371's own refusal message names.

Changeset

.changeset/engine-write-failure-log-level-warn.md, patch — published
behaviour does move (the level is what an operator greps, and
publish-smoke.sh reads it structurally), so skip-changeset would have been
wrong. It states the FROM → TO for anyone grepping or alerting on these lines.

维护者速读(草稿)

改了什么 — packages/objectql 的三个写入门(insert/update/delete)在把失败抛回调用方之前打的那条日志,级别从 error 降到 warn;内容一个字节没动。

为什么改 — AGENTS.md 明文规定:失败已经交给调用方的 catch,不算降级,不该挂 logger.error。代价是实测过的:全新项目第一次启动时,@better-auth/oauth-provider 用 UNIQUE 约束做竞态保护(它自己的文档就是这么写的),我们却在它 catch 之前先打了一条 ERROR,连续六次把 publish-smoke / packed-tarballs 刷红,而那个候选版本的探针全绿。

风险与代价(含回滚) — 风险集中在一处:warn 没有 Error 参数位,而 Error 的 message/stack 不可枚举,直接把错误对象塞进 meta 会静默变成 {},#8682 和 #14095 两轮裁决保下来的诊断就没了。所以按 ObjectLogger 自己的拼法重建了那个字段,并用真实 logger 实测:除级别词外整行字节一致(负对照见上)。回滚成本低——单包单文件,三处调用点加一个模块内私有函数。已发布面只动了日志级别,changeset 里写清了 FROM → TO。

席位意见 — (留空)

你要做的 — 确认 warn 是这条线的终局级别(卡片允许 warn 或 debug,我按已有 pin 与默认日志级别选了 warn);以及 find 门的同类问题我按裁决另立卡而没有顺手改,请确认这个边界。

🤖 Generated with Claude Code

https://claude.ai/code/session_019wtfW1ZxGnP1XKGc9uZVms

`insert`, `update` and `delete` each end their catch with `throw e` and logged
the failure at ERROR one statement earlier. AGENTS.md → Degradation log levels
names that shape: "a failure handed to the CALLER is not a degradation at all
… Do not bolt a `logger.error` onto such a site."

The diagnosis two earlier rulings shaped survives the move. `warn(message,
meta?)` has no `Error` slot, and `Error.message`/`stack` are non-enumerable, so
handing the error over as meta would have serialised `{}`. The doors instead
build the `{ error: { message, stack } }` bag `ObjectLogger.write()` builds from
the slot, keeping #8682's redaction and #14095's choice of the driver error over
the envelope. The rendered line is byte-identical apart from the level word.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019wtfW1ZxGnP1XKGc9uZVms
@github-actions github-actions Bot added the size/m label Sep 9, 2026
@os-bill os-bill added the tests label Sep 9, 2026 — with Claude
@github-actions github-actions Bot added documentation Improvements or additions to documentation tooling labels Sep 9, 2026
@github-actions

github-actions Bot commented Sep 9, 2026 •

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

This PR changes 1 package(s): @objectstack/objectql, touching 2 documentable anchor(s).

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

  • content/docs/api/client-sdk.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/data-modeling/object-extensions.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/deployment/validating-metadata.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/getting-started/examples.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/kernel/runtime-services/data-service.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/kernel/runtime-services/examples.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/permissions/system-context.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/protocol/kernel/i18n-standard.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/ui/actions.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/ui/doc-pages.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/ui/index.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/ui/translations.mdx (via crm_account (literal, a string literal on a changed line))

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

  • content/docs/releases/v13.mdx (via crm_account (literal, a string literal on a changed line))
  • content/docs/releases/v17/17-1.mdx (via crm_account (literal, a string literal on a changed line))

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
  • 1 anchor(s) matched too much of the corpus to be a work list: ObjectQL (symbol, 68 pages)
  • 2 name(s) were too generic to anchor anything (single lowercase words)
  • the SDK route bridge reached 60 of 215 client-bound route-ledger rows — the other 155 have no registrar path: tail to select them, so pages documenting THEIR client methods cannot appear above, on this or any run. Of those 155: 0 are remediable by widening that discovery convention (an in-repo file declares the path; the convention did not scan it); 55 are structural — on a ledger where NOT ONE row is declared in-repo, so no discovery change reaches them at any price; 100 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 — 17 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 5a95b0e93d048d96736a5ab678642416b6277c42 → packageMentionDocs.

Which tree this was computed on

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

node scripts/docs-audit/affected-docs.mjs --json 5a95b0e93d048d96736a5ab678642416b6277c42

⚠️ 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 5a95b0e93d048d96736a5ab678642416b6277c42 → pass the list as
args.docs, on the commit named under Which tree this was computed on.

…7052)

Running the whole package rather than the message-matched files found one
consumer a message grep could not see, plus two rig defects of my own:

- `engine-delete-restricted-locale.test.ts` — #7307's pin that the delete
  door's `developerMessage` reaches the SERVER LOG. It monkey-patches the
  logger method and reads the meta by ARGUMENT POSITION, so it never mentions
  `Delete operation failed` and no grep for that message could find it. Now
  captures both `warn` and `error`, taking meta from the right position for
  each, so it stays a statement about the log rather than about one method.
- `engine-strict-readonly-warning-truthful.test.ts` — `warns` collected every
  warn-level message, so the door's entry made each strip assertion count 2.
  The message isolation this suite already performed in `stripLineLevels()`
  now backs `warns` too, which is where the strip assertions actually read.
- `engine-write-failure-log-level.test.ts` — the delete door was driven with
  an unrecognised `id` option, so the engine refused the call before reaching
  the driver and the door logged nothing. Addressed through `where`, which is
  what #4371's refusal message names.

Full suite: 289/289 files, 4865/4865 tests. typecheck: OK.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_019wtfW1ZxGnP1XKGc9uZVms
@github-actions github-actions Bot added size/l and removed size/m labels Sep 9, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentation Improvements or additions to documentation size/l tests tooling

Projects

None yet

Development

Successfully merging this pull request may close these issues.

objectql: engine.insert logs Insert operation failed at ERROR inside a catch that rethrows — the case AGENTS.md names as "not a degradation at all"

2 participants