Skip to content

Commit 04f0cc4

Browse files
fix(objectql): redact a driver fault where it leaves the engine, not only in the engine's log line (#21335)
Fixes #21274 Clause-②: no ## What this changes A driver error that **leaves the ObjectQL engine** is now cut the way the engine's own log line has long been cut: the bound statement and the caller's values are removed. Its class, codes and the database's own diagnostic are kept. The cut runs once, at the engine boundary, through one helper, `redactPropagatedDriverFault`, in `packages/objectql/src/driver-fault-redaction.ts`. Every consumer that logs a propagated error gets it, and the auth library is the one measured. ⛔ No edit to `plugin-auth` source, its ObjectQL adapter, or its logger wiring. Its only change is one new test file. Security handling: this PR body, the commits, the changeset and the test names carry classes and positions only. Every pin uses a synthetic sentinel and asserts that it is absent. ## Measured driver shapes (H2) Measured off thrown errors (knex 3.3, better-sqlite3 13, node-postgres 8 on PostgreSQL 16, mysql2 3 on MySQL 8.0.46). The families were unknown column on insert, update and select; unique; not-null; type error; value too long. | Driver | Carries the statement or a caller value (cut) | Carries the class and code (kept) | |---|---|---| | better-sqlite3 `SqliteError` | `message`, `stack` (knex inlines the bound values) | class, `code` | | node-postgres `DatabaseError` | `message`, `stack` (the statement with placeholders; the value itself for 22P02); `detail` (unique: key-shaped line; not-null: the failing row); `where` (a bound value once the server enables `log_parameter_max_length_on_error`, measured both ways); `internalQuery` (statement text) | class, `name`, `code`, `severity`, `routine`, `file`, `line`, `position`, `schema`, `table`, `column`, `dataType`, `constraint`, `hint` | | mysql2 (plain `Error`) | `message`, `stack`, `sql`; `sqlMessage` (value-bearing for 1062 and 1366) | `code`, `errno`, `sqlState` | Each property has one cut rule, kept in one table in the helper: - `message` and `stack` take the shared statement cut. - `sql` and `internalQuery` become the statement marker. - `sqlMessage` takes the existing measured value templates. - A key-shaped pg `detail` keeps its identifier half (`Key (cols)=(` plus the value marker); any other `detail` and every `where` become a marker. - `cause` is cut recursively, to depth 4, the depth the shared predicates read to. The Postgres-generic names (`detail`, `where`, `internalQuery`) are cut only on an error carrying pg's `severity`. The result is a native `Error` with the input's prototype and every own property, symbol-keyed and non-enumerable ones included, with enumerability kept. The input is never mutated. Nothing to cut returns the same reference, and the cut is idempotent. ## One measured fork from the ruling's wording, reported rather than chosen silently The ruling says the propagated error "carries the same redaction the engine's own log line already applies". The **cut** is literally the same function: `splitDriverDump` is shared by both faces, and the log helper's output is byte-identical (its existing 50+ case suite is green). The **presentation** differs. The log line appends the marker. The propagated message keeps the statement's position and its leading verb: `VERB [statement and bound values redacted] - DIAGNOSTIC`. The verb names the statement's kind only, with no identifier and no value. The reason is measured (H4). The propagated message is read by classifiers the log line never feeds. For 9 families on each of 3 dialects (26 raised errors), I compared the REST answer (`mapDataError`: status, code, `field`) for the raw message, the appended form and the verb-head form: | Form | Answers moved (of 26) | |---|---| | appended marker (the log line's form) | **6**: SQLite unique-violation `field` lost (2; the column reader reads to end of line); pg 22P02 and 22001, MySQL 1366 and 1406 move from `500 DATABASE_ERROR` to `500 INTERNAL_ERROR` (the leak predicate recognised them only by the statement's leading verb) | | verb-head (this PR) | **0**: every status, code, `field` and leak verdict is equal | If the maintainer prefers the appended form, the cost is those six answers. ## Every engine site where a driver error leaves the engine (H1) Positions are `packages/objectql/src/engine.ts` at this PR's head. | Site | Driver calls reached | Verdict | |---|---|---| | `executeWithMiddleware` executor, `:5164`–`:5178` | `find` `:11768`, `findOne` `:12068`, `count` `:16991`, `aggregate` `:17103` (native and the `find` fallback), `insert` `:12712` (single, `bulkCreate`, the autonumber-resync creates), `update` `:13764` (by id and `updateMany`, prior reads included), `delete` `:16457` (by id and `deleteMany`, pre-reads included) | **redacted now**, one site; innermost, so middlewares see the cut error too | | `execute` `:17570` | `driver.execute` (raw command, caller `params` bound) | **redacted now** (`:17618`) | | `ObjectQL.transaction` `:17668` | commit / rollback, and a callback that reached the driver through the handle | **redacted now** at the rethrow (`:17737`); a callback error that already crossed a boundary comes back as the same reference | | `ScopedContext.transaction` | the same, scoped face | **redacted now** (`:18632`) | | `resolveSecretField` `:9027`, `resolveInternalField` `:9111` | `driver.find` with record ids bound | **redacted now** (`:9052`, `:9148`) | | the three write-door log lines (insert `:13689`, update `:15459`, delete `:16978`) | | **unchanged**: still computed from the raw error, before the boundary | | `SummaryRecomputeError.failures[].error` (`recomputeSummaries` `:10910`) | `this.update` / `this.aggregate` | **already safe by construction**: both exit through the seam; pinned | | `insertMany` partial-mode outcomes `{ ok: false, error }` | validation, hooks, secret encryption, autonumber seeding (`this.find`), reference checks (`this.findOne`) | **already safe by construction**: no direct driver call feeds a row error; the reads go through the seam | | `ScopedContext.beginTransaction` `:18746` / `commitTransaction` / `rollbackTransaction`; `ObjectQL.transaction`'s `beginTransaction` | BEGIN / COMMIT / ROLLBACK | **already safe**: those statements bind no caller value | | `init` `:9580` (connect), `checkDriversHealth` `:9643`, `destroy` / `close` | connect, health, disconnect | **out of scope**: no statement and no caller value | | `syncSchemas` `:18030`, `syncObjectSchema`, `dropObjectSchema`, `introspectDatasource` `:17995` | DDL and introspection | **out of scope**: statements composed from metadata, with no caller-bound value; boot and admin paths | | `datasource()` `:18117`, `getDriverByName`, `getDriverForObject` | hand the raw driver to the caller | **out of scope**: no engine boundary is crossed | ## H1–H5 - **H1: confirmed.** At the base, the three write doors logged a redacted copy and rethrew the raw error, and every other site above rethrew raw. - **H2: confirmed and refined.** pg `where` carries a value only under a server setting (measured both ways). pg's statement text binds by placeholder, so the pg value rides `detail`, or `message` for 22P02. The required kept-set (class, codes, identifiers, diagnostic) survives on every measured shape. - **H3: confirmed.** `DuplicateRecordError.cause` carried the raw statement and value out of the engine. It is cut now. `field` is computed in the engine from the raw error, before the boundary, and REST's envelope arm reads `field` off the envelope, so it does not move. The readers found are: - `isUniqueViolationError` and `uniqueViolationColumn` (code, errno, message, pg `detail`, `cause`); - `mapDataError`; - `isMissingTableError` (code, errno, message, the targeted-table symbol, `cause`); - `sanitizeRowError` (import rows); - `defaultIsTransientError` (core bulk-write). Each reader's verdict is pinned equal, raw against cut, on every measured shape. `sanitizeRowError` measured equal on 8 of 10 families; the other 2 are covered under acceptance notes. `SummaryRecomputeError`'s failures are already safe (pinned). - **H4: confirmed.** The REST answers do not move. That is pinned per shape (`mapDataError` status, code and `field` equal, raw against cut) in the new objectql file. The existing REST pins are listed under Gates. - **H5: confirmed.** After the engine fix no carrier shows the sentinel on SQLite, live PostgreSQL or live MySQL. The adapter rethrows the engine's error verbatim, so no `plugin-auth` source edit was needed. ## Pins - `packages/objectql/src/driver-fault-boundary-redaction.test.ts` (new): - per measured shape: no carrier holds the value; no carrier holds the bound statement (only its kind); class, codes and diagnostic kept; every shared classifier and the REST answer equal raw against cut; idempotent; the input is not mutated; - a non-driver error is returned as the same reference; - `DuplicateRecordError` over sqlite, pg and mysql (own fields kept, `cause` cut); - the driver's `DATABASE_ERROR` read envelope (non-enumerable `cause` cut, targeted-table symbol kept); - 13 engine doors × 3 dialects; - the envelope through insert and update; - a middleware sees the cut error; - `SummaryRecomputeError` failures; - **control:** the WARN line's meta is byte-identical to `writeFailureLogMeta(redactBoundStatement(raw))` on all three doors, and spelled out for three dialects. - `packages/plugins/plugin-auth/src/driver-fault-auth-log-carriers.test.ts` (new), on SQLite always and on live PostgreSQL / MySQL when `OS_TEST_POSTGRES_URL` / `OS_TEST_MYSQL_URL` are set, each in its own schema or database: - a unique index forced on `sys_user.name`, then two auth-table writes refused by the database: the sign-up user insert, which hits the library's error line plus the error object, and update-user, which hits the router's server-error line plus the error object; - no console line carries the sentinel, rendered as `console` renders it plus the hidden-field inspect, and neither do the engine's or the manager's logs or the HTTP bodies; - the envelope's class, code, `cause.code` and diagnostic survive. The live cells mirror the REST and runtime precedent of local env-gated cells, because the driver-sql testkit is test-only and not exported. - Re-judged, because they pinned the overturned "rethrown raw" contract. Each now asserts what it protected, not identity: - `driver-fault-redaction.test.ts`, 2 pins: the caller's 400 `INVALID_FIELD` answer and the unique-violation verdicts; - `engine-insert-duplicate-record.test.ts`, 8 assertion sites; - `engine-update-duplicate-record.test.ts`, 9 assertion sites: `cause` is the driver error as it leaves (same class, code and cut message), and an envelope still nests one deep. ## Reverse verification (one-shot, no permanent file) `node scripts/ablation-replace.mjs` (WRAP, trap-restored) rebinds the boundary name in `engine.ts` to an identity function. That turns all eight boundary sites off and leaves the helper intact. - Mutation leg: the anchor went from 1 to 0 and the blob changed. objectql was rebuilt, and `ablation-dist-preflight.mjs @objectstack/objectql MARKER` exited 0. - objectql pins: **61 red / 220 green**. The 47 engine-door pins and the 14 re-judged pins went red. Every helper-level shape pin and **all 16 WARN byte-identity controls stayed green**. - plugin-auth carrier pin (3 dialects): **6 red / 9 green**. Per cell, the two carrier pins went red, while non-vacuity, the engine-log control and the HTTP-answer pins stayed green. - Restore leg: the blob equals HEAD and `git diff HEAD` is empty. objectql was rebuilt, and `--absent` exited 0 with a clean tree. objectql **281/281**, plugin-auth **15/15**. ## Verification at `fd19d3661b` Package tests. Each exit was captured before any pipe; heavy runs went through `scripts/pm/os-verify-lock.sh`. - `pnpm --filter @objectstack/objectql exec vitest run --project local --maxWorkers=2`: **361 files, 7242 passed**. - `pnpm --filter @objectstack/plugin-auth exec vitest run --maxWorkers=2`: **117 files, 2489 passed, 10 skipped**. The 10 are the new file's live cells, which skip without the env. - The new carrier pin with `OS_TEST_POSTGRES_URL` (PostgreSQL 16) and `OS_TEST_MYSQL_URL` (MySQL 8.0.46): **15/15**, with zero sentinel occurrences in the run log. These ran against local servers. No CI job provisions those variables for plugin-auth, so in CI the live cells are red-capable but do not run. - `pnpm --filter @objectstack/driver-sql exec vitest run --maxWorkers=2`: **214 files passed, 11 skipped; 3578 passed, 202 skipped** (live cells). driver-sql has no dependency path to objectql. - `packages/rest/src/rest-duplicate-record-arm.test.ts`: **33/33**. - H3 consumers: every test file that reads a driver error's properties through an ObjectQL engine, 33 files in 10 packages, run at `c2cf5b1924`. Results: core 23, metadata-protocol 64, plugin-audit 47, plugin-security 86, plugin-sharing 157, rest (local) 94/95, rest (repo) 50, runtime 22, service-automation 31, cli (integration) 7. - The one red was `rest-duplicate-record-arm.test.ts`. Its precondition line asserted that the envelope's `cause` still carried the value into REST, which is the overturned contract. It is re-judged in `fd19d3661b` (33/33 above). REST's answer assertions in that test did not change. - Typecheck: the `typecheck` script of objectql, plugin-auth, driver-sql and rest, test layer included, is green for each. Gates: - `node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack --commands` derived 68 families at `fd19d3661b`. All 68 ran, and `--ran` with exit codes recorded reports: 68 run, 0 NOT-MEASURED (a derived zero, since every family recorded an exit code). - On the first pass, two were red and three needed a second look: - `check:query-options-erasure` was red: the new aggregate door erased its options. It now uses `satisfies EngineAggregateOptions`, and the ratchet holds. - `check:dual-build-cjs-loads` reported PREREQUISITE NOT MET (nothing measured) until every package had a `dist/`; the re-run is green (105 entry points across 66 packages load). - `check:type-check-debt` was cut by my 300 s per-gate timeout; the re-run with a longer cap is OK. - The ratchet and test-reading families (16) were re-run at `fd19d3661b`; all green. - The first derivation flagged its tree as behind `origin/main` with one changed input, `scripts/pm/fleet-write/dispatch.mjs`, which this diff does not touch. The re-derivation at the final head gave the same 68. ## File surface As claimed, plus two additions, reported here: - `packages/objectql/src/duplicate-record-error.ts`: doc comment only. Its `cause` note promised the driver error "WHOLE and unmodified". - `packages/rest/src/rest-duplicate-record-arm.test.ts`: one precondition line re-judged (above). REST source is untouched. The re-judged objectql pins (`driver-fault-redaction.test.ts`, `engine-insert-duplicate-record.test.ts`, `engine-update-duplicate-record.test.ts`) are pins in `packages/objectql`, as claimed. Changeset: `.changeset/21274-driver-fault-boundary-redaction.md` (`@objectstack/objectql` patch, `Clause-②: no`). ## Acceptance notes (not filed) - `defaultIsTransientError` (core bulk-write) classifies by message text. After the cut it judges only the database's own words, so a bound value or column name in the statement can no longer steer a retry verdict either way. - Import row text (`sanitizeRowError`) is unchanged on 8 of 10 measured families. For pg 22P02 and MySQL 1366 the row text used to repeat the caller's rejected value; it now reads the value marker. The changeset says so. - The engine's `Roll-up summary recompute failed` warn logs `err.message` of the failed parent update. That was raw and is now the cut message, because the error arrives after the inner boundary. - For a nested engine call (a hook's write that fails inside an outer write), the outer door's WARN line is computed from an already-cut error. The log cut is idempotent on the verb-head form, so the line's bytes match the raw-derived line on the measured shapes. - A pre-existing residue of the shared predicate, for both faces: a dump whose statement opens with a verb outside the predicate's list (`with`, `replace`) and whose diagnostic matches no dialect limb is not recognised, so nothing is cut. The engine's own statements open with the four listed verbs, while a raw `execute` command may not. That was observed and not reproduced through a public door, so it is not filed. The carrier would be the next PR that touches the shared leak predicate. --- _Generated by [Claude Code](https://claude.ai/code/session_017xfMoEjKUuSh2xYB8sCozp)_ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent 1911d7c commit 04f0cc4

