Skip to content

Commit 6a40a09

Browse files
fix(plugin-audit): a failed boot provisioning of an audit table is logged at error, naming what is lost and the fix (#22981)
Fixes #22913 Clause-②: no ## What this changes `AuditPlugin.provisionSystemTables` (`packages/plugins/plugin-audit/src/audit-plugin.ts`) creates the storage for `sys_audit_log`, `sys_activity`, `sys_comment` and `sys_comment_reaction` at `kernel:ready`. When the driver refused one of those DDL statements, the catch logged it at `warn` and continued. The boot completes and the deployment looks healthy while the table does not exist. For the two audit tables, audited writes keep succeeding while their rows have nowhere to land. AGENTS.md "Degradation log levels" sends that class to `error`. - The catch now logs **one `error` per object per boot**, never per write. Its first line names the object, what is lost without it, that the deployment keeps looking healthy, and the fix: resolve the driver's refusal, then restart (this provisioning runs on every boot) or run `os migrate apply`. The driver's refusal is in the record's meta (`{ object, error }`), not in the message, so a multi-line driver error stays one record. - **The boot is not failed**, per the triage direction (comment 6116902332): making a boot refuse is a separate policy call. - The provisioning docblock loses a stale claim, "lazy-created on first WRITE": a write to a missing table fails with `no such table` (measured below). - Ride-along, test-only: `plan.telemetry-sibling.integration.test.ts` now carries the `serve` child's own stderr and stdout in every assertion that reads what the boot provisioned. Before, a boot that exited 0 with a table missing printed nothing of its own account. What a forced refusal of `sys_activity`'s DDL prints now, through `os serve` (`OS_MIGRATE_AND_EXIT=1`, `OS_LOG_LEVEL=warn`, telemetry sibling on), once, with exit 0: ```text ERROR AuditPlugin: could not provision sys_activity storage — its storage was NOT created. Audited writes keep succeeding, but their `sys_activity` rows (a record's activity timeline and the recent-activity feed) cannot land, and nothing retries them. The boot still completes and the deployment keeps looking healthy. Fix: resolve the driver's refusal (in this record's meta), then restart, since this provisioning runs on every boot, or run `os migrate apply`, which creates the missing storage (`os migrate plan` lists it as `create_table:sys_activity`). If the boot log also carries `Schema sync FAILED for object 'sys_activity'`, that is the same refusal. {"object":"sys_activity","error":"CREATE VIEW \"sys_activity\" AS SELECT … - there is already an index named sys_activity"} ``` On `main` the same boot printed `WARN AuditPlugin: could not provision sys_activity storage — …` inside the `Boot diagnostics — N informational` block. ## Measured before writing the fix half (dispatch A3) Harness: a scratch app (`requires: ['auth', 'automation']`), booted through `os serve` with `OS_MIGRATE_AND_EXIT=1`. The DDL refusal was forced by pre-creating an INDEX named `sys_activity`: SQLite tables, views and indexes share one namespace, so the CREATE is refused. Run on `main` `1f312fdfa` code, in both compositions (`OS_TELEMETRY_DB=0`, and the default telemetry sibling). | step | reading | |:--|:--| | boot with the refusal | `serve` exits 0; the `sys_activity` view is absent; the audit write that follows logs `no such table: sys_activity` | | fault removed, `os migrate plan --json` | exit 0, `pending = ["create_table:sys_activity"]` | | `os migrate apply --yes --json` (on a copy) | exit 0, `created` = `sys_activity`; the view exists afterwards (in the sibling file when the sibling is on) | | a plain restart (on another copy) | exit 0; the view exists afterwards | | `OS_SKIP_SCHEMA_SYNC=1` boot of an existing schema with `sys_comment_reaction` dropped | objectql logs `Skipping schema sync … WITHOUT DDL`, and the table is re-created anyway: this provisioning issues its DDL whatever that flag says | So the line names restart and `os migrate apply`, which were both measured to restore the table. It does not name `OS_SKIP_SCHEMA_SYNC`: setting that flag does not stop this DDL, so it cannot make this failure deliberate. ## Measured: is the same failure reported elsewhere? (dispatch A2) The line is printed once per object per boot (`kernel:ready` fires once, and the loop visits each object once). In both compositions above, objectql's boot schema sync had also tried the same object, so the boot log also carries `ERROR Schema sync FAILED for object 'sys_activity'`. It carries it twice, from two sync passes in that boot, each with its own `finished with 1 FAILED object(s)` summary. The audit writer's per-write line (`Audit write FAILED on sys_activity`, printed once per audited object, table and code) follows. The new line says that the objectql line is the same refusal. It adds the audit-specific consequence. The duplicate objectql pass is noted below and not changed here. ## Measured: `check:durability-log-level` cannot see this site (dispatch A4) - The audit site calls `sync.call(engine, obj.name)`. The checker's `calleeName` reads that callee as `call`: it unwraps `.call` / `.apply` / `.bind` on the log side (`resolveLogCallee`) but not on the guarded side. So a `syncObjectSchema` entry in `DURABILITY_CRITICAL_CALLEES` would not light this site, or the identical messaging site. - Adding `['syncObjectSchema', …]` to the map (in a scratch copy, on `1f312fdfa`) raised the seam count from 46 to 49. It turned the checker red on three sites, **all outside this PR's file surface**: - `packages/cli/src/utils/schema-migration-plugins.ts:2401` (SILENT; the catch counts the failure into the plan's notes) - `packages/metadata-protocol/src/protocol.ts:19337` (QUIET, `console.warn` in `ensureObjectStorage`) - `packages/services/service-datasource/src/datasource-connection-service.ts:658` (QUIET, `warn`) - So, per the dispatch, **the entry is not added here**, and none of those sites is touched. This departs from AGENTS.md's "add it to `DURABILITY_CRITICAL_CALLEES` in the same PR that fixes it". The entry and its sites belong to one family card, which the seat files. Until then the unit pins below hold this site. ## Pins (`audit-plugin.test.ts`) - For each of the four objects (`it.each`): a refused DDL logs exactly one `error`. The line names the object and `os migrate apply` and has no newline. The refusal is in meta. No `could not provision` line is logged at `warn`. The other three objects still provision, and `kernel:ready` resolves (the boot is not failed). - CONTROL: a clean provision logs zero `error` calls. - The existing `keeps reporting placements when one object fails to sync` now reads the line from `error`. - The wording is not pinned. The pins hold the level, the count, the named object, the named remedy command, and the refusal in meta. Ablations (one-shot, `scripts/ablation-replace.mjs` in WRAP mode, run on committed `168cf1e33`, restore proved by blob == HEAD and an empty `git diff HEAD`): - **A, the old level back** (`ctx.logger.error(provisionFailureLine(…), undefined, {` changed to `ctx.logger.warn(provisionFailureLine(…), {`): 5 failed / 10 passed. The four per-object pins fail with `expected [] to have a length of 1 but got +0`, and so does the placement test. The CONTROL stays green. - **B, an `error` on the clean path** (the line also emitted before each successful placement): 5 failed / 10 passed. The CONTROL fails with `expected [ { …(3) }, { …(3) }, { …(3) }, …(1) ] to deeply equal []`, and so do the four per-object pins. First attempt not run: its replacement contained its own anchor, so `ablation-replace` refused it (anchor count 1 to 1) and ran no test. The second anchor ran. - **Ride-along proof**: the CONTROL's `pendingTables` expectation was mutated to `['demo:forced-failure']`. The failure message then opened with `--- the serving boot's stderr (exit 0) ---` and the child's full boot-diagnostics block. Restored by blob. ## Tests and gates All on head `9ac3a46f5`, the PR's last commit. It changes only the changeset text after `168cf1e33`. - `pnpm --filter @objectstack/plugin-audit test`: 47 files, 748 tests passed. `pnpm --filter @objectstack/plugin-audit typecheck` (tsc, scripts project, `check:test-typecheck`) passed at `168cf1e33`, which has the same source. - `@objectstack/cli`, the touched integration file (`--project integration`, `plan.telemetry-sibling.integration.test.ts`): 2 passed. `pnpm --filter @objectstack/cli typecheck` passed, and the cli test-typecheck debt is unchanged; the touched file is not in it. The cli `unit` layer is left to CI: the only cli file changed is this integration test. - `node scripts/pm/dispatch-gates.mjs --commands` over the real change set derived 67 gate commands. All 67 ran, and `--ran` reconciles **67 derived, 67 run, 0 NOT-MEASURED, 0 UNRUN**. Five first exited 3 (PREREQUISITE NOT MET) and were rerun green after their prerequisite was met: `check-plugin-teardown-shape --self-test` after fetching its pinned control commit, and `check:dual-build-cjs-loads`, `check:i18n`, `check:i18n-coverage` and `check:i18n-walk-parity` after a full workspace build. - `pnpm check:durability-log-level` (run explicitly; the derivation does not place it): green, 46 seams. The seam count is unchanged because this site is outside the checker's view (section above). - Narrowed `eslint --no-inline-config` over the three touched TS files: 3 files (count read from `--format json`), 0 errors, 0 warnings. `--print-config` resolves rules for each file, so none is ignored, and no `parserOptions.project` or `projectService` is set. Linting is not type-aware, so this diff cannot change the verdict on an untouched file. The repo-wide `pnpm lint` is left to CI. ## Acceptance notes - **objectql reports one refused object twice in one `serve` boot.** `Schema sync FAILED for object 'X'` and the `finished with 1 FAILED object(s)` summary each print twice, in two passes about 350 ms apart (measured above). Observation only; Carrier: none. - **The `no syncObjectSchema` warn in the same method still says the tables "stay lazy-created on first WRITE".** That is stale for the SQL driver (measured: an insert fails with `no such table`). It is left as is because it guards engines without on-demand DDL, which this card does not cover. Carrier: none. - **The `resolves to NO datasource driver` branch in the same loop is still a `warn`.** No storage is created there either. It was not changed: no composition reaching it was measured, and the triage pinned only the throwing branch. Carrier: none. - **The audit writer's per-write missing-table line says the boot log "carries `Schema sync FAILED for object …`".** That holds whenever objectql also tried the object, which was the case in every boot measured here. It does not cover this plugin's own provisioning line, which this PR makes a sibling `error` with the same object name. Carrier: none. --- _Generated by [Claude Code](https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce)_ --------- Co-authored-by: Claude <noreply@anthropic.com> Co-authored-by: objectstack-fleet[bot] <332303061+objectstack-fleet[bot]@users.noreply.github.com>
1 parent 0524c16 commit 6a40a09

4 files changed

Lines changed: 193 additions & 26 deletions

File tree

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,13 @@
1+
---
2+
'@objectstack/plugin-audit': patch
3+
---
4+
5+
A failed boot provisioning of an audit table is logged at `error`, naming what is lost and the fix
6+
7+
Clause-②: no
8+
9+
At `kernel:ready`, `AuditPlugin` creates the storage for `sys_audit_log`, `sys_activity`, `sys_comment` and `sys_comment_reaction`. When the driver refuses one of those DDL statements, the boot still completes and the deployment looks healthy, but the table does not exist. For `sys_audit_log` and `sys_activity` the loss is silent: audited writes keep succeeding while their audit and activity rows have nowhere to land. That failure was logged at `warn`. It is now logged at `error`, once per object per boot and never per write. The boot is still not failed.
10+
11+
- **What the line says.** It names the object, what is lost without it, and that the deployment keeps looking healthy. It gives the fix: resolve the driver's refusal, then restart (this provisioning runs on every boot) or run `os migrate apply`, which creates the missing storage. `os migrate plan` lists it as a `create_table` entry for that object. Both remedies were measured to create a missing `sys_activity` once the fault was gone, with and without the telemetry sibling database.
12+
- **Where the driver's error is.** In the record's meta as `{ object, error }`, not in the message, so a multi-line driver error stays one record.
13+
- **What is unchanged.** The other objects are still provisioned when one fails, and the placement lines (`system tables provisioned`, the non-default datasource note) are unchanged. A log search on `could not provision sys_activity storage` (or any of the four object names) still matches the line.

‎packages/cli/src/commands/migrate/plan.telemetry-sibling.integration.test.ts‎

Lines changed: 29 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -105,15 +105,30 @@ function childEnv(f: Fixture, extra: NodeJS.ProcessEnv = {}): NodeJS.ProcessEnv
105105
};
106106
}
107107

