diff --git a/.changeset/audit-skip-sys-job-queue.md b/.changeset/audit-skip-sys-job-queue.md new file mode 100644 index 0000000000..619355fb51 --- /dev/null +++ b/.changeset/audit-skip-sys-job-queue.md @@ -0,0 +1,32 @@ +--- +"@objectstack/plugin-audit": patch +--- + +fix(plugin-audit): stop mirroring `sys_job_queue` traffic into the audit ledger (#5193) + +`SKIP_OBJECTS` in `audit-writers.ts` excludes operational telemetry / plumbing +from `sys_audit_log` and `sys_activity` — ADR-0057 decision 5, *"stop the +amplifier"*. Its group (2) already listed `sys_job`, `sys_job_run` and +`sys_automation_run`; `sys_job_queue` — the highest-volume table of that same +family — was the one sibling missing, so every durable queue message was +mirrored into both sinks. + +The audit hooks register for **all** objects (`afterInsert` / `afterUpdate` / +`afterDelete`) and there is no "writes made under a system context are not +audited" exemption, so `DbQueueAdapter`'s own writes were recorded like user +edits. One message costs at least three of them — the publish insert, the lease +`pending → running` update and the terminal `→ completed` update, plus one retry +update per failure and the reaper's periodic DELETE of completed rows — each +producing an `sys_audit_log` **and** an `sys_activity` row. Since queue-backed +email delivery landed, that ran on every single mail. Each `beforeUpdate` also +paid an extra `findOne` snapshot of the row it was about to change. + +`sys_job_queue` is engine-owned plumbing (`managedBy: 'engine-owned'`, +`enable.apiMethods: ['get', 'list']`, `lifecycle.class: 'transient'`) that no +user can write, so those rows carried no compliance value — only noise and write +amplification. Nothing else changes: the exemption is one name in one list, and +ordinary business objects are audited exactly as before. + +Operators who charted queue throughput off `sys_activity` should read +`sys_job_queue` directly instead — it is the system of record for queue state, +and unlike the audit sinks it is exposed for reading (`get` / `list`). diff --git a/packages/plugins/plugin-audit/src/audit-writers.test.ts b/packages/plugins/plugin-audit/src/audit-writers.test.ts index aaea8cd36c..75bc5bff7b 100644 --- a/packages/plugins/plugin-audit/src/audit-writers.test.ts +++ b/packages/plugins/plugin-audit/src/audit-writers.test.ts @@ -242,6 +242,117 @@ describe('audit writers — actor attribution (ADR-0014 D2, cloud#340)', () => { }); }); +describe('audit writers — operational plumbing is excluded (#5193, ADR-0057 D5)', () => { + // The queue table as `DbQueueAdapter` writes it, alongside the two audit + // sinks. Everything here goes through the SAME wildcard hooks a business + // object does — `SKIP_OBJECTS` is the only thing standing between the queue + // and the ledger (there is no "system context writes are not audited" rule). + const SCHEMA = { + sys_audit_log: SINGLE_TENANT.sys_audit_log, + sys_activity: SINGLE_TENANT.sys_activity, + sys_job_queue: ['id', 'queue', 'status', 'attempts', 'locked_by', 'locked_until', 'completed_at'], + crm_lead: ['id', 'name'], + }; + // Every write `service-queue` performs for ONE message, in order: publish, + // lease (`pending→running`), terminal (`→completed`), and the #5192 reaper's + // periodic DELETE of completed rows. + const QUEUE_MESSAGE_LIFECYCLE: Array<[string, Record]> = [ + [ + 'afterInsert', + { + input: { id: 'msg-1' }, + result: { id: 'msg-1', queue: 'email_delivery', status: 'pending', attempts: 0 }, + }, + ], + [ + 'afterUpdate', + { + input: { id: 'msg-1', status: 'running' }, + __previous: { id: 'msg-1', queue: 'email_delivery', status: 'pending', attempts: 0 }, + result: { id: 'msg-1', queue: 'email_delivery', status: 'running', attempts: 1, locked_by: 'worker-1' }, + }, + ], + [ + 'afterUpdate', + { + input: { id: 'msg-1', status: 'completed' }, + __previous: { id: 'msg-1', queue: 'email_delivery', status: 'running', attempts: 1, locked_by: 'worker-1' }, + result: { id: 'msg-1', queue: 'email_delivery', status: 'completed', attempts: 1, completed_at: '2026-08-04T00:00:00.000Z' }, + }, + ], + [ + 'afterDelete', + { + input: { id: 'msg-1' }, + __previous: { id: 'msg-1', queue: 'email_delivery', status: 'completed', attempts: 1 }, + result: { id: 'msg-1' }, + }, + ], + ]; + + it('writes NO audit/activity row for a full sys_job_queue message lifecycle', async () => { + const { engine, fire, created } = makeEngine(SCHEMA); + installAuditWriters(engine as any, 'test.audit'); + + for (const [event, ctx] of QUEUE_MESSAGE_LIFECYCLE) { + await fire(event, { object: 'sys_job_queue', session: { isSystem: true }, ...ctx }); + } + + // Not "fewer rows" — zero. One email used to cost ≥3 audit + ≥3 activity + // rows here, and the reaper's sweep another delete row apiece (#5160). + expect(created).toEqual([]); + }); + + it('pins sys_job_queue in the same exemption group as its siblings sys_job / sys_job_run', async () => { + const SIBLINGS = ['sys_job', 'sys_job_run', 'sys_job_queue', 'sys_automation_run']; + for (const object of SIBLINGS) { + const { engine, fire, created } = makeEngine({ ...SCHEMA, [object]: ['id', 'status'] }); + installAuditWriters(engine as any, 'test.audit'); + await fire('afterInsert', { + object, + input: { id: 'row-1' }, + result: { id: 'row-1', status: 'pending' }, + session: { isSystem: true }, + }); + expect(created, `${object} must not reach the audit ledger`).toEqual([]); + } + }); + + it('does not pay the beforeUpdate snapshot read for a skipped object', async () => { + const { engine, fire } = makeEngine(SCHEMA); + installAuditWriters(engine as any, 'test.audit'); + const reads: string[] = []; + const ql = { + async findOne(object: string) { + reads.push(object); + return { id: 'msg-1' }; + }, + }; + + // Every queue state transition would otherwise re-read its own row… + await fire('beforeUpdate', { object: 'sys_job_queue', input: { id: 'msg-1', status: 'running' }, ql }); + await fire('beforeDelete', { object: 'sys_job_queue', input: { id: 'msg-1' }, ql }); + expect(reads).toEqual([]); + + // …and the control proves the assertion above can fail: a business object + // on the same harness DOES get snapshotted. + await fire('beforeUpdate', { object: 'crm_lead', input: { id: 'lead-1', name: 'Acme' }, ql }); + expect(reads).toEqual(['crm_lead']); + }); + + it('still audits ordinary business writes (the skip stays narrow)', async () => { + const { engine, fire, created } = makeEngine(SCHEMA); + installAuditWriters(engine as any, 'test.audit'); + await fire('afterInsert', { + object: 'crm_lead', + input: { id: 'lead-1' }, + result: { id: 'lead-1', name: 'Acme' }, + session: { userId: 'user-1' }, + }); + expect(created.map((c) => c.object)).toEqual(['sys_audit_log', 'sys_activity']); + }); +}); + describe('audit writers — declarative trackHistory activity (ADR-0052 §5b)', () => { // crm_opportunity with a tracked select field (Stage) carrying option labels. const SCHEMA = { diff --git a/packages/plugins/plugin-audit/src/audit-writers.ts b/packages/plugins/plugin-audit/src/audit-writers.ts index 914c11e584..6e05541cd2 100644 --- a/packages/plugins/plugin-audit/src/audit-writers.ts +++ b/packages/plugins/plugin-audit/src/audit-writers.ts @@ -108,6 +108,17 @@ const SKIP_OBJECTS = new Set([ // (2) operational telemetry / plumbing (ADR-0057 — telemetry/transient/event) 'sys_job', // schedule heartbeats (last_run_at churn) 'sys_job_run', // one row per scheduled execution + // [#5193, ADR-0057 D5 "stop the amplifier"] `sys_job_queue` is `sys_job_run`'s + // sibling — `lifecycle.class: 'transient'` since #5179 — and the highest-volume + // table of this family. It is engine-owned plumbing (`managedBy: + // 'engine-owned'`, `enable.apiMethods: ['get','list']`), written ONLY by + // `DbQueueAdapter` under SYSTEM_CTX, so no row here is a user-attributable, + // compliance-relevant change. Every message costs at least three writes — + // publish insert, lease `pending→running`, terminal `→completed` (plus a retry + // update per failure and the #5192 reaper's periodic DELETE of completed rows) + // — and each one mirrored into `sys_audit_log` AND `sys_activity`. Since #5160 + // routes email through the queue, that is the amplifier on every single mail. + 'sys_job_queue', // durable queue/DLQ messages (≥3 writes each) 'sys_automation_run', // one row per automation execution 'sys_notification', // messaging-owned (ADR-0030); its own lifecycle 'sys_notification_delivery',