diff --git a/integrationTests/database/condition-mutation-integrity.test.ts b/integrationTests/database/condition-mutation-integrity.test.ts new file mode 100644 index 0000000000..b5635f17f1 --- /dev/null +++ b/integrationTests/database/condition-mutation-integrity.test.ts @@ -0,0 +1,471 @@ +/** + * QA-714 — regression anchor for harper#1572 / PR #1911 ("fix(query): stop query planning + * from mutating the caller's conditions"), plus a probe of the adjacent corners the shipped + * unit test (unitTests/resources/conditionsArrayMutation.test.js) likely doesn't cover: + * NESTED `operator:'and'|'or'` sub-condition arrays, pagination sweeps, three distinct sort + * planner paths (secondary-indexed-matching-a-top-level-condition / secondary-indexed-nested- + * only / primary-key / non-indexed-postOrdering), array-form targets & array-form condition + * entries, and TRUE concurrent reuse of one shared conditions object. + * + * Core question: a caller-owned query object (its `conditions` array AND any nested + * `operator:'and'|'or'` sub-arrays) must come back from a query byte-identical to what the + * caller passed in (including recursive server-side value types), and remain safely reusable + * for a 2nd/3rd/concurrent query. + * + * App under test (integrationTests/database/condition-mutation-integrity/): a product-catalog + * service (`resources.js`) that builds ONE `conditions` array once at module scope -- + * `[{category='electronics'}, {or: [{price<500}, {createdAt>2024-01-01}]}]` -- and reuses it + * across a paginated sweep, a count, a live-refresh loop, and a burst of concurrent queries. + * Since Harper runs as a separate process from this test, and JS object identity can't cross + * the HTTP boundary, the oracle is: capture a PRISTINE snapshot of the held object from the + * server BEFORE any query runs, then after every query re-fetch the object's current JSON + * state and assert.deepStrictEqual it against the pristine copy. Section Q0c proves this + * oracle is not blind (it can detect an actual mutation) before we trust its silence. + * + * threads.count:1 is pinned in the Harper config so the held module-level arrays are + * genuinely the SAME JS reference across every request in the suite -- multi-threaded Harper + * gives each worker its own module instance, which would make cross-request aliasing (and the + * concurrency probe in particular) untestable. + * + * Reproduction: + * npm run test:integration -- "integrationTests/database/condition-mutation-integrity.test.ts" + * Harper SHA: b8c843a24 (main, includes PR #1911) + */ +import { suite, test, before, after } from 'node:test'; +import { AssertionError, ok, strictEqual, deepStrictEqual, throws } from 'node:assert'; +import { resolve } from 'node:path'; +import { setTimeout as sleep } from 'node:timers/promises'; +import { + setupHarperWithFixture, + teardownHarper, + sendOperation, + DEFAULT_ADMIN_USERNAME, + DEFAULT_ADMIN_PASSWORD, + type ContextWithHarper, +} from '@harperfast/integration-testing'; + +const FIXTURE_PATH = resolve(import.meta.dirname, 'condition-mutation-integrity'); +const SCHEMA = 'data'; +const AUTH = 'Basic ' + Buffer.from(`${DEFAULT_ADMIN_USERNAME}:${DEFAULT_ADMIN_PASSWORD}`).toString('base64'); +const PRODUCT_COUNT = 90; +const CATEGORIES = ['electronics', 'home', 'garden']; + +// ---------- Independent ground truth (mirrors resources.js Seed exactly) ------------------- +function seedRow(i: number) { + return { + id: `p-${String(i).padStart(4, '0')}`, + category: CATEGORIES[i % CATEGORIES.length], + price: 100 + ((i * 37) % 900), + createdAt: new Date(Date.UTC(2023, 0, 1) + i * 20 * 24 * 3600 * 1000), + rank: PRODUCT_COUNT - i, + }; +} +// electronics AND (price<500 OR createdAt>2024-01-01) +const CUTOVER = new Date('2024-01-01T00:00:00.000Z').getTime(); +function expectedIds(): Set { + const out = new Set(); + for (let i = 0; i < PRODUCT_COUNT; i++) { + const r = seedRow(i); + if (r.category === 'electronics' && (r.price < 500 || r.createdAt.getTime() > CUTOVER)) out.add(r.id); + } + return out; +} +const EXPECTED_IDS = expectedIds(); +// electronics-only (for the array-form probe: [['category','electronics']]) +const EXPECTED_ELECTRONICS_IDS = new Set( + Array.from({ length: PRODUCT_COUNT }, (_, i) => seedRow(i)) + .filter((r) => r.category === 'electronics') + .map((r) => r.id) +); + +suite('QA-714 conditions array mutation regression anchor (harper#1572 / PR #1911)', (ctx: ContextWithHarper) => { + let httpURL: string; + + before(async () => { + await setupHarperWithFixture(ctx, FIXTURE_PATH, { + config: { + threads: { count: 1 }, + logging: { console: true, level: 'error' }, + }, + env: {}, + }); + httpURL = (ctx.harper as any).httpURL; + + // Poll the probe route directly until it stops returning 404 (component is + // pre-installed; no restartHttpWorkers() -- that races and flakes on CI here). + const deadline = Date.now() + 120_000; + let ready = false; + while (Date.now() < deadline) { + try { + // Node's fetch has no default timeout, and a before() hook has no runner timeout either: + // without this a wedged server would hang the whole suite instead of failing the poll. + const res = await fetch(`${httpURL}/Product/`, { + headers: { Authorization: AUTH }, + signal: AbortSignal.timeout(3_000), + }); + await res.body?.cancel(); + if (res.status !== 404) { + ready = true; + break; + } + } catch { + /* not ready yet */ + } + await sleep(250); + } + ok(ready, 'Product route did not become ready within 120 seconds'); + }); + + after(async () => { + await teardownHarper(ctx); + }); + + // ---------- HTTP helpers ------------------------------------------------------------ + // On a non-200 the body carries the reason the route rejected the call; read it into the + // assertion message instead of leaving a bare status (and an unconsumed body) behind. + async function assertOK(res: Response, what: string): Promise { + if (res.status !== 200) { + const text = await res.text().catch(() => ''); + strictEqual(res.status, 200, `${what} should return 200, got ${res.status}: ${text}`); + } + return res.json(); + } + async function getJSON(path: string): Promise { + const res = await fetch(`${httpURL}${path}`, { + headers: { Authorization: AUTH }, + signal: AbortSignal.timeout(30_000), + }); + return assertOK(res, `GET ${path}`); + } + async function postJSON(path: string, body: unknown): Promise { + const res = await fetch(`${httpURL}${path}`, { + method: 'POST', + headers: { 'Content-Type': 'application/json', 'Authorization': AUTH }, + body: JSON.stringify(body), + signal: AbortSignal.timeout(30_000), + }); + return assertOK(res, `POST ${path}`); + } + function snapshot(which: 'live' | 'concurrent' | 'arrayForm'): Promise { + return getJSON(`/Snapshot/?which=${which}`); + } + function idsSorted(ids: string[]): string[] { + return [...ids].sort(); + } + + let pristineLive: any; + let pristineConcurrent: any; + let pristineArrayForm: any; + + // ========================================================================================== + // Q0 — setup, oracle self-check, seed + // ========================================================================================== + test('Q0a reset + capture pristine snapshots of all three held objects', async () => { + const r = await postJSON('/Reset/', {}); + ok(r.ok, 'Reset should succeed'); + pristineLive = await snapshot('live'); + pristineConcurrent = await snapshot('concurrent'); + pristineArrayForm = await snapshot('arrayForm'); + + // Shape sanity: top-level array of 2, entry[1] is the nested `or` group of 2. + strictEqual(pristineLive.conditions.length, 2, 'pristine live conditions should have 2 top-level entries'); + strictEqual(pristineLive.conditions[1].operator, 'or', 'entry[1] should be the nested or-group'); + strictEqual(pristineLive.conditions[1].conditions.length, 2, 'nested or-group should have 2 sub-conditions'); + strictEqual(pristineArrayForm.conditions.length, 1, 'pristine array-form conditions should have 1 tuple entry'); + deepStrictEqual( + pristineArrayForm.conditions[0], + ['category', 'electronics'], + 'array-form tuple should be [attr, value]' + ); + strictEqual( + pristineLive.types[1].conditions[1].value, + 'string', + 'createdAt condition must begin as a server-side string' + ); + }); + + test('Q0b ORACLE SELF-CHECK: deepStrictEqual must actually fire on a real mutation', () => { + // Prove the assertion we rely on everywhere below is not vacuously true. Take a + // structuredClone of pristine, inflict the EXACT two classes of mutation the original + // bug produced (a leaked top-level sort pseudo-condition, and a coerced/annotated + // value inside the NESTED or-group), and confirm deepStrictEqual throws on each. + const leakedPseudoCondition = structuredClone(pristineLive); + leakedPseudoCondition.conditions.push({ attribute: 'category', comparator: 'sort', descending: true }); + throws( + () => deepStrictEqual(leakedPseudoCondition, pristineLive), + AssertionError, + 'oracle failed to detect a leaked top-level sort pseudo-condition' + ); + + const mutatedNested = structuredClone(pristineLive); + mutatedNested.conditions[1].conditions[0].estimated_count = 42; // simulates a leaked cache annotation + throws( + () => deepStrictEqual(mutatedNested, pristineLive), + AssertionError, + 'oracle failed to detect a mutation inside the NESTED or-group' + ); + + const mutatedNestedValue = structuredClone(pristineLive); + mutatedNestedValue.conditions[1].conditions[1].value = '1999-01-01T00:00:00.000Z'; // simulates in-place coercion + throws( + () => deepStrictEqual(mutatedNestedValue, pristineLive), + AssertionError, + 'oracle failed to detect a coerced value inside the NESTED or-group' + ); + + const mutatedNestedType = structuredClone(pristineLive); + mutatedNestedType.types[1].conditions[1].value = 'Date'; + throws( + () => deepStrictEqual(mutatedNestedType, pristineLive), + AssertionError, + 'oracle failed to detect a server-side string-to-Date coercion' + ); + + // And confirm it does NOT fire on a genuinely identical (but distinct-object) copy. + deepStrictEqual(structuredClone(pristineLive), pristineLive, 'oracle false-positived on an untouched clone'); + }); + + test('Q0c seed 90 deterministic product rows', async () => { + const r = await postJSON('/Seed/', { count: PRODUCT_COUNT }); + ok(r.ok, 'Seed should succeed'); + strictEqual(r.count, PRODUCT_COUNT); + console.log(`[QA-714 Q0c] seeded ${PRODUCT_COUNT} rows; expected compound-match count=${EXPECTED_IDS.size}`); + }); + + // ========================================================================================== + // Q1 — sequential reuse (3x), sort by an attribute that MATCHES an EXISTING top-level + // condition (category): planner aligns in place via `orderAlignedCondition.descending = ...` + // on the matched TOP-level entry. This is the single most direct path to the original bug. + // ========================================================================================== + test('Q1 reuse liveConditions 3x with sort=category (top-level-aligned path)', async () => { + for (let i = 1; i <= 3; i++) { + const r = await getJSON('/RunOnce/?sortAttr=category&desc=true'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), `run ${i}: wrong result set`); + deepStrictEqual(r.conditionsAfter, pristineLive, `run ${i}: liveConditions mutated (top-level-aligned sort)`); + } + }); + + // ========================================================================================== + // Q2 — paginated sweep + reuse: page through results with limit/offset while sorted, using + // the SAME shared object for every page (the realistic "sweep" workload from the brief). + // ========================================================================================== + test('Q2 paginated sweep (limit/offset) reusing liveConditions across pages', async () => { + const pageSize = 4; + const seen = new Set(); + for (let offset = 0; offset < EXPECTED_IDS.size + pageSize; offset += pageSize) { + const r = await getJSON(`/RunOnce/?sortAttr=category&limit=${pageSize}&offset=${offset}`); + for (const id of r.ids) { + ok(!seen.has(id), `page at offset=${offset} re-returned id ${id} (torn/duplicated page)`); + seen.add(id); + } + deepStrictEqual(r.conditionsAfter, pristineLive, `offset=${offset}: liveConditions mutated mid-sweep`); + if (r.ids.length === 0) break; + } + deepStrictEqual(seen, EXPECTED_IDS, 'paginated sweep did not cover exactly the expected id set'); + }); + + // ========================================================================================== + // Q3 — NESTED-ONLY indexed sort attributes (price, createdAt): both live ONLY inside the + // nested `or` group, not at the top level, so `conditions.find` at the top level can't align + // them -> planner pushes a NEW top-level `{comparator:'sort'}` pseudo-condition instead. This + // is the highest-value probe: does the pseudo-condition (or any other annotation) leak onto + // the caller's TOP-level array, and does the untouched NESTED array stay byte-identical? + // ========================================================================================== + test('Q3 sort by price (indexed, nested-only) x2 -- top array must not grow, nested must not change', async () => { + for (let i = 1; i <= 2; i++) { + const r = await getJSON('/RunOnce/?sortAttr=price'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), `run ${i}: wrong result set`); + strictEqual( + r.conditionsAfter.conditions.length, + 2, + `run ${i}: top-level conditions array grew (leaked pseudo-condition)` + ); + deepStrictEqual(r.conditionsAfter, pristineLive, `run ${i}: liveConditions mutated (nested-only indexed sort)`); + } + }); + + test('Q3b sort by createdAt (Date-typed, indexed, nested-only) x2 -- coercion must not leak', async () => { + for (let i = 1; i <= 2; i++) { + const r = await getJSON('/RunOnce/?sortAttr=createdAt&desc=true'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), `run ${i}: wrong result set`); + strictEqual( + r.conditionsAfter.conditions.length, + 2, + `run ${i}: top-level conditions array grew (leaked pseudo-condition)` + ); + // The nested Date condition's value must still be the ORIGINAL ISO string, not + // coerced to a Date in place (harper#1572's exact failure mode, relocated to a + // nested sub-array where the shipped unit test never looked). + strictEqual( + r.conditionsAfter.conditions[1].conditions[1].value, + '2024-01-01T00:00:00.000Z', + `run ${i}: nested Date condition value was coerced in place` + ); + deepStrictEqual(r.conditionsAfter, pristineLive, `run ${i}: liveConditions mutated (nested Date sort+coercion)`); + } + }); + + // ========================================================================================== + // Q4 — primary-key sort path (attribute.isPrimaryKey branch) and non-indexed postOrdering + // path (rank) -- two more distinct planner branches, reusing the same array. + // ========================================================================================== + test('Q4a sort by id (primary key path) x2', async () => { + for (let i = 1; i <= 2; i++) { + const r = await getJSON('/RunOnce/?sortAttr=id'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), `run ${i}: wrong result set`); + deepStrictEqual(r.conditionsAfter, pristineLive, `run ${i}: liveConditions mutated (primary-key sort)`); + } + }); + + test('Q4b sort by rank (non-indexed, postOrdering path) x2 -- correctness + no mutation', async () => { + for (let i = 1; i <= 2; i++) { + const r = await getJSON('/RunOnce/?sortAttr=rank'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), `run ${i}: wrong result set`); + // rank = PRODUCT_COUNT - i, so ascending rank = descending seed-index; just confirm monotonic. + const ranks = r.ids.map((id: string) => PRODUCT_COUNT - Number(id.slice(2))); + const sortedRanks = [...ranks].sort((a, b) => a - b); + deepStrictEqual(ranks, sortedRanks, `run ${i}: rank sort order incorrect`); + deepStrictEqual( + r.conditionsAfter, + pristineLive, + `run ${i}: liveConditions mutated (non-indexed postOrdering sort)` + ); + } + }); + + // ========================================================================================== + // Q5 — select projection combined with sort, reusing the same array again. + // ========================================================================================== + test('Q5 select+sort reuse does not mutate liveConditions', async () => { + const r = await getJSON('/RunOnce/?sortAttr=category&select=id,price'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), 'wrong result set with select'); + deepStrictEqual(r.conditionsAfter, pristineLive, 'liveConditions mutated (select+sort)'); + }); + + // ========================================================================================== + // Q6 — count query (the "count" leg of the sweep+count+refresh workload) + one more bare + // reuse, confirming the FULL gauntlet above left the object pristine for a plain caller. + // ========================================================================================== + test('Q6 count query + final bare reuse of liveConditions', async () => { + const c = await getJSON('/Count/'); + strictEqual(c.count, EXPECTED_IDS.size, 'count query wrong total'); + deepStrictEqual(c.conditionsAfter, pristineLive, 'liveConditions mutated by count query'); + + const r = await getJSON('/RunOnce/'); + deepStrictEqual(idsSorted(r.ids), idsSorted([...EXPECTED_IDS]), 'final bare reuse wrong result set'); + deepStrictEqual(r.conditionsAfter, pristineLive, 'liveConditions mutated by final bare reuse'); + }); + + // ========================================================================================== + // Q7 — array-form TARGET (search(array) instead of search({conditions:array})) built from an + // array-form CONDITION ENTRY (`[attribute, value]` tuple) -- the OTHER clone branch in + // cloneConditions (Object.assign(condition.slice(), condition)). + // ========================================================================================== + test('Q7 array-form target + array-form condition entry, reused 3x (bare, bare, sorted)', async () => { + for (const qs of ['', '', '?sortAttr=category']) { + const r = await getJSON(`/RunArrayForm/${qs}`); + deepStrictEqual( + idsSorted(r.ids), + idsSorted([...EXPECTED_ELECTRONICS_IDS]), + `arrayForm '${qs}': wrong result set` + ); + deepStrictEqual(r.conditionsAfter, pristineArrayForm, `arrayForm '${qs}': arrayFormConditions mutated`); + strictEqual(r.conditionsAfter.conditions.length, 1, `arrayForm '${qs}': tuple array grew`); + ok(Array.isArray(r.conditionsAfter.conditions[0]), `arrayForm '${qs}': tuple entry lost its array-ness`); + } + }); + + // ========================================================================================== + // Q8 — TRUE concurrency: N parallel queries (Promise.all, single worker thread) sharing ONE + // conditions object. Any cross-talk would show up as divergent id sets/order across runs, a + // thrown coercion error, or a post-burst mutation of concurrentConditions. + // ========================================================================================== + test('Q8 N=12 concurrent queries sharing concurrentConditions (sorted desc)', async () => { + const r = await getJSON('/RunConcurrent/?n=12&sortAttr=category&desc=true'); + strictEqual(r.runs.length, 12); + const first = r.runs[0]; + for (let i = 1; i < r.runs.length; i++) { + deepStrictEqual(r.runs[i], first, `concurrent run ${i} diverged from run 0 (cross-talk)`); + } + deepStrictEqual(idsSorted(first), idsSorted([...EXPECTED_IDS]), 'concurrent runs returned wrong result set'); + deepStrictEqual(r.conditionsAfter, pristineConcurrent, 'concurrentConditions mutated by the concurrent burst'); + }); + + test('Q8b concurrentConditions still reusable unsorted after the concurrent burst', async () => { + const r = await getJSON('/RunConcurrent/?n=3'); + deepStrictEqual(idsSorted(r.runs[0]), idsSorted([...EXPECTED_IDS]), 'post-burst unsorted reuse wrong result set'); + deepStrictEqual(r.conditionsAfter, pristineConcurrent, 'concurrentConditions mutated after post-burst reuse'); + }); + + // ========================================================================================== + // Q9 — surface coverage: REST query params and the ops API (search_by_conditions). These + // build a FRESH condition object graph per HTTP request (JSON parse) so they cannot exhibit + // the caller-reuse defect themselves -- this is a sanity/no-crash check on other entry + // points, not an additional mutation oracle. + // ========================================================================================== + test('Q9a REST query params: sort+limit over the automatic API', async () => { + const res = await fetch(`${httpURL}/Product/?category=electronics&sort(+price)&limit(5)`, { + headers: { Authorization: AUTH }, + }); + strictEqual(res.status, 200, `REST sort+limit should return 200, got ${res.status}`); + const rows = (await res.json()) as any[]; + ok(Array.isArray(rows), 'REST sort+limit should return an array'); + strictEqual(rows.length, 5, 'REST sort+limit should return exactly five rows'); + ok( + rows.every((r) => r.category === 'electronics'), + 'REST sort+limit returned a non-electronics row' + ); + }); + + test('Q9b ops API search_by_conditions with nested or-group, run twice', async () => { + for (let i = 1; i <= 2; i++) { + const res = await sendOperation(ctx.harper, { + operation: 'search_by_conditions', + schema: SCHEMA, + table: 'Product', + operator: 'and', + conditions: [ + { search_attribute: 'category', search_type: 'equals', search_value: 'electronics' }, + { + operator: 'or', + conditions: [ + { search_attribute: 'price', search_type: 'less_than', search_value: 500 }, + { search_attribute: 'createdAt', search_type: 'greater_than', search_value: '2024-01-01T00:00:00.000Z' }, + ], + }, + ], + get_attributes: ['id'], + }); + const rows: any[] = Array.isArray(res) ? res : []; + deepStrictEqual( + idsSorted(rows.map((r) => r.id)), + idsSorted([...EXPECTED_IDS]), + `ops search_by_conditions run ${i} wrong result set` + ); + } + }); + + // ========================================================================================== + // Q10 — final overall re-verification across all three held objects, single clear verdict. + // ========================================================================================== + test('Q10 final verdict: all three held objects still byte-identical to pristine', async () => { + const finalLive = await snapshot('live'); + const finalConcurrent = await snapshot('concurrent'); + const finalArrayForm = await snapshot('arrayForm'); + const liveOk = JSON.stringify(finalLive) === JSON.stringify(pristineLive); + const concurrentOk = JSON.stringify(finalConcurrent) === JSON.stringify(pristineConcurrent); + const arrayFormOk = JSON.stringify(finalArrayForm) === JSON.stringify(pristineArrayForm); + console.log( + `\n[QA-714 Q10] liveConditions pristine=${liveOk} concurrentConditions pristine=${concurrentOk} ` + + `arrayFormConditions pristine=${arrayFormOk}\n` + + ` >>> ${ + liveOk && concurrentOk && arrayFormOk + ? 'FIX HOLDS -- caller conditions (incl. nested or-group) survive reuse, pagination, and concurrency (green regression anchor)' + : 'DEFECT -- a held conditions object was mutated by query planning; see per-section assertions above for exactly which one' + }` + ); + deepStrictEqual(finalLive, pristineLive, 'FINAL: liveConditions not pristine'); + deepStrictEqual(finalConcurrent, pristineConcurrent, 'FINAL: concurrentConditions not pristine'); + deepStrictEqual(finalArrayForm, pristineArrayForm, 'FINAL: arrayFormConditions not pristine'); + }); +}); diff --git a/integrationTests/database/condition-mutation-integrity/config.yaml b/integrationTests/database/condition-mutation-integrity/config.yaml new file mode 100644 index 0000000000..efffc0833f --- /dev/null +++ b/integrationTests/database/condition-mutation-integrity/config.yaml @@ -0,0 +1,5 @@ +graphqlSchema: + files: '*.graphql' +jsResource: + files: resources.js +rest: true diff --git a/integrationTests/database/condition-mutation-integrity/resources.js b/integrationTests/database/condition-mutation-integrity/resources.js new file mode 100644 index 0000000000..0e8a04b8d8 --- /dev/null +++ b/integrationTests/database/condition-mutation-integrity/resources.js @@ -0,0 +1,173 @@ +// QA-706 — regression anchor + adjacent-corner probe for harper#1572 / PR #1911 +// ("fix(query): stop query planning from mutating the caller's conditions"). +// +// Product-catalog service: builds ONE `conditions` array (WITH a nested `operator:'or'` +// sub-array) ONCE at module scope, then reuses it across a paginated sweep, a count, a +// live-refresh loop, and a burst of concurrent queries -- the natural "module-level held +// query filter" pattern the original bug report described. Every endpoint returns the +// CURRENT state of the held object (via /Snapshot/) so the test process -- which is a +// SEPARATE OS process from this Harper worker -- can deep-equal it against a pristine +// copy captured before any query ran. JS object identity can't cross the HTTP boundary, +// so a JSON snapshot + deepStrictEqual on the test side is the oracle. +// +// The test's Harper config pins threads.count:1 so `liveConditions` / `concurrentConditions` +// are genuinely the SAME JS array reference across every request in this suite. With more +// than one worker thread each gets its own module instance (no shared JS heap), which would +// make the concurrent cross-request aliasing scenario untestable. + +function buildConditions() { + return [ + { attribute: 'category', comparator: 'equals', value: 'electronics' }, + { + operator: 'or', + conditions: [ + { attribute: 'price', comparator: 'less_than', value: 500 }, + { attribute: 'createdAt', comparator: 'greater_than', value: '2024-01-01T00:00:00.000Z' }, + ], + }, + ]; +} + +// Array-form TARGET (search(array) instead of search({conditions: array})) built from an +// array-form CONDITION ENTRY (`[attribute, value]` tuple) -- a distinct clone code path in +// cloneConditions (`Object.assign(condition.slice(), condition)`). +function buildArrayFormConditions() { + return [['category', 'electronics']]; +} + +let liveConditions = buildConditions(); +let concurrentConditions = buildConditions(); +let arrayFormConditions = buildArrayFormConditions(); + +function qget(query, key) { + if (!query) return undefined; + return query.get ? query.get(key) : query[key]; +} + +function typeFingerprint(value) { + if (value instanceof Date) return 'Date'; + if (Array.isArray(value)) return value.map(typeFingerprint); + if (value && typeof value === 'object') { + return Object.fromEntries(Object.entries(value).map(([key, entry]) => [key, typeFingerprint(entry)])); + } + return value === null ? 'null' : typeof value; +} + +function snapshotState(conditions) { + return { conditions, types: typeFingerprint(conditions) }; +} + +// POST /Reset/ -> rebuild all three held objects fresh. Lets test sections isolate. +export class Reset extends Resource { + static loadAsInstance = false; + async post() { + liveConditions = buildConditions(); + concurrentConditions = buildConditions(); + arrayFormConditions = buildArrayFormConditions(); + return { ok: true }; + } +} + +// POST /Seed/ { count } -- deterministic product-catalog spread. +// category cycles electronics/home/garden; price ramps 100..999 so roughly a third of +// electronics rows are <500; createdAt ramps 2023-01-01.. so roughly half are >2024-01-01; +// rank = count-i (unindexed, monotonic) for the postOrdering-sort probe. +const CATEGORIES = ['electronics', 'home', 'garden']; +export class Seed extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const count = Number(b.count) || 90; + for (let i = 0; i < count; i++) { + await tables.Product.put({ + id: `p-${String(i).padStart(4, '0')}`, + category: CATEGORIES[i % CATEGORIES.length], + price: 100 + ((i * 37) % 900), + createdAt: new Date(Date.UTC(2023, 0, 1) + i * 20 * 24 * 3600 * 1000), + rank: count - i, + name: `Widget ${i}`, + }); + } + return { ok: true, count }; + } +} + +// GET /Snapshot/?which=live|concurrent|arrayForm -> current state of the held object. +export class Snapshot extends Resource { + static loadAsInstance = false; + async get(query) { + const which = qget(query, 'which') || 'live'; + if (which === 'concurrent') return snapshotState(concurrentConditions); + if (which === 'arrayForm') return snapshotState(arrayFormConditions); + return snapshotState(liveConditions); + } +} + +// GET /RunOnce/?sortAttr=&desc=&limit=&offset=&select= -> ONE query against liveConditions. +export class RunOnce extends Resource { + static loadAsInstance = false; + async get(query) { + const sortAttr = qget(query, 'sortAttr'); + const desc = qget(query, 'desc') === 'true'; + const limit = qget(query, 'limit'); + const offset = qget(query, 'offset'); + const select = qget(query, 'select'); + const options = { conditions: liveConditions }; + if (sortAttr) options.sort = { attribute: sortAttr, descending: desc }; + if (limit != null) options.limit = Number(limit); + if (offset != null) options.offset = Number(offset); + if (select) options.select = select.split(','); + const ids = []; + for await (const r of tables.Product.search(options)) ids.push(r.id); + return { ids, count: ids.length, conditionsAfter: snapshotState(liveConditions) }; + } +} + +// GET /RunArrayForm/?sortAttr= -> reuses arrayFormConditions. Without sortAttr, uses the +// bare-array TARGET form (search(array)); with sortAttr, wraps in object form (sort has no +// slot on a bare-array target) while still pointing `.conditions` at the SAME shared array. +export class RunArrayForm extends Resource { + static loadAsInstance = false; + async get(query) { + const sortAttr = qget(query, 'sortAttr'); + const ids = []; + if (sortAttr) { + for await (const r of tables.Product.search({ conditions: arrayFormConditions, sort: { attribute: sortAttr } })) + ids.push(r.id); + } else { + for await (const r of tables.Product.search(arrayFormConditions)) ids.push(r.id); + } + return { ids, count: ids.length, conditionsAfter: snapshotState(arrayFormConditions) }; + } +} + +// GET /RunConcurrent/?n=&sortAttr=&desc= -> fire N queries in TRUE parallel (Promise.all, +// same JS event loop / same worker thanks to threads.count:1) sharing ONE conditions object. +export class RunConcurrent extends Resource { + static loadAsInstance = false; + async get(query) { + const n = Number(qget(query, 'n')) || 8; + const sortAttr = qget(query, 'sortAttr'); + const desc = qget(query, 'desc') === 'true'; + const runOne = async () => { + const options = { conditions: concurrentConditions }; + if (sortAttr) options.sort = { attribute: sortAttr, descending: desc }; + const ids = []; + for await (const r of tables.Product.search(options)) ids.push(r.id); + return ids; + }; + const runs = await Promise.all(Array.from({ length: n }, runOne)); + return { runs, conditionsAfter: snapshotState(concurrentConditions) }; + } +} + +// GET /Count/ -> plain count query using liveConditions, no sort (the "count" leg of the +// paginated-sweep + count + live-refresh workload). +export class Count extends Resource { + static loadAsInstance = false; + async get() { + let count = 0; + for await (const _r of tables.Product.search({ conditions: liveConditions })) count++; + return { count, conditionsAfter: snapshotState(liveConditions) }; + } +} diff --git a/integrationTests/database/condition-mutation-integrity/schema.graphql b/integrationTests/database/condition-mutation-integrity/schema.graphql new file mode 100644 index 0000000000..ed547b5874 --- /dev/null +++ b/integrationTests/database/condition-mutation-integrity/schema.graphql @@ -0,0 +1,22 @@ +# QA-706 — regression anchor for harper#1572 / PR #1911: "fix(query): stop query planning +# from mutating the caller's conditions". +# +# Product-catalog service. `category`, `price`, and `createdAt` are secondary-indexed so a +# `sort` can take three different planner paths: +# - sort by `category`: matches an EXISTING top-level condition -> planner aligns the +# existing entry in place (sets `descending` on it) instead of pushing a new pseudo-condition. +# - sort by `price` / `createdAt`: indexed but only present INSIDE the nested `or` group, +# not at the top level -> planner can't find an alignment target and pushes a NEW +# `{ comparator: 'sort' }` pseudo-condition onto the TOP-level array. +# - sort by `id` (primary key): no secondary index but still index-order-aligned -> same +# pseudo-condition push, different code branch (`attribute.isPrimaryKey`). +# `rank` is intentionally NOT indexed, to exercise the in-memory postOrdering sort path +# (no pseudo-condition pushed at all). +type Product @table @export { + id: ID @primaryKey + category: String @indexed + price: Float @indexed + createdAt: Date @indexed + rank: Int + name: String +} diff --git a/integrationTests/database/eviction-phantom-null.test.ts b/integrationTests/database/eviction-phantom-null.test.ts new file mode 100644 index 0000000000..1cf78d1246 --- /dev/null +++ b/integrationTests/database/eviction-phantom-null.test.ts @@ -0,0 +1,362 @@ +/** + * QA-670 — does harper#1896 ("fix: TTL eviction/delete no longer orphans secondary-index + * entries (F-149)") ALSO eliminate the F-175 phantom null-keyed secondary-index entry that every + * removal path inserts (updateIndices(id, existing, null) resolves the new value to `null` + * instead of "absent", and indexNulls defaults to true, so removal INSERTS a [null, id] entry + * instead of only deleting the real one)? Or does #1896 fix only the narrow RocksDB TTL-batcher + * leg from the original issue framing (#1894), leaving the broader every-removal leak intact? + * + * CODE READING (this branch, resources/Table.ts): the PR's diff touches exactly ONE line, inside + * the SHARED `updateIndices()` closure used by every removal call site: + * - const value = record && (resolver ? resolver(record) : record[key]); + * + const value = record == null ? undefined : resolver ? resolver(record) : record[key]; + * All three removal call sites funnel through this same function with `record=null`: + * 1. Table.delete() -> _writeDelete()'s commit callback -> updateIndices(id, existingRecord, null) + * 2. TableResource.evict() (used by BOTH the read-triggered lazy-eviction path in + * ensureLoadedFromSource() AND runRecordExpirationEviction()) -> updateIndices(id, existing, null) + * 3. RocksDB's createEvictionBatcher().stageInto() (the background scheduleCleanup() sweep) -> + * updateIndices(item.key, entry.value, null, options) directly + * getIndexedValues(undefined, indexNulls) always returns undefined (utility/lmdb/commonUtility.ts), + * vs getIndexedValues(null, true) === [null] — so if the a-priori reading is right, the fix should + * suppress the phantom on ALL THREE call sites and BOTH engines, not just the RocksDB TTL batcher. + * This experiment MEASURES that instead of trusting the PR description or a static read. + * + * Design — four tables isolate the three removal call sites plus an update-in-place control (see + * schema.graphql for the exact TTL/scanInterval isolation of the sweep vs the lazy-evict leg): + * DelTable — explicit Table.delete(), no TTL anywhere. + * SweepTable — background TTL/expiration sweep (scheduleCleanup(); RocksDB batcher or LMDB + * per-record evict()). + * EvictTable — TableResource.evict() via the READ-triggered LAZY path only (scanInterval so + * large the background sweep can't fire in this test's window). + * ControlTable — update-in-place only, never deleted. Zero phantoms expected — proves the oracle + * isn't manufacturing them. + * + * Oracle (direct index-store reads, D-230/D-242 protocol — never search_by_value, which joins + * through the primary record and is blind to a dangling/phantom entry by construction; and never + * an unqualified getRange(), which on LMDB starts after `null` and silently skips null-keyed + * entries): + * nullKeyed — index.getRange({start:null}) entries with indexedValue===null. No row in + * this fixture ever legitimately has bucket=null, so ANY null-keyed entry is + * by construction a phantom (F-175 signature). + * danglingNonNull — index.getRange({start:null}) entries with indexedValue!==null whose + * primaryKey is NOT in the primaryStore dump (classic F-149-style dangling + * real-key entry pointing at a gone row). + * phantomForRemoved — of nullKeyed, how many point at an id this test actually removed (vs. some + * unrelated stray null). + * + * Run against BOTH this branch (PR #1896) and current main (baseline, no fix) to get the delta. + * + * Harper SHA (this branch, PR #1896 head): e54365be75e696994bca2785a7cdaa6bbebe50d1 + * Reproduction: + * npm run test:integration -- "integrationTests/database/eviction-phantom-null.test.ts" + * HARPER_STORAGE_ENGINE=lmdb npm run test:integration -- "integrationTests/database/eviction-phantom-null.test.ts" + */ +import { suite, test, before, after } from 'node:test'; +import { ok, strictEqual } from 'node:assert'; +import { resolve } from 'node:path'; +import { setTimeout as sleep } from 'node:timers/promises'; +import { setupHarperWithFixture, teardownHarper, type ContextWithHarper } from '@harperfast/integration-testing'; +// @ts-expect-error utils/client.mjs has no type declarations; runtime resolves fine +import { createApiClient } from '../apiTests/utils/client.mjs'; + +const FIXTURE_PATH = resolve(import.meta.dirname, 'eviction-phantom-null'); +const ENGINE = process.env.HARPER_STORAGE_ENGINE === 'lmdb' ? 'lmdb' : 'rocksdb'; +const skipSuite = process.platform === 'win32'; + +const N = 20; // rows per group (tens, not thousands) + +interface BaseRow { + id: string; + bucket: string; +} +interface IndexRow { + indexedValue: unknown; + primaryKey: string; +} + +const matrix: Array> = []; + +function ids(prefix: string, n: number): string[] { + return Array.from({ length: n }, (_, i) => `${prefix}-${String(i).padStart(4, '0')}`); +} + +suite(`QA-670 harper#1896 vs F-175 phantom-null [${ENGINE}]`, { skip: skipSuite }, (ctx: ContextWithHarper) => { + let client: ReturnType; + let httpURL: string; + let auth: string; + + before(async () => { + await setupHarperWithFixture(ctx, FIXTURE_PATH, { + config: { + threads: { count: 1 }, + logging: { console: true, level: 'error' }, + ...(ENGINE === 'lmdb' ? { storage: { engine: 'lmdb' } } : {}), + }, + env: {}, + }); + client = createApiClient(ctx.harper); + httpURL = ctx.harper.httpURL; + auth = client.headers.Authorization; + + // Readiness poll: hit the fixture's own probe route directly for non-404 (no restartHttpWorkers()). + const deadline = Date.now() + 120_000; + let ready = false; + while (Date.now() < deadline) { + try { + const probe = await fetch(`${httpURL}/Dump/?table=DelTable`, { + headers: { Authorization: auth }, + signal: AbortSignal.timeout(3_000), + }); + await probe.body?.cancel(); + if (probe.status !== 404) { + ready = true; + break; + } + } catch { + /* not ready yet */ + } + await sleep(250); + } + ok(ready, 'fixture routes did not become ready within 120 seconds'); + }); + + after(async () => { + console.log(`\n[QA-670 MATRIX ${ENGINE}]\n${JSON.stringify(matrix, null, 2)}`); + await teardownHarper(ctx); + }); + + async function getJSON(path: string): Promise { + const r = await fetch(`${httpURL}${path}`, { + headers: { Authorization: auth }, + signal: AbortSignal.timeout(30_000), + }); + if (r.status !== 200) { + const text = await r.text().catch(() => ''); + throw new Error(`${path} should return 200, got ${r.status}: ${text}`); + } + return r.json(); + } + async function post(path: string, body: unknown, timeoutMs = 30_000): Promise { + const r = await fetch(`${httpURL}${path}`, { + method: 'POST', + headers: { 'Content-Type': 'application/json', 'Authorization': auth }, + body: JSON.stringify(body), + signal: AbortSignal.timeout(timeoutMs), + }); + if (r.status !== 200) { + const text = await r.text().catch(() => ''); + throw new Error(`POST ${path} should return 200, got ${r.status}: ${text}`); + } + return r.json(); + } + async function dump(table: string): Promise { + return getJSON(`/Dump/?table=${table}`); + } + async function indexDump(table: string, attr = 'bucket'): Promise { + return getJSON(`/IndexDump/?table=${table}&attr=${attr}`); + } + async function waitForState(description: string, read: () => Promise, timeoutMs = 15_000): Promise { + const deadline = Date.now() + timeoutMs; + while (Date.now() < deadline) { + if (await read()) return; + await sleep(100); + } + throw new Error(`Timed out waiting for ${description}`); + } + async function waitForStableIndex(table: string, timeoutMs = 15_000): Promise { + const deadline = Date.now() + timeoutMs; + let previous = ''; + let stableReads = 0; + while (Date.now() < deadline) { + const current = JSON.stringify( + (await indexDump(table)).sort((a, b) => String(a.primaryKey).localeCompare(String(b.primaryKey))) + ); + stableReads = current === previous ? stableReads + 1 : 0; + if (stableReads >= 2) return; + previous = current; + await sleep(100); + } + throw new Error(`Timed out waiting for ${table} index to stabilize`); + } + + /** + * The 3-count oracle described in the task: for a set of removedIds against a table, + * danglingNonNull — real-key (non-null) index entries pointing at a gone row (any gone row, + * not just ones this test removed — classic F-149 shape). + * nullKeyed — ALL null-keyed index entries (no row here ever legitimately has + * bucket=null, so every one is a phantom). + * phantomForRemoved— of nullKeyed, how many point specifically at an id this test removed. + */ + async function measure(table: string, removedIds: Set) { + const base = await dump(table); + const baseIds = new Set(base.map((r) => r.id)); + const idx = await indexDump(table); + const nullKeyed = idx.filter((e) => e.indexedValue === null); + const danglingNonNull = idx.filter((e) => e.indexedValue !== null && !baseIds.has(e.primaryKey)); + const phantomForRemoved = nullKeyed.filter((e) => removedIds.has(e.primaryKey)); + return { + table, + baseCount: base.length, + indexCount: idx.length, + danglingNonNullCount: danglingNonNull.length, + nullKeyedCount: nullKeyed.length, + phantomForRemovedCount: phantomForRemoved.length, + removedCount: removedIds.size, + }; + } + + function report(label: string, m: Awaited>, expectPhantom: boolean) { + console.log( + `[QA-670 ${ENGINE}] ${label}: base=${m.baseCount} index=${m.indexCount} ` + + `danglingNonNull=${m.danglingNonNullCount} nullKeyed(=phantom)=${m.nullKeyedCount} ` + + `phantomForRemoved=${m.phantomForRemovedCount}/${m.removedCount} >>> ${ + m.nullKeyedCount === 0 && m.danglingNonNullCount === 0 + ? 'CLEAN (no F-149 dangling, no F-175 phantom)' + : m.nullKeyedCount > 0 + ? 'F-175 PHANTOM NULL-KEYED LEAK PRESENT' + : 'F-149-STYLE DANGLING (non-null) PRESENT' + }` + ); + matrix.push({ label, engine: ENGINE, expectPhantomPreFix: expectPhantom, ...m }); + } + + // ---- Q0: explicit delete() (fastest, no wait — runs first so a partial run still verdicts) -- + test('Q0 DelTable: explicit delete() phantom-null check', { timeout: 45_000 }, async () => { + const delIds = ids('del', N); + await post('/Load/', { table: 'DelTable', ids: delIds, bucket: 'DEL' }); + let base = await dump('DelTable'); + strictEqual(base.length, N, 'all rows present pre-delete'); + + await post('/Delete/', { table: 'DelTable', ids: delIds }); + await waitForState('all DelTable rows to be removed', async () => (await dump('DelTable')).length === 0); + await waitForStableIndex('DelTable'); + + const m = await measure('DelTable', new Set(delIds)); + report('Q0 explicit-delete', m, true); + strictEqual(m.baseCount, 0, 'all deleted rows gone from base store'); + strictEqual( + m.nullKeyedCount, + 0, + `explicit delete() must leave no null-keyed (phantom) index entry, got ${m.nullKeyedCount}` + ); + strictEqual( + m.danglingNonNullCount, + 0, + `explicit delete() must leave no dangling index entry, got ${m.danglingNonNullCount}` + ); + strictEqual( + m.phantomForRemovedCount, + 0, + `no removed id may retain a phantom index entry, got ${m.phantomForRemovedCount}/${N}` + ); + }); + + // ---- Q3: update-in-place control (fast, no removal — must show zero phantoms) --------------- + test( + 'Q3 ControlTable: update-in-place, zero phantoms expected (oracle sanity control)', + { timeout: 45_000 }, + async () => { + const ctrlIds = ids('ctrl', N); + await post('/Load/', { table: 'ControlTable', ids: ctrlIds, bucket: 'ORIG' }); + await post('/UpdateInPlace/', { table: 'ControlTable', ids: ctrlIds, bucket: 'UPDATED' }); + await waitForState('all ControlTable index entries to reflect the update', async () => { + const indexRows = await indexDump('ControlTable'); + return indexRows.length === N && indexRows.every((row) => row.indexedValue === 'UPDATED'); + }); + + const m = await measure('ControlTable', new Set()); // nothing removed + report('Q3 update-in-place-control', m, false); + strictEqual(m.baseCount, N, 'all control rows still present (never deleted)'); + strictEqual(m.indexCount, N, 'oracle control must see every control row in the raw index'); + strictEqual(m.nullKeyedCount, 0, 'update-in-place must NOT produce any null-keyed index entry'); + strictEqual(m.danglingNonNullCount, 0, 'update-in-place must NOT produce any dangling index entry'); + } + ); + + // ---- Q2: read-triggered LAZY eviction (TableResource.evict() called directly from a GET, ------ + // isolated from the background sweep by a huge scanInterval) -------------------------------- + test('Q2 EvictTable: read-triggered lazy eviction (evict()) phantom-null check', { timeout: 60_000 }, async () => { + const evictIds = ids('evict', N); + await post('/Load/', { table: 'EvictTable', ids: evictIds, bucket: 'EVICT' }); + let base = await dump('EvictTable'); + strictEqual(base.length, N, 'all rows present pre-expiry'); + + // expiration:2s — wait past it, then GET each id to trigger the lazy-eviction path directly + // (ensureLoadedFromSource -> TableResource.evict()), NOT the background sweep (scanInterval:300s). + await sleep(2_500); + for (const id of evictIds) { + const r = await fetch(`${httpURL}/EvictTable/${id}`, { + headers: { Authorization: auth }, + signal: AbortSignal.timeout(5_000), + }); + await r.body?.cancel(); + } + // give the fire-and-forget evict() commits a moment to land + const deadline = Date.now() + 15_000; + let baseLen = -1; + while (Date.now() < deadline) { + baseLen = (await dump('EvictTable')).length; + if (baseLen === 0) break; + await sleep(300); + } + await waitForStableIndex('EvictTable'); + + const m = await measure('EvictTable', new Set(evictIds)); + report('Q2 lazy-evict()', m, true); + strictEqual(m.baseCount, 0, `all lazily-evicted rows should be gone from base, got ${m.baseCount}`); + strictEqual( + m.nullKeyedCount, + 0, + `lazy evict() must leave no null-keyed (phantom) index entry, got ${m.nullKeyedCount}` + ); + strictEqual( + m.danglingNonNullCount, + 0, + `lazy evict() must leave no dangling index entry, got ${m.danglingNonNullCount}` + ); + strictEqual( + m.phantomForRemovedCount, + 0, + `no evicted id may retain a phantom index entry, got ${m.phantomForRemovedCount}/${N}` + ); + }); + + // ---- Q1: background TTL/expiration SWEEP (scheduleCleanup(); RocksDB batcher path or LMDB ---- + // per-record evict() path) -------------------------------------------------------------------- + test('Q1 SweepTable: background TTL/expiration sweep phantom-null check', { timeout: 75_000 }, async () => { + const sweepIds = ids('sweep', N); + await post('/Load/', { table: 'SweepTable', ids: sweepIds, bucket: 'SWEEP' }); + let base = await dump('SweepTable'); + strictEqual(base.length, N, 'all rows present pre-expiry'); + + // expiration:3s, scanInterval:1s — poll until the background sweep drains the table. NO + // intervening reads (isolates the sweep path from the lazy-read path tested in Q2). + const deadline = Date.now() + 45_000; + let baseLen = -1; + while (Date.now() < deadline) { + baseLen = (await dump('SweepTable')).length; + if (baseLen === 0) break; + await sleep(500); + } + await waitForStableIndex('SweepTable'); + + const m = await measure('SweepTable', new Set(sweepIds)); + report('Q1 background-sweep', m, true); + strictEqual(m.baseCount, 0, `all swept rows should be gone from base, got ${m.baseCount}`); + strictEqual( + m.nullKeyedCount, + 0, + `background sweep must leave no null-keyed (phantom) index entry, got ${m.nullKeyedCount}` + ); + strictEqual( + m.danglingNonNullCount, + 0, + `background sweep must leave no dangling index entry, got ${m.danglingNonNullCount}` + ); + strictEqual( + m.phantomForRemovedCount, + 0, + `no swept id may retain a phantom index entry, got ${m.phantomForRemovedCount}/${N}` + ); + }); +}); diff --git a/integrationTests/database/eviction-phantom-null/config.yaml b/integrationTests/database/eviction-phantom-null/config.yaml new file mode 100644 index 0000000000..efffc0833f --- /dev/null +++ b/integrationTests/database/eviction-phantom-null/config.yaml @@ -0,0 +1,5 @@ +graphqlSchema: + files: '*.graphql' +jsResource: + files: resources.js +rest: true diff --git a/integrationTests/database/eviction-phantom-null/resources.js b/integrationTests/database/eviction-phantom-null/resources.js new file mode 100644 index 0000000000..b38d5c8f69 --- /dev/null +++ b/integrationTests/database/eviction-phantom-null/resources.js @@ -0,0 +1,92 @@ +// QA-670 — F-175 phantom null-keyed index entry vs harper#1896 (F-149 fix). +// +// Direct-store oracle: IndexDump reads the raw secondary-index DBI via .getRange({ start: null }) +// (D-242: an UNQUALIFIED getRange() on LMDB starts after `null` and silently skips null-keyed +// entries — an explicit `start: null` is required to see the F-175 phantom). Dump reads the raw +// primary store, no join, so it is the ground truth for "is this id still a real row". +// +// Endpoints: +// POST /Load/ { table, ids: [...], bucket } — bulk insert. +// POST /Delete/ { table, ids: [...] } — explicit Table.delete() per id. +// POST /UpdateInPlace/ { table, ids: [...], bucket } — re-put same id with a new bucket value +// (record stays non-null; exercises the ordinary update branch of +// updateIndices(), never the removal branch). +// GET /Dump/?table=X — raw primaryStore.getRange() scan (base ground truth). +// GET /IndexDump/?table=X&attr=Y — raw index.getRange({ start: null }) scan (direct +// index-store read, D-242-safe, never joins through the primary record). + +function getTable(name) { + const t = tables[name]; + if (!t) throw new Error(`unknown table "${name}"`); + return t; +} +function qget(query, key) { + if (!query) return undefined; + return query.get ? query.get(key) : query[key]; +} + +export class Load extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const t = getTable(b.table); + const ids = b.ids || []; + const bucket = b.bucket ?? 'B'; + for (const id of ids) await t.put({ id, bucket }); + return { ok: true, table: b.table, count: ids.length }; + } +} + +export class Delete extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const t = getTable(b.table); + const ids = b.ids || []; + for (const id of ids) await t.delete(id); + return { ok: true, table: b.table, count: ids.length }; + } +} + +export class UpdateInPlace extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const t = getTable(b.table); + const ids = b.ids || []; + const bucket = b.bucket ?? 'UPDATED'; + for (const id of ids) await t.put({ id, bucket }); + return { ok: true, table: b.table, count: ids.length }; + } +} + +export class Dump extends Resource { + static loadAsInstance = false; + async get(query) { + const tableName = qget(query, 'table'); + const t = getTable(tableName); + const out = []; + for (const entry of t.primaryStore.getRange({ start: false, snapshot: false, versions: true })) { + if (entry.value == null) continue; // tombstone + if (typeof entry.key === 'symbol') continue; // internal metadata entry, not a row + out.push({ id: entry.key, bucket: entry.value.bucket }); + } + return out; + } +} + +export class IndexDump extends Resource { + static loadAsInstance = false; + async get(query) { + const tableName = qget(query, 'table'); + const attr = qget(query, 'attr') || 'bucket'; + const t = getTable(tableName); + const index = t.indices[attr]; + if (!index) throw new Error(`No index ${attr} on ${tableName}`); + const out = []; + for (const entry of index.getRange({ start: null })) { + out.push({ indexedValue: entry.key, primaryKey: entry.value }); + } + return out; + } +} diff --git a/integrationTests/database/eviction-phantom-null/schema.graphql b/integrationTests/database/eviction-phantom-null/schema.graphql new file mode 100644 index 0000000000..2b9fce6c6d --- /dev/null +++ b/integrationTests/database/eviction-phantom-null/schema.graphql @@ -0,0 +1,36 @@ +# QA-670 — does harper#1896 (F-149 fix) also eliminate the F-175 phantom null-keyed index +# entry on EVERY removal path, or only the narrow RocksDB TTL-eviction-batcher leg? +# +# Four tables isolate the three removal call sites plus an update-in-place control: +# DelTable — no TTL. Removed via explicit Table.delete() (_writeDelete -> updateIndices(id, +# existing, null)). +# SweepTable — table-level TTL (expiration:3, scanInterval:1). Removed by the BACKGROUND +# cleanup sweep (scheduleCleanup(): RocksDB batcher's stageInto() calls +# updateIndices() directly; LMDB takes the per-record TableResource.evict() path). +# EvictTable — table-level TTL (expiration:2) but a huge scanInterval:300 so the background +# sweep never fires inside this test's window. Removed only via the READ-triggered +# LAZY eviction path (ensureLoadedFromSource -> TableResource.evict() called +# directly from a GET, independent of the sweep timer) — isolates evict() from the +# sweep call site. +# ControlTable — no TTL, never deleted. Rows are only ever UPDATED IN PLACE (bucket changed, +# record stays non-null). Must show zero phantom null-keyed entries — proves the +# oracle itself doesn't manufacture phantoms out of ordinary updates. +type DelTable @table @export { + id: ID @primaryKey + bucket: String @indexed +} + +type SweepTable @table(expiration: 3, scanInterval: 1) @export { + id: ID @primaryKey + bucket: String @indexed +} + +type EvictTable @table(expiration: 2, scanInterval: 300) @export { + id: ID @primaryKey + bucket: String @indexed +} + +type ControlTable @table @export { + id: ID @primaryKey + bucket: String @indexed +} diff --git a/integrationTests/database/longtxn-index-orphan.test.ts b/integrationTests/database/longtxn-index-orphan.test.ts new file mode 100644 index 0000000000..f604f918c9 --- /dev/null +++ b/integrationTests/database/longtxn-index-orphan.test.ts @@ -0,0 +1,357 @@ +/** + * QA-601 — over-time transaction x secondary-index (I x K), MULTI-STORE `next`-chain corner. + * + * Anchored on #1407/#1411 (Abort over-time write transactions instead of force-committing, + * merged as commit 21ed179c2 / PR #1411). That fix is confirmed present on the checkout under + * test: `git merge-base --is-ancestor 3249fb58e 3dbcf7b9e` succeeds. It replaced the old + * force-commit-with-partial-writes path with abort+poison: a write-bearing transaction that + * exceeds `storage.maxTransactionOpenTime` is aborted, and `timedOut` is set so any further + * write/commit throws `transactionOpenTooLongError` instead of silently landing a partial + * write set (see resources/DatabaseTransaction.ts `transactionOpenTooLongError` doc comment). + * + * Existing qa-scratch coverage (qa176/qa309/qa314/qa317/qa318/qa455/qa-overtime-txn) already + * exercises SINGLE-store held transactions extensively, mostly against pre-#1411 commits. The + * first-party regression anchor `integrationTests/resources/txn-overtime-atomicity.test.ts` + * covers the same-table pre-await/post-await case. None of them combine the over-time axis with + * a MULTI-STORE (cross-table) transaction — confirmed via `grep -rl maxTransactionOpenTime` + * (single-store only) vs `grep -rln txnForContext` (only qa552/qa596, neither touching + * maxTransactionOpenTime). That gap is this test's target: `abortDueToTimeout()` + * (resources/DatabaseTransaction.ts) walks and poisons the whole `next` chain — but its own doc + * comment only claims to poison links that EXIST at the moment the monitor fires: + * + * abortDueToTimeout(): for (let txn = this; txn; txn = txn.next) { txn.timedOut = true; ... } + * + * HYPOTHESIS (disproven — see below): a request writes table A (creating+tracking the head + * DatabaseTransaction), sleeps past the threshold (monitor fires, poisons the head — chain is + * just [A], B never touched), then writes table B for the first time. If `txnForContext` + * (resources/Table.ts ~line 5026) created B's `next` link fresh at that point, it would inherit + * `open = CLOSED` from the head but NOT `timedOut`, and take the `immediateCommit` branch in + * `save()` — durably committing standalone, bypassing the poison. + * + * ACTUAL (traced + confirmed via server-side debug logging, see resources.js console.error + * trace captured below): this does NOT happen. `resources/Resource.ts`'s `applyContext` (the + * `transactional()` wrapper behind every static Table/Resource call, e.g. `tables.TableB.put()`) + * has its own explicit guard — `context?.transaction?.open === OPEN || context?.transaction?.timedOut` + * — that is checked BEFORE `txnForContext` is ever reached for the second store. Once the head is + * poisoned, this guard routes table B's write through the SAME poisoned ambient transaction + * instead of starting fresh, so it throws `transactionOpenTooLongError` immediately (confirmed in + * the debug trace: `next.open=undefined next.timedOut=undefined` — the `.next` link for table B + * was never even created). This guard is deliberate and documented in Resource.ts (citing exactly + * this class of hazard) and is exactly what closes the gap `abortDueToTimeout()`'s own comment + * worried about, for the standard Resource-API write path. Net: table B's write is rejected, NOT + * silently committed. Neither table survives — true cross-store atomicity holds. + * + * This is a legitimate negative result: a plausible, code-comment-motivated defect that does NOT + * reproduce via the standard Resource/Table API, adding coverage for an architectural corner + * (multi-store `next` chain) that no existing test — including the first-party anchor — exercises + * by name. + * + * Harper SHA: 3dbcf7b9e + * Reproduction: + * npm run test:integration -- "integrationTests/database/longtxn-index-orphan.test.ts" + */ +import { suite, test, before, after } from 'node:test'; +import { ok, strictEqual } from 'node:assert'; +import { resolve, join } from 'node:path'; +import { closeSync, existsSync, openSync, readSync, statSync } from 'node:fs'; +import { setTimeout as sleep } from 'node:timers/promises'; +import { setupHarperWithFixture, teardownHarper, type ContextWithHarper } from '@harperfast/integration-testing'; +// @ts-expect-error utils/client.mjs has no type declarations; runtime resolves fine +import { createApiClient } from '../apiTests/utils/client.mjs'; + +const FIXTURE_PATH = resolve(import.meta.dirname, 'longtxn-index-orphan'); +const SCHEMA = 'data'; +// Threshold low enough that a single real sleep() reliably crosses it on ONE transaction +// (not wall-clock across many short txns — see task methodology note). +const MAX_TXN_OPEN_MS = 500; +const HOLD_MS = 3000; // 6x threshold; monitor's setInterval(MAX_TXN_OPEN_MS) ticks multiple times mid-hold. +const skipSuite = process.platform === 'win32'; + +suite( + 'QA-601 over-time write-txn x multi-store next-chain vs secondary index [rocksdb]', + { skip: skipSuite }, + (ctx: ContextWithHarper) => { + let client: ReturnType; + let httpURL: string; + let procOutput = ''; + + before(async () => { + await setupHarperWithFixture(ctx, FIXTURE_PATH, { + config: { + storage: { maxTransactionOpenTime: MAX_TXN_OPEN_MS, debugLongTransactions: true }, + logging: { console: true, level: 'error' }, + }, + env: {}, + }); + client = createApiClient(ctx.harper); + httpURL = ctx.harper.httpURL; + + procOutput += ctx.harper.startupOutput?.stdout ?? ''; + procOutput += ctx.harper.startupOutput?.stderr ?? ''; + const proc = ctx.harper.process; + proc?.stdout?.on('data', (d: Buffer) => (procOutput += d.toString())); + proc?.stderr?.on('data', (d: Buffer) => (procOutput += d.toString())); + + // Readiness poll — workers register routes async (see integrationTests/database/ttl.test.ts pattern). + const deadline = Date.now() + 30_000; + let ready = false; + while (Date.now() < deadline) { + try { + const probe = await fetch(`${httpURL}/ReadyProbe/`, { + headers: { Authorization: client.headers.Authorization }, + signal: AbortSignal.timeout(3_000), + }); + await probe.body?.cancel(); + if (probe.status === 200) { + ready = true; + break; + } + } catch { + /* not ready */ + } + await sleep(250); + } + ok(ready, 'ReadyProbe route did not become ready within 30 seconds'); + }); + + after(async () => { + await teardownHarper(ctx); + }); + + function postJSON(path: string, body: unknown): Promise { + return fetch(`${httpURL}${path}`, { + method: 'POST', + headers: { 'Content-Type': 'application/json', 'Authorization': client.headers.Authorization }, + body: JSON.stringify(body), + signal: AbortSignal.timeout(30_000), + }); + } + + /** + * Assert a 200 without abandoning the body. An unread body holds its socket in undici's + * keep-alive pool, and these helpers run inside a suite that then waits on the over-time + * monitor — a leaked connection here shows up as a teardown hang, not as this failure. + */ + async function assertOK(res: Response, what: string): Promise { + if (res.status !== 200) { + const text = await res.text().catch(() => ''); + strictEqual(res.status, 200, `${what} should return 200, got ${res.status}: ${text}`); + } + } + + /** + * Count monitor firings so each trial must produce a new over-time event. + * + * Read only what was APPENDED since the last call: this runs in a 100ms poll loop for up to + * 5s per trial, and re-reading (and re-scanning) every log file from byte 0 each time is + * quadratic in the log Harper is actively writing. Per file we keep a byte offset plus the + * trailing partial line, so a match split across two reads is still counted exactly once; a + * file that shrank was rotated, so its cursor resets. + */ + const logCursors = new Map(); + let logMatches = 0; + function countOverTimeOccurrences(): number { + const logDir = (ctx.harper as any).logDir as string | undefined; + if (logDir) { + for (const name of ['hdb.log', 'stdout.log', 'stderr.log']) { + const p = join(logDir, name); + if (!existsSync(p)) continue; + const cursor = logCursors.get(p) ?? { pos: 0, carry: '' }; + try { + const size = statSync(p).size; + if (size < cursor.pos) { + cursor.pos = 0; + cursor.carry = ''; + } + if (size > cursor.pos) { + const fd = openSync(p, 'r'); + try { + // Cap the per-call read: sizing the buffer off the file would let a + // suddenly-verbose log force one huge synchronous allocation. The cursor + // advances either way, so the remainder is picked up on the next poll. + const buf = Buffer.allocUnsafe(Math.min(size - cursor.pos, 1 << 20)); + const read = readSync(fd, buf, 0, buf.length, cursor.pos); + cursor.pos += read; + const text = cursor.carry + buf.subarray(0, read).toString('utf8'); + const lastBreak = text.lastIndexOf('\n'); + const complete = lastBreak === -1 ? '' : text.slice(0, lastBreak + 1); + cursor.carry = lastBreak === -1 ? text : text.slice(lastBreak + 1); + logMatches += complete.match(/Transaction was open too long/gi)?.length ?? 0; + } finally { + closeSync(fd); + } + } + } catch { + /* ignore */ + } + logCursors.set(p, cursor); + } + } + // Also scan each file's un-terminated trailing line: the monitor's message is written to + // hdb.log before its newline is necessarily flushed, and a match parked in `carry` would + // otherwise stay invisible until the next line arrived. It moves into logMatches once the + // line completes, so this cannot double-count. + let carryMatches = 0; + for (const cursor of logCursors.values()) { + carryMatches += cursor.carry.match(/Transaction was open too long/gi)?.length ?? 0; + } + return logMatches + carryMatches + (procOutput.match(/Transaction was open too long/gi)?.length ?? 0); + } + + async function dumpA(): Promise> { + const r = await fetch(`${httpURL}/DumpA/`, { + headers: { Authorization: client.headers.Authorization }, + signal: AbortSignal.timeout(30_000), + }); + await assertOK(r, 'DumpA'); + return (await r.json()) as Array<{ id: string; tag: string }>; + } + async function dumpB(): Promise> { + const r = await fetch(`${httpURL}/DumpB/`, { + headers: { Authorization: client.headers.Authorization }, + signal: AbortSignal.timeout(30_000), + }); + await assertOK(r, 'DumpB'); + return (await r.json()) as Array<{ id: string; tag: string }>; + } + async function searchByTag(table: string, tag: string): Promise> { + const r = await client + .req() + .send({ + operation: 'search_by_value', + schema: SCHEMA, + table, + search_attribute: 'tag', + search_value: tag, + get_attributes: ['id', 'tag'], + }) + .timeout(30_000) + .expect(200); + const rows: any[] = Array.isArray(r.body) ? r.body : []; + return new Set(rows.map((row) => String(row.id))); + } + + /** Both-direction index<->primary consistency check for one table + tag. */ + async function checkConsistency(table: string, tag: string, baseRows: Array<{ id: string; tag: string }>) { + const indexHits = await searchByTag(table, tag); + const baseIds = new Set(baseRows.filter((r) => r.tag === tag).map((r) => r.id)); + const phantom = [...indexHits].filter((id) => !baseIds.has(id)); // index -> no live base row + const missing = [...baseIds].filter((id) => !indexHits.has(id)); // base row -> not findable via index + return { indexCount: indexHits.size, baseCount: baseIds.size, phantom, missing }; + } + + // ---- CONTROL: quick write to both tables under threshold commits atomically ---- + test('CONTROL: under-threshold cross-table write commits both A and B, index-consistent', async () => { + const tag = 'ctrl'; + const res = await postJSON('/CrossBaseline/', { tag }); + await assertOK(res, 'Baseline'); + await res.body?.cancel(); + + const [a, b] = await Promise.all([dumpA(), dumpB()]); + const rA = await checkConsistency('TableA', tag, a); + const rB = await checkConsistency('TableB', tag, b); + console.log( + `[QA-601 CONTROL] status=${res.status} A(base=${rA.baseCount},idx=${rA.indexCount}) B(base=${rB.baseCount},idx=${rB.indexCount})` + ); + strictEqual(rA.baseCount, 1, 'Table A should have the control row'); + strictEqual(rB.baseCount, 1, 'Table B should have the control row'); + strictEqual( + rA.phantom.length + rA.missing.length + rB.phantom.length + rB.missing.length, + 0, + 'no orphaned index entries in control' + ); + }); + + async function runCrossOvertimeTrial(tag: string) { + const overTimeBaseline = countOverTimeOccurrences(); + const t0 = Date.now(); + const res = await postJSON('/CrossOvertime/', { tag, holdMs: HOLD_MS }); + const elapsed = Date.now() - t0; + const body = (await res.json().catch(() => ({}))) as Record; + let overTimeCount = countOverTimeOccurrences(); + const deadline = Date.now() + 5_000; + while (overTimeCount <= overTimeBaseline && Date.now() < deadline) { + await sleep(100); + overTimeCount = countOverTimeOccurrences(); + } + const fired = overTimeCount > overTimeBaseline; + const [a, b] = await Promise.all([dumpA(), dumpB()]); + const rA = await checkConsistency('TableA', tag, a); + const rB = await checkConsistency('TableB', tag, b); + const aSurvived = rA.baseCount > 0; + const bSurvived = rB.baseCount > 0; + + const debugLines = procOutput + .split('\n') + .filter((line) => line.includes(`QA601-DEBUG ${tag}`)) + .join('\n'); + console.log( + `\n[QA-601 ${tag}] status=${res.status} elapsedMs=${elapsed} bError=${JSON.stringify((body as any).bError)}\n` + + ` overTimeFired=${fired}\n` + + ` TableA: base=${rA.baseCount} idx=${rA.indexCount} phantom=${rA.phantom.length} missing=${rA.missing.length}\n` + + ` TableB: base=${rB.baseCount} idx=${rB.indexCount} phantom=${rB.phantom.length} missing=${rB.missing.length}\n` + + ` *** aSurvived=${aSurvived} bSurvived=${bSurvived} clientStatus=${res.status} ***\n` + + ` --- server debug trace ---\n${debugLines}\n --- end trace ---` + ); + + return { res, fired, rA, rB, aSurvived, bSurvived }; + } + + // ---- PROBE run 1 ---- + test( + 'PROBE run 1: write A, hold past threshold (single txn), first-touch write B', + { timeout: 30_000 }, + async () => { + const { res, fired, rA, rB, aSurvived, bSurvived } = await runCrossOvertimeTrial('probe1'); + + // Hard precondition: the force-commit/abort path must have actually been entered on a + // single transaction (not inferred from wall-clock). + ok( + fired, + 'Long-transaction monitor must have logged "Transaction was open too long" — else this run does not cover the axis' + ); + + // Index/primary consistency must hold in BOTH directions on EACH table, regardless of + // which rows ultimately survived. + strictEqual(rA.phantom.length, 0, `Table A phantom index entries: ${JSON.stringify(rA.phantom)}`); + strictEqual(rA.missing.length, 0, `Table A missing index entries: ${JSON.stringify(rA.missing)}`); + strictEqual(rB.phantom.length, 0, `Table B phantom index entries: ${JSON.stringify(rB.phantom)}`); + strictEqual(rB.missing.length, 0, `Table B missing index entries: ${JSON.stringify(rB.missing)}`); + + // Cross-table atomicity: table A (the poisoned head) must NOT have survived. + strictEqual( + aSurvived, + false, + 'Table A (head, poisoned by the monitor) unexpectedly survived — should have been aborted/rolled back' + ); + + // Client must be told the request failed (never a silent-success 2xx over a torn write). + ok(res.status < 200 || res.status >= 300, `expected a non-2xx response, got ${res.status}`); + + // The core hypothesis check: table B's write must NOT escape the head's poison and land as + // a silently-committed partial write while the client is told the overall request failed. + // Per transactionOpenTooLongError's own contract ("the request rolls back cleanly instead + // of silently committing a partial write set"), table B surviving here would violate it. + strictEqual( + bSurvived, + false, + `DEFECT: client got status=${res.status} (reported failure) but table B's row durably committed anyway — ` + + `silent partial-write survival under a reported abort (multi-store next-chain poison gap)` + ); + } + ); + + // ---- PROBE run 2 (reproducibility) ---- + test('PROBE run 2: repeat to confirm reproducibility', { timeout: 30_000 }, async () => { + const { res, fired, rA, rB, aSurvived, bSurvived } = await runCrossOvertimeTrial('probe2'); + ok(fired, 'Long-transaction monitor must have fired on run 2 as well'); + strictEqual(rA.phantom.length, 0, `Run 2 Table A phantom: ${JSON.stringify(rA.phantom)}`); + strictEqual(rA.missing.length, 0, `Run 2 Table A missing: ${JSON.stringify(rA.missing)}`); + strictEqual(rB.phantom.length, 0, `Run 2 Table B phantom: ${JSON.stringify(rB.phantom)}`); + strictEqual(rB.missing.length, 0, `Run 2 Table B missing: ${JSON.stringify(rB.missing)}`); + strictEqual(aSurvived, false, 'Run 2: Table A (head) unexpectedly survived'); + ok(res.status < 200 || res.status >= 300, `Run 2: expected a non-2xx response, got ${res.status}`); + strictEqual(bSurvived, false, 'Run 2: DEFECT — table B row survived despite reported failure'); + }); + } +); diff --git a/integrationTests/database/longtxn-index-orphan/config.yaml b/integrationTests/database/longtxn-index-orphan/config.yaml new file mode 100644 index 0000000000..efffc0833f --- /dev/null +++ b/integrationTests/database/longtxn-index-orphan/config.yaml @@ -0,0 +1,5 @@ +graphqlSchema: + files: '*.graphql' +jsResource: + files: resources.js +rest: true diff --git a/integrationTests/database/longtxn-index-orphan/resources.js b/integrationTests/database/longtxn-index-orphan/resources.js new file mode 100644 index 0000000000..9a317738e9 --- /dev/null +++ b/integrationTests/database/longtxn-index-orphan/resources.js @@ -0,0 +1,106 @@ +// QA-601 — over-time write transaction x secondary index, multi-store `next`-chain corner. +// +// Mechanism (resources/DatabaseTransaction.ts, resources/Table.ts txnForContext, read at +// harper @ 3dbcf7b9e): the long-transaction monitor's abortDueToTimeout() poisons every link +// of a transaction's multi-store `next` chain that EXISTS at the moment it fires: +// for (let txn = this; txn; txn = txn.next) { txn.timedOut = true; txn.open = CLOSED; } +// HYPOTHESIS (disproven — see the test file's header for the full trace): if table B is +// touched for the first time AFTER the head (table A) is poisoned, txnForContext would create +// B's `next` link fresh, inheriting `open = CLOSED` but not `timedOut`, and slip through +// save()'s `immediateCommit` branch to durably commit standalone. Empirically this does NOT +// happen: resources/Resource.ts's `applyContext` (the transactional() wrapper behind every +// `tables.X.put()` call) checks `context.transaction.timedOut` BEFORE txnForContext is ever +// reached for the second store, so table B's write throws transactionOpenTooLongError +// immediately — confirmed via the console.error trace below (`next.open=undefined` — table B's +// `next` link is never even created). The console.error calls are debug instrumentation kept in +// place so the trace is visible in the test's captured stdout; they are load-bearing evidence, +// not incidental logging. +// +// Endpoints: +// POST /CrossOvertime/ { tag, holdMs } — write A, hold past threshold, write B (the probe) +// POST /CrossBaseline/ { tag } — write A then B quickly, no hold (control) +// GET /DumpA/ /DumpB/ — raw primary-store scan [{id,tag}] +// GET /ReadyProbe/ — { ok: true } readiness check + +function sleep(ms) { + return new Promise((r) => setTimeout(r, ms)); +} + +// POST /CrossOvertime/ { tag, holdMs } +export class CrossOvertime extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const tag = b.tag || 'cross'; + const holdMs = b.holdMs != null ? Number(b.holdMs) : 3000; + const t0 = Date.now(); + const ctx = this.getContext(); + console.error(`[QA601-DEBUG ${tag}] start ctx.transaction=${!!ctx.transaction}`); + // Phase 1: write TABLE A — creates+tracks the head DatabaseTransaction (A's store). + await tables.TableA.put({ id: `${tag}-a`, tag, payload: 'A' }); + console.error( + `[QA601-DEBUG ${tag}] after A write: open=${ctx.transaction?.open} timedOut=${ctx.transaction?.timedOut} db=${ctx.transaction?.db?.name ?? ctx.transaction?.db?.tableName ?? 'n/a'}` + ); + // Phase 2: hold past threshold — monitor should fire on the head here. TableB's `next` + // link does not exist yet, so only the head is in the poison walk. + await sleep(holdMs); + console.error( + `[QA601-DEBUG ${tag}] after sleep: open=${ctx.transaction?.open} timedOut=${ctx.transaction?.timedOut} next=${!!ctx.transaction?.next}` + ); + // Phase 3: FIRST touch of TABLE B, after the head was (predicted) poisoned+aborted. + let bError = null; + let bResult = null; + try { + bResult = await tables.TableB.put({ id: `${tag}-b`, tag, payload: 'B' }); + console.error(`[QA601-DEBUG ${tag}] B write returned OK, result=${JSON.stringify(bResult)}`); + } catch (error) { + bError = { message: error.message, code: error.statusCode ?? error.code }; + console.error(`[QA601-DEBUG ${tag}] B write THREW: ${error.message} code=${error.statusCode ?? error.code}`); + } + console.error( + `[QA601-DEBUG ${tag}] after B write attempt: head.open=${ctx.transaction?.open} head.timedOut=${ctx.transaction?.timedOut} ` + + `next.open=${ctx.transaction?.next?.open} next.timedOut=${ctx.transaction?.next?.timedOut}` + ); + return { ok: true, tag, elapsedMs: Date.now() - t0, bError }; + } +} + +// POST /CrossBaseline/ { tag } — control: write A then B quickly, well under threshold. +export class CrossBaseline extends Resource { + static loadAsInstance = false; + async post(query, body) { + const b = body || query || {}; + const tag = b.tag || 'baseline'; + await tables.TableA.put({ id: `${tag}-a`, tag, payload: 'A' }); + await tables.TableB.put({ id: `${tag}-b`, tag, payload: 'B' }); + return { ok: true, tag }; + } +} + +// GET /DumpA/ -> [{id,tag}] +export class DumpA extends Resource { + static loadAsInstance = false; + async get() { + const out = []; + for await (const r of tables.TableA.search({})) out.push({ id: r.id, tag: r.tag }); + return out; + } +} + +// GET /DumpB/ -> [{id,tag}] +export class DumpB extends Resource { + static loadAsInstance = false; + async get() { + const out = []; + for await (const r of tables.TableB.search({})) out.push({ id: r.id, tag: r.tag }); + return out; + } +} + +// GET /ReadyProbe/ -> { ok: true } +export class ReadyProbe extends Resource { + static loadAsInstance = false; + async get() { + return { ok: true }; + } +} diff --git a/integrationTests/database/longtxn-index-orphan/schema.graphql b/integrationTests/database/longtxn-index-orphan/schema.graphql new file mode 100644 index 0000000000..7a645d2d0e --- /dev/null +++ b/integrationTests/database/longtxn-index-orphan/schema.graphql @@ -0,0 +1,17 @@ +# QA-601 — over-time transaction x secondary-index, MULTI-STORE chain corner. +# +# Two separate tables (two separate RocksDB stores/paths) so a single logical write +# transaction that touches both chains a `next` DatabaseTransaction link +# (resources/Table.ts txnForContext, ~line 5026). `tag` is @indexed on both so we can +# cross-check index vs primary in both directions on each table independently. +type TableA @table @export { + id: ID @primaryKey + tag: String @indexed + payload: String +} + +type TableB @table @export { + id: ID @primaryKey + tag: String @indexed + payload: String +} diff --git a/integrationTests/security/mcp-record-scoped-rbac.test.ts b/integrationTests/security/mcp-record-scoped-rbac.test.ts new file mode 100644 index 0000000000..9d4bb732ab --- /dev/null +++ b/integrationTests/security/mcp-record-scoped-rbac.test.ts @@ -0,0 +1,528 @@ +/** + * QA-408 — Verify harper#1522 closes MCP authz bypasses F-092 (read) and F-093 (write). + * + * PR #1522 (`fix(mcp): enforce row-level RBAC on MCP application verb tools`, commit + * 2e3620c6e, merged 2026-06-29) introduced `liveResource()` in + * components/mcp/tools/application.ts: all 5 verb handlers now resolve the LIVE + * registry Resource class at call time instead of the base table class captured at + * tool-registration. This closes both bypasses in one shot. + * + * What we test: + * F-092 (read): lowuser MCP get_Doc on admin's row → denied (isError or empty), + * NOT the row. search_Doc → only lowuser-owned rows, NOT admin-owned. + * F-093 (write): lowuser MCP update_Doc/delete_Doc/create_Doc on denied rows → + * MCP error + NO persistence (verified by admin read-back). + * + * Controls (all must pass for result to be valid): + * POSITIVE CONTROL: admin MCP get/update/create/delete succeed and persist. + * OWN-ROW: lowuser can get and update its OWN row. + * REST ANCHOR: REST GET/PUT/DELETE as lowuser on admin's row → 403. + * + * Fixture: integrationTests/fixtures/mcp-row-authz — the same guards used by the + * focused MCP regression suite. + * + * Harper SHA: 1b45db9ea (v5.1.15 + 2e3620c6e merged). + * Run: npm run test:integration -- "integrationTests/security/mcp-record-scoped-rbac.test.ts" + */ +import { suite, test, before, after } from 'node:test'; +import { ok, strictEqual } from 'node:assert'; +import { resolve } from 'node:path'; +import { setTimeout as sleep } from 'node:timers/promises'; + +import { setupHarperWithFixture, teardownHarper, type ContextWithHarper } from '@harperfast/integration-testing'; +import { Client } from '@modelcontextprotocol/sdk/client/index.js'; +import { StreamableHTTPClientTransport } from '@modelcontextprotocol/sdk/client/streamableHttp.js'; + +const FIXTURE_PATH = resolve(import.meta.dirname, '../fixtures/mcp-row-authz'); +const HARPER_SHA = '1b45db9ea'; + +const LOWUSER = { username: 'qa408_lowuser', password: 'LowPw-408!' }; +const ROLE = 'qa408_writer'; + +const ADMIN_ROW = 'qa408-admin-row'; +const LOWUSER_ROW = 'qa408-lowuser-row'; + +// A row id lowuser will try to CREATE with owner=admin (should be denied). +const LOWUSER_CREATE_ID = 'qa408-lowuser-creates-for-admin'; + +// ─── Result tracking ────────────────────────────────────────────────────────── + +interface Finding { + op: string; + principal: string; + allowed: boolean | 'n/a'; + persisted?: boolean | 'n/a'; + verdict: 'ENFORCED' | 'BYPASS' | 'PASS' | 'FAIL' | 'N/A'; + note?: string; +} + +function recordFinding(f: Finding): void { + const line = ` ${f.op.padEnd(30)} | ${f.principal.padEnd(20)} | allowed=${String(f.allowed).padEnd(5)} | persisted=${String(f.persisted ?? 'n/a').padEnd(5)} | ${f.verdict}${f.note ? ' — ' + f.note : ''}`; + console.log(line); +} + +function log(msg: string): void { + const line = `[QA-408] ${msg}`; + console.log(line); +} + +// ─── MCP client helpers ─────────────────────────────────────────────────────── + +function basicAuth(u: string, p: string): string { + return `Basic ${Buffer.from(`${u}:${p}`).toString('base64')}`; +} + +interface ToolResult { + isError?: boolean; + content?: Array<{ type: string; text: string }>; +} + +async function appClient( + ctx: ContextWithHarper, + username: string, + password: string +): Promise<{ client: Client; transport: StreamableHTTPClientTransport }> { + const transport = new StreamableHTTPClientTransport(new URL('/mcp', ctx.harper.httpURL), { + requestInit: { headers: { Authorization: basicAuth(username, password) } }, + }); + const client = new Client({ name: 'qa408', version: '1.0.0' }, { capabilities: {} }); + await client.connect(transport); + return { client, transport }; +} + +async function call(client: Client, name: string, args: Record): Promise { + return (await client.callTool({ name, arguments: args })) as ToolResult; +} + +function resultText(r: ToolResult): string { + return r.content?.map((c) => c.text ?? '').join('') ?? ''; +} + +// ─── Persistence oracle (admin ops API read-back) ───────────────────────────── + +async function readDoc(ctx: ContextWithHarper, id: string): Promise | null> { + const res = await fetch(new URL('', ctx.harper.operationsAPIURL), { + method: 'POST', + // Node's fetch has no default timeout: a wedged server that accepts the socket and never + // answers would hang this oracle (and, from the before() hook, the whole suite) forever + // instead of failing the trial. + signal: AbortSignal.timeout(10_000), + headers: { + 'Content-Type': 'application/json', + 'Authorization': basicAuth(ctx.harper.admin.username, ctx.harper.admin.password), + }, + body: JSON.stringify({ + operation: 'search_by_value', + schema: 'data', + table: 'Doc', + search_attribute: 'id', + search_value: id, + get_attributes: ['*'], + }), + }); + const text = await res.text(); + // Throw rather than fall back to null on an error/unparsable response: null is this oracle's + // "row is absent" answer, so swallowing a 500 here would let a broken read-back masquerade as + // a successful denial and turn every persistence assertion below into a vacuous pass. + if (!res.ok) throw new Error(`search_by_value read-back for ${id} failed: ${res.status} ${text}`); + let rows: unknown; + try { + rows = JSON.parse(text); + } catch { + throw new Error(`search_by_value read-back for ${id} returned non-JSON: ${res.status} ${text}`); + } + if (!Array.isArray(rows)) throw new Error(`search_by_value read-back for ${id} returned non-array: ${text}`); + return rows.length > 0 ? (rows[0] as Record) : null; +} + +// ─── Suite ──────────────────────────────────────────────────────────────────── + +suite('QA-408: verify harper#1522 closes F-092/F-093 MCP RBAC bypasses', (ctx: ContextWithHarper) => { + let admin: { client: Client; transport: StreamableHTTPClientTransport }; + let low: { client: Client; transport: StreamableHTTPClientTransport }; + let appURL: string; + + before(async () => { + log(`Starting Harper with mcp.application config (Harper ${HARPER_SHA})...`); + await setupHarperWithFixture(ctx, FIXTURE_PATH, { + config: { mcp: { application: { mountPath: '/mcp' } } }, + env: {}, + }); + + appURL = ctx.harper.httpURL; + log(`Harper started. httpURL=${appURL}`); + + // Role: table-level CRUD — row-level guards are the ONLY barrier. + const adminAuth = basicAuth(ctx.harper.admin.username, ctx.harper.admin.password); + + const roleRes = await fetch(new URL('', ctx.harper.operationsAPIURL), { + method: 'POST', + signal: AbortSignal.timeout(10_000), + headers: { 'Content-Type': 'application/json', 'Authorization': adminAuth }, + body: JSON.stringify({ + operation: 'add_role', + role: ROLE, + permission: { + super_user: false, + data: { + tables: { + Doc: { read: true, insert: true, update: true, delete: true, attribute_permissions: [] }, + }, + }, + }, + }), + }); + const roleResBody = await roleRes.text(); + log(`add_role: ${roleRes.status}`); + strictEqual(roleRes.status, 200, `add_role should succeed, got ${roleRes.status}: ${roleResBody}`); + + const userRes = await fetch(new URL('', ctx.harper.operationsAPIURL), { + method: 'POST', + signal: AbortSignal.timeout(10_000), + headers: { 'Content-Type': 'application/json', 'Authorization': adminAuth }, + body: JSON.stringify({ + operation: 'add_user', + role: ROLE, + username: LOWUSER.username, + password: LOWUSER.password, + active: true, + }), + }); + const userResBody = await userRes.text(); + log(`add_user: ${userRes.status}`); + strictEqual(userRes.status, 200, `add_user should succeed, got ${userRes.status}: ${userResBody}`); + + // Seed rows. + const insertRes = await fetch(new URL('', ctx.harper.operationsAPIURL), { + method: 'POST', + signal: AbortSignal.timeout(10_000), + headers: { 'Content-Type': 'application/json', 'Authorization': adminAuth }, + body: JSON.stringify({ + operation: 'insert', + schema: 'data', + table: 'Doc', + records: [ + { id: ADMIN_ROW, owner: ctx.harper.admin.username, payload: 'admin-original' }, + { id: LOWUSER_ROW, owner: LOWUSER.username, payload: 'lowuser-original' }, + ], + }), + }); + const insertResBody = await insertRes.text(); + log(`insert rows: ${insertRes.status}`); + strictEqual(insertRes.status, 200, `seed insert should succeed, got ${insertRes.status}: ${insertResBody}`); + + // Poll until Doc route is ready. + const deadline = Date.now() + 30_000; + let ready = false; + while (Date.now() < deadline) { + try { + const probe = await fetch(new URL('/Doc/', appURL), { + headers: { Authorization: adminAuth }, + signal: AbortSignal.timeout(3_000), + }); + if (probe.status !== 404) { + await probe.body?.cancel(); + ready = true; + break; + } + await probe.body?.cancel(); + } catch { + /* not ready */ + } + await sleep(250); + } + ok(ready, 'Doc route did not become ready within 30 seconds'); + + // Open authenticated MCP sessions. MUST pass real Authorization header — + // loopback-without-auth is auto-promoted to super_user and would mask the fix. + admin = await appClient(ctx, ctx.harper.admin.username, ctx.harper.admin.password); + low = await appClient(ctx, LOWUSER.username, LOWUSER.password); + log('MCP sessions established (admin + lowuser)'); + }); + + after(async () => { + try { + await admin?.transport.close(); + } finally { + try { + await low?.transport.close(); + } finally { + await teardownHarper(ctx); + log('Teardown complete.'); + } + } + }); + + // ── REST ANCHORS ───────────────────────────────────────────────────────────── + + test('REST anchor: lowuser GET admin row → 403/404 (cross-surface reference)', async () => { + const res = await fetch(new URL(`/Doc/${ADMIN_ROW}`, appURL), { + headers: { Authorization: basicAuth(LOWUSER.username, LOWUSER.password) }, + }); + await res.body?.cancel(); + log(`REST GET admin row as lowuser: status=${res.status}`); + recordFinding({ + op: 'REST GET admin row', + principal: 'lowuser', + allowed: false, + persisted: 'n/a', + verdict: res.status === 403 || res.status === 404 ? 'ENFORCED' : 'BYPASS', + note: `HTTP ${res.status}`, + }); + ok(res.status === 403 || res.status === 404, `REST GET should deny lowuser on admin's row, got ${res.status}`); + }); + + test('REST anchor: lowuser PUT admin row → 403 (cross-surface reference)', async () => { + const res = await fetch(new URL(`/Doc/${ADMIN_ROW}`, appURL), { + method: 'PUT', + headers: { + 'Authorization': basicAuth(LOWUSER.username, LOWUSER.password), + 'Content-Type': 'application/json', + }, + body: JSON.stringify({ owner: ctx.harper.admin.username, payload: 'rest-overwrite' }), + }); + await res.body?.cancel(); + log(`REST PUT admin row as lowuser: status=${res.status}`); + recordFinding({ + op: 'REST PUT admin row', + principal: 'lowuser', + allowed: false, + persisted: 'n/a', + verdict: res.status === 403 ? 'ENFORCED' : 'BYPASS', + note: `HTTP ${res.status}`, + }); + strictEqual(res.status, 403, `REST PUT should deny lowuser with 403, got ${res.status}`); + }); + + test('REST anchor: lowuser DELETE admin row → 403 (cross-surface reference)', async () => { + const res = await fetch(new URL(`/Doc/${ADMIN_ROW}`, appURL), { + method: 'DELETE', + headers: { Authorization: basicAuth(LOWUSER.username, LOWUSER.password) }, + }); + await res.body?.cancel(); + log(`REST DELETE admin row as lowuser: status=${res.status}`); + recordFinding({ + op: 'REST DELETE admin row', + principal: 'lowuser', + allowed: false, + persisted: 'n/a', + verdict: res.status === 403 ? 'ENFORCED' : 'BYPASS', + note: `HTTP ${res.status}`, + }); + strictEqual(res.status, 403, `REST DELETE should deny lowuser with 403, got ${res.status}`); + }); + + // ── POSITIVE CONTROL: admin can do everything ───────────────────────────── + + test('Positive control: admin MCP create/update/delete persist (write wiring intact)', async () => { + const ctrlId = 'qa408-ctrl-admin'; + + const created = await call(admin.client, 'create_Doc', { + id: ctrlId, + owner: ctx.harper.admin.username, + payload: 'ctrl', + }); + log(`admin create_Doc: isError=${created.isError}`); + ok(!created.isError, `admin create_Doc errored: ${resultText(created)}`); + const afterCreate = await readDoc(ctx, ctrlId); + ok(afterCreate != null, 'admin create_Doc must persist'); + recordFinding({ + op: 'MCP create_Doc (ctrl row)', + principal: 'admin', + allowed: true, + persisted: afterCreate != null, + verdict: afterCreate != null ? 'PASS' : 'FAIL', + }); + + const updated = await call(admin.client, 'update_Doc', { + id: ctrlId, + owner: ctx.harper.admin.username, + payload: 'ctrl-updated', + }); + log(`admin update_Doc: isError=${updated.isError}`); + ok(!updated.isError, `admin update_Doc errored: ${resultText(updated)}`); + const afterUpdate = await readDoc(ctx, ctrlId); + strictEqual(afterUpdate?.payload, 'ctrl-updated', 'admin update_Doc must persist'); + recordFinding({ + op: 'MCP update_Doc (ctrl row)', + principal: 'admin', + allowed: true, + persisted: afterUpdate?.payload === 'ctrl-updated', + verdict: afterUpdate?.payload === 'ctrl-updated' ? 'PASS' : 'FAIL', + }); + + const deleted = await call(admin.client, 'delete_Doc', { id: ctrlId }); + log(`admin delete_Doc: isError=${deleted.isError}`); + ok(!deleted.isError, `admin delete_Doc errored: ${resultText(deleted)}`); + const afterDelete = await readDoc(ctx, ctrlId); + strictEqual(afterDelete, null, 'admin delete_Doc must remove the row'); + recordFinding({ + op: 'MCP delete_Doc (ctrl row)', + principal: 'admin', + allowed: true, + persisted: afterDelete == null, + verdict: afterDelete == null ? 'PASS' : 'FAIL', + }); + }); + + // ── OWN-ROW CONTROLS: lowuser reads/writes its own row ──────────────────── + + test('Own-row control: lowuser MCP get_Doc on own row returns the row', async () => { + const result = await call(low.client, 'get_Doc', { id: LOWUSER_ROW }); + const text = resultText(result); + log(`lowuser get_Doc own row: isError=${result.isError} hasPayload=${text.includes('lowuser')}`); + ok(!result.isError, `lowuser get own row errored: ${text}`); + ok(text.includes('lowuser'), `own row payload not returned: ${text}`); + recordFinding({ + op: 'MCP get_Doc (own row)', + principal: 'lowuser', + allowed: true, + persisted: 'n/a', + verdict: 'PASS', + }); + }); + + test('Own-row control: lowuser MCP update_Doc on own row persists', async () => { + const result = await call(low.client, 'update_Doc', { + id: LOWUSER_ROW, + owner: LOWUSER.username, + payload: 'lowuser-self-updated', + }); + log(`lowuser update_Doc own row: isError=${result.isError}`); + ok(!result.isError, `lowuser update own row errored: ${resultText(result)}`); + const afterUpdate = await readDoc(ctx, LOWUSER_ROW); + strictEqual(afterUpdate?.payload, 'lowuser-self-updated', 'own-row update must persist'); + recordFinding({ + op: 'MCP update_Doc (own row)', + principal: 'lowuser', + allowed: true, + persisted: afterUpdate?.payload === 'lowuser-self-updated', + verdict: 'PASS', + }); + }); + + // ── F-092 READ ENFORCEMENT ───────────────────────────────────────────────── + + test('F-092 (read): lowuser MCP get_Doc on admin row is denied and leaks nothing', async () => { + const result = await call(low.client, 'get_Doc', { id: ADMIN_ROW }); + const text = resultText(result); + log(`F-092 get_Doc admin row: isError=${result.isError} text=${text.slice(0, 120)}`); + const leaked = text.includes(ADMIN_ROW) || text.includes('admin-original'); + recordFinding({ + op: 'MCP get_Doc (admin row)', + principal: 'lowuser', + allowed: !result.isError, + persisted: 'n/a', + verdict: leaked ? 'BYPASS' : 'ENFORCED', + note: leaked ? 'admin-original payload leaked — F-092 still open' : 'no leak', + }); + ok(!leaked, `F-092 BYPASS: get_Doc leaked admin payload. isError=${result.isError} text=${text}`); + }); + + test('F-092 (read): lowuser MCP search_Doc does not leak admin-owned rows', async () => { + const result = await call(low.client, 'search_Doc', {}); + const text = resultText(result); + log(`F-092 search_Doc: isError=${result.isError} text=${text.slice(0, 200)}`); + const leaked = text.includes(ADMIN_ROW) || text.includes('admin-original'); + recordFinding({ + op: 'MCP search_Doc', + principal: 'lowuser', + allowed: !result.isError, + persisted: 'n/a', + verdict: leaked ? 'BYPASS' : 'ENFORCED', + note: leaked ? 'admin-original in search results — F-092 still open on search' : 'no leak', + }); + // Search may either filter denied rows or reject the call; it must not return the admin row. + ok(!leaked, `F-092 BYPASS: search_Doc returned admin row. isError=${result.isError} text=${text}`); + // ...but the accepted rejection has to be an AUTHZ rejection. Without this, a schema or + // parameter-validation failure would satisfy `!leaked` without the search ever running, and + // the whole case would pass vacuously. + if (result.isError) { + ok( + /unauthorized|not allowed|permission|forbidden|denied/i.test(text), + `search_Doc was rejected for a non-authorization reason, so this case proved nothing: ${text}` + ); + } else { + ok( + text.includes(LOWUSER_ROW), + `search_Doc succeeded but returned no lowuser-owned row, so the filter was never exercised: ${text}` + ); + } + }); + + // ── F-093 WRITE ENFORCEMENT ─────────────────────────────────────────────── + + test('F-093 (write): lowuser MCP update_Doc on admin row is denied and does not persist', async () => { + const result = await call(low.client, 'update_Doc', { + id: ADMIN_ROW, + owner: ctx.harper.admin.username, + payload: 'LOWUSER-OVERWRITE', + }); + log(`F-093 update_Doc admin row: isError=${result.isError} text=${resultText(result).slice(0, 120)}`); + const afterUpdate = await readDoc(ctx, ADMIN_ROW); + const payloadChanged = afterUpdate?.payload === 'LOWUSER-OVERWRITE'; + // A bypass is unauthorized PERSISTENCE, whatever the tool reported: a handler that writes the + // row and then fails while formatting its reply (isError=true) is still a bypass, and gating the + // verdict on !isError would print ENFORCED one line before the assertion below fails. + const bypassed = payloadChanged; + recordFinding({ + op: 'MCP update_Doc (admin row)', + principal: 'lowuser', + allowed: !result.isError, + persisted: payloadChanged, + verdict: bypassed ? 'BYPASS' : 'ENFORCED', + note: bypassed + ? 'write persisted despite guard — F-093 still open' + : `isError=${result.isError} payloadChanged=${payloadChanged}`, + }); + ok(result.isError, `F-093 BYPASS: update_Doc on admin row did not return isError. text=${resultText(result)}`); + ok(!payloadChanged, `F-093 BYPASS: update_Doc persisted on admin row (payload changed to LOWUSER-OVERWRITE)`); + }); + + test('F-093 (write): lowuser MCP delete_Doc on admin row is denied and does not persist', async () => { + const result = await call(low.client, 'delete_Doc', { id: ADMIN_ROW }); + log(`F-093 delete_Doc admin row: isError=${result.isError} text=${resultText(result).slice(0, 120)}`); + const afterDelete = await readDoc(ctx, ADMIN_ROW); + const rowGone = afterDelete == null; + const bypassed = rowGone; // see update_Doc: persistence alone decides the verdict + recordFinding({ + op: 'MCP delete_Doc (admin row)', + principal: 'lowuser', + allowed: !result.isError, + persisted: rowGone, + verdict: bypassed ? 'BYPASS' : 'ENFORCED', + note: bypassed + ? 'row deleted despite guard — F-093 still open' + : `isError=${result.isError} rowStillPresent=${afterDelete != null}`, + }); + ok(result.isError, `F-093 BYPASS: delete_Doc on admin row did not return isError. text=${resultText(result)}`); + ok(!rowGone, `F-093 BYPASS: delete_Doc removed admin row`); + }); + + test('F-093 (write): lowuser MCP create_Doc for admin-owned row is denied and does not persist', async () => { + const result = await call(low.client, 'create_Doc', { + id: LOWUSER_CREATE_ID, + owner: ctx.harper.admin.username, + payload: 'LOWUSER-CREATE-FOR-ADMIN', + }); + log(`F-093 create_Doc (owned by admin): isError=${result.isError} text=${resultText(result).slice(0, 120)}`); + const afterCreate = await readDoc(ctx, LOWUSER_CREATE_ID); + const rowCreated = afterCreate != null; + const bypassed = rowCreated; // see update_Doc: persistence alone decides the verdict + recordFinding({ + op: 'MCP create_Doc (owned by admin)', + principal: 'lowuser', + allowed: !result.isError, + persisted: rowCreated, + verdict: bypassed ? 'BYPASS' : 'ENFORCED', + note: bypassed + ? 'row created despite guard — F-093 still open' + : `isError=${result.isError} rowCreated=${rowCreated}`, + }); + ok( + result.isError, + `F-093 BYPASS: create_Doc for admin-owned row did not return isError. text=${resultText(result)}` + ); + ok(!rowCreated, `F-093 BYPASS: create_Doc inserted row despite allowCreate denial`); + }); +}); diff --git a/integrationTests/server/sse-throw-midstream.test.ts b/integrationTests/server/sse-throw-midstream.test.ts new file mode 100644 index 0000000000..7a7d9ec246 --- /dev/null +++ b/integrationTests/server/sse-throw-midstream.test.ts @@ -0,0 +1,417 @@ +/** + * QA-559 — regression verify for #1789 "Fix SSE hang + uncaughtException when a generator + * throws mid-stream" (commit 8930b1ef2), the error-path sibling of #1628/#1632 (QA-537) and + * our earlier filed finding F-133. + * + * Bug recap (see server/http.ts, `pipeBodyToResponse` / the old inline `body.pipe(nodeResponse)` + * wiring in the Node HTTP requestHandler): the plain Node HTTP path piped a streaming response + * body with a bare `body.pipe(nodeResponse)` and never attached an 'error' listener on the + * source. `pipe()` does not forward the source's 'error' event to the destination, and an + * unhandled 'error' on an EventEmitter is a Node `uncaughtException` — contentTypes.ts's + * serializeStream()/Readable.from already surfaced a mid-iteration generator rejection + * correctly as an 'error' event, it just had no listener downstream. The net effect (F-133): + * an async generator streamed over SSE that threw partway through left the HTTP response open + * forever (client hangs) AND crashed the process with an uncaughtException. + * + * The fix extracts an exported `pipeBodyToResponse(body, nodeResponse, ...)` helper that wires + * the pipe via `stream.pipeline()` instead of a bare `.pipe()`. `pipeline()` tears down both + * sides symmetrically: a source 'error' destroys the response too, closing the connection + * (abruptly, not via a clean `.end()` — deliberate, per PR review, so the client doesn't get + * misled into thinking a truncated transfer completed normally). So post-fix, a client + * consuming an SSE stream whose generator throws mid-iteration should observe the HTTP + * response terminate (via 'end', 'error', or 'close' — any of the three, per the updated unit + * test in contentTypes.test.js) in bounded time, receiving only the events flushed before the + * throw, with NO uncaughtException logged and the worker still alive afterward. + * + * This suite starts from the QA-537 harness/fixture pattern (qa-scratch/qa537-sse-finite- + * generator/) and its `ThrowGen` case, which *documented* (did not assert) the pre-fix hang. + * Here the throw cases are promoted to hard assertions of clean termination: + * ThrowFirst - throws on the very first step, before any bytes are yielded. + * ThrowMid - yields 3 of an intended 6 events, then throws (genuine mid-stream failure). + * CleanGen - control: 5 events then natural completion, no throw at all. + * + * Every request is wrapped in an AbortController with a bounded (12-15s) timeout, so if the + * regression were present, the test would fail/timeout deterministically instead of hanging the + * whole run forever. After the throw cases, a plain Probe/ request confirms the server process + * is still healthy (no uncaughtException crashed/wedged a worker), and the hdb.log is scanned + * for any newly-appeared `uncaughtException` lines. + * + * Harper SHA under test: 182971ad1 (includes fix commit 8930b1ef2, confirmed via + * `git merge-base --is-ancestor 8930b1ef2 182971ad1`). + * + * Reproduction: + * npm run test:integration -- "integrationTests/server/sse-throw-midstream.test.ts" + */ +import { suite, test, before, after } from 'node:test'; +import { ok, strictEqual } from 'node:assert'; +import { resolve, join } from 'node:path'; +import { readFileSync } from 'node:fs'; +import { StringDecoder } from 'node:string_decoder'; +import { setTimeout as sleep } from 'node:timers/promises'; +import http from 'node:http'; +import https from 'node:https'; +import { URL } from 'node:url'; +import { setupHarperWithFixture, teardownHarper, type ContextWithHarper } from '@harperfast/integration-testing'; +// @ts-expect-error utils/client.mjs has no type declarations; runtime resolves fine +import { createApiClient } from '../apiTests/utils/client.mjs'; + +const FIXTURE_PATH = resolve(import.meta.dirname, 'sse-throw-midstream'); +const skipSuite = process.platform === 'win32'; + +type Client = ReturnType; + +interface ProbeSnap { + ok: boolean; + throwFirst: { opened: number; closed: number }; + throwMid: { opened: number; closed: number }; + clean: { opened: number; closed: number }; +} + +async function getProbe(restBase: string, authHeaders: Record): Promise { + const url = new URL(`${restBase}/Probe/`); + const lib = url.protocol === 'https:' ? https : http; + return new Promise((resolvePromise, reject) => { + const req = lib.request( + url, + { + method: 'GET', + headers: { ...authHeaders, Accept: 'application/json' }, + rejectUnauthorized: false, + signal: AbortSignal.timeout(3_000), + } as any, + (res) => { + const chunks: Buffer[] = []; + res.on('data', (d: Buffer) => chunks.push(d)); + res.on('end', () => { + try { + resolvePromise(JSON.parse(Buffer.concat(chunks).toString('utf8'))); + } catch (e) { + reject(e); + } + }); + res.on('error', reject); + } + ); + req.on('error', reject); + req.end(); + }); +} + +async function waitForProbe( + restBase: string, + authHeaders: Record, + predicate: (probe: ProbeSnap) => boolean, + timeoutMs = 5_000 +): Promise { + const deadline = Date.now() + timeoutMs; + let probe: ProbeSnap | null = null; + while (Date.now() < deadline) { + probe = await getProbe(restBase, authHeaders).catch(() => null); + if (probe && predicate(probe)) return probe; + await sleep(50); + } + return probe; +} + +// ── AbortController-bounded SSE stream consumer ────────────────────────────────────────── +// Wraps the request in an AbortController with a generous but bounded timeout, so a genuine +// regression (hung response) shows up as a caught timeout/abort in the test, never a hung +// process. Resolves on whichever of 'end' / 'error' / 'close' fires first, since the fixed +// pipeline()-based teardown closes the response abruptly (not via a clean 'end') on a source +// error -- see PR #1789. + +interface SseResult { + status: number; + raw: string; + events: string[]; // parsed `data: ...` payloads, in order + terminatedBy: 'end' | 'error' | 'close' | null; // which event resolved the request + aborted: boolean; // did our own timeout abort fire (i.e. it hung)? + errored: Error | null; + elapsedMs: number; +} + +function consumeSse(urlStr: string, authHeaders: Record, timeoutMs = 12_000): Promise { + const url = new URL(urlStr); + const lib = url.protocol === 'https:' ? https : http; + const controller = new AbortController(); + let timedOut = false; + const start = Date.now(); + const timer = setTimeout(() => { + timedOut = true; + controller.abort(); + }, timeoutMs); + + return new Promise((resolvePromise) => { + const result: SseResult = { + status: 0, + raw: '', + events: [], + terminatedBy: null, + aborted: false, + errored: null, + elapsedMs: 0, + }; + let settled = false; + const finish = (terminatedBy: SseResult['terminatedBy'], err?: Error) => { + if (settled) return; + settled = true; + clearTimeout(timer); + result.terminatedBy = terminatedBy; + result.errored = err ?? null; + result.elapsedMs = Date.now() - start; + result.events = result.raw + .split('\n') + .filter((l) => l.startsWith('data: ')) + .map((l) => l.slice('data: '.length)); + resolvePromise(result); + }; + const req = lib.request( + url, + { + method: 'GET', + headers: { ...authHeaders, Accept: 'text/event-stream' }, + rejectUnauthorized: false, + signal: controller.signal, + } as any, + (res) => { + result.status = res.statusCode ?? 0; + // Decode incrementally: a bare d.toString('utf8') per chunk corrupts any multi-byte + // character that straddles a TCP chunk boundary into U+FFFD. + const decoder = new StringDecoder('utf8'); + res.on('data', (d: Buffer) => { + result.raw += decoder.write(d); + }); + res.on('end', () => { + result.raw += decoder.end(); + finish('end'); + }); + res.on('error', (e: Error) => finish('error', e)); + res.on('close', () => finish('close')); + } + ); + req.on('error', (e: any) => { + if (timedOut || e?.name === 'AbortError') { + if (settled) return; + settled = true; + clearTimeout(timer); + result.aborted = true; + result.elapsedMs = Date.now() - start; + result.events = result.raw + .split('\n') + .filter((l) => l.startsWith('data: ')) + .map((l) => l.slice('data: '.length)); + resolvePromise(result); + } else { + finish('error', e); + } + }); + req.end(); + }); +} + +function readLogSafe(logPath: string): string { + try { + return readFileSync(logPath, 'utf8'); + } catch { + return ''; + } +} + +function countUncaught(log: string): number { + return log.split('\n').filter((l) => l.includes('uncaughtException')).length; +} + +/** + * Asserting a NON-event: the worker logs an uncaughtException asynchronously, so reading hdb.log + * the instant the response closes can pass vacuously by simply outrunning the flush. Give the + * writer a bounded settle first — one of the cases AGENTS.md reserves a fixed sleep for. + */ +async function uncaughtAfterSettle(logPath: string): Promise { + await sleep(1_000); + return countUncaught(readLogSafe(logPath)); +} + +// ── Suite ────────────────────────────────────────────────────────────────────────────────── + +suite( + 'QA-559 SSE throw-mid-stream regression verify (#1789 / commit 8930b1ef2)', + { skip: skipSuite }, + (ctx: ContextWithHarper) => { + let client: Client; + let restBase = ''; + let authHeaders: Record = {}; + let logPath = ''; + + before(async () => { + await setupHarperWithFixture(ctx, FIXTURE_PATH, { + config: { threads: { count: 1 }, logging: { console: true, level: 'error' } }, + env: {}, + }); + client = createApiClient(ctx.harper); + restBase = client.restURL; + authHeaders = { Authorization: client.headers.Authorization as string }; + logPath = (ctx.harper as any).logDir + ? join((ctx.harper as any).logDir, 'hdb.log') + : join((ctx.harper as any).dataRootDir, 'log', 'hdb.log'); + + const deadline = Date.now() + 30_000; + let ready = false; + while (Date.now() < deadline) { + try { + const p = await getProbe(restBase, authHeaders); + if (p?.ok !== undefined) { + ready = true; + break; + } + } catch { + /* not ready */ + } + await sleep(250); + } + ok(ready, 'Probe route did not become ready within 30 seconds'); + readFileSync(logPath, 'utf8'); + }); + + after(async () => { + await teardownHarper(ctx); + }); + + // ── 1: throw on the very first step, before any bytes ──────────────────────────────── + + test( + '1: ThrowFirst -- throws before any yield; response terminates in bounded time, no uncaughtException', + { timeout: 25_000 }, + async () => { + const logBefore = readLogSafe(logPath); + const uncaughtBefore = countUncaught(logBefore); + + const r = await consumeSse(`${restBase}/ThrowFirst/`, authHeaders, 15_000); + console.log( + `[QA-559][1] ThrowFirst: status=${r.status} events=${r.events.length} terminatedBy=${r.terminatedBy} aborted=${r.aborted} errored=${r.errored?.message ?? null} elapsedMs=${r.elapsedMs}` + ); + + ok( + !r.aborted, + `must not hit the AbortController timeout -- a timeout here indicates the #1789 hang regressed. raw:\n${r.raw}` + ); + ok(r.terminatedBy !== null, 'response must terminate via end/error/close, not hang indefinitely'); + strictEqual( + r.events.length, + 0, + `expected 0 events (throw before any yield), got ${r.events.length}. raw:\n${r.raw}` + ); + + const probe = await waitForProbe(restBase, authHeaders, (snapshot) => snapshot.throwFirst.closed >= 1); + ok(probe && probe.throwFirst.closed >= 1, 'ThrowFirst generator should have completed cleanup'); + const uncaughtAfter = await uncaughtAfterSettle(logPath); + strictEqual( + uncaughtAfter - uncaughtBefore, + 0, + 'no NEW uncaughtException should be logged for a throw-before-first-yield generator' + ); + } + ); + + // ── 2: throw mid-stream, after some events already flushed ────────────────────────── + + test( + '2: ThrowMid -- yields 3 of 6 then throws; pre-error events delivered, response terminates cleanly, no uncaughtException', + { timeout: 25_000 }, + async () => { + const logBefore = readLogSafe(logPath); + const uncaughtBefore = countUncaught(logBefore); + + const r = await consumeSse(`${restBase}/ThrowMid/`, authHeaders, 15_000); + console.log( + `[QA-559][2] ThrowMid: status=${r.status} events=${r.events.length} terminatedBy=${r.terminatedBy} aborted=${r.aborted} errored=${r.errored?.message ?? null} elapsedMs=${r.elapsedMs}` + ); + + ok( + !r.aborted, + `must not hit the AbortController timeout -- a timeout here indicates the #1789 hang regressed. raw:\n${r.raw}` + ); + ok(r.terminatedBy !== null, 'response must terminate via end/error/close, not hang indefinitely'); + ok( + r.events.length >= 1 && r.events.length <= 3, + `expected a 1-3 event prefix before the abrupt close, got ${r.events.length}. raw:\n${r.raw}` + ); + for (let i = 0; i < r.events.length; i++) { + ok(r.events[i].includes(`"n":${i}`), `expected event ${i} to contain n=${i}, got: ${r.events[i]}`); + } + + const probe = await waitForProbe(restBase, authHeaders, (snapshot) => snapshot.throwMid.closed >= 1); + ok(probe && probe.throwMid.closed >= 1, 'ThrowMid generator should have completed cleanup'); + const uncaughtAfter = await uncaughtAfterSettle(logPath); + strictEqual( + uncaughtAfter - uncaughtBefore, + 0, + 'no NEW uncaughtException should be logged for a mid-stream throw' + ); + } + ); + + // ── 3: control -- finite generator completes cleanly, no throw ────────────────────── + + test( + '3: CleanGen (control, N=5) -- all 5 events arrive and the response closes cleanly via end', + { timeout: 20_000 }, + async () => { + const r = await consumeSse(`${restBase}/CleanGen/`, authHeaders, 15_000); + ok(r.status >= 200 && r.status < 300, `expected 2xx, got ${r.status}`); + strictEqual(r.events.length, 5, `expected 5 SSE data events, got ${r.events.length}. raw:\n${r.raw}`); + for (let i = 0; i < 5; i++) { + ok(r.events[i].includes(`"n":${i}`), `expected event ${i} to contain n=${i}, got: ${r.events[i]}`); + } + ok(!r.aborted, 'must not hit the AbortController timeout on a completing control generator'); + strictEqual( + r.terminatedBy, + 'end', + `a non-throwing generator should close via a clean 'end', got terminatedBy=${r.terminatedBy}` + ); + } + ); + + // ── Z: liveness canary + final uncaughtException sweep ────────────────────────────── + + test( + 'Z: liveness canary -- server survived all throw-mid-stream probes, no new uncaughtException', + { timeout: 30_000 }, + async () => { + const logBefore = readLogSafe(logPath); + const p = await waitForProbe( + restBase, + authHeaders, + (snapshot) => snapshot.throwFirst.closed >= 1 && snapshot.throwMid.closed >= 1 && snapshot.clean.closed >= 1 + ); + console.log(`[QA-559][Z] liveness probe: ${p ? 'alive' : 'DEAD'} ${p ? JSON.stringify(p) : ''}`); + ok( + p !== null, + 'Harper must still respond to Probe/ after all throw-mid-stream cases (worker not crashed/wedged)' + ); + ok( + p!.throwFirst.opened >= 1 && p!.throwFirst.closed >= 1, + 'ThrowFirst should show a matched open/close pair (generator finally ran)' + ); + ok( + p!.throwMid.opened >= 1 && p!.throwMid.closed >= 1, + 'ThrowMid should show a matched open/close pair (generator finally ran)' + ); + ok(p!.clean.opened >= 1 && p!.clean.closed >= 1, 'CleanGen should show a matched open/close pair'); + + await sleep(1_000); // same non-event settle as the per-case sweeps above + const logAfter = readLogSafe(logPath); + const newLines = logAfter.slice(logBefore.length); + const newUncaught = newLines.split('\n').filter((l) => l.includes('uncaughtException')).length; + if (newUncaught > 0) { + console.log( + `[QA-559][Z] NEW uncaughtException lines found:\n${newLines + .split('\n') + .filter((l) => l.includes('uncaughtException')) + .join('\n')}` + ); + } + strictEqual(newUncaught, 0, 'no uncaughtException should have appeared anywhere across the whole suite'); + } + ); + } +); diff --git a/integrationTests/server/sse-throw-midstream/config.yaml b/integrationTests/server/sse-throw-midstream/config.yaml new file mode 100644 index 0000000000..efffc0833f --- /dev/null +++ b/integrationTests/server/sse-throw-midstream/config.yaml @@ -0,0 +1,5 @@ +graphqlSchema: + files: '*.graphql' +jsResource: + files: resources.js +rest: true diff --git a/integrationTests/server/sse-throw-midstream/resources.js b/integrationTests/server/sse-throw-midstream/resources.js new file mode 100644 index 0000000000..745e221bbb --- /dev/null +++ b/integrationTests/server/sse-throw-midstream/resources.js @@ -0,0 +1,88 @@ +// QA-559 — regression verify for #1789 ("Fix SSE hang + uncaughtException when a generator +// throws mid-stream", commit 8930b1ef2). +// +// Bug recap: server/http.ts's plain Node HTTP requestHandler piped a streaming response body +// with `body.pipe(nodeResponse)` but never attached an 'error' listener on the source. pipe() +// doesn't forward source 'error' events to the destination, and an unhandled 'error' on an +// EventEmitter is a Node uncaughtException -- contentTypes.ts's serializeStream()/Readable.from +// already surfaced the generator's rejection correctly, it just had no listener downstream. The +// fix extracts an exported `pipeBodyToResponse` helper that wires the pipe via `stream.pipeline`, +// which tears down both sides (including closing the response, abruptly rather than cleanly) on +// a source error instead of leaving it hanging / crashing the process. +// +// This fixture exercises multiple throw-timing shapes over SSE (dispatched via +// `resource.connect()`, which is what Harper's REST layer invokes for CONNECT/SSE requests -- +// see server/REST.ts: `isSse` sets method to 'CONNECT', which calls `resource.connect(...)`): +// ThrowFirst - throws on the very first step, before any event is yielded. +// ThrowMid - yields 3 of an intended 6 events, then throws (genuine mid-stream failure). +// CleanGen - control: 5 events then a bare `return` (natural completion, no throw). +// Probe - readiness + per-resource open/close lifecycle counters, plain JSON. + +const G = (globalThis.__QA559__ ??= { + throwFirst: { opened: 0, closed: 0 }, + throwMid: { opened: 0, closed: 0 }, + clean: { opened: 0, closed: 0 }, +}); + +function sleep(ms) { + return new Promise((r) => setTimeout(r, ms)); +} + +// GET /ThrowFirst/ (Accept: text/event-stream) — throws on the very first step, before any +// bytes are yielded. Exercises the throw-before-any-yield edge of the fix. +export class ThrowFirst extends Resource { + static loadAsInstance = false; + static async *connect(_target, _incomingMessages, _request) { + G.throwFirst.opened++; + try { + throw new Error('QA559-intentional-throw-first'); + // eslint-disable-next-line no-unreachable + yield { n: 0 }; + } finally { + G.throwFirst.closed++; + } + } +} + +// GET /ThrowMid/ (Accept: text/event-stream) — yields 3 of an intended 6 events, then throws. +// Genuine mid-stream failure: some bytes already flushed to the client before the error. +export class ThrowMid extends Resource { + static loadAsInstance = false; + static async *connect(_target, _incomingMessages, _request) { + G.throwMid.opened++; + try { + for (let i = 0; i < 6; i++) { + if (i === 3) throw new Error('QA559-intentional-throw-mid'); + yield { n: i }; + await sleep(2); + } + } finally { + G.throwMid.closed++; + } + } +} + +// GET /CleanGen/ (Accept: text/event-stream) — control case: 5 events then natural completion, +// no throw. Must still deliver exactly the right event count and close cleanly. +export class CleanGen extends Resource { + static loadAsInstance = false; + static async *connect(_target, _incomingMessages, _request) { + G.clean.opened++; + try { + for (let i = 0; i < 5; i++) { + yield { n: i }; + await sleep(2); + } + } finally { + G.clean.closed++; + } + } +} + +// GET /Probe/ — readiness + lifecycle-counter snapshot (plain JSON, not SSE). +export class Probe extends Resource { + static loadAsInstance = false; + static async get() { + return { ok: true, ...G }; + } +} diff --git a/integrationTests/server/sse-throw-midstream/schema.graphql b/integrationTests/server/sse-throw-midstream/schema.graphql new file mode 100644 index 0000000000..fcb1c43348 --- /dev/null +++ b/integrationTests/server/sse-throw-midstream/schema.graphql @@ -0,0 +1,9 @@ +# QA-559 — regression verify for #1789 "Fix SSE hang + uncaughtException when a generator +# throws mid-stream" (commit 8930b1ef2). +# +# No table backing is needed for the generator Resources under test, but a jsResource fixture +# requires at least one @table/@export type to be a valid component, so this is a minimal +# placeholder. +type Placeholder @table @export { + id: ID @primaryKey +}