108-
/** `os serve`'s own provision-and-exit: the full composition schema-synced into the fixture's database(s). */
109-
function serveBoot(f: Fixture, extra: NodeJS.ProcessEnv = {}): void {
108+
/** How much of each of the serving boot's streams an assertion message carries: its TAIL, where the boot diagnostics replay. */
109+
const BOOT_STREAM_TAIL = 8_000;
110+
111+
/**
112+
* `os serve`'s own provision-and-exit: the full composition schema-synced into the fixture's database(s).
113+
*
114+
* [#22913] Returns the child's own output, so every later assertion that reads what the boot provisioned can
115+
* carry it: a boot that exits 0 with one table missing names its cause on its stderr (a refused DDL is logged
116+
* there at `error`), and an assertion that failed without it left the CI log unable to confirm or refute one.
117+
*/
118+
function serveBoot(f: Fixture, extra: NodeJS.ProcessEnv = {}): string {
110119
const boot = spawnSync(TSX, [RUN_DEV, 'serve', '--no-server', '--no-ui', '--no-console', '--port', '0'], {
111120
cwd: f.dir, env: childEnv(f, { ...extra, OS_MIGRATE_AND_EXIT: '1' }), encoding: 'utf8', timeout: 240_000,
112121
});
113-
expect(boot.status, `the serving boot did not provision the database:\n${`${boot.stdout}\n${boot.stderr}`.slice(-800)}`)
114-
.toBe(0);
122+
const output =
123+
`--- the serving boot's stderr (exit ${boot.status}) ---\n${(boot.stderr ?? '').slice(-BOOT_STREAM_TAIL)}\n` +
124+
`--- the serving boot's stdout ---\n${(boot.stdout ?? '').slice(-BOOT_STREAM_TAIL)}`;
125+
expect(boot.status, `the serving boot did not provision the database:\n${output}`).toBe(0);
126+
return output;
115127
}
116128

129+
/** The message an assertion on what the boot provisioned carries, so its failure names the boot's own account. */
130+
const afterBoot = (bootOutput: string, what: string): string => `${what}\n${bootOutput}`;
131+
117132
function command(f: Fixture, argv: string[], extra: NodeJS.ProcessEnv = {}): { exit: number | null; payload: any } {
118133
const run = spawnSync(TSX, [RUN_DEV, 'migrate', ...argv], { cwd: f.dir, env: childEnv(f, extra), encoding: 'utf8', timeout: 240_000 });
119134
let payload: any;
@@ -154,14 +169,14 @@ const pendingTables = (payload: any): string[] => (payload.pending ?? []).map((p
154169
describe('os migrate plan / apply plan each object against the database it lives in (#22579)', () => {
155170
it('after a development boot: the sibling is named and planned, nothing lifecycle-classed is planned for the primary, apply creates nothing', () => {
156171
const f = fixture();
157-
serveBoot(f);
172+
const booted = serveBoot(f);
158173

159174
// The serving boot's layout — the thing the plan must describe.
160-
expect(existsSync(f.sibling), 'the development boot provisioned no telemetry sibling: nothing to plan against').toBe(true);
175+
expect(existsSync(f.sibling), afterBoot(booted, 'the development boot provisioned no telemetry sibling: nothing to plan against')).toBe(true);
161176
const primaryTables = tables(f.primary);
162177
const siblingTables = tables(f.sibling);
163-
expect(siblingTables).toEqual(expect.arrayContaining(['sys_audit_log', 'sys_metadata_audit']));
164-
expect(primaryTables.filter((t) => siblingTables.includes(t)), 'one table in both databases').toEqual([]);
178+
expect(siblingTables, afterBoot(booted, 'the sibling the boot provisioned')).toEqual(expect.arrayContaining(['sys_audit_log', 'sys_metadata_audit']));
179+
expect(primaryTables.filter((t) => siblingTables.includes(t)), afterBoot(booted, 'one table in both databases')).toEqual([]);
165180
// [#22580] What a retired lifecycle-classed object leaves behind: its table,
166181
// in the sibling, declared by nothing.
167182
const retired = 'sys_os22580_retired_event';
@@ -172,8 +187,8 @@ describe('os migrate plan / apply plan each object against the database it lives
172187
const plan = command(f, ['plan', '--json']);
173188
expect(plan.exit, JSON.stringify(plan.payload).slice(0, 800)).toBe(0);
174189
// Nothing to create anywhere — above all no lifecycle-classed object for the primary.
175-
expect(pendingTables(plan.payload)).toEqual([]);
176-
expect(plan.payload.changes).toEqual([]);
190+
expect(pendingTables(plan.payload), afterBoot(booted, 'a table the serving boot did not provision')).toEqual([]);
191+
expect(plan.payload.changes, afterBoot(booted, 'a change the serving boot did not make')).toEqual([]);
177192
expect(plan.payload.telemetryDatabase).toBe(f.sibling);
178193
expect(plan.payload.composition?.coverage?.unexaminedObjects).toBe(0);
179194
// Both databases' objects examined: their tables, less the raw-DDL one.
@@ -197,17 +212,17 @@ describe('os migrate plan / apply plan each object against the database it lives
197212

198213
it('the control — a deployment with no sibling plans as it did; with the sibling on, an absent one is planned and not created', () => {
199214
const f = fixture();
200-
serveBoot(f, { OS_TELEMETRY_DB: '0' });
215+
const booted = serveBoot(f, { OS_TELEMETRY_DB: '0' });
201216
expect(existsSync(f.sibling)).toBe(false);
202217
const primaryTables = tables(f.primary);
203-
expect(primaryTables).toEqual(expect.arrayContaining(['sys_audit_log', 'sys_metadata_audit']));
218+
expect(primaryTables, afterBoot(booted, 'the primary the boot provisioned')).toEqual(expect.arrayContaining(['sys_audit_log', 'sys_metadata_audit']));
204219

205220
// No sibling: no sibling named, nothing pending, every object on the primary.
206221
const control = command(f, ['plan', '--json'], { OS_TELEMETRY_DB: '0' });
207222
expect(control.exit, JSON.stringify(control.payload).slice(0, 800)).toBe(0);
208223
expect('telemetryDatabase' in control.payload).toBe(false);
209-
expect(pendingTables(control.payload)).toEqual([]);
210-
expect(control.payload.changes).toEqual([]);
224+
expect(pendingTables(control.payload), afterBoot(booted, 'a table the serving boot did not provision')).toEqual([]);
225+
expect(control.payload.changes, afterBoot(booted, 'a change the serving boot did not make')).toEqual([]);
211226
expect(control.payload.managedTables).toBe(primaryTables.length - NOT_AN_OBJECT.length);
212227

213228
// The sibling on, over this deployment: the serving boot would now keep

‎packages/plugins/plugin-audit/src/audit-plugin.test.ts‎

Lines changed: 77 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -42,11 +42,20 @@ function makeCtx(engine: unknown) {
4242
// #4887 — the log IS the deliverable for the provisioning path: its silence
4343
// is what made a working-but-elsewhere table read as a never-created one.
4444
// Capture info/warn so the tests can assert on what an operator would see.
45-
const logs = { info: [] as string[], warn: [] as string[] };
45+
// [#22913] …and every `error` call whole, in the contract's
46+
// `error(message, error?, meta?)` shape, so a pin can count them.
47+
const logs = {
48+
info: [] as string[],
49+
warn: [] as string[],
50+
error: [] as Array<{ message: string; error: unknown; meta: Record<string, unknown> | undefined }>,
51+
};
4652
const logger = {
4753
info(msg: string) { logs.info.push(String(msg)); },
4854
warn(msg: string) { logs.warn.push(String(msg)); },
49-
error() {}, debug() {},
55+
error(msg: string, error?: unknown, meta?: Record<string, unknown>) {
56+
logs.error.push({ message: String(msg), error, meta });
57+
},
58+
debug() {},
5059
child() { return logger; },
5160
};
5261
const ctx = {
@@ -95,6 +104,71 @@ describe('AuditPlugin — system table provisioning', () => {
95104
});
96105
});
97106

107+
/**
108+
* [#22913] A failed provision is a DURABILITY degradation, so it is reported at
109+
* `error` — once per object, never per write — and the boot is not failed.
110+
*
111+
* When an object's DDL throws, the boot still completes and the deployment
112+
* serves as healthy while the table does not exist; for `sys_audit_log` /
113+
* `sys_activity`, audited writes keep succeeding while their audit rows have
114+
* nowhere to land. AGENTS.md "Degradation log levels" sends that class to
115+
* `error`, with the consequence and the fix in the first line. The wording is
116+
* not pinned: the pins hold the level, the count, the named object, the named
117+
* remedy command and the driver's refusal in meta.
118+
*/
119+
describe('AuditPlugin — a failed provision is an error, once per object (#22913)', () => {
120+
const OBJECTS = ['sys_audit_log', 'sys_activity', 'sys_comment', 'sys_comment_reaction'];
121+
122+
/** Every DDL succeeds except the named object's, which the driver refuses. */
123+
function makeEngine(refused?: string) {
124+
return {
125+
async syncObjectSchema(name: string) {
126+
if (name === refused) throw new Error(`there is already an index named ${name}`);
127+
},
128+
getDriverForObject() { return { name: 'sqlite' }; },
129+
getDefaultDriverName() { return 'sqlite'; },
130+
};
131+
}
132+
133+
async function boot(refused?: string) {
134+
const { ctx, logs, fireReady } = makeCtx(makeEngine(refused));
135+
const plugin = new AuditPlugin();
136+
await plugin.init(ctx);
137+
await plugin.start(ctx);
138+
// The boot is NOT failed: kernel:ready resolves.
139+
await expect(fireReady()).resolves.toBeUndefined();
140+
return logs;
141+
}
142+
143+
it.each(OBJECTS)('a refused DDL for %s logs exactly one error line naming it, the remedy and the refusal', async (name) => {
144+
const logs = await boot(name);
145+
146+
expect(logs.error).toHaveLength(1);
147+
const [line] = logs.error;
148+
expect(line.message).toContain(name);
149+
// ② the fix, by its named subject: the command measured to create it.
150+
expect(line.message).toContain('os migrate apply');
151+
// One line: the first line carries both halves.
152+
expect(line.message).not.toContain('\n');
153+
// The driver's refusal travels in meta, never interpolated into the line.
154+
expect(line.meta).toEqual({ object: name, error: `there is already an index named ${name}` });
155+
// …and it is not ALSO reported at a quieter level.
156+
expect(logs.warn.filter((m) => m.includes('could not provision'))).toEqual([]);
157+
// The other three objects still provisioned.
158+
const placement = logs.info.find((m) => m.includes('system tables provisioned'));
159+
for (const other of OBJECTS.filter((o) => o !== name)) expect(placement).toContain(`${other}→sqlite`);
160+
expect(placement).not.toContain(`${name}→`);
161+
});
162+
163+
it('CONTROL: a clean provision logs no error at all', async () => {
164+
const logs = await boot();
165+
166+
expect(logs.error).toEqual([]);
167+
const placement = logs.info.find((m) => m.includes('system tables provisioned'));
168+
for (const name of OBJECTS) expect(placement).toContain(`${name}→sqlite`);
169+
});
170+
});
171+
98172
/**
99173
* #4887 — provisioning must SAY what it did.
100174
*
@@ -231,7 +305,7 @@ describe('AuditPlugin — provisioning is audible (#4887)', () => {
231305
await plugin.start(ctx);
232306
await fireReady();
233307

234-
expect(logs.warn.some((m) => m.includes('could not provision sys_activity'))).toBe(true);
308+
expect(logs.error.some((e) => e.message.includes('could not provision sys_activity'))).toBe(true);
235309
const placement = logs.info.find((m) => m.includes('system tables provisioned'));
236310
expect(placement).toContain('sys_audit_log→sqlite');
237311
expect(placement).toContain('sys_comment→sqlite');

‎packages/plugins/plugin-audit/src/audit-plugin.ts‎

Lines changed: 74 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -138,6 +138,48 @@ function createHostLocaleReader(
138138
};
139139
}
140140

141+
/**
142+
* [#22913] What is lost when one of this plugin's objects has no storage — the
143+
* CONSEQUENCE half of {@link provisionFailureLine}, said concretely per object.
144+
* `sys_audit_log` / `sys_activity` are written as a side effect of audited
145+
* writes, so their loss is invisible to the writer; a comment or a reaction is
146+
* written by its own request, which fails.
147+
*/
148+
function lostWithoutStorage(objectName: string): string {
149+
switch (objectName) {
150+
case 'sys_audit_log':
151+
return 'Audited writes keep succeeding, but the `sys_audit_log` rows that record who did what, and the ' +
152+
'`sys_activity` rows written after them, cannot land, and nothing retries them.';
153+
case 'sys_activity':
154+
return "Audited writes keep succeeding, but their `sys_activity` rows (a record's activity timeline and the " +
155+
'recent-activity feed) cannot land, and nothing retries them.';
156+
case 'sys_comment':
157+
return 'Every comment write fails until it exists.';
158+
case 'sys_comment_reaction':
159+
return 'Every comment reaction write fails until it exists.';
160+
default:
161+
return 'Every write to it fails until it exists.';
162+
}
163+
}
164+
165+
/**
166+
* [#22913] The ONE line `provisionSystemTables` prints when an object's DDL
167+
* throws — at `error`, carrying both halves AGENTS.md "Degradation log levels"
168+
* asks of a durability degradation: ① the consequence, and that the deployment
169+
* keeps looking healthy; ② the fix. Both remedies named were measured to create
170+
* the missing storage once the driver fault is gone.
171+
*/
172+
function provisionFailureLine(objectName: string): string {
173+
return (
174+
`AuditPlugin: could not provision ${objectName} storage — its storage was NOT created. ` +
175+
`${lostWithoutStorage(objectName)} The boot still completes and the deployment keeps looking healthy. ` +
176+
"Fix: resolve the driver's refusal (in this record's meta), then restart, since this provisioning runs on " +
177+
`every boot, or run \`os migrate apply\`, which creates the missing storage (\`os migrate plan\` lists it as ` +
178+
`\`create_table:${objectName}\`). If the boot log also carries \`Schema sync FAILED for object ` +
179+
`'${objectName}'\`, that is the same refusal.`
180+
);
181+
}
182+
141183
/**
142184
* AuditPlugin
143185
*
@@ -472,20 +514,34 @@ export class AuditPlugin implements Plugin {
472514
/**
473515
* Provision the physical tables for this plugin's system objects up-front.
474516
*
475-
* sys_audit_log / sys_activity / sys_comment are otherwise lazy-created on
476-
* first WRITE (the SQL driver issues DDL when the first row is inserted). A
477-
* freshly provisioned env that READS one first — the home page's recent-
478-
* activity feed queries sys_activity before any mutation has happened — hits
479-
* SQLite "no such table", which the engine logs as a `Find operation failed`
480-
* ERROR on every load. The UI degrades to an empty feed, but the log is noisy
481-
* and can mask real errors. Creating the tables at kernel:ready (once the
482-
* engine + registry are ready) makes a new env consistent from the start.
517+
* A freshly provisioned env that READS one of these tables before anything
518+
* created it — the home page's recent-activity feed queries sys_activity
519+
* before any mutation has happened — hits SQLite "no such table", which the
520+
* engine logs as a `Find operation failed` ERROR on every load. Creating the
521+
* tables at kernel:ready (once the engine + registry are ready) makes a new
522+
* env consistent from the start. A WRITE does not create a missing table
523+
* either: the SQL driver's insert fails with the same "no such table".
483524
*
484525
* `syncObjectSchema` is idempotent — the SQL driver only creates a table when
485526
* it is absent (and alters to add columns) — so this is safe on every boot,
486527
* and a no-op for objects whose table already exists. Per-object failures are
487528
* isolated so one bad object can't block the rest.
488529
*
530+
* ## Why a failed provision is an `error` (#22913)
531+
*
532+
* When an object's DDL throws here, the boot still completes and the
533+
* deployment serves as healthy, but the table does not exist. For
534+
* `sys_audit_log` / `sys_activity` the loss is invisible: they are written as
535+
* a SIDE EFFECT of audited writes, which keep succeeding while their audit
536+
* rows have nowhere to land. That is the durability class AGENTS.md
537+
* "Degradation log levels" sends to `error`, with the consequence and the
538+
* fix in the first line. Both remedies the line names were measured to
539+
* create a missing table once the driver fault is gone: a restart (this
540+
* method runs on every boot) and `os migrate apply` (`os migrate plan` lists
541+
* it as `create_table`). `OS_SKIP_SCHEMA_SYNC` is NOT named: this method
542+
* issues its DDL whether or not that flag is set, so the flag cannot make
543+
* this failure deliberate.
544+
*
489545
* ## Why this method reports where each table landed (#4887)
490546
*
491547
* `syncObjectSchema` returns `void` and exits SILENTLY on three conditions
@@ -542,7 +598,16 @@ export class AuditPlugin implements Plugin {
542598
try {
543599
await sync.call(engine, obj.name);
544600
} catch (err) {
545-
ctx.logger.warn(`AuditPlugin: could not provision ${obj.name} storage — ${(err as Error)?.message ?? err}`);
601+
// A DURABILITY degradation, so `error` (AGENTS.md "Degradation log
602+
// levels"; see "Why a failed provision is an `error`" above). Once per
603+
// object per boot, never per write. The boot is deliberately NOT failed:
604+
// refusing to boot is a separate policy call. The driver's refusal goes
605+
// in meta, not in the message: a multi-line driver error would split the
606+
// record, and only its first fragment would carry the level.
607+
ctx.logger.error(provisionFailureLine(obj.name), undefined, {
608+
object: obj.name,
609+
error: (err as Error)?.message ?? String(err),
610+
});
546611
continue;
547612
}
548613
if (typeof resolveDriver !== 'function') continue;

0 commit comments

Comments
 (0)