Repository navigation
fix(plugin-audit): a failed boot provisioning of an audit table is logged at error, naming what is lost and the fix - #22981
Conversation
…gged at error, naming what is lost and the fix AuditPlugin's kernel:ready provisioning caught a refused DDL for sys_audit_log / sys_activity / sys_comment / sys_comment_reaction and logged it at warn. 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. That is the durability class AGENTS.md "Degradation log levels" sends to error. The catch now logs one error per object per boot. Its first line names the object, what is lost, that the deployment keeps looking healthy, and the measured fix: resolve the driver's refusal, then restart or run `os migrate apply`. The driver's message goes in meta. The boot is still not failed. Pins: a refused DDL on each of the four objects logs exactly one error naming it and `os migrate apply`, with the refusal in meta; the control, a clean provision, logs no error. The telemetry-sibling integration test now carries the serve child's own output in the assertions that read what the boot provisioned. Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude <[email protected]>
…e-bracket placeholders Claude-Session: https://claude.ai/code/session_01CeRCvvvjxbxu2iYJAc5Cce Co-authored-by: Claude <[email protected]>
📓 Docs Drift CheckThis PR changes 1 package(s): 8 hand-written doc(s) NAME something this change touched and may need an implementation-accuracy re-verification:
⛔ 8 release-owned page(s) also name something this change touched. These are read-only:
What this run could not see
Coarse fallback — 9 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): Which tree this was computed onThis run read A worktree cut from an older # while this PR is open — GitHub drops the merge commit once it closes
git fetch origin 276071b44bbbffddcaa7d9a05677b6249006414d && git checkout 276071b44bbbffddcaa7d9a05677b6249006414d
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin a2240c4dcfc3a19f058cb0b3a4f15a351908acde f8d993e084ff600a5a494350002351e73e2a31d6 && git checkout -B drift-repro a2240c4dcfc3a19f058cb0b3a4f15a351908acde && git merge --no-ff f8d993e084ff600a5a494350002351e73e2a31d6
node scripts/docs-audit/affected-docs.mjs --json a2240c4dcfc3a19f058cb0b3a4f15a351908acde
|
|
Seat note ·
Generated by Claude Code |
Fixes #22913
Clause-②: no
What this changes
AuditPlugin.provisionSystemTables(packages/plugins/plugin-audit/src/audit-plugin.ts) creates the storage forsys_audit_log,sys_activity,sys_commentandsys_comment_reactionatkernel:ready. When the driver refused one of those DDL statements, the catch logged it atwarnand 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 toerror.errorper 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 runos 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.no such table(measured below).plan.telemetry-sibling.integration.test.tsnow carries theservechild'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, throughos serve(OS_MIGRATE_AND_EXIT=1,OS_LOG_LEVEL=warn, telemetry sibling on), once, with exit 0:On
mainthe same boot printedWARN AuditPlugin: could not provision sys_activity storage — …inside theBoot diagnostics — N informationalblock.Measured before writing the fix half (dispatch A3)
Harness: a scratch app (
requires: ['auth', 'automation']), booted throughos servewithOS_MIGRATE_AND_EXIT=1. The DDL refusal was forced by pre-creating an INDEX namedsys_activity: SQLite tables, views and indexes share one namespace, so the CREATE is refused. Run onmain1f312fdfacode, in both compositions (OS_TELEMETRY_DB=0, and the default telemetry sibling).serveexits 0; thesys_activityview is absent; the audit write that follows logsno such table: sys_activityos migrate plan --jsonpending = ["create_table:sys_activity"]os migrate apply --yes --json(on a copy)created=sys_activity; the view exists afterwards (in the sibling file when the sibling is on)OS_SKIP_SCHEMA_SYNC=1boot of an existing schema withsys_comment_reactiondroppedSkipping schema sync … WITHOUT DDL, and the table is re-created anyway: this provisioning issues its DDL whatever that flag saysSo the line names restart and
os migrate apply, which were both measured to restore the table. It does not nameOS_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:readyfires 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 carriesERROR Schema sync FAILED for object 'sys_activity'. It carries it twice, from two sync passes in that boot, each with its ownfinished 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-levelcannot see this site (dispatch A4)sync.call(engine, obj.name). The checker'scalleeNamereads that callee ascall: it unwraps.call/.apply/.bindon the log side (resolveLogCallee) but not on the guarded side. So asyncObjectSchemaentry inDURABILITY_CRITICAL_CALLEESwould not light this site, or the identical messaging site.['syncObjectSchema', …]to the map (in a scratch copy, on1f312fdfa) 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.warninensureObjectStorage)packages/services/service-datasource/src/datasource-connection-service.ts:658(QUIET,warn)DURABILITY_CRITICAL_CALLEESin 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)it.each): a refused DDL logs exactly oneerror. The line names the object andos migrate applyand has no newline. The refusal is in meta. Nocould not provisionline is logged atwarn. The other three objects still provision, andkernel:readyresolves (the boot is not failed).errorcalls.keeps reporting placements when one object fails to syncnow reads the line fromerror.Ablations (one-shot,
scripts/ablation-replace.mjsin WRAP mode, run on committed168cf1e33, restore proved by blob == HEAD and an emptygit diff HEAD):ctx.logger.error(provisionFailureLine(…), undefined, {changed toctx.logger.warn(provisionFailureLine(…), {): 5 failed / 10 passed. The four per-object pins fail withexpected [] to have a length of 1 but got +0, and so does the placement test. The CONTROL stays green.erroron the clean path (the line also emitted before each successful placement): 5 failed / 10 passed. The CONTROL fails withexpected [ { …(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, soablation-replacerefused it (anchor count 1 to 1) and ran no test. The second anchor ran.pendingTablesexpectation 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 after168cf1e33.pnpm --filter @objectstack/plugin-audit test: 47 files, 748 tests passed.pnpm --filter @objectstack/plugin-audit typecheck(tsc, scripts project,check:test-typecheck) passed at168cf1e33, 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 typecheckpassed, and the cli test-typecheck debt is unchanged; the touched file is not in it. The cliunitlayer is left to CI: the only cli file changed is this integration test.node scripts/pm/dispatch-gates.mjs --commandsover the real change set derived 67 gate commands. All 67 ran, and--ranreconciles 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-testafter fetching its pinned control commit, andcheck:dual-build-cjs-loads,check:i18n,check:i18n-coverageandcheck:i18n-walk-parityafter 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).eslint --no-inline-configover the three touched TS files: 3 files (count read from--format json), 0 errors, 0 warnings.--print-configresolves rules for each file, so none is ignored, and noparserOptions.projectorprojectServiceis set. Linting is not type-aware, so this diff cannot change the verdict on an untouched file. The repo-widepnpm lintis left to CI.Acceptance notes
serveboot.Schema sync FAILED for object 'X'and thefinished with 1 FAILED object(s)summary each print twice, in two passes about 350 ms apart (measured above). Observation only; Carrier: none.no syncObjectSchemawarn 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 withno such table). It is left as is because it guards engines without on-demand DDL, which this card does not cover. Carrier: none.resolves to NO datasource driverbranch in the same loop is still awarn. 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.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 siblingerrorwith the same object name. Carrier: none.Generated by Claude Code