Skip to content

Commit 6a56b45

Browse files
feat(web): log system-initiated model access changes to audit log (#2871)
* feat: record audit logs on model snapshot change * fix: serialize concurrent sync transactions with pg_advisory_xact_lock Concurrent syncs could both read the same previous snapshot under Postgres' default READ COMMITTED isolation, causing duplicate system audit log emission for the same diff. Take a transaction-scoped advisory lock before reading the previous snapshot and writing the new one so overlapping syncs serialize.
1 parent d0f7476 commit 6a56b45

8 files changed

Lines changed: 1544 additions & 12 deletions

File tree

Lines changed: 155 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,155 @@
1+
import { describe, expect, test } from '@jest/globals';
2+
import type {
3+
NormalizedOpenRouterResponse,
4+
NormalizedProvider,
5+
} from '@/lib/ai-gateway/providers/openrouter/openrouter-types';
6+
import { computeSnapshotDiff } from '@/lib/ai-gateway/providers/openrouter/snapshot-diff';
7+
8+
function buildSnapshot(
9+
providers: Array<{ slug: string; models: string[] }>
10+
): NormalizedOpenRouterResponse {
11+
const mapped: NormalizedProvider[] = providers.map(({ slug, models }) => ({
12+
name: slug,
13+
displayName: slug,
14+
slug,
15+
dataPolicy: { training: false, retainsPrompts: false, canPublish: false },
16+
models: models.map(modelSlug => ({
17+
slug: modelSlug,
18+
name: modelSlug,
19+
author: slug,
20+
description: '',
21+
context_length: 0,
22+
input_modalities: [],
23+
output_modalities: [],
24+
group: 'other',
25+
updated_at: '',
26+
endpoint: {
27+
provider_display_name: slug,
28+
is_free: false,
29+
pricing: { prompt: '0', completion: '0' },
30+
},
31+
})),
32+
}));
33+
34+
return {
35+
providers: mapped,
36+
total_providers: mapped.length,
37+
total_models: mapped.reduce((sum, p) => sum + p.models.length, 0),
38+
generated_at: '2026-01-01T00:00:00Z',
39+
};
40+
}
41+
42+
describe('computeSnapshotDiff', () => {
43+
test('returns empty diff when old snapshot is null', () => {
44+
const snapshot = buildSnapshot([{ slug: 'z-ai', models: ['z-ai/glm-5'] }]);
45+
const diff = computeSnapshotDiff(null, snapshot);
46+
47+
expect(diff.addedByProvider.size).toBe(0);
48+
expect(diff.removedByProvider.size).toBe(0);
49+
expect(diff.oldModelProvidersIndex.size).toBe(0);
50+
expect(diff.newModelProvidersIndex.get('z-ai/glm-5')).toEqual(new Set(['z-ai']));
51+
});
52+
53+
test('returns empty diff maps when snapshots are identical', () => {
54+
const snapshot = buildSnapshot([
55+
{ slug: 'z-ai', models: ['z-ai/glm-5'] },
56+
{ slug: 'anthropic', models: ['anthropic/claude-4.6'] },
57+
]);
58+
const diff = computeSnapshotDiff(snapshot, snapshot);
59+
60+
expect(diff.addedByProvider.size).toBe(0);
61+
expect(diff.removedByProvider.size).toBe(0);
62+
});
63+
64+
test('detects new model on existing provider', () => {
65+
const oldSnapshot = buildSnapshot([{ slug: 'z-ai', models: ['z-ai/glm-5'] }]);
66+
const newSnapshot = buildSnapshot([
67+
{ slug: 'z-ai', models: ['z-ai/glm-5', 'z-ai/glm-5.1', 'z-ai/glm-5.1-air'] },
68+
]);
69+
70+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
71+
72+
expect(diff.addedByProvider.get('z-ai')).toEqual(['z-ai/glm-5.1', 'z-ai/glm-5.1-air']);
73+
expect(diff.removedByProvider.size).toBe(0);
74+
});
75+
76+
test('detects brand-new provider with its models', () => {
77+
const oldSnapshot = buildSnapshot([{ slug: 'z-ai', models: ['z-ai/glm-5'] }]);
78+
const newSnapshot = buildSnapshot([
79+
{ slug: 'z-ai', models: ['z-ai/glm-5'] },
80+
{ slug: 'xyz-corp', models: ['xyz-corp/foo', 'xyz-corp/bar'] },
81+
]);
82+
83+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
84+
85+
expect(diff.addedByProvider.get('xyz-corp')).toEqual(['xyz-corp/bar', 'xyz-corp/foo']);
86+
expect(diff.addedByProvider.has('z-ai')).toBe(false);
87+
});
88+
89+
test('detects model removed from catalog', () => {
90+
const oldSnapshot = buildSnapshot([{ slug: 'z-ai', models: ['z-ai/glm-4.0', 'z-ai/glm-5'] }]);
91+
const newSnapshot = buildSnapshot([{ slug: 'z-ai', models: ['z-ai/glm-5'] }]);
92+
93+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
94+
95+
expect(diff.removedByProvider.get('z-ai')).toEqual(['z-ai/glm-4.0']);
96+
expect(diff.addedByProvider.size).toBe(0);
97+
});
98+
99+
test('detects additional provider offering an existing model as addition for that provider only', () => {
100+
const oldSnapshot = buildSnapshot([
101+
{ slug: 'openai', models: ['openai/gpt-4o'] },
102+
{ slug: 'azure', models: [] },
103+
]);
104+
const newSnapshot = buildSnapshot([
105+
{ slug: 'openai', models: ['openai/gpt-4o'] },
106+
{ slug: 'azure', models: ['openai/gpt-4o'] },
107+
]);
108+
109+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
110+
111+
expect(diff.addedByProvider.get('azure')).toEqual(['openai/gpt-4o']);
112+
expect(diff.addedByProvider.has('openai')).toBe(false);
113+
expect(diff.removedByProvider.size).toBe(0);
114+
});
115+
116+
test('normalizes variant suffixes like :free', () => {
117+
const oldSnapshot = buildSnapshot([{ slug: 'openai', models: ['openai/gpt-4o'] }]);
118+
const newSnapshot = buildSnapshot([
119+
{ slug: 'openai', models: ['openai/gpt-4o', 'openai/gpt-4o:free'] },
120+
]);
121+
122+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
123+
124+
expect(diff.addedByProvider.size).toBe(0);
125+
expect(diff.newModelProvidersIndex.get('openai/gpt-4o')).toEqual(new Set(['openai']));
126+
});
127+
128+
test('sorts model ids alphabetically within each provider group', () => {
129+
const oldSnapshot = buildSnapshot([{ slug: 'z-ai', models: [] }]);
130+
const newSnapshot = buildSnapshot([
131+
{ slug: 'z-ai', models: ['z-ai/beta', 'z-ai/alpha', 'z-ai/gamma'] },
132+
]);
133+
134+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
135+
136+
expect(diff.addedByProvider.get('z-ai')).toEqual(['z-ai/alpha', 'z-ai/beta', 'z-ai/gamma']);
137+
});
138+
139+
test('handles simultaneous additions and removals', () => {
140+
const oldSnapshot = buildSnapshot([
141+
{ slug: 'z-ai', models: ['z-ai/glm-4.0', 'z-ai/glm-5'] },
142+
{ slug: 'anthropic', models: ['anthropic/claude-4.5'] },
143+
]);
144+
const newSnapshot = buildSnapshot([
145+
{ slug: 'z-ai', models: ['z-ai/glm-5', 'z-ai/glm-5.1'] },
146+
{ slug: 'anthropic', models: ['anthropic/claude-4.5', 'anthropic/claude-4.6'] },
147+
]);
148+
149+
const diff = computeSnapshotDiff(oldSnapshot, newSnapshot);
150+
151+
expect(diff.addedByProvider.get('z-ai')).toEqual(['z-ai/glm-5.1']);
152+
expect(diff.addedByProvider.get('anthropic')).toEqual(['anthropic/claude-4.6']);
153+
expect(diff.removedByProvider.get('z-ai')).toEqual(['z-ai/glm-4.0']);
154+
});
155+
});
Lines changed: 117 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,117 @@
1+
import type { NormalizedOpenRouterResponse } from '@/lib/ai-gateway/providers/openrouter/openrouter-types';
2+
import { normalizeModelId } from '@/lib/ai-gateway/model-utils';
3+
4+
export type SnapshotDiff = {
5+
/** providerSlug -> sorted list of normalized model ids newly offered by that provider */
6+
addedByProvider: Map<string, string[]>;
7+
/** providerSlug -> sorted list of normalized model ids no longer offered by that provider */
8+
removedByProvider: Map<string, string[]>;
9+
/** modelId -> set of providerSlugs that offered it in the OLD snapshot */
10+
oldModelProvidersIndex: Map<string, Set<string>>;
11+
/** modelId -> set of providerSlugs that offer it in the NEW snapshot */
12+
newModelProvidersIndex: Map<string, Set<string>>;
13+
};
14+
15+
function buildModelProvidersIndex(
16+
snapshot: NormalizedOpenRouterResponse
17+
): Map<string, Set<string>> {
18+
const index = new Map<string, Set<string>>();
19+
for (const provider of snapshot.providers) {
20+
for (const model of provider.models) {
21+
const normalizedModelId = normalizeModelId(model.slug);
22+
const existing = index.get(normalizedModelId);
23+
if (existing) {
24+
existing.add(provider.slug);
25+
} else {
26+
index.set(normalizedModelId, new Set([provider.slug]));
27+
}
28+
}
29+
}
30+
return index;
31+
}
32+
33+
function emptyDiff(
34+
oldIndex: Map<string, Set<string>>,
35+
newIndex: Map<string, Set<string>>
36+
): SnapshotDiff {
37+
return {
38+
addedByProvider: new Map(),
39+
removedByProvider: new Map(),
40+
oldModelProvidersIndex: oldIndex,
41+
newModelProvidersIndex: newIndex,
42+
};
43+
}
44+
45+
/**
46+
* Compare two OpenRouter snapshots and produce the set of provider→model
47+
* additions and removals implied by the diff.
48+
*
49+
* A `(provider, model)` pair is "added" when the NEW snapshot contains that
50+
* pair and the OLD snapshot did not. This naturally covers two scenarios:
51+
* 1. A brand-new model on an existing provider (e.g. `z-ai/glm-5.1` appears
52+
* under `z-ai`).
53+
* 2. An existing model newly offered by an additional provider.
54+
*
55+
* Similarly, a `(provider, model)` pair is "removed" when the OLD snapshot
56+
* contained it and the NEW snapshot does not.
57+
*
58+
* When `oldSnapshot` is null (first run / fresh database), returns empty
59+
* add/remove maps so callers produce no audit log flood.
60+
*/
61+
export function computeSnapshotDiff(
62+
oldSnapshot: NormalizedOpenRouterResponse | null,
63+
newSnapshot: NormalizedOpenRouterResponse
64+
): SnapshotDiff {
65+
const newIndex = buildModelProvidersIndex(newSnapshot);
66+
67+
if (oldSnapshot === null) {
68+
return emptyDiff(new Map(), newIndex);
69+
}
70+
71+
const oldIndex = buildModelProvidersIndex(oldSnapshot);
72+
73+
const addedByProvider = new Map<string, string[]>();
74+
const removedByProvider = new Map<string, string[]>();
75+
76+
for (const [modelId, newProviders] of newIndex) {
77+
const oldProviders = oldIndex.get(modelId);
78+
for (const providerSlug of newProviders) {
79+
if (!oldProviders || !oldProviders.has(providerSlug)) {
80+
const list = addedByProvider.get(providerSlug);
81+
if (list) {
82+
list.push(modelId);
83+
} else {
84+
addedByProvider.set(providerSlug, [modelId]);
85+
}
86+
}
87+
}
88+
}
89+
90+
for (const [modelId, oldProviders] of oldIndex) {
91+
const newProviders = newIndex.get(modelId);
92+
for (const providerSlug of oldProviders) {
93+
if (!newProviders || !newProviders.has(providerSlug)) {
94+
const list = removedByProvider.get(providerSlug);
95+
if (list) {
96+
list.push(modelId);
97+
} else {
98+
removedByProvider.set(providerSlug, [modelId]);
99+
}
100+
}
101+
}
102+
}
103+
104+
for (const list of addedByProvider.values()) {
105+
list.sort((a, b) => a.localeCompare(b));
106+
}
107+
for (const list of removedByProvider.values()) {
108+
list.sort((a, b) => a.localeCompare(b));
109+
}
110+
111+
return {
112+
addedByProvider,
113+
removedByProvider,
114+
oldModelProvidersIndex: oldIndex,
115+
newModelProvidersIndex: newIndex,
116+
};
117+
}

apps/web/src/lib/ai-gateway/providers/openrouter/sync-providers.ts

Lines changed: 76 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -17,8 +17,10 @@ import {
1717
} from '@/lib/ai-gateway/providers/openrouter/openrouter-types';
1818
import { modelsByProvider } from '@kilocode/db/schema';
1919
import { db } from '@/lib/drizzle';
20-
import { lt } from 'drizzle-orm';
20+
import { desc, lt, sql } from 'drizzle-orm';
21+
import { captureException } from '@sentry/nextjs';
2122
import PROVIDERS from '@/lib/ai-gateway/providers/provider-definitions';
23+
import { logAutoModelChangesForAllOrgs } from '@/lib/organizations/auto-model-change-log';
2224
import type { Provider } from '@/lib/ai-gateway/providers/types';
2325
import type { StoredModel } from '@/lib/ai-gateway/providers/vercel/types';
2426
import { EndpointsSchema, ModelsSchema } from '@/lib/ai-gateway/providers/vercel/types';
@@ -31,6 +33,14 @@ const ATTRIBUTION_HEADERS = {
3133
'X-Title': 'Kilo Code',
3234
} as const;
3335

36+
/**
37+
* Advisory lock key hashed from a stable identifier. Serializes concurrent
38+
* calls to `applySnapshotChangesAndAudit` so two overlapping syncs cannot
39+
* both read the same "previous" snapshot and emit duplicate system audit
40+
* logs for the same diff. Auto-releases on transaction commit/rollback.
41+
*/
42+
const SYNC_PROVIDERS_SNAPSHOT_LOCK_KEY = 'sync-providers:snapshot';
43+
3444
async function fetchGatewayModels(gateway: Provider) {
3545
const headers = {
3646
...ATTRIBUTION_HEADERS,
@@ -309,6 +319,67 @@ async function mirrorToRedis(values: {
309319
await Promise.all(entries.map(([key, value]) => redisSet(key, JSON.stringify(value))));
310320
}
311321

322+
/**
323+
* Apply a freshly-synced OpenRouter snapshot to the database and emit
324+
* per-org audit log entries describing how it affects each enterprise
325+
* organization's effective model availability.
326+
*
327+
* Extracted from `syncAndStoreProviders` so it can be tested without
328+
* mocking upstream HTTP calls: seed the DB with a prior snapshot row, call
329+
* this with a new synthetic snapshot, and assert on the resulting rows in
330+
* `organization_audit_logs`.
331+
*
332+
* Concurrency safety: a transaction-scoped Postgres advisory lock
333+
* (`pg_advisory_xact_lock`) is taken before the previous-snapshot read so
334+
* two overlapping sync runs cannot both observe the same "previous" row
335+
* and emit duplicate system audit logs for the same diff. The lock is
336+
* released automatically on commit/rollback.
337+
*/
338+
export async function applySnapshotChangesAndAudit(params: {
339+
providers: NormalizedOpenRouterResponse;
340+
openrouter_data: Record<string, StoredModel>;
341+
vercel_data: Record<string, StoredModel>;
342+
}): Promise<{
343+
id: number;
344+
data: NormalizedOpenRouterResponse;
345+
previousSnapshot: NormalizedOpenRouterResponse | null;
346+
}> {
347+
const { providers, openrouter_data, vercel_data } = params;
348+
349+
const { row, previousSnapshot } = await db.transaction(async tx => {
350+
await tx.execute(
351+
sql`SELECT pg_advisory_xact_lock(hashtext(${SYNC_PROVIDERS_SNAPSHOT_LOCK_KEY}))`
352+
);
353+
354+
const [previousSnapshotRow] = await tx
355+
.select({ data: modelsByProvider.data })
356+
.from(modelsByProvider)
357+
.orderBy(desc(modelsByProvider.id))
358+
.limit(1);
359+
const previousSnapshot = previousSnapshotRow?.data ?? null;
360+
361+
const results = await tx
362+
.insert(modelsByProvider)
363+
.values({
364+
data: providers,
365+
openrouter: openrouter_data,
366+
vercel: vercel_data,
367+
})
368+
.returning();
369+
await tx.delete(modelsByProvider).where(lt(modelsByProvider.id, results[0].id));
370+
return { row: results[0], previousSnapshot };
371+
});
372+
373+
try {
374+
await logAutoModelChangesForAllOrgs(previousSnapshot, providers);
375+
} catch (err) {
376+
console.error('[sync-providers] auto-change audit logging failed', err);
377+
captureException(err, { tags: { component: 'sync-providers-auto-audit' } });
378+
}
379+
380+
return { id: row.id, data: row.data, previousSnapshot };
381+
}
382+
312383
export async function syncAndStoreProviders() {
313384
const startTime = performance.now();
314385

@@ -332,17 +403,10 @@ export async function syncAndStoreProviders() {
332403
throw new Error(`Suspicious: total number of models is ${providers.total_models} < 100`);
333404
}
334405

335-
const result = await db.transaction(async tx => {
336-
const results = await tx
337-
.insert(modelsByProvider)
338-
.values({
339-
data: providers,
340-
openrouter: openrouter_data,
341-
vercel: vercel_data,
342-
})
343-
.returning();
344-
await tx.delete(modelsByProvider).where(lt(modelsByProvider.id, results[0].id));
345-
return results[0];
406+
const result = await applySnapshotChangesAndAudit({
407+
providers,
408+
openrouter_data,
409+
vercel_data,
346410
});
347411

348412
await mirrorToRedis({

0 commit comments

Comments
 (0)