Skip to content

Commit 59bbfd5

Browse files
authored
perf(audit-logs): index organization-level rows and read them as two keyset parts (#9437)
Fixes a regression from #9419: the organization-level branch of the audit-log listing had no index serving it in order, so a listing walked every workspace-less audit row. Migration 0444 adds a partial keyset index on workspace-less rows that name an organization, and the branch is split into two disjoint keyset parts (metadata through the new index, organization-resource rows through the resource index). A plan test pins the index use.
1 parent 70c8231 commit 59bbfd5

8 files changed

Lines changed: 31598 additions & 19 deletions

File tree

Lines changed: 120 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
/**
2+
* The plan an organization's audit-log listing must get, proven on the exact SQL
3+
* `queryAuditLogs` sends against a table with many workspace-less rows of other organizations:
4+
* the organization-level metadata part is read through `audit_log_org_level_created_at_id_idx`,
5+
* which can stream it in keyset order and stop after a page, and never by seeking
6+
* `workspace_id IS NULL` and filtering every workspace-less row in the table.
7+
*/
8+
import { db } from '@sim/db'
9+
import { auditLog, user, workspace } from '@sim/db/schema'
10+
import { explainCaptured, type PlanNode } from '@sim/db/testing/explain'
11+
import { assertDisposableTestDatabaseUrl } from '@sim/db/testing/test-infrastructure'
12+
import { deleteWorkspaceFixture, insertWorkspaceFixture } from '@sim/db/testing/workspace-fixtures'
13+
import { generateId } from '@sim/utils/id'
14+
import { eq, like, sql } from 'drizzle-orm'
15+
import { afterAll, beforeAll, describe, expect, it } from 'vitest'
16+
import { type AuditLogListScope, queryAuditLogs } from '@/lib/audit-logs/query'
17+
18+
const organizationId = generateId()
19+
const memberId = generateId()
20+
const workspaceId = generateId()
21+
const idPrefix = `audit_plan_${generateId()}_`
22+
const orgLevelIndex = 'audit_log_org_level_created_at_id_idx'
23+
24+
const cursor = Buffer.from(
25+
JSON.stringify({ createdAt: '2026-01-02T00:00:00.000Z', id: `${idPrefix}~` })
26+
).toString('base64')
27+
28+
const listingPlan = (
29+
includeDeparted: boolean,
30+
pageCursor: string | undefined,
31+
gucs?: Record<string, string>
32+
) => {
33+
const scope: AuditLogListScope = {
34+
organizationId,
35+
orgWorkspaceIds: [workspaceId],
36+
orgMemberIds: [memberId],
37+
includeDeparted,
38+
}
39+
return explainCaptured(db, () => queryAuditLogs(scope, [], 50, pageCursor), { gucs })
40+
}
41+
42+
const scansOf = (nodes: PlanNode[], index: string) =>
43+
nodes.filter((node) => node['Index Name'] === index)
44+
45+
const CASES = [
46+
['current members', false, undefined],
47+
['departed members included', true, undefined],
48+
['current members, after a cursor', false, cursor],
49+
['departed members included, after a cursor', true, cursor],
50+
] as const
51+
52+
describe('organization audit-log listing plans in PostgreSQL', () => {
53+
beforeAll(async () => {
54+
assertDisposableTestDatabaseUrl(process.env.DATABASE_URL ?? '')
55+
await db.insert(user).values({
56+
id: memberId,
57+
name: 'Audit plan fixture',
58+
email: `${memberId}@audit-plan.test`,
59+
emailVerified: true,
60+
createdAt: new Date(),
61+
updatedAt: new Date(),
62+
})
63+
await insertWorkspaceFixture(db, {
64+
id: workspaceId,
65+
name: 'Audit plan fixture',
66+
ownerId: memberId,
67+
billedAccountUserId: memberId,
68+
})
69+
// Workspace-less rows of many other organizations across the whole history, and a few
70+
// hundred of this organization's, so a scan that filters workspace-less rows for the
71+
// organization costs far more than one that reads only the organization's rows.
72+
await db.execute(sql`
73+
INSERT INTO ${auditLog} (id, workspace_id, actor_id, action, resource_type, resource_id,
74+
metadata, created_at)
75+
SELECT ${idPrefix} || n, CASE WHEN n % 10 = 1 THEN ${workspaceId} END,
76+
CASE WHEN n % 2 = 0 THEN ${memberId} END, 'organization.updated',
77+
CASE WHEN n % 997 = 0 THEN 'organization' ELSE 'workflow' END,
78+
CASE WHEN n % 997 = 0 THEN ${organizationId} ELSE 'resource-' || n END,
79+
jsonb_build_object('organizationId',
80+
CASE WHEN n % 50 = 0 THEN ${organizationId} ELSE 'other-organization-' || (n % 400) END),
81+
timestamp '2026-01-01' + n * interval '1 second'
82+
FROM generate_series(1, 20000) AS n`)
83+
await db.execute(sql`VACUUM ANALYZE ${auditLog}`)
84+
})
85+
86+
afterAll(async () => {
87+
await db.delete(auditLog).where(like(auditLog.id, `${idPrefix}%`))
88+
await deleteWorkspaceFixture(db, eq(workspace.id, workspaceId))
89+
await db.delete(user).where(eq(user.id, memberId))
90+
})
91+
92+
it.each(CASES)(
93+
'reads organization-level metadata rows through their index, never every workspace-less row (%s)',
94+
async (_label, includeDeparted, pageCursor) => {
95+
const nodes = await listingPlan(includeDeparted, pageCursor)
96+
const orgLevel = scansOf(nodes, orgLevelIndex)
97+
expect(orgLevel).toHaveLength(1)
98+
expect(orgLevel[0]['Index Cond']).toMatch(/'organizationId'/)
99+
expect(nodes.filter((node) => /workspace_id IS NULL/.test(node['Index Cond'] ?? ''))).toEqual(
100+
[]
101+
)
102+
}
103+
)
104+
105+
/**
106+
* Whether the planner streams the part or collects and sorts it is a cost choice: the
107+
* expression has no statistics (a partial index's are not used), so the estimate grows with
108+
* the table. What must hold is that the index can serve the part in keyset order, so that on a
109+
* large table the scan stops after a page.
110+
*/
111+
it.each(CASES)(
112+
'can stream organization-level metadata rows newest first from their index (%s)',
113+
async (_label, includeDeparted, pageCursor) => {
114+
const nodes = await listingPlan(includeDeparted, pageCursor, { enable_bitmapscan: 'off' })
115+
const [orgLevel] = scansOf(nodes, orgLevelIndex)
116+
expect(orgLevel).toMatchObject({ 'Node Type': 'Index Scan', 'Scan Direction': 'Backward' })
117+
if (pageCursor) expect(orgLevel['Index Cond']).toMatch(/ROW\(date_trunc/)
118+
}
119+
)
120+
})

‎apps/sim/lib/audit-logs/list-scope.integration.ts‎

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -21,29 +21,44 @@ const foreignWorkspace = generateId()
2121
const workspaceIds = [workspaceA, workspaceB, foreignWorkspace]
2222

2323
type Placement = { workspaceId: string | null; resourceId: string; metadata: object }
24+
/**
25+
* Organization-level rows reach the listing through two disjoint parts, so the placements cover
26+
* each part alone, a row both parts would match (it must be read once), a resource row whose
27+
* metadata names another organization (only the resource part matches it), and rows of another
28+
* organization that neither part may read.
29+
*/
2430
const PLACEMENTS: Placement[] = [
2531
{ workspaceId: workspaceA, resourceId: generateId(), metadata: {} },
2632
{ workspaceId: workspaceB, resourceId: generateId(), metadata: {} },
2733
{ workspaceId: foreignWorkspace, resourceId: generateId(), metadata: {} },
2834
{ workspaceId: null, resourceId: generateId(), metadata: { organizationId } },
2935
{ workspaceId: null, resourceId: organizationId, metadata: {} },
36+
{ workspaceId: null, resourceId: organizationId, metadata: { organizationId } },
37+
{
38+
workspaceId: null,
39+
resourceId: organizationId,
40+
metadata: { organizationId: otherOrganizationId },
41+
},
3042
{
3143
workspaceId: null,
3244
resourceId: generateId(),
3345
metadata: { organizationId: otherOrganizationId },
3446
},
47+
{ workspaceId: null, resourceId: otherOrganizationId, metadata: {} },
3548
]
3649
const ACTORS = [memberId, departedId, null]
3750

38-
const rows = Array.from({ length: 72 }, (_, index) => {
51+
const rows = Array.from({ length: 81 }, (_, index) => {
3952
const placement = PLACEMENTS[index % PLACEMENTS.length]
4053
return {
4154
id: `${generateId()}-${String(index).padStart(2, '0')}`,
4255
index,
4356
workspaceId: placement.workspaceId,
4457
actorId: ACTORS[Math.floor(index / PLACEMENTS.length) % ACTORS.length],
4558
action: index % 4 === 0 ? 'workflow.deployed' : 'workflow.updated',
46-
resourceType: placement.resourceId === organizationId ? 'organization' : 'workflow',
59+
resourceType: [organizationId, otherOrganizationId].includes(placement.resourceId)
60+
? 'organization'
61+
: 'workflow',
4762
resourceId: placement.resourceId,
4863
metadata: { ...placement.metadata, fixture: 'x'.repeat(200) },
4964
}
@@ -162,6 +177,11 @@ describe('queryAuditLogs scope against real Postgres', () => {
162177
expect(
163178
new Set(rows.filter((row) => ids.includes(row.id)).map((row) => row.workspaceId))
164179
).toEqual(new Set([null]))
180+
expect(
181+
new Set(
182+
rows.filter((row) => ids.includes(row.id)).map((row) => row.index % PLACEMENTS.length)
183+
)
184+
).toEqual(new Set([3, 4, 5, 6]))
165185
})
166186

167187
it('narrows to one workspace when the filter names it', async () => {

‎apps/sim/lib/audit-logs/query.ts‎

Lines changed: 45 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -106,19 +106,47 @@ export interface OrgScopeParams {
106106
includeDeparted: boolean
107107
}
108108

109+
/**
110+
* An organization-level row has no workspace and names the organization in its metadata, or is
111+
* the organization resource itself: {@link orgLevelCondition}, read by a listing as
112+
* {@link orgLevelParts}.
113+
*/
114+
function orgMetadataMatch(organizationId: string): SQL<unknown> {
115+
return sql`${auditLog.metadata}->>'organizationId' = ${organizationId}`
116+
}
117+
118+
function orgResourceMatch(organizationId: string): SQL<unknown>[] {
119+
return [
120+
eq(auditLog.resourceType, AuditResourceType.ORGANIZATION),
121+
eq(auditLog.resourceId, organizationId),
122+
]
123+
}
124+
109125
function orgLevelCondition(organizationId: string): SQL<unknown> {
110126
return and(
111127
isNull(auditLog.workspaceId),
112-
or(
113-
sql`${auditLog.metadata}->>'organizationId' = ${organizationId}`,
114-
and(
115-
eq(auditLog.resourceType, AuditResourceType.ORGANIZATION),
116-
eq(auditLog.resourceId, organizationId)
117-
)
118-
)
128+
or(orgMetadataMatch(organizationId), and(...orgResourceMatch(organizationId)))
119129
)!
120130
}
121131

132+
/**
133+
* {@link orgLevelCondition} as two disjoint parts, each with its own index. The metadata match,
134+
* which can hold thousands of rows, is read through `audit_log_org_level_created_at_id_idx`, which
135+
* can stream it in keyset order and stop after a page: it spells `workspace_id IS NULL` and a strict equality on the key, which proves that
136+
* partial index's predicate. The resource match whose metadata does not already name the
137+
* organization is a few rows, sought on `audit_log_resource_idx` and sorted.
138+
*/
139+
function orgLevelParts(organizationId: string): SQL<unknown>[] {
140+
return [
141+
conjunction([isNull(auditLog.workspaceId), orgMetadataMatch(organizationId)]),
142+
conjunction([
143+
isNull(auditLog.workspaceId),
144+
...orgResourceMatch(organizationId),
145+
sql`(${orgMetadataMatch(organizationId)}) is not true`,
146+
]),
147+
]
148+
}
149+
122150
function currentActorCondition(orgMemberIds: string[]): SQL<unknown> {
123151
return orgMemberIds.length > 0
124152
? or(inArray(auditLog.actorId, orgMemberIds), isNull(auditLog.actorId))!
@@ -170,15 +198,15 @@ function conjunction(conditions: SQL<unknown>[]): SQL<unknown> {
170198
}
171199

172200
/**
173-
* The ids of the first `take` rows in scope, newest first. The scope is a
174-
* disjoint union — a row either belongs to one of the organization's workspaces
175-
* or has no workspace and names the organization — so each part is read
176-
* separately: one keyset scan of `audit_log_workspace_created_at_id_idx` per
177-
* workspace, plus the organization-level rows, each stopping after `take`
178-
* matches. The first `take` rows of the union are exactly the first `take` of
179-
* the whole scope. Planned as one `OR`, Postgres can follow no index in order
180-
* and sorts every row in the scope (for a busy organization, a full scan of the
181-
* table) to return one page.
201+
* The ids of the first `take` rows in scope, newest first. The scope is a disjoint union, read
202+
* part by part, each part limited to `take`: one keyset scan of
203+
* `audit_log_workspace_created_at_id_idx` per organization workspace, and the two
204+
* {@link orgLevelParts}. The first `take` rows of the union are exactly the first `take` of the
205+
* whole scope, and disjointness keeps `union all` free of duplicates. A part is cheap only when an
206+
* index serves its filter in order, so the scan stops after a page, or its filter matches few
207+
* rows; otherwise it reads and sorts every row it matches. Planned as one `OR`, that is the whole
208+
* scope (for a busy organization, a full scan of the table); with only `workspace_id IS NULL`
209+
* indexed, it is every workspace-less row in the table, spread across the heap.
182210
*/
183211
function pageIdsQuery(scope: AuditLogListScope, conditions: SQL<unknown>[], take: number): SQL {
184212
const shared = scope.includeDeparted
@@ -187,7 +215,7 @@ function pageIdsQuery(scope: AuditLogListScope, conditions: SQL<unknown>[], take
187215
const branch = (part: SQL<unknown>) =>
188216
sql`(select ${auditLog.id}, ${auditLog.createdAt} from ${auditLog} where ${conjunction([part, ...shared])} order by ${auditLogTimestamp} desc, ${auditLog.id} desc limit ${take})`
189217

190-
const parts = [branch(orgLevelCondition(scope.organizationId))]
218+
const parts = orgLevelParts(scope.organizationId).map(branch)
191219
const workspaceIds = [...new Set(scope.orgWorkspaceIds)]
192220
if (workspaceIds.length > 0) {
193221
parts.unshift(
Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,35 @@
1+
-- The organization-level rows of an organization's audit log, newest first. A listing reads them
2+
-- as one keyset branch (workspace_id IS NULL, metadata organizationId equal to the organization,
3+
-- ordered by the millisecond-truncated created_at and id), and no index served that order: the
4+
-- planner fetched every workspace-less row, which are spread across the whole heap, and filtered
5+
-- them for the organization, so an organization with few such rows near the top paid for all of
6+
-- them on every page.
7+
--
8+
-- The partial predicate is what that branch states: equality on the metadata key is strict, so it
9+
-- implies the IS NOT NULL, and the branch spells workspace_id IS NULL literally. Rows attributed
10+
-- only by resource (resource_type 'organization') stay on audit_log_resource_idx; there are few.
11+
--
12+
-- Replay-safety: audit_log takes writes continuously, so the build is CONCURRENTLY, below an
13+
-- embedded COMMIT, and a failure there replays the whole file from the top. A failed concurrent
14+
-- build leaves an INVALID index that IF NOT EXISTS would keep: the replay moves only that one aside
15+
-- to be dropped, so a valid index built by an earlier attempt is kept rather than rebuilt.
16+
DO $$
17+
BEGIN
18+
IF EXISTS (
19+
SELECT 1 FROM pg_index WHERE indexrelid = to_regclass('audit_log_org_level_created_at_id_idx_failed')
20+
AND (indisvalid OR indrelid <> to_regclass('audit_log'))
21+
) THEN
22+
RAISE EXCEPTION 'Refusing to drop unexpected recovery index audit_log_org_level_created_at_id_idx_failed';
23+
END IF;
24+
IF EXISTS (
25+
SELECT 1 FROM pg_index WHERE indexrelid = to_regclass('audit_log_org_level_created_at_id_idx')
26+
AND indrelid = to_regclass('audit_log') AND NOT indisvalid
27+
) THEN
28+
ALTER INDEX "audit_log_org_level_created_at_id_idx" RENAME TO "audit_log_org_level_created_at_id_idx_failed";
29+
END IF;
30+
END $$;--> statement-breakpoint
31+
COMMIT;--> statement-breakpoint
32+
SET lock_timeout = 0;--> statement-breakpoint
33+
DROP INDEX CONCURRENTLY IF EXISTS "audit_log_org_level_created_at_id_idx_failed";--> statement-breakpoint
34+
CREATE INDEX CONCURRENTLY IF NOT EXISTS "audit_log_org_level_created_at_id_idx" ON "audit_log" USING btree (("metadata"->>'organizationId'),date_trunc('milliseconds', "created_at"),"id") WHERE "audit_log"."workspace_id" IS NULL AND ("audit_log"."metadata"->>'organizationId') IS NOT NULL;--> statement-breakpoint
35+
SET lock_timeout = '5s';

0 commit comments

Comments
 (0)