Audit Log Backend Performance

Audience: Platform operators and contributors evaluating audit log storage options or RBAC performance.

Related UI-wide benchmark results are tracked in UI Performance Benchmark Results.

Three improvements shipped together in #1903 / PR #1917:

1. Audit service — MongoDB writes replaced by a lightweight service that owns local/S3 storage
2. OpenFGA N+1 fix — sequential permission checks on /api/rbac/admin-tab-gates parallelized with Promise.all
3. OpenFGA BatchCheck — 18 parallel RPCs collapsed into a single HTTP call via /batch-check

---

How to run the benchmarks yourself

Prerequisites

pip install locust
# Node ≥18 required for mint-test-session.mjs
nvm use  # or: node --version

1. Start the production image

# from repo root
docker compose -f docker-compose.dev.yaml --profile caipe-ui-prod up -d

The caipe-ui-prod service builds from the local branch source. Relevant env vars in .env:

AUDIT_LOG_BACKEND=service
AUDIT_SERVICE_URL=http://audit-service:8010
AUDIT_SERVICE_BACKEND=local    # or: s3
AUDIT_SERVICE_LOCAL_RETENTION_DAYS=1
AUDIT_SERVICE_S3_BUCKET=<your-bucket>
AUDIT_SERVICE_S3_REGION=us-east-2
AUDIT_SERVICE_S3_PREFIX=audit

2. Mint a test session token

The locust file auto-mints a JWT session for the admin user defined in NEXTAUTH_SECRET. It calls ui/mint-test-session.mjs, which must run from the ui/ directory so it can resolve next-auth from ui/node_modules.

export NEXTAUTH_SECRET="$(grep NEXTAUTH_SECRET .env | cut -d= -f2)"

3. Run the load test

# 20 concurrent users — baseline comparison
locust -f scripts/locustfile.py --headless -u 20 -r 5 --run-time 60s \
  --host http://localhost:3000 --csv reports/run-label

# 300 concurrent users — scaling stress test
locust -f scripts/locustfile.py --headless -u 300 -r 10 --run-time 60s \
  --host http://localhost:3000 --csv reports/300u-label

The locustfile.py samples these endpoints per virtual user:

• GET /api/auth/session (every task — session keepalive)
• GET /api/rbac/admin-tab-gates (admin gate check — the critical path)
• GET /api/admin/stats
• GET /api/admin/platform-config
• GET /api/dynamic-agents/available
• GET /api/chat/conversations (list and pagination)

4. Compare results

CSV files land in reports/. The key column is 95% (p95) in *_stats.csv:

column -t -s, reports/*.csv | grep admin-tab-gates

---

Benchmark runs

All runs: 60 s, production Docker image, MacBook (Apple Silicon), OpenFGA on the same host.

Run matrix

Run label	Users	Audit backend	OpenFGA strategy
before-mongodb	20	MongoDB (legacy)	Sequential for loop
after-local	20	Local NDJSON	Promise.all parallel
after-s3	20	S3 gzip-NDJSON	Promise.all parallel
300u-local	300	Local NDJSON	Promise.all parallel
300u-s3	300	S3 gzip-NDJSON	Promise.all parallel
300u-batchcheck	300	S3 gzip-NDJSON	BatchCheck single RPC

---

Results: /api/rbac/admin-tab-gates

This endpoint gates every Admin tab open — it's on the critical path for every admin page load.

20 concurrent users

Strategy	p50	p75	p95	p99
MongoDB + sequential checks (before)	170 ms	190 ms	390 ms	760 ms
Local + Promise.all	130 ms	150 ms	230 ms	350 ms
S3 + Promise.all	130 ms	140 ms	170 ms	220 ms

p50: −24% (170 → 130 ms). p99: −71% (760 → 220 ms).

300 concurrent users

Strategy	p50	p75	p95	p99
Promise.all (18 parallel RPCs)	200 ms	310 ms	800 ms	960 ms
BatchCheck (1 RPC)	46 ms	93 ms	450 ms	780 ms

p50: −77% (200 → 46 ms). p95: −44% (800 → 450 ms) at 300 users.

---

What drove the improvements

1. Audit service: fire-and-forget writes

The legacy path called db.collection("audit_logs").insertOne(event) inline and await-ed the result before returning. Under load, MongoDB connection-pool contention added 30–50 ms to the median and caused the long tail (760 ms p99).

Services now write fire-and-forget to audit-service — the handler returns immediately:

• local — audit-service appends date-partitioned NDJSON under AUDIT_SERVICE_LOCAL_PATH and purges files older than AUDIT_SERVICE_LOCAL_RETENTION_DAYS (default: 1).
• s3 — audit-service flushes date-partitioned Parquet objects to AUDIT_SERVICE_S3_BUCKET.

2. OpenFGA N+1: parallelized with Promise.all

Before the fix, each of 18 tab checks was await-ed sequentially:

// before — 18 × RTT ≈ 18 × 7 ms = 126 ms
for (const tab of ALL_TABS) {
  gates[tab] = await checkOpenFgaTuple({ user, relation, object });
}

After the fix, all checks race concurrently:

// after — 1 × RTT (the slowest single check)
const [tabResults] = await Promise.all([
  Promise.all(ALL_TABS.map(evaluateTab)),
  repairCurrentUserBaseline(currentSubject, isAdmin),
]);

Wall-clock drops from N × RTT to 1 × RTT. At 20 users: 170 ms → 130 ms.

3. OpenFGA BatchCheck: 18 RPCs → 1 RPC

At 300 users, Promise.all fires 18 × 300 = 5,400 concurrent OpenFGA RPCs per second — OpenFGA's gRPC pool saturates and p95 climbs back to 800 ms.

The /batch-check API accepts all checks in a single HTTP request:

// one round-trip regardless of how many tabs
const batchResults = await batchCheckOpenFgaTuples(
  batchEntries.map((e) => e.tuple)
);

Each check is identified by a correlation_id; OpenFGA resolves all of them concurrently server-side and returns a single result map. This reduces outbound RPC count from 18 to 1 per request. At 300 users: p50 200 ms → 46 ms.

---

Remaining latency at scale

The residual 450 ms p95 at 300 users is primarily:

• hasAccessibleSlackChannel / hasAccessibleWebexSpace — each does a MongoDB query for active channel/space rows, then a per-row OpenFGA check in a sequential loop. These are secondary checks run only for users whose primary check failed; they are excluded from the batch.
• /api/admin/stats — aggregates several MongoDB collections; p95 climbs to 650 ms at 300 users.

Next levers: add an OpenFGA server-side check-query cache (OPENFGA_CHECK_QUERY_CACHE_ENABLED=true, ~40% QPS reduction) or scale OpenFGA to 3 replicas.

---

Backend selection guide

Environment	Recommended backend	Reason
Local development	local	Zero config, immediately readable NDJSON files
Single-node staging	local	No external dependencies
Multi-replica Kubernetes	s3	All pods write to the same bucket; survives pod restarts
Air-gapped / on-prem	local	S3 not available

Set AUDIT_LOG_BACKEND=service on producers and point AUDIT_SERVICE_URL at audit-service. Then set AUDIT_SERVICE_BACKEND=local or AUDIT_SERVICE_BACKEND=s3 on audit-service.

---

Full benchmark data

20 users — all endpoints

Baseline — MongoDB + sequential OpenFGA

Endpoint	p50	p95	p99
/api/auth/session	4 ms	18 ms	62 ms
/api/chat/conversations (list)	8 ms	27 ms	110 ms
/api/admin/stats	26 ms	190 ms	410 ms
/api/dynamic-agents/available	39 ms	230 ms	310 ms
/api/rbac/admin-tab-gates	170 ms	390 ms	760 ms

Local file backend + Promise.all

Endpoint	p50	p95	p99
/api/auth/session	5 ms	15 ms	23 ms
/api/chat/conversations (list)	8 ms	32 ms	87 ms
/api/admin/stats	21 ms	61 ms	170 ms
/api/dynamic-agents/available	34 ms	73 ms	260 ms
/api/rbac/admin-tab-gates	130 ms	230 ms	350 ms

S3 backend + Promise.all

Endpoint	p50	p95	p99
/api/auth/session	5 ms	14 ms	52 ms
/api/chat/conversations (list)	8 ms	27 ms	100 ms
/api/admin/stats	20 ms	51 ms	130 ms
/api/dynamic-agents/available	27 ms	70 ms	88 ms
/api/rbac/admin-tab-gates	130 ms	170 ms	220 ms

---

Multi-user scaling — admin-tab-gates (BatchCheck)

Test environment note: All runs below are on a single developer laptop (Apple Silicon, 16 GB RAM) with OpenFGA, PostgreSQL, MongoDB, and the Next.js server all running as local Docker containers. Back-to-back runs without cooldown inflate numbers at 50–100 users because the JIT is cold on the first run and the CPU saturates on subsequent runs. The 25-user and 300-user numbers are the most reliable (25 = warm JIT, low contention; 300 = isolated clean run after container rebuild). In a real Kubernetes deployment with dedicated nodes the crossover point would be significantly higher.

Users	p50	p95	p99	Condition
10	49 ms	250 ms	600 ms	Cold JIT (first run after restart)
25	31 ms	48 ms	88 ms	Warm JIT, isolated run
50	220 ms	2100 ms	2600 ms	Back-to-back, CPU contention
100	680 ms	2600 ms	2800 ms	Back-to-back, CPU-bound
300	46 ms	450 ms	780 ms	Isolated clean run after rebuild

The 50/100 degradation is a single-node Docker resource limit, not an inherent BatchCheck ceiling. On the warm 25-user and clean 300-user runs the endpoint stays well under 50 ms p50.

300 users — all endpoints

S3 backend + Promise.all (18 parallel RPCs)

Endpoint	p50	p95	p99
/api/auth/session	8 ms	48 ms	130 ms
/api/chat/conversations (list)	16 ms	190 ms	360 ms
/api/admin/stats	37 ms	400 ms	700 ms
/api/dynamic-agents/available	45 ms	400 ms	700 ms
/api/rbac/admin-tab-gates	200 ms	800 ms	960 ms

S3 backend + BatchCheck (1 RPC)

Endpoint	p50	p95	p99
/api/auth/session	9 ms	53 ms	130 ms
/api/chat/conversations (list)	15 ms	400 ms	760 ms
/api/admin/stats	33 ms	650 ms	1200 ms
/api/dynamic-agents/available	38 ms	640 ms	940 ms
/api/rbac/admin-tab-gates	46 ms	450 ms	780 ms