Skip to content

Commit 61fd152

Browse files
committed
perf(audit-logs): index organization-level rows and read them as two keyset parts
The organization listing reads its organization-level rows as one keyset branch: workspace_id IS NULL and (metadata organizationId = org, or the organization resource itself). No index served that branch, so the planner seeked workspace_id IS NULL and filtered every workspace-less row in the table, spread across the heap. An organization without a page of such rows near the top paid for all of them on every request. A partial expression index on (metadata->>'organizationId', the millisecond created_at, id) over workspace-less rows that carry the key now serves the metadata match, and the branch is split into two disjoint parts so that part can be read in keyset order and stop after a page: the metadata match, and the organization-resource match whose metadata does not already name the organization (a few rows, on audit_log_resource_idx). Disjointness keeps the union exact; buildOrgScopeCondition keeps its predicate. The index alone is not enough: under the single OR the planner can only BitmapOr the two indexes and sort, which reads every organization-level row of the organization. The existing list-scope suite compared results only, which the slow plan returns correctly; a plan suite now asserts the metadata part is read through the new index, never by a workspace_id IS NULL seek, and that the index can stream it backward in keyset order. The scope suite gains rows matching both parts, only the resource part, and another organization.
1 parent 70c8231 commit 61fd152

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)