10 files changed

Lines changed: 1490 additions & 83 deletions
Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
---
2+
'@objectstack/objectql': patch
3+
---
4+
5+
fix(objectql): a driver error that leaves the engine no longer carries the failing statement or the caller's values
6+
7+
Clause-②: no
8+
9+
The engine has cut the bound statement out of its own log line for a failed driver call for a long time, but it rethrew the driver's raw error. Any in-process code that logged what it caught, such as an auth library's error logger, printed the statement and the row's values. The same cut now runs where the error leaves the engine, so no consumer needs a patch of its own.
10+
11+
- **Where.** Every engine operation that reaches a driver: `find`, `findOne`, `count`, `aggregate`, `insert` (batch included), `update` and `delete` (by id and by predicate), `execute`, `transaction`, `resolveSecretField` and `resolveInternalField`.
12+
- **What is cut.** The statement and the caller's values, from the error's `message` and `stack`, from the properties drivers attach (mysql2's `sql` and `sqlMessage`; node-postgres' `detail`, `where` and `internalQuery`), and down the `cause` chain. A `DuplicateRecordError` keeps its own fields and carries a cut `cause`.
13+
- **What stays.** The error's class (`instanceof` still holds), `name`, `code`, `errno`, `sqlState`, Postgres' identifier fields (`constraint`, `table`, `column`, …) and the database's own diagnostic. The message now reads as the statement's kind, a `[statement and bound values redacted]` marker and the diagnostic. A Postgres key-shaped `detail` keeps its column list. Every REST answer keeps its status, code and `field`.
14+
- **What changes for a caller.** Code that read the statement or a value out of a driver error's message or properties now gets the marker instead. Branch on the class, `code` or `errno` instead. The driver error on a `DuplicateRecordError`'s `cause` is an equivalent copy, no longer the object the driver threw. An import's row report for a value-bearing database error no longer repeats the rejected value.

‎packages/objectql/src/driver-fault-boundary-redaction.test.ts‎

Lines changed: 625 additions & 0 deletions
Large diffs are not rendered by default.

‎packages/objectql/src/driver-fault-redaction.test.ts‎

Lines changed: 26 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@
2323
// the tolerant-fallback direction, not the loud one.
2424

2525
import { describe, it, expect } from 'vitest';
26-
import { isUniqueViolationError, uniqueViolationColumn } from '@objectstack/types';
26+
import { isUniqueViolationError, mapDataError, uniqueViolationColumn } from '@objectstack/types';
2727
import { ObjectQL } from './engine.js';
2828
import {
2929
VALUE_BEARING_TEMPLATES,
@@ -853,14 +853,23 @@ describe('#8682 half B — the write-path loggers', () => {
853853
}
854854
});
855855

856-
it('the RETHROWN error is untouched — the caller`s 400 must not move', async () => {
857-
// `mapDataError` reads the driver's raw message to extract the failing
858-
// field and answer `400 INVALID_FIELD`. Redacting what we THROW would break
859-
// that answer; the redaction is one argument at one call site.
856+
it('the caller`s 400 does not move — and since #21274 the rethrown error carries no caller value either', async () => {
857+
// `mapDataError` reads the thrown message to extract the failing field and
858+
// answer `400 INVALID_FIELD`. This pin used to hold that by asserting the
859+
// thrown error was the driver's RAW one, statement and values included —
860+
// which is the exposure #21274 closed for every in-process logger. What it
861+
// protects is the ANSWER, so the answer is what it asserts now: the cut at
862+
// the engine boundary keeps the diagnostic the field is read from.
860863
const { thrown } = await insertAgainstADriftedColumn();
861864

862-
expect(String(thrown?.message)).toContain('insert into');
863-
expect(String(thrown?.message)).toContain(SECRET);
865+
expect(String(thrown?.message)).not.toContain(SECRET);
866+
expect(String(thrown?.message)).not.toContain(DESCRIPTION);
867+
expect(String(thrown?.stack)).not.toContain(SECRET);
868+
expect(String(thrown?.message)).toContain('has no column named secret_note');
869+
expect(thrown?.code).toBe('SQLITE_ERROR');
870+
const answer = mapDataError(thrown, 'crm_account');
871+
expect(answer.status).toBe(400);
872+
expect(answer.body).toMatchObject({ code: 'INVALID_FIELD', field: 'secret_note' });
864873
});
865874

866875
/**
@@ -905,10 +914,13 @@ describe('#8682 half B — the write-path loggers', () => {
905914
}
906915
});
907916

908-
it('MySQL duplicate entry — the driver error reaches the caller UNTOUCHED, on `cause`', async () => {
909-
// Same boundary as above: the log narrows, and what the driver said is not
910-
// rewritten anywhere. `isUniqueViolationError` and `uniqueViolationColumn`
911-
// read this text downstream and must keep seeing it.
917+
it('MySQL duplicate entry — the driver error reaches the caller on `cause`, cut, with every verdict kept', async () => {
918+
// `isUniqueViolationError` and `uniqueViolationColumn` read this error
919+
// downstream and must keep answering as they did. This pin used to hold
920+
// that by asserting the `cause` was the driver's error UNTOUCHED, statement
921+
// and value included; #21274 cuts both where the error leaves the engine,
922+
// so what is asserted now is what those readers actually read — the code,
923+
// the diagnostic and the index name — and that the value is gone.
912924
//
913925
// ⚠️ [#14095] WHERE the caller finds it moved by one step, and only for a
914926
// recognised unique violation: the insert door now answers the
@@ -924,9 +936,10 @@ describe('#8682 half B — the write-path loggers', () => {
924936
expect((thrown as any)?.status).toBe(409);
925937

926938
const cause = (thrown as any)?.cause;
927-
expect(String(cause?.message)).toContain('insert into');
928-
expect(String(cause?.message)).toContain(SECRET);
939+
expect(String(cause?.message)).not.toContain(SECRET);
940+
expect(String(cause?.message)).not.toContain(DESCRIPTION);
929941
expect(String(cause?.message)).toContain('Duplicate entry');
942+
expect(String(cause?.message)).toContain("for key 'crm_account.secret_note'");
930943
expect(cause?.code).toBe('ER_DUP_ENTRY');
931944

932945
// The verdicts the downstream consumers ask of it, asked of the envelope.

0 commit comments

Comments
 (0)