Skip to content

Commit e62a2fa

Browse files
committed
fix(audit): scope rollups to the run that recorded them and bound flush concurrency
1 parent ca902f3 commit e62a2fa

6 files changed

Lines changed: 101 additions & 50 deletions

File tree

‎apps/sim/lib/table/application/row-audit.integration.ts‎

Lines changed: 10 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,4 @@
1-
import { flushAuditRollups } from '@sim/audit'
1+
import { withAuditRollupScope } from '@sim/audit'
22
import { db } from '@sim/db'
33
import {
44
auditLog,
@@ -206,7 +206,6 @@ describe('table mutation audit history in PostgreSQL', () => {
206206
}
207207

208208
async function auditRows() {
209-
await flushAuditRollups()
210209
return db
211210
.select()
212211
.from(auditLog)
@@ -216,7 +215,9 @@ describe('table mutation audit history in PostgreSQL', () => {
216215

217216
it("merges one execution's repeated row inserts into one row that keeps every row id and count", async () => {
218217
const rowIds: string[] = []
219-
for (const value of ['a', 'b', 'c']) rowIds.push(await insertAsExecution('exec-1', value))
218+
await withAuditRollupScope(async () => {
219+
for (const value of ['a', 'b', 'c']) rowIds.push(await insertAsExecution('exec-1', value))
220+
})
220221

221222
const entries = await auditRows()
222223
expect(entries).toHaveLength(1)
@@ -242,9 +243,11 @@ describe('table mutation audit history in PostgreSQL', () => {
242243
})
243244

244245
it('never merges row changes from two executions', async () => {
245-
await insertAsExecution('exec-1', 'a')
246-
await insertAsExecution('exec-2', 'b')
247-
await insertAsExecution('exec-1', 'c')
246+
await withAuditRollupScope(async () => {
247+
await insertAsExecution('exec-1', 'a')
248+
await insertAsExecution('exec-2', 'b')
249+
await insertAsExecution('exec-1', 'c')
250+
})
248251

249252
const entries = await auditRows()
250253
expect(entries).toHaveLength(2)
@@ -258,7 +261,7 @@ describe('table mutation audit history in PostgreSQL', () => {
258261
})
259262

260263
it('writes a lone execution change exactly as an unmerged entry', async () => {
261-
const insertedRowId = await insertAsExecution('exec-1', 'a')
264+
const insertedRowId = await withAuditRollupScope(() => insertAsExecution('exec-1', 'a'))
262265

263266
const [entry] = await auditRows()
264267
expect(entry.metadata).toMatchObject({

‎apps/sim/lib/workflows/deployment-outbox.ts‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ import type { PrincipalActor } from '@sim/auth/principal'
33
import { db, workflowDeploymentVersion, workflow as workflowTable } from '@sim/db'
44
import { outboxEvent, workspaceOperationReceipt } from '@sim/db/schema'
55
import { createLogger } from '@sim/logger'
6+
import { toStringOrNull } from '@sim/utils/coerce'
67
import { toError } from '@sim/utils/errors'
78
import { and, eq } from 'drizzle-orm'
89
import { NextRequest } from 'next/server'
@@ -1528,11 +1529,25 @@ function parseOptionalPrincipalActor(value: unknown): PrincipalActor | undefined
15281529
serviceId,
15291530
subjectUserId: parseRequiredString(record.subjectUserId, 'actor.subjectUserId'),
15301531
delegationId: parseRequiredString(record.delegationId, 'actor.delegationId'),
1532+
...parseOptionalActorRun(record),
15311533
}
15321534
}
15331535
throw new Error(`Invalid deployment outbox actor kind: ${kind}`)
15341536
}
15351537

1538+
/** The workflow run an executor delegation acted for, kept so its audit stays traceable. */
1539+
function parseOptionalActorRun(record: Record<string, unknown>): {
1540+
workflowId?: string
1541+
executionId?: string
1542+
} {
1543+
const workflowId = toStringOrNull(record.workflowId)
1544+
const executionId = toStringOrNull(record.executionId)
1545+
return {
1546+
...(workflowId ? { workflowId } : {}),
1547+
...(executionId ? { executionId } : {}),
1548+
}
1549+
}
1550+
15361551
function parseDeploymentPreparationCheckpoints(value: unknown): DeploymentPreparationCheckpoints {
15371552
if (!value || typeof value !== 'object' || Array.isArray(value)) return {}
15381553
const record = value as Record<string, unknown>

‎apps/sim/lib/workflows/executor/execution-core.ts‎

Lines changed: 8 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,7 @@
33
* This is the SINGLE source of truth for workflow execution
44
*/
55

6-
import { flushAuditRollups } from '@sim/audit'
6+
import { withAuditRollupScope } from '@sim/audit'
77
import { resolvePrincipalSubject } from '@sim/auth/principal'
88
import { db } from '@sim/db'
99
import { organization, workspace } from '@sim/db/schema'
@@ -609,17 +609,14 @@ function prefetchExecutionReads(options: ExecuteWorkflowCoreOptions): ExecutionR
609609
*
610610
* Runs under `runWorkflowOutsideContentDelivery`, so a run Chat started reads what any run reads.
611611
*
612-
* Writes pending audit rollups before returning, since a background run's process
613-
* may be frozen or ended once it does.
612+
* Owns the audit rollups the run and its inline child runs record, and writes
613+
* them before returning, since a background run's process may be frozen or
614+
* ended once it does.
614615
*/
615-
export async function executeWorkflowCore(
616-
options: ExecuteWorkflowCoreOptions
617-
): Promise<ExecutionResult> {
618-
try {
619-
return await runWorkflowOutsideContentDelivery(() => executeWorkflowCoreInRun(options))
620-
} finally {
621-
await flushAuditRollups()
622-
}
616+
export function executeWorkflowCore(options: ExecuteWorkflowCoreOptions): Promise<ExecutionResult> {
617+
return withAuditRollupScope(() =>
618+
runWorkflowOutsideContentDelivery(() => executeWorkflowCoreInRun(options))
619+
)
623620
}
624621

625622
async function executeWorkflowCoreInRun(

‎packages/audit/src/index.ts‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
export type { AuditLogParams } from './log'
22
export { recordAudit, recordAuditBatch, recordAuditOnce } from './log'
3-
export type { AuditRollupEntry, AuditRollupSummary } from './rollup'
4-
export { flushAuditRollups, recordAuditRollup } from './rollup'
3+
export type { AuditRollupSummary } from './rollup'
4+
export { recordAuditRollup, withAuditRollupScope } from './rollup'
55
export type { AuditActionType, AuditResourceTypeValue } from './types'
66
export { AuditAction, AuditResourceType } from './types'
77
export { auditUpdatedFields } from './updated-fields'

‎packages/audit/src/rollup.ts‎

Lines changed: 62 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import { AsyncLocalStorage } from 'node:async_hooks'
12
import { createLogger } from '@sim/logger'
23
import { type AuditLogParams, ambientSurface, insertDeferredAuditEntry } from './log'
34

@@ -12,6 +13,9 @@ const ROLLUP_MAX_ENTRIES = 100
1213
/** Pending rollups held by the process; reaching it writes every one of them. */
1314
const ROLLUP_MAX_PENDING = 1_000
1415

16+
/** Rows inserted at once by one write, so a large flush never floods the pool. */
17+
const ROLLUP_WRITE_CONCURRENCY = 10
18+
1519
export interface AuditRollupSummary {
1620
entries: number
1721
counters: Record<string, number>
@@ -41,7 +45,17 @@ export interface AuditRollupEntry {
4145
describe(summary: AuditRollupSummary): string
4246
}
4347

48+
/**
49+
* A unit of work that owns the rollups recorded inside it (a workflow run and
50+
* the child runs it executes inline), so its end writes only its own rows.
51+
*/
52+
interface RollupScope {
53+
id: number
54+
writes: Set<Promise<void>>
55+
}
56+
4457
interface PendingRollup {
58+
scope: RollupScope | undefined
4559
first: AuditRollupEntry
4660
surface: string | undefined
4761
firstAt: Date
@@ -53,20 +67,22 @@ interface PendingRollup {
5367
}
5468

5569
const pending = new Map<string, PendingRollup>()
56-
57-
/** Writes started but not finished, so a flush also waits for rows already leaving. */
58-
const inFlight = new Set<Promise<void>>()
70+
const scopeStorage = new AsyncLocalStorage<RollupScope>()
71+
let nextScopeId = 0
5972

6073
/**
6174
* Records a repetitive audit event, merging it with its repeats. Fire-and-forget
6275
* like `recordAudit`. Each pending row is written when its window closes, when
63-
* it reaches {@link ROLLUP_MAX_ENTRIES}, or on {@link flushAuditRollups}. The
64-
* window timer is not unref'd, so a process that ends naturally still writes it.
76+
* it reaches {@link ROLLUP_MAX_ENTRIES}, or when the {@link withAuditRollupScope}
77+
* it was recorded in ends. The window timer is not unref'd, so a process that
78+
* ends naturally still writes it.
6579
*/
6680
export function recordAuditRollup(entry: AuditRollupEntry): void {
6781
const surface = ambientSurface()
82+
const scope = scopeStorage.getStore()
6883
const { params } = entry
6984
const key = JSON.stringify([
85+
scope?.id ?? null,
7086
surface ?? null,
7187
params.workspaceId ?? null,
7288
params.actorId,
@@ -90,6 +106,7 @@ export function recordAuditRollup(entry: AuditRollupEntry): void {
90106

91107
const now = new Date()
92108
const rollup: PendingRollup = {
109+
scope,
93110
first: entry,
94111
surface,
95112
firstAt: now,
@@ -104,19 +121,33 @@ export function recordAuditRollup(entry: AuditRollupEntry): void {
104121
}
105122

106123
/**
107-
* Writes every pending row now and waits for writes already started. Work that
108-
* may be frozen or ended once it returns (a workflow run) awaits this at its
109-
* end. Never throws.
124+
* Runs `work` as the owner of the rollups recorded inside it, then writes them
125+
* and waits for those writes before returning, so work whose process may be
126+
* frozen or ended once it returns (a background workflow run) leaves nothing
127+
* pending. Other scopes' rollups keep their own window. Each write is one
128+
* insert, bounded by the database's statement and connect timeouts; a failed
129+
* one is logged, never thrown.
110130
*/
111-
export async function flushAuditRollups(): Promise<void> {
112-
if (pending.size > 0) startWrite([...pending.keys()].map(take))
113-
await Promise.all(inFlight)
131+
export async function withAuditRollupScope<T>(work: () => Promise<T>): Promise<T> {
132+
const scope: RollupScope = { id: nextScopeId++, writes: new Set() }
133+
try {
134+
return await scopeStorage.run(scope, work)
135+
} finally {
136+
const keys = [...pending.entries()]
137+
.filter(([, rollup]) => rollup.scope === scope)
138+
.map(([key]) => key)
139+
if (keys.length > 0) startWrite(keys.map(take))
140+
await Promise.all(scope.writes)
141+
}
114142
}
115143

116144
function startWrite(rollups: PendingRollup[]): void {
117145
const done = writePending(rollups)
118-
inFlight.add(done)
119-
void done.finally(() => inFlight.delete(done))
146+
const scopes = new Set(rollups.map((rollup) => rollup.scope))
147+
for (const scope of scopes) scope?.writes.add(done)
148+
void done.finally(() => {
149+
for (const scope of scopes) scope?.writes.delete(done)
150+
})
120151
}
121152

122153
function mergeInto(rollup: PendingRollup, entry: AuditRollupEntry): void {
@@ -163,19 +194,24 @@ function toAuditParams(rollup: PendingRollup): AuditLogParams {
163194
}
164195
}
165196

166-
/** One insert per row, so a row that cannot be written never takes others with it. */
197+
/**
198+
* One insert per row, so a row that cannot be written never takes others with
199+
* it, at most {@link ROLLUP_WRITE_CONCURRENCY} at a time.
200+
*/
167201
async function writePending(rollups: PendingRollup[]): Promise<void> {
168-
await Promise.all(
169-
rollups.map(async (rollup) => {
170-
try {
171-
await insertDeferredAuditEntry(toAuditParams(rollup), rollup.surface)
172-
} catch (error) {
173-
logger.error('Failed to record audit log rollup', {
174-
error,
175-
action: rollup.first.params.action,
176-
entries: rollup.entries,
177-
})
178-
}
202+
for (let index = 0; index < rollups.length; index += ROLLUP_WRITE_CONCURRENCY) {
203+
await Promise.all(rollups.slice(index, index + ROLLUP_WRITE_CONCURRENCY).map(writeRollup))
204+
}
205+
}
206+
207+
async function writeRollup(rollup: PendingRollup): Promise<void> {
208+
try {
209+
await insertDeferredAuditEntry(toAuditParams(rollup), rollup.surface)
210+
} catch (error) {
211+
logger.error('Failed to record audit log rollup', {
212+
error,
213+
action: rollup.first.params.action,
214+
entries: rollup.entries,
179215
})
180-
)
216+
}
181217
}

‎packages/testing/src/mocks/audit.mock.ts‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -272,8 +272,8 @@ const AuditResourceType = {
272272
/**
273273
* Controllable mock functions for `@sim/audit`.
274274
*
275-
* `mockRecordAuditOnce` and `mockFlushAuditRollups` resolve `undefined` by default,
276-
* like the real awaited writes.
275+
* `mockRecordAuditOnce` resolves `undefined` by default, like the real awaited insert.
276+
* `mockWithAuditRollupScope` runs the work it is given, like the real scope.
277277
*
278278
* @example
279279
* ```ts
@@ -292,7 +292,7 @@ export const auditMockFns = {
292292
mockRecordAuditBatch: vi.fn(),
293293
mockRecordAuditOnce: vi.fn(async (_id: string, _params: unknown): Promise<void> => undefined),
294294
mockRecordAuditRollup: vi.fn(),
295-
mockFlushAuditRollups: vi.fn(async (): Promise<void> => undefined),
295+
mockWithAuditRollupScope: vi.fn(<T>(work: () => Promise<T>): Promise<T> => work()),
296296
}
297297

298298
/**
@@ -309,7 +309,7 @@ export const auditMock = {
309309
recordAuditBatch: auditMockFns.mockRecordAuditBatch,
310310
recordAuditOnce: auditMockFns.mockRecordAuditOnce,
311311
recordAuditRollup: auditMockFns.mockRecordAuditRollup,
312-
flushAuditRollups: auditMockFns.mockFlushAuditRollups,
312+
withAuditRollupScope: auditMockFns.mockWithAuditRollupScope,
313313
/**
314314
* Real implementation, not a stub: callers under test derive their audit
315315
* metadata through it, so stubbing it would erase what the test asserts.

0 commit comments

Comments
 (0)