Skip to content

Commit 93d2d67

Browse files
os-muskclaude
andauthored
test(runtime): pin the batch-row sink's disclose/withhold log coherence (#14684)
WIP checkpoint before the verification round. Claude-Session: https://claude.ai/code/session_0112hMx9hjJ9BgB28X97DS68 Co-authored-by: Claude <noreply@anthropic.com>
1 parent 5dee191 commit 93d2d67

2 files changed

Lines changed: 111 additions & 18 deletions

File tree

packages/metadata-protocol/src/protocol.ts

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2252,6 +2252,32 @@ export function clientFacingFailureText(err: unknown, fallback: string): string
22522252
* persisted was silently dropped (the row reports `success: false` and the
22532253
* counters reconcile), which is the AGENTS.md judgment question the durability
22542254
* levels turn on.
2255+
*
2256+
* ## [#14403] …and the DISCLOSED row deliberately logs NOTHING
2257+
*
2258+
* Since #14095 a driver unique violation arrives here already wrapped in the
2259+
* engine's `DUPLICATE_RECORD` envelope, which declares `status: 409` — so the
2260+
* row is disclosed and this function returns before the `console.warn` above.
2261+
* That was filed as a possibly LOST diagnostic: withholding used to be what
2262+
* carried the driver's own sentence to an operator, and disclosure removes
2263+
* that carrier.
2264+
*
2265+
* Measured on the real stack rather than reasoned about — a real `SqlDriver`
2266+
* over better-sqlite3 through this very sink, in `@objectstack/runtime`'s
2267+
* `batch-row-driver-text-real-driver.integration.test.ts` — the sentence is
2268+
* NOT lost: the engine's own insert door logs the envelope's `cause`
2269+
* (#14095 / #14390, `e instanceof DuplicateRecordError ? e.cause : e`,
2270+
* because the platform logger serializes only `message` and `stack`), so
2271+
* `UNIQUE constraint failed: bd_note.email` is in the server log with the
2272+
* failing column intact. The diagnostic moved one hop; it was not deleted.
2273+
*
2274+
* ⛔ So do NOT add a log line to the disclosed branch. It would restate what
2275+
* the engine already logged, once per duplicate row of a batch, at a site
2276+
* where the failure was handed to the CALLER — the third answer AGENTS.md's
2277+
* degradation rule names, which is "not a degradation at all". The invariant
2278+
* this function owes is one-directional and is pinned in BOTH directions by
2279+
* that integration file: it logs when it WITHHOLDS, and is silent when it
2280+
* does not.
22552281
*/
22562282
function clientFacingRowFailureText(err: unknown, fallback: string): string {
22572283
// 500 as the fallback status: an error that declared nothing is a server

packages/runtime/src/batch-row-driver-text-real-driver.integration.test.ts

Lines changed: 85 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@ import { describe, it, expect, afterEach } from 'vitest';
4242
import { mkdtempSync, rmSync } from 'node:fs';
4343
import { tmpdir } from 'node:os';
4444
import { join } from 'node:path';
45+
import { inspect } from 'node:util';
4546
import { ObjectQL } from '@objectstack/objectql';
4647
import { ObjectStackProtocolImplementation } from '@objectstack/metadata-protocol';
4748
import { SqlDriver } from '@objectstack/driver-sql';
@@ -86,13 +87,27 @@ const NOTE = {
8687
*/
8788
const ABSENT_TENANCY_TABLE = 'sys_organization';
8889

90+
/**
91+
* [#14403] The first bytes of the batch-row sink's OWN log line
92+
* (`clientFacingRowFailureText`, `metadata-protocol/src/protocol.ts`). A
93+
* literal rather than an import: the sink keeps that function private on
94+
* purpose, and what this suite pins is the line an OPERATOR reads, which is
95+
* the string itself.
96+
*/
97+
const SINK_WITHHOLD_PREFIX = "[Protocol] Withheld a caught error's text from a batch row";
98+
8999
describe('[#8502] a REAL driver fault is withheld from every batch row', () => {
90100
/** [#10629] The expected-noise capture belonging to the latest rig. */
91101
let noise: ExpectedReadRefusalCapture | null = null;
92102
let dir: string | null = null;
93103
let engine: ObjectQL | null = null;
104+
/** [#14403] Undoes the latest rig's `console.warn` recorder. */
105+
let restoreWarn: (() => void) | null = null;
94106

95107
afterEach(async () => {
108+
// [#14403] First, so a throw below can never leave `console.warn` patched.
109+
restoreWarn?.();
110+
restoreWarn = null;
96111
try { await engine?.destroy(); } catch { /* noop */ }
97112
engine = null;
98113
if (dir) { rmSync(dir, { recursive: true, force: true }); dir = null; }
@@ -145,11 +160,29 @@ describe('[#8502] a REAL driver fault is withheld from every batch row', () => {
145160
engine.registry.registerObject(o as any, 'com.objectstack.test.8502');
146161
}
147162
const protocol: any = new ObjectStackProtocolImplementation(engine as any);
148-
return { protocol, real, rawOf: () => raw };
163+
164+
// [#14403] Record the sink's own withhold line so BOTH directions of
165+
// its decision can be asserted: it must log exactly when it withheld.
166+
// ⛔ Recorded, never muted — every call is forwarded to the real
167+
// `console.warn`, so what a shard log shows is unchanged by this
168+
// suite. The recorder wraps whatever `console.warn` is current, so it
169+
// composes with the driver-channel pass-through above rather than
170+
// replacing it.
171+
const sinkWarnings: string[] = [];
172+
const outerWarn = console.warn;
173+
restoreWarn = () => { console.warn = outerWarn; };
174+
console.warn = (...args: unknown[]) => {
175+
if (typeof args[0] === 'string' && args[0].startsWith(SINK_WITHHOLD_PREFIX)) {
176+
sinkWarnings.push(args.map((a) => (typeof a === 'string' ? a : inspect(a))).join(' '));
177+
}
178+
(outerWarn as (...a: unknown[]) => void)(...args);
179+
};
180+
181+
return { protocol, real, rawOf: () => raw, sinkWarnings };
149182
}
150183

151184
it('deleteManyData leaks neither the DELETE statement nor the bound id it names', async () => {
152-
const { protocol, real, rawOf } = await rig();
185+
const { protocol, real, rawOf, sinkWarnings } = await rig();
153186
await engine!.insert('bd_parent', { id: 'p1', name: 'kept' });
154187
await engine!.insert('bd_child', { id: 'c1', name: 'dependent', parent: 'p1' });
155188

@@ -180,6 +213,19 @@ describe('[#8502] a REAL driver fault is withheld from every batch row', () => {
180213
expect(payload).not.toContain('SQLITE');
181214
expect(payload).not.toContain('bd_child');
182215

216+
// ── [#14403] The sink's OPERATOR half, direction one: it withheld,
217+
// so it LOGGED — and the line carries the driver's own sentence whole.
218+
// That is what keeps withholding distinguishable from DELETING the
219+
// diagnostic, which is the failure this file's sink was built against.
220+
//
221+
// It is also the live control for the disclosed row in the next test,
222+
// where the same recorder on the same rig must see nothing: without
223+
// this assertion a green zero over there could mean the recorder was
224+
// never wired rather than that the sink stayed silent.
225+
expect(sinkWarnings).toHaveLength(1);
226+
expect(sinkWarnings[0]).toContain('cause (withheld from the response)');
227+
expect(sinkWarnings[0]).toContain('FOREIGN KEY constraint failed');
228+
183229
// Non-vacuity on the other side: the row is still there, so the
184230
// failure was real rather than a swallowed success.
185231
expect(await engine!.findOne('bd_parent', { where: { id: 'p1' } })).toBeTruthy();
@@ -189,7 +235,7 @@ describe('[#8502] a REAL driver fault is withheld from every batch row', () => {
189235
});
190236

191237
it('batchData create leaks neither the INSERT statement nor the values it carries', async () => {
192-
const { protocol, rawOf } = await rig();
238+
const { protocol, rawOf, sinkWarnings } = await rig();
193239
await engine!.insert('bd_note', { id: 'n1', body: 'first', email: 'dup@example.com' });
194240

195241
const res: any = await protocol.batchData({
@@ -247,22 +293,43 @@ describe('[#8502] a REAL driver fault is withheld from every batch row', () => {
247293
expect(payload).not.toContain('UNIQUE constraint failed');
248294
expect(payload).not.toContain('SQLITE_CONSTRAINT');
249295

250-
// ── ⚠️ The OPERATOR half of this row is a KNOWN RESIDUAL, not a pin ──
251-
// Measured on this exact rig: with the row disclosed, the sink returns
252-
// before its `console.warn`, so the warn fires ZERO times and the
253-
// driver's own sentence — `UNIQUE constraint failed: bd_note.email` —
254-
// reaches neither the response nor the console. Withholding used to be
255-
// what carried it to an operator; disclosure removed the carrier
256-
// without replacing it.
296+
// ── [#14403] The OPERATOR half — re-measured, and now a PIN ────────
297+
// What stood here called this a KNOWN RESIDUAL and deliberately
298+
// asserted nothing, on the reading that the driver's own sentence
299+
// "reaches neither the response nor the console". Re-measured on this
300+
// exact rig, one half of that holds and the other does not — so it is
301+
// pinned instead of left as prose that can drift:
302+
//
303+
// * TRUE — the sink returns before its `console.warn`, so its own
304+
// line fires ZERO times for this row. That is CORRECT rather than
305+
// a loss: the line exists to record a WITHHOLD, and nothing was
306+
// withheld. The caller received the producer's authored sentence.
307+
// * FALSE — "nor the console". The driver's sentence does reach an
308+
// operator one layer down, on the engine's insert door:
309+
// `ERROR Insert operation failed {"object":"bd_note","error":
310+
// {"message":"UNIQUE constraint failed: bd_note.email …"}}`.
311+
// That line takes the envelope's `cause` on purpose (#14095 /
312+
// #14390, `e instanceof DuplicateRecordError ? e.cause : e`,
313+
// because the platform logger serializes only `message` and
314+
// `stack`) and is pinned in objectql's
315+
// `driver-fault-redaction.test.ts`, which asserts the failing
316+
// column survives in it. The diagnostic moved one hop; it was
317+
// never deleted.
318+
//
319+
// ⇒ There is nothing to repair in `metadata-protocol/src/protocol.ts`,
320+
// and adding a second log line to its disclosed branch would be wrong
321+
// twice over: it would restate what the engine already logged, once
322+
// per duplicate row of a batch, at a site where the failure was handed
323+
// to the CALLER — which AGENTS.md's degradation rule names as not a
324+
// degradation at all.
257325
//
258-
// ⛔ Deliberately NOT asserted either way here: asserting the zero
259-
// would PIN the loss as correct, and the remedy is one file over in
260-
// `metadata-protocol/src/protocol.ts`, which is another card's surface.
261-
// The seed loader's twin of this defect IS fixed (`seedFailureCause`
262-
// now reaches through `cause`) and is pinned in
263-
// `seed-loader-driver-text-real-driver.integration.test.ts`; this one
264-
// is tracked as the residual on #14403. When it is taken, the pin
265-
// belongs right here.
326+
// So what is pinned is the sink's decision/log COHERENCE, in both
327+
// directions on one rig: it logs when it withholds (the
328+
// `deleteManyData` case above, same recorder) and is silent when it
329+
// discloses (here). A regression that started withholding this row
330+
// again reddens both at once — the sentence assertions up top, and
331+
// this zero.
332+
expect(sinkWarnings).toEqual([]);
266333
});
267334

268335
it('a stopped batch does not re-publish the withheld text through its NOT_ATTEMPTED rows', async () => {

0 commit comments

Comments
 (0)