diff --git a/.changeset/hook-nested-write-timeout.md b/.changeset/hook-nested-write-timeout.md new file mode 100644 index 0000000000..877c580246 --- /dev/null +++ b/.changeset/hook-nested-write-timeout.md @@ -0,0 +1,24 @@ +--- +'@objectstack/runtime': patch +--- + +fix(runtime): honor a hook body's declared `timeoutMs` so nested cross-object writes aren't clamped to 250ms (#1867) + +Hook bodies run in the QuickJS sandbox with a default 250ms timeout. The runner +folded that engine default straight into `Math.min(...)` when resolving the +effective timeout, so it *always* dominated for hooks: a body that declared a +larger `timeoutMs` (the spec permits up to 30_000ms — `ScriptBody.timeoutMs`) to +give a legitimate nested write — "when a child changes, update the parent" — +room to settle was silently clamped back to 250ms and killed mid-flight. The +declared knob was never enforced. + +The engine default is now a FALLBACK used only when no explicit timeout is +supplied, not a hard ceiling. An explicit `body.timeoutMs` (and/or an enclosing +hook/action timeout) is honored; when both are present the smaller wins. Bodies +that declare nothing still get the 250ms hook / 5000ms action default, and a +body may still LOWER its own timeout below the default. + +This clears the last reliability blocker for nested cross-object writes from +hooks — the sandbox crash itself (`memory access out of bounds`) was already +fixed by the deferred-promise host-call model — so header/rollup fields no +longer need denormalized, hand-maintained workarounds. diff --git a/content/docs/automation/hook-bodies.mdx b/content/docs/automation/hook-bodies.mdx index ed1312fb9f..55df9dcecc 100644 --- a/content/docs/automation/hook-bodies.mdx +++ b/content/docs/automation/hook-bodies.mdx @@ -131,6 +131,10 @@ The sandbox engine is **`quickjs-emscripten`** — pure-WASM, runs on every JS h Per-invocation timeouts default to **250ms** for hooks and **5000ms** for actions; per-invocation memory caps at **32 MB**. Both are overridable per body. +### Nested cross-object writes + +A body may write *other* objects — e.g. `await ctx.api.object('parent').update({ ... })` from a child's `afterInsert`/`afterUpdate` (requires `api.write`). The target's own hooks fire too: the nested write runs in a **fresh sandbox VM** while the calling body is suspended, and this composes to any depth. This is the natural "when a child changes, roll the total up to the parent" automation — it does **not** need a denormalized, hand-maintained mirror field. The 250ms default suits a single quick write; give a deeper or slower rollup chain headroom by declaring a larger `timeoutMs` on the outer body (up to 30_000ms), so the whole chain settles within budget. + ## L3 — Compiled modules (intentionally disabled) An earlier design allowed the CLI to emit a sibling `objectstack-runtime..mjs` that `objectos` would `import()` at runtime. We removed that path because: diff --git a/packages/runtime/src/sandbox/nested-write-real-sqlite.integration.test.ts b/packages/runtime/src/sandbox/nested-write-real-sqlite.integration.test.ts new file mode 100644 index 0000000000..adb49c55e6 --- /dev/null +++ b/packages/runtime/src/sandbox/nested-write-real-sqlite.integration.test.ts @@ -0,0 +1,110 @@ +// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * Real-SQLite regression for #1867 — a nested cross-object write from a hook. + * + * This is the exact automation the `objectstack-ai/templates` CHARTERs say + * authors could not write ("when a child changes, update the parent"), modeled + * on the expense template: an `expense_line` hook recomputes and writes + * `expense_report.total_amount`. The in-memory mock can hide driver/transaction + * behavior (cf. bulk-write-real-driver.integration.test.ts), so this wires the + * REAL {@link ObjectQL} engine to the REAL {@link SqlDriver} (better-sqlite3, + * on-disk) and drives the whole hook → sandbox → nested-write path — insert, + * update, and delete of a line — asserting the parent rollup lands each time + * and the process never crashes with `memory access out of bounds`. + * + * SCOPE: this exercises the insert/update rollup — the cases a hook can resolve, + * where the child's FK is in the payload. Delete-inclusive AGGREGATE rollups are + * better served by the engine's native `summary` field: an `afterDelete` hook + * receives only `{ id, options }` (no pre-image of the deleted row's FK), so it + * cannot know which parent to recompute, whereas the engine captures that + * pre-image itself and recomputes summaries on delete (proven under real SQL in + * `bulk-write-real-driver.integration.test.ts`). The nested-write hook is the + * GENERAL mechanism #1867 unblocks (conditional / non-aggregate cross-object + * writes); the `summary` field is the declarative tool for delete-safe sums. + */ + +import { describe, it, expect, afterEach } from 'vitest'; +import { mkdtempSync, rmSync } from 'node:fs'; +import { tmpdir } from 'node:os'; +import { join } from 'node:path'; +import { ObjectQL, bindHooksToEngine } from '@objectstack/objectql'; +import { SqlDriver } from '@objectstack/driver-sql'; +import { hookBodyRunnerFactory } from './body-runner.js'; +import { QuickJSScriptRunner } from './quickjs-runner.js'; + +const EXPENSE_REPORT = { + name: 'expense_report', + fields: { + title: { type: 'text' }, + total_amount: { type: 'number' }, + line_count: { type: 'number' }, + }, +}; +const EXPENSE_LINE = { + name: 'expense_line', + fields: { + amount: { type: 'number' }, + // The owning report id. Kept a plain text column so this test isolates the + // nested-write behavior from FK/cascade machinery. + expense_report: { type: 'text' }, + }, +}; + +const ROLLUP_HOOK = { + name: 'expense_line_rollup', + object: 'expense_line', + events: ['afterInsert', 'afterUpdate'], + body: { + language: 'js', + source: ` + const rid = ctx.input.expense_report; + if (!rid) return; + const lines = await ctx.api.object('expense_line').find({ where: { expense_report: rid } }); + const total = lines.reduce((s, l) => s + (l.amount || 0), 0); + await ctx.api.object('expense_report').update({ id: rid, total_amount: total, line_count: lines.length }); + `, + capabilities: ['api.read', 'api.write'], + }, +}; + +describe('#1867 nested cross-object write — REAL SqlDriver (better-sqlite3, on-disk)', () => { + let engine: ObjectQL | null = null; + let dir: string | null = null; + + afterEach(async () => { + try { await engine?.destroy(); } catch { /* noop */ } + engine = null; + if (dir) { rmSync(dir, { recursive: true, force: true }); dir = null; } + }); + + async function boot() { + dir = mkdtempSync(join(tmpdir(), 'os-nested-1867-')); + const driver = new SqlDriver({ client: 'better-sqlite3', connection: { filename: join(dir, 'data.sqlite') }, useNullAsDefault: true }); + await driver.initObjects([EXPENSE_REPORT, EXPENSE_LINE]); // create real tables + engine = new ObjectQL(); + engine.registerDriver(driver, true); + await engine.init(); + for (const o of [EXPENSE_REPORT, EXPENSE_LINE]) engine.registry.registerObject(o as any); + engine.setDefaultBodyRunner(hookBodyRunnerFactory(new QuickJSScriptRunner(), { ql: engine, appId: 'expense' })); + bindHooksToEngine(engine, [ROLLUP_HOOK as any], { packageId: 'expense' }); + return engine; + } + + it('rolls the child line total up to the parent on insert / update — no crash, correct total', async () => { + const e = await boot(); + const report = await e.insert('expense_report', { title: 'Q3 travel', total_amount: 0, line_count: 0 }); + + // Insert two lines — each afterInsert nested-writes the parent. + await e.insert('expense_line', { amount: 100, expense_report: report.id }); + const line2 = await e.insert('expense_line', { amount: 50, expense_report: report.id }); + let parent: any = (await e.find('expense_report', { where: { id: report.id } }))[0]; + expect(parent.total_amount).toBe(150); + expect(parent.line_count).toBe(2); + + // Update a line — afterUpdate re-rolls up. + await e.update('expense_line', { id: line2.id, amount: 75, expense_report: report.id }); + parent = (await e.find('expense_report', { where: { id: report.id } }))[0]; + expect(parent.total_amount).toBe(175); + }, 30000); +}); diff --git a/packages/runtime/src/sandbox/nested-write.integration.test.ts b/packages/runtime/src/sandbox/nested-write.integration.test.ts new file mode 100644 index 0000000000..53561aa077 --- /dev/null +++ b/packages/runtime/src/sandbox/nested-write.integration.test.ts @@ -0,0 +1,172 @@ +// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * End-to-end regression for #1867 — nested cross-object writes from a hook. + * + * A child object's `afterInsert` / `afterUpdate` hook issues an engine write to + * its parent (`ctx.api.object('parent').update(...)`). The parent *also* has a + * hook, so the child's nested write fires a SECOND sandbox VM while the child's + * hook is still in flight — the exact re-entrancy that used to crash the process + * with `memory access out of bounds` under the old single-suspended-asyncify + * model. This wires a REAL {@link ObjectQL} engine (in-memory driver) to the + * real {@link QuickJSScriptRunner} through {@link hookBodyRunnerFactory}, so the + * whole hook → sandbox → nested-write → nested-hook path is exercised. + * + * This is the "when a child changes, update the parent" rollup the issue says + * authors could not write; it must complete without a crash and land the + * correct denormalized total on the parent. + */ + +import { describe, it, expect, beforeEach } from 'vitest'; +import { ObjectQL, bindHooksToEngine } from '@objectstack/objectql'; +import { hookBodyRunnerFactory } from './body-runner.js'; +import { QuickJSScriptRunner } from './quickjs-runner.js'; + +const parent = { + name: 'parent', + label: 'Parent', + fields: { + id: { name: 'id', type: 'text' as const, primaryKey: true }, + total_amount: { name: 'total_amount', type: 'number' as const }, + child_count: { name: 'child_count', type: 'number' as const }, + }, +}; +const child = { + name: 'child', + label: 'Child', + fields: { + id: { name: 'id', type: 'text' as const, primaryKey: true }, + amount: { name: 'amount', type: 'number' as const }, + parent_id: { name: 'parent_id', type: 'text' as const }, + }, +}; + +function makeMemoryDriver() { + const stores = new Map>>(); + const storeFor = (o: string) => { + let s = stores.get(o); + if (!s) { s = new Map(); stores.set(o, s); } + return s; + }; + let nextId = 0; + const matches = (row: Record, where: any): boolean => { + if (!where || typeof where !== 'object') return true; + for (const [k, v] of Object.entries(where)) { + if (k.startsWith('$')) continue; + const exp = (v && typeof v === 'object' && '$eq' in (v as any)) ? (v as any).$eq : v; + if ((row[k] ?? null) !== (exp ?? null)) return false; + } + return true; + }; + const driver: any = { + name: 'memory', version: '0.0.0', supports: {}, + async connect() {}, async disconnect() {}, async checkHealth() { return true; }, async execute() { return null; }, + async find(o: string, ast: any) { return Array.from(storeFor(o).values()).filter((r) => matches(r, ast?.where)); }, + findStream() { throw new Error('ns'); }, + async findOne(o: string, ast: any) { for (const r of storeFor(o).values()) if (matches(r, ast?.where)) return r; return null; }, + async create(o: string, data: Record) { + nextId += 1; const id = (data.id as string) ?? `r_${nextId}`; const row = { ...data, id }; storeFor(o).set(id, row); return row; + }, + async update(o: string, id: string, data: Record) { + const s = storeFor(o); const cur = s.get(id); if (!cur) throw new Error(`nf ${o}/${id}`); + const up = { ...cur, ...data, id }; s.set(id, up); return up; + }, + async upsert(o: string, data: Record) { const id = data.id as string | undefined; return id && storeFor(o).has(id) ? this.update(o, id, data) : this.create(o, data); }, + async delete(o: string, id: string) { return storeFor(o).delete(id); }, + async count(o: string, ast: any) { return (await this.find(o, ast)).length; }, + async bulkCreate(o: string, rows: Record[]) { return Promise.all(rows.map((r) => this.create(o, r))); }, + async bulkUpdate() { return []; }, async bulkDelete() {}, + async beginTransaction() { return { commit: async () => {}, rollback: async () => {} }; }, async commit() {}, async rollback() {}, + }; + return { driver, stores }; +} + +describe('#1867 nested cross-object write from a hook (real engine + sandbox)', () => { + let engine: ObjectQL; + + beforeEach(async () => { + engine = new ObjectQL(); + const { driver } = makeMemoryDriver(); + engine.registerDriver(driver, true); + await engine.init(); + for (const o of [parent, child]) engine.registry.registerObject(o as any); + engine.setDefaultBodyRunner( + hookBodyRunnerFactory(new QuickJSScriptRunner(), { ql: engine, appId: 'test' }), + ); + }); + + it('a child afterInsert hook writes the parent rollup without crashing (parent has its own hook → real nested VM)', async () => { + bindHooksToEngine( + engine, + [ + { + name: 'rollup_parent_total', + object: 'child', + events: ['afterInsert', 'afterUpdate'], + body: { + language: 'js', + source: ` + // On update the patch may omit parent_id; fall back to the + // pre-write record so the rollup targets the right parent. + const pid = ctx.input.parent_id || (ctx.previous && ctx.previous.parent_id); + const rows = await ctx.api.object('child').find({ where: { parent_id: pid } }); + const total = rows.reduce((s, r) => s + (r.amount || 0), 0); + await ctx.api.object('parent').update({ id: pid, total_amount: total, child_count: rows.length }); + `, + capabilities: ['api.read', 'api.write'], + }, + } as any, + { + name: 'parent_touch_marker', + object: 'parent', + events: ['afterUpdate'], + // Trivial body — its mere presence forces a second sandbox VM to run + // (re-entrant) while the child's hook VM is still suspended. + body: { language: 'js', source: "return { seen: ctx.input.id };", capabilities: [] }, + } as any, + ], + { packageId: 'test' }, + ); + + const p = await engine.insert('parent', { id: 'p1', total_amount: 0, child_count: 0 }); + await engine.insert('child', { id: 'c1', amount: 100, parent_id: p.id }); + await engine.insert('child', { id: 'c2', amount: 50, parent_id: p.id }); + + const parentRow = (await engine.findOne('parent', { where: { id: 'p1' } })) as any; + expect(parentRow.total_amount).toBe(150); + expect(parentRow.child_count).toBe(2); + }, 20000); + + it('re-rolls up on child update (afterUpdate nested write)', async () => { + bindHooksToEngine( + engine, + [ + { + name: 'rollup_parent_total', + object: 'child', + events: ['afterInsert', 'afterUpdate'], + body: { + language: 'js', + source: ` + // On update the patch may omit parent_id; fall back to the + // pre-write record so the rollup targets the right parent. + const pid = ctx.input.parent_id || (ctx.previous && ctx.previous.parent_id); + const rows = await ctx.api.object('child').find({ where: { parent_id: pid } }); + const total = rows.reduce((s, r) => s + (r.amount || 0), 0); + await ctx.api.object('parent').update({ id: pid, total_amount: total, child_count: rows.length }); + `, + capabilities: ['api.read', 'api.write'], + }, + } as any, + ], + { packageId: 'test' }, + ); + + await engine.insert('parent', { id: 'p1', total_amount: 0, child_count: 0 }); + await engine.insert('child', { id: 'c1', amount: 100, parent_id: 'p1' }); + expect(((await engine.findOne('parent', { where: { id: 'p1' } })) as any).total_amount).toBe(100); + + await engine.update('child', { id: 'c1', amount: 250, parent_id: 'p1' }); + expect(((await engine.findOne('parent', { where: { id: 'p1' } })) as any).total_amount).toBe(250); + }, 20000); +}); diff --git a/packages/runtime/src/sandbox/quickjs-runner.test.ts b/packages/runtime/src/sandbox/quickjs-runner.test.ts index 363abf3720..7e0b25786e 100644 --- a/packages/runtime/src/sandbox/quickjs-runner.test.ts +++ b/packages/runtime/src/sandbox/quickjs-runner.test.ts @@ -264,6 +264,156 @@ describe('QuickJSScriptRunner — async host APIs', () => { }); }); +// --------------------------------------------------------------------------- +// Nested cross-object writes (#1867). +// +// A hook body that issues an engine write (`ctx.api.object('parent').update`) +// re-enters the sandbox: the host-side write fires the *parent's* hook, which +// runs its own body inside a fresh VM while the child's hook is still in flight. +// The old asyncify host-call model crashed here ("memory access out of bounds" +// — the stack cannot be unwound twice). The deferred-promise + pump model must +// compose any depth of nesting safely. +// --------------------------------------------------------------------------- +describe('QuickJSScriptRunner — nested sandbox re-entrancy (#1867)', () => { + it('a host write that re-invokes the runner (parent hook) does not crash and returns correctly', async () => { + // The parent's afterUpdate hook body, run when the child writes the parent. + const parentBody = { + language: 'js' as const, + source: 'return { parentTouched: true, doubled: (ctx.input.n || 0) * 2 };', + capabilities: [] as const, + }; + const api = { + object: (_n: string) => ({ + update: async (patch: Record) => { + // Re-enter the sandbox exactly as the engine does when the parent + // write fires the parent's own hook body. + const nested = await runner.run( + parentBody, + { input: { n: 21 } } as ScriptContext, + { origin: { kind: 'hook', name: 'parent_hook' } }, + ); + return { updated: patch, nested: nested.value }; + }, + }), + }; + const r = await runner.run( + { + language: 'js', + source: "return await ctx.api.object('parent').update({ total: ctx.input.amount });", + capabilities: ['api.write'], + }, + ctx({ input: { amount: 100 }, api }), + { origin: { kind: 'hook', name: 'child_hook' } }, + ); + expect(r.value).toEqual({ + updated: { total: 100 }, + nested: { parentTouched: true, doubled: 42 }, + }); + }, 15000); + + it('survives a multi-level nested write chain (child → parent → grandparent → …)', async () => { + const makeApi = (depth: number): any => ({ + object: () => ({ + update: async () => { + if (depth <= 0) return { leaf: true }; + const nested = await runner.run( + { language: 'js', source: "return await ctx.api.object('x').update({});", capabilities: ['api.write'] }, + { input: {}, api: makeApi(depth - 1) } as ScriptContext, + { origin: { kind: 'hook', name: `lvl${depth}` } }, + ); + return { depth, nested: nested.value }; + }, + }), + }); + const r = await runner.run( + { language: 'js', source: "return await ctx.api.object('x').update({});", capabilities: ['api.write'] }, + { input: {}, api: makeApi(4) } as ScriptContext, + { origin: { kind: 'hook', name: 'child' }, timeoutMs: 10000 }, + ); + // Four levels of nesting resolve without a WASM crash. + expect((r.value as any).nested.nested.nested.nested).toEqual({ leaf: true }); + }, 20000); + + it('runs concurrent nested invocations (fan-out) without cross-VM corruption', async () => { + const leaf = { language: 'js' as const, source: 'return { leaf: true };', capabilities: [] as const }; + const api: any = { + object: () => ({ + update: async () => { + const [a, b, c] = await Promise.all([ + runner.run(leaf, { input: {} } as ScriptContext, { origin: { kind: 'hook', name: 'p1' } }), + runner.run(leaf, { input: {} } as ScriptContext, { origin: { kind: 'hook', name: 'p2' } }), + runner.run(leaf, { input: {} } as ScriptContext, { origin: { kind: 'hook', name: 'p3' } }), + ]); + return { a: a.value, b: b.value, c: c.value }; + }, + }), + }; + const r = await runner.run( + { language: 'js', source: "return await ctx.api.object('x').update({});", capabilities: ['api.write'] }, + { input: {}, api } as ScriptContext, + { origin: { kind: 'hook', name: 'child' }, timeoutMs: 10000 }, + ); + expect(r.value).toEqual({ a: { leaf: true }, b: { leaf: true }, c: { leaf: true } }); + }, 20000); +}); + +// --------------------------------------------------------------------------- +// Timeout resolution (#1867). The engine default is a FALLBACK, not a hard +// ceiling: a hook body may declare a larger `timeoutMs` (spec allows ≤30s) so a +// legitimate nested-write rollup has room to settle instead of being clamped to +// the 250ms hook default and killed mid-flight. +// --------------------------------------------------------------------------- +describe('QuickJSScriptRunner — timeout resolution honors body.timeoutMs (#1867)', () => { + it('honors a hook body timeoutMs above the 250ms hook default', async () => { + // Host call settles at ~600ms — comfortably past the old 250ms hook cap but + // within the body's declared 5000ms budget. Must resolve, not time out. + const api = { + object: () => ({ + update: async () => { + await new Promise((resolve) => setTimeout(resolve, 600)); + return { ok: true }; + }, + }), + }; + const r = await runner.runScript( + { + language: 'js', + source: "return await ctx.api.object('x').update({});", + capabilities: ['api.write'], + timeoutMs: 5000, + }, + ctx({ api }), + hookOpts, // hook origin → old code hard-capped at 250ms + ); + expect(r.value).toEqual({ ok: true }); + }, 10000); + + it('still applies the 250ms hook default when the body declares no timeoutMs', async () => { + const api = { object: () => ({ update: () => new Promise(() => {}) }) }; + const start = Date.now(); + await expect( + runner.runScript( + { language: 'js', source: "return await ctx.api.object('x').update({});", capabilities: ['api.write'] }, + ctx({ api }), + hookOpts, + ), + ).rejects.toThrow(/timeout/i); + // Fired near the 250ms default, not some larger value. + expect(Date.now() - start).toBeLessThan(2000); + }, 10000); + + it('lets a hook body LOWER its timeout below the default', async () => { + const api = { object: () => ({ update: () => new Promise(() => {}) }) }; + await expect( + runner.runScript( + { language: 'js', source: "return await ctx.api.object('x').update({});", capabilities: ['api.write'], timeoutMs: 50 }, + ctx({ api }), + hookOpts, + ), + ).rejects.toThrow(/timeout/i); + }, 10000); +}); + describe('QuickJSScriptRunner — long-running async host work (pump budget)', () => { // Regression: an action's single `ctx.api.update(...)` can synchronously drive // a large amount of awaited host work — e.g. a record-change flow that the diff --git a/packages/runtime/src/sandbox/quickjs-runner.ts b/packages/runtime/src/sandbox/quickjs-runner.ts index df749b7815..3fd29f77fb 100644 --- a/packages/runtime/src/sandbox/quickjs-runner.ts +++ b/packages/runtime/src/sandbox/quickjs-runner.ts @@ -104,10 +104,28 @@ export class QuickJSScriptRunner implements ScriptRunner { /* no-op — runtimes are per-invocation in v1 */ } - /** Pick the smallest of body / opts / engine-default. */ + /** + * Resolve the effective per-invocation timeout. + * + * The engine default (`hookTimeoutMs` / `actionTimeoutMs`) is a FALLBACK used + * only when the caller supplies no explicit timeout — it is NOT a hard + * ceiling. Whichever explicit timeout the caller *did* supply wins: the body's + * own `timeoutMs` (the spec permits up to 30_000ms — see `ScriptBody.timeoutMs`) + * and/or an enclosing hook/action timeout passed via `opts.timeoutMs`; when + * both are present the smaller wins, matching the spec's "smaller of this and + * the enclosing hook/action timeout wins". + * + * Previously the default was folded straight into `Math.min(...)`, so for + * hooks — whose default is 250ms — it *always* dominated: a body that declared + * `timeoutMs: 5000` to give a legitimate nested cross-object write room to + * settle was silently clamped back to 250ms and killed mid-flight. That made + * the spec's `ScriptBody.timeoutMs` a declared-but-unenforced knob for hooks + * and pushed template authors toward denormalized rollup workarounds (#1867). + */ private resolveTimeout(opts: ScriptRunOptions, bodyTimeoutMs: number | undefined): number { const def = opts.origin.kind === 'hook' ? this.opts.hookTimeoutMs : this.opts.actionTimeoutMs; - return Math.min(...[def, opts.timeoutMs, bodyTimeoutMs].filter((n): n is number => typeof n === 'number')); + const explicit = [opts.timeoutMs, bodyTimeoutMs].filter((n): n is number => typeof n === 'number'); + return explicit.length > 0 ? Math.min(...explicit) : def; } private async execute(args: {