diff --git a/packages/cli/__tests__/commands/perf.test.ts b/packages/cli/__tests__/commands/perf.test.ts index e13c8c12a..1ea1ad177 100644 --- a/packages/cli/__tests__/commands/perf.test.ts +++ b/packages/cli/__tests__/commands/perf.test.ts @@ -1,27 +1,66 @@ import { describe, it, expect, vi, beforeEach, afterEach } from "vitest"; import type { ParsedRequest } from "../../src/lib/perf-utils.js"; -const { mockPercentile, mockNormalizeRoutePath, mockResolveLogDir, mockLoadRequests } = vi.hoisted( - () => ({ - mockPercentile: vi.fn((sorted: number[], p: number) => { +const { mockPercentile, mockResolveLogDir, mockLoadRequests, mockComputeApiStats } = + vi.hoisted(() => { + const mockPercentile = vi.fn((sorted: number[], p: number) => { if (sorted.length === 0) return 0; const idx = Math.ceil((p / 100) * sorted.length) - 1; return sorted[Math.max(0, idx)]; - }), - mockNormalizeRoutePath: vi.fn( + }); + const mockNormalizeRoutePath = vi.fn( (path: string) => path .replace(/\/sessions\/[^/]+/g, "/sessions/:id") .replace(/\/prs\/[^/]+/g, "/prs/:id"), - ), - mockResolveLogDir: vi.fn(() => "/tmp/logs"), - mockLoadRequests: vi.fn(), - }), -); + ); + + // Inline implementation that mirrors computeApiStats in core. + // Needed because perf.ts delegates route grouping to computeApiStats. + const mockComputeApiStats = vi.fn( + (entries: { method: string; path: string; statusCode: number; durationMs: number; error?: string; cacheStats?: unknown }[]) => { + const byRoute = new Map(); + for (const e of entries) { + const key = `${e.method} ${mockNormalizeRoutePath(e.path)}`; + const arr = byRoute.get(key) ?? []; + arr.push(e); + byRoute.set(key, arr); + } + const routes: Record = {}; + for (const [route, logs] of byRoute) { + const durations = logs.map((l) => l.durationMs).sort((a, b) => a - b); + routes[route] = { + count: logs.length, + avgMs: Math.round(durations.reduce((s, d) => s + d, 0) / durations.length), + p50Ms: mockPercentile(durations, 50), + p95Ms: mockPercentile(durations, 95), + p99Ms: mockPercentile(durations, 99), + errors: logs.filter((l) => l.error !== undefined || l.statusCode >= 400).length, + }; + } + const slowest = [...entries].sort((a, b) => b.durationMs - a.durationMs).slice(0, 10); + let latestCacheStats = null; + for (let i = entries.length - 1; i >= 0; i--) { + if ((entries[i] as { cacheStats?: unknown }).cacheStats) { + latestCacheStats = (entries[i] as { cacheStats?: unknown }).cacheStats; + break; + } + } + return { routes, slowest, latestCacheStats }; + }, + ); + + return { + mockPercentile, + mockComputeApiStats, + mockResolveLogDir: vi.fn(() => "/tmp/logs"), + mockLoadRequests: vi.fn(), + }; + }); vi.mock("@composio/ao-core", () => ({ percentile: mockPercentile, - normalizeRoutePath: mockNormalizeRoutePath, + computeApiStats: mockComputeApiStats, })); vi.mock("../../src/lib/perf-utils.js", () => ({ diff --git a/packages/cli/src/commands/perf.ts b/packages/cli/src/commands/perf.ts index b615ac80c..607b4f573 100644 --- a/packages/cli/src/commands/perf.ts +++ b/packages/cli/src/commands/perf.ts @@ -11,7 +11,7 @@ import chalk from "chalk"; import type { Command } from "commander"; -import { percentile, normalizeRoutePath } from "@composio/ao-core"; +import { percentile, computeApiStats } from "@composio/ao-core"; import { padCol, parseSinceArg, formatMs } from "../lib/format.js"; import { loadRequests, resolveLogDir, type ParsedRequest } from "../lib/perf-utils.js"; @@ -41,32 +41,10 @@ export function registerPerf(program: Command): void { return; } - // Group by normalized route - const byRoute = new Map(); - const errorsByRoute = new Map(); - for (const req of requests) { - const key = `${req.method} ${normalizeRoutePath(req.path)}`; - const durations = byRoute.get(key) ?? []; - durations.push(req.durationMs); - byRoute.set(key, durations); - if (req.error || req.statusCode >= 400) { - errorsByRoute.set(key, (errorsByRoute.get(key) ?? 0) + 1); - } - } + const { routes } = computeApiStats(requests); if (opts.json) { - const result: Record = {}; - for (const [route, durations] of byRoute) { - durations.sort((a, b) => a - b); - result[route] = { - count: durations.length, - p50: percentile(durations, 50), - p95: percentile(durations, 95), - p99: percentile(durations, 99), - errors: errorsByRoute.get(route) ?? 0, - }; - } - console.log(JSON.stringify(result, null, 2)); + console.log(JSON.stringify(routes, null, 2)); return; } @@ -85,23 +63,17 @@ export function registerPerf(program: Command): void { ); console.log(chalk.dim(" " + "─".repeat(70))); - const sorted = [...byRoute.entries()].sort((a, b) => { - const medA = percentile(a[1].sort((x, y) => x - y), 95); - const medB = percentile(b[1].sort((x, y) => x - y), 95); - return medB - medA; - }); + const sorted = Object.entries(routes).sort((a, b) => b[1].p95Ms - a[1].p95Ms); - for (const [route, durations] of sorted) { - durations.sort((a, b) => a - b); - const errors = errorsByRoute.get(route) ?? 0; + for (const [route, stats] of sorted) { console.log( " " + padCol(chalk.cyan(route), COL.route) + - padCol(String(durations.length), COL.count) + - padCol(formatMs(percentile(durations, 50)), COL.p50) + - padCol(formatMs(percentile(durations, 95)), COL.p95) + - padCol(formatMs(percentile(durations, 99)), COL.p99) + - (errors > 0 ? chalk.red(String(errors)) : chalk.dim("0")), + padCol(String(stats.count), COL.count) + + padCol(formatMs(stats.p50Ms), COL.p50) + + padCol(formatMs(stats.p95Ms), COL.p95) + + padCol(formatMs(stats.p99Ms), COL.p99) + + (stats.errors > 0 ? chalk.red(String(stats.errors)) : chalk.dim("0")), ); } console.log(chalk.dim(`\n ${requests.length} total requests`)); diff --git a/packages/core/src/__tests__/log-reader.test.ts b/packages/core/src/__tests__/log-reader.test.ts index 6e3223841..3cfd76058 100644 --- a/packages/core/src/__tests__/log-reader.test.ts +++ b/packages/core/src/__tests__/log-reader.test.ts @@ -4,7 +4,7 @@ import { join } from "node:path"; import { tmpdir } from "node:os"; import { randomUUID } from "node:crypto"; import type { LogEntry } from "../types.js"; -import { readLogs, readLogsFromDir, tailLogs } from "../log-reader.js"; +import { readLogs, readLogsFromDir, tailLogs, parseApiLogs, computeApiStats, type ApiLogEntry } from "../log-reader.js"; let testDir: string; @@ -696,3 +696,189 @@ describe("tailLogs", () => { expect(result[0].data).toEqual({ key: "value", count: 42 }); }); }); + +// ── parseApiLogs ───────────────────────────────────────────────────────────── + +describe("parseApiLogs", () => { + it("parses api.jsonl entries into ApiLogEntry objects", () => { + const entries: LogEntry[] = [ + makeEntry({ + source: "api", + sessionId: "ao-1", + data: { method: "GET", path: "/api/sessions", statusCode: 200, durationMs: 50 }, + }), + ]; + writeJsonl(join(testDir, "api.jsonl"), entries); + + const result = parseApiLogs(testDir); + expect(result).toHaveLength(1); + expect(result[0].method).toBe("GET"); + expect(result[0].path).toBe("/api/sessions"); + expect(result[0].statusCode).toBe(200); + expect(result[0].durationMs).toBe(50); + expect(result[0].sessionId).toBe("ao-1"); + }); + + it("skips entries missing method or path", () => { + const entries: LogEntry[] = [ + makeEntry({ source: "api", data: { statusCode: 200, durationMs: 10 } }), + makeEntry({ source: "api", data: { method: "GET", statusCode: 200, durationMs: 10 } }), + makeEntry({ source: "api", data: { method: "GET", path: "/api/health", statusCode: 200, durationMs: 10 } }), + ]; + writeJsonl(join(testDir, "api.jsonl"), entries); + + const result = parseApiLogs(testDir); + expect(result).toHaveLength(1); + expect(result[0].path).toBe("/api/health"); + }); + + it("parses optional error, timings, and cacheStats fields", () => { + const entries: LogEntry[] = [ + makeEntry({ + source: "api", + data: { + method: "POST", + path: "/api/spawn", + statusCode: 500, + durationMs: 200, + error: "spawn failed", + timings: { serviceInit: 5, prEnrichment: 150 }, + cacheStats: { hits: 10, misses: 2, hitRate: 0.83, size: 12 }, + }, + }), + ]; + writeJsonl(join(testDir, "api.jsonl"), entries); + + const result = parseApiLogs(testDir); + expect(result[0].error).toBe("spawn failed"); + expect(result[0].timings).toEqual({ serviceInit: 5, prEnrichment: 150 }); + expect(result[0].cacheStats).toEqual({ hits: 10, misses: 2, hitRate: 0.83, size: 12 }); + }); + + it("filters by route when opts.route is provided", () => { + const entries: LogEntry[] = [ + makeEntry({ source: "api", data: { method: "GET", path: "/api/sessions", statusCode: 200, durationMs: 10 } }), + makeEntry({ source: "api", data: { method: "GET", path: "/api/health", statusCode: 200, durationMs: 5 } }), + ]; + writeJsonl(join(testDir, "api.jsonl"), entries); + + const result = parseApiLogs(testDir, { route: "sessions" }); + expect(result).toHaveLength(1); + expect(result[0].path).toBe("/api/sessions"); + }); + + it("returns empty array when no api.jsonl exists", () => { + const result = parseApiLogs(testDir); + expect(result).toEqual([]); + }); +}); + +// ── computeApiStats ─────────────────────────────────────────────────────────── + +function makeApiEntry(overrides: Partial = {}): ApiLogEntry { + return { + ts: "2026-01-15T12:00:00Z", + method: "GET", + path: "/api/sessions", + sessionId: null, + statusCode: 200, + durationMs: 100, + ...overrides, + }; +} + +describe("computeApiStats", () => { + it("returns empty routes and slowest for empty input", () => { + const result = computeApiStats([]); + expect(result.routes).toEqual({}); + expect(result.slowest).toEqual([]); + expect(result.latestCacheStats).toBeNull(); + }); + + it("groups entries by normalized route key", () => { + const entries = [ + makeApiEntry({ path: "/api/sessions/abc", durationMs: 100 }), + makeApiEntry({ path: "/api/sessions/def", durationMs: 200 }), + makeApiEntry({ path: "/api/health", durationMs: 5 }), + ]; + + const result = computeApiStats(entries); + expect(result.routes["GET /api/sessions/:id"]).toBeDefined(); + expect(result.routes["GET /api/sessions/:id"].count).toBe(2); + expect(result.routes["GET /api/health"]).toBeDefined(); + expect(result.routes["GET /api/health"].count).toBe(1); + }); + + it("computes correct avgMs, p50Ms, p95Ms, p99Ms", () => { + const durations = [100, 200, 300, 400]; + const entries = durations.map((durationMs) => makeApiEntry({ durationMs })); + + const result = computeApiStats(entries); + const route = result.routes["GET /api/sessions"]; + expect(route.count).toBe(4); + expect(route.avgMs).toBe(250); // (100+200+300+400)/4 + expect(route.p50Ms).toBeGreaterThanOrEqual(100); + expect(route.p50Ms).toBeLessThanOrEqual(200); + expect(route.p95Ms).toBeGreaterThanOrEqual(300); + expect(route.p99Ms).toBeGreaterThanOrEqual(300); + }); + + it("counts errors for status >= 400", () => { + const entries = [ + makeApiEntry({ statusCode: 200 }), + makeApiEntry({ statusCode: 400 }), + makeApiEntry({ statusCode: 500 }), + ]; + + const result = computeApiStats(entries); + expect(result.routes["GET /api/sessions"].errors).toBe(2); + }); + + it("counts errors when error field is present regardless of status code", () => { + const entries = [ + makeApiEntry({ statusCode: 200, error: "something failed" }), + ]; + + const result = computeApiStats(entries); + expect(result.routes["GET /api/sessions"].errors).toBe(1); + }); + + it("separates routes by HTTP method", () => { + const entries = [ + makeApiEntry({ method: "GET", path: "/api/sessions" }), + makeApiEntry({ method: "POST", path: "/api/sessions" }), + ]; + + const result = computeApiStats(entries); + expect(result.routes["GET /api/sessions"]).toBeDefined(); + expect(result.routes["POST /api/sessions"]).toBeDefined(); + }); + + it("returns top 10 slowest requests sorted descending", () => { + const entries = Array.from({ length: 15 }, (_, i) => + makeApiEntry({ durationMs: (i + 1) * 10 }), + ); + + const result = computeApiStats(entries); + expect(result.slowest).toHaveLength(10); + expect(result.slowest[0].durationMs).toBe(150); // fastest of top 10: 15*10 + expect(result.slowest[0].durationMs).toBeGreaterThan(result.slowest[1].durationMs); + }); + + it("returns latestCacheStats from most recent entry with cacheStats", () => { + const entries = [ + makeApiEntry({ cacheStats: { hits: 1, misses: 1, hitRate: 0.5, size: 2 } }), + makeApiEntry({}), + makeApiEntry({ cacheStats: { hits: 20, misses: 5, hitRate: 0.8, size: 25 } }), + ]; + + const result = computeApiStats(entries); + expect(result.latestCacheStats).toEqual({ hits: 20, misses: 5, hitRate: 0.8, size: 25 }); + }); + + it("returns null latestCacheStats when no entries have cacheStats", () => { + const entries = [makeApiEntry(), makeApiEntry()]; + const result = computeApiStats(entries); + expect(result.latestCacheStats).toBeNull(); + }); +}); diff --git a/packages/core/src/index.ts b/packages/core/src/index.ts index 1a6a5c488..b12e0ebc1 100644 --- a/packages/core/src/index.ts +++ b/packages/core/src/index.ts @@ -89,8 +89,8 @@ export { LogWriter } from "./log-writer.js"; export type { LogWriterOptions } from "./log-writer.js"; // Log reader — query and filter JSONL logs -export { readLogs, readLogsFromDir, tailLogs, parseApiLogs } from "./log-reader.js"; -export type { ApiLogEntry } from "./log-reader.js"; +export { readLogs, readLogsFromDir, tailLogs, parseApiLogs, computeApiStats } from "./log-reader.js"; +export type { ApiLogEntry, RouteStats, ApiPerfResult } from "./log-reader.js"; // Session report card — per-session metrics export { generateReportCard } from "./session-report-card.js"; diff --git a/packages/core/src/log-reader.ts b/packages/core/src/log-reader.ts index 17a291d20..f430e6fcc 100644 --- a/packages/core/src/log-reader.ts +++ b/packages/core/src/log-reader.ts @@ -8,6 +8,7 @@ import { readFileSync, existsSync, readdirSync } from "node:fs"; import { join, basename } from "node:path"; import type { LogEntry, LogQueryOptions } from "./types.js"; +import { percentile, normalizeRoutePath } from "./utils.js"; /** Read and filter log entries from a single JSONL file. */ export function readLogs(filePath: string, opts?: LogQueryOptions): LogEntry[] { @@ -214,3 +215,59 @@ export function parseApiLogs( return results; } + +/** Per-route aggregated performance stats. */ +export interface RouteStats { + count: number; + avgMs: number; + p50Ms: number; + p95Ms: number; + p99Ms: number; + errors: number; +} + +/** Result of computing API performance stats from parsed log entries. */ +export interface ApiPerfResult { + routes: Record; + slowest: ApiLogEntry[]; + latestCacheStats: ApiLogEntry["cacheStats"] | null; +} + +/** + * Compute per-route performance stats from parsed API log entries. + * Shared by `ao perf routes` CLI and the web `/api/perf` route. + */ +export function computeApiStats(entries: ApiLogEntry[]): ApiPerfResult { + const byRoute = new Map(); + for (const entry of entries) { + const key = `${entry.method} ${normalizeRoutePath(entry.path)}`; + const existing = byRoute.get(key) ?? []; + existing.push(entry); + byRoute.set(key, existing); + } + + const routes: Record = {}; + for (const [route, logs] of byRoute) { + const durations = logs.map((l) => l.durationMs).sort((a, b) => a - b); + routes[route] = { + count: logs.length, + avgMs: Math.round(durations.reduce((s, d) => s + d, 0) / durations.length), + p50Ms: percentile(durations, 50), + p95Ms: percentile(durations, 95), + p99Ms: percentile(durations, 99), + errors: logs.filter((l) => l.error !== undefined || l.statusCode >= 400).length, + }; + } + + let latestCacheStats: ApiLogEntry["cacheStats"] | null = null; + for (let i = entries.length - 1; i >= 0; i--) { + if (entries[i].cacheStats) { + latestCacheStats = entries[i].cacheStats!; + break; + } + } + + const slowest = [...entries].sort((a, b) => b.durationMs - a.durationMs).slice(0, 10); + + return { routes, slowest, latestCacheStats }; +} diff --git a/packages/web/src/__tests__/observability-routes.test.ts b/packages/web/src/__tests__/observability-routes.test.ts index 6ba87e1f9..8e2ec7b64 100644 --- a/packages/web/src/__tests__/observability-routes.test.ts +++ b/packages/web/src/__tests__/observability-routes.test.ts @@ -8,26 +8,88 @@ const mockResolveProjectLogDir = vi.fn(); const mockLoadConfig = vi.fn(); const mockLogWriterAppend = vi.fn(); -vi.mock("@composio/ao-core", () => ({ - resolveProjectLogDir: (...args: unknown[]) => mockResolveProjectLogDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - tailLogs: (...args: unknown[]) => mockTailLogs(...args), - loadConfig: (...args: unknown[]) => mockLoadConfig(...args), - percentile: (sorted: number[], p: number) => { +vi.mock("@composio/ao-core", () => { + function percentile(sorted: number[], p: number): number { if (sorted.length === 0) return 0; const idx = Math.ceil((p / 100) * sorted.length) - 1; return sorted[Math.max(0, idx)]; - }, - normalizeRoutePath: (path: string) => - path + } + function normalizeRoutePath(path: string): string { + return path .replace(/\/sessions\/[^/]+/g, "/sessions/:id") - .replace(/\/prs\/[^/]+/g, "/prs/:id"), - LogWriter: vi.fn().mockImplementation(() => ({ - append: mockLogWriterAppend, - appendLine: vi.fn(), - close: vi.fn(), - })), -})); + .replace(/\/prs\/[^/]+/g, "/prs/:id"); + } + return { + resolveProjectLogDir: (...args: unknown[]) => mockResolveProjectLogDir(...args), + readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), + tailLogs: (...args: unknown[]) => mockTailLogs(...args), + loadConfig: (...args: unknown[]) => mockLoadConfig(...args), + percentile, + normalizeRoutePath, + /** Inline implementation of parseApiLogs from core (uses mocked readLogsFromDir). */ + parseApiLogs: (logDir: string, opts?: { since?: Date; route?: string }) => { + const raw = mockReadLogsFromDir(logDir, "api", { + source: "api", + since: opts?.since, + }) as Array<{ ts: string; sessionId?: string | null; data?: Record }>; + const results = []; + for (const entry of raw) { + const data = entry.data ?? {}; + if (!data["method"] || !data["path"]) continue; + const req = { + ts: entry.ts, + method: String(data["method"]), + path: String(data["path"]), + sessionId: entry.sessionId ?? null, + statusCode: Number(data["statusCode"]) || 0, + durationMs: Number(data["durationMs"]) || 0, + error: data["error"] ? String(data["error"]) : undefined, + timings: data["timings"] as Record | undefined, + cacheStats: data["cacheStats"] as { hits: number; misses: number; hitRate: number; size: number } | undefined, + }; + if (opts?.route && !req.path.includes(opts.route)) continue; + results.push(req); + } + return results; + }, + /** Inline implementation of computeApiStats from core. */ + computeApiStats: (entries: Array<{ method: string; path: string; statusCode: number; durationMs: number; error?: string; cacheStats?: unknown }>) => { + const byRoute = new Map(); + for (const entry of entries) { + const key = `${entry.method} ${normalizeRoutePath(entry.path)}`; + const arr = byRoute.get(key) ?? []; + arr.push(entry); + byRoute.set(key, arr); + } + const routes: Record = {}; + for (const [route, logs] of byRoute) { + const durations = logs.map((l) => l.durationMs).sort((a, b) => a - b); + routes[route] = { + count: logs.length, + avgMs: Math.round(durations.reduce((s, d) => s + d, 0) / durations.length), + p50Ms: percentile(durations, 50), + p95Ms: percentile(durations, 95), + p99Ms: percentile(durations, 99), + errors: logs.filter((l) => l.error !== undefined || l.statusCode >= 400).length, + }; + } + let latestCacheStats = null; + for (let i = entries.length - 1; i >= 0; i--) { + if ((entries[i] as { cacheStats?: unknown }).cacheStats) { + latestCacheStats = (entries[i] as { cacheStats?: unknown }).cacheStats; + break; + } + } + const slowest = [...entries].sort((a, b) => b.durationMs - a.durationMs).slice(0, 10); + return { routes, slowest, latestCacheStats }; + }, + LogWriter: vi.fn().mockImplementation(() => ({ + append: mockLogWriterAppend, + appendLine: vi.fn(), + close: vi.fn(), + })), + }; +}); // ── Import routes after mocking ───────────────────────────────────────── @@ -437,8 +499,8 @@ describe("GET /api/perf", () => { const json = await res.json(); // Only entries whose path includes "sessions" should appear - expect(json.totalRequests).toBe(3); // totalRequests is entries.length (all from readLogsFromDir) - // But routes should only contain session-related entries + expect(json.totalRequests).toBe(2); // 2 session entries passed route filter + // Routes should only contain session-related entries expect(json.routes["POST /api/spawn"]).toBeUndefined(); expect(json.routes["GET /api/sessions"]).toBeDefined(); expect(json.routes["GET /api/sessions/:id"]).toBeDefined(); @@ -558,7 +620,7 @@ describe("GET /api/perf", () => { // All entries should be skipped — no routes recorded expect(json.routes).toEqual({}); expect(json.slowest).toEqual([]); - expect(json.totalRequests).toBe(4); // entries.length from readLogsFromDir + expect(json.totalRequests).toBe(0); // 0 valid entries parsed }); it("applies combined since + route filtering", async () => { diff --git a/packages/web/src/app/api/perf/route.ts b/packages/web/src/app/api/perf/route.ts index 5a8878f83..388bded3e 100644 --- a/packages/web/src/app/api/perf/route.ts +++ b/packages/web/src/app/api/perf/route.ts @@ -1,11 +1,6 @@ import { NextResponse } from "next/server"; -import { - resolveProjectLogDir, - readLogsFromDir, - loadConfig, - percentile, - normalizeRoutePath, -} from "@composio/ao-core"; +import { resolveProjectLogDir, loadConfig } from "@composio/ao-core"; +import { getRequestStats } from "../../../lib/request-logger.js"; function resolveLogDir(): string { const dir = resolveProjectLogDir(loadConfig()); @@ -27,74 +22,16 @@ export async function GET(request: Request) { const route = searchParams.get("route"); const logDir = resolveLogDir(); - const entries = readLogsFromDir(logDir, "api", { - source: "api", + const stats = getRequestStats(logDir, { ...(since && { since: new Date(since) }), + ...(route && { route }), }); - // Parse and group by route - const byRoute = new Map(); - const errorsByRoute = new Map(); - const slowest: Array<{ - ts: string; - method: string; - path: string; - durationMs: number; - timings?: Record; - }> = []; - - let latestCacheStats: unknown = null; - - for (const entry of entries) { - const data = entry.data ?? {}; - if (!data["method"] || !data["path"]) continue; - - const method = String(data["method"]); - const path = String(data["path"]); - const durationMs = Number(data["durationMs"]) || 0; - - if (route && !path.includes(route)) continue; - - const key = `${method} ${normalizeRoutePath(path)}`; - const durations = byRoute.get(key) ?? []; - durations.push(durationMs); - byRoute.set(key, durations); - - if (data["error"] || (Number(data["statusCode"]) || 0) >= 400) { - errorsByRoute.set(key, (errorsByRoute.get(key) ?? 0) + 1); - } - - if (data["cacheStats"]) { - latestCacheStats = data["cacheStats"]; - } - - slowest.push({ ts: entry.ts, method, path, durationMs, - timings: data["timings"] as Record | undefined, - }); - } - - // Build route stats - const routes: Record = {}; - for (const [routeKey, durations] of byRoute) { - durations.sort((a, b) => a - b); - routes[routeKey] = { - count: durations.length, - avgMs: Math.round(durations.reduce((s, d) => s + d, 0) / durations.length), - p50Ms: percentile(durations, 50), - p95Ms: percentile(durations, 95), - p99Ms: percentile(durations, 99), - errors: errorsByRoute.get(routeKey) ?? 0, - }; - } - - // Top 10 slowest - slowest.sort((a, b) => b.durationMs - a.durationMs); - return NextResponse.json({ - routes, - slowest: slowest.slice(0, 10), - cacheStats: latestCacheStats, - totalRequests: entries.length, + routes: stats.routes, + slowest: stats.slowest, + cacheStats: stats.latestCacheStats, + totalRequests: Object.values(stats.routes).reduce((s, r) => s + r.count, 0), }); } catch (err) { return NextResponse.json( diff --git a/packages/web/src/lib/__tests__/request-logger.test.ts b/packages/web/src/lib/__tests__/request-logger.test.ts index 29aa7fb25..80f130e7a 100644 --- a/packages/web/src/lib/__tests__/request-logger.test.ts +++ b/packages/web/src/lib/__tests__/request-logger.test.ts @@ -1,38 +1,23 @@ /** - * Tests for request-logger: logApiRequest, getRequestStats, normalizePath, percentile. + * Tests for request-logger: logApiRequest (write path) and getRequestStats (delegation). */ import { describe, it, expect, vi, beforeEach } from "vitest"; -import type { getRequestStats as GetRequestStatsFn } from "../request-logger.js"; // ── Mock fns (hoisted) ──────────────────────────────────────────────── const mockLoadConfig = vi.fn(); const mockGetLogsDir = vi.fn(); -const mockReadLogsFromDir = vi.fn(); +const mockParseApiLogs = vi.fn(); +const mockComputeApiStats = vi.fn(); const mockLogWriterAppend = vi.fn(); const mockLogWriterClose = vi.fn(); -/** Inline percentile impl (matches core's implementation) used in every mock below. */ -function mockPercentileImpl(sorted: number[], p: number): number { - if (sorted.length === 0) return 0; - const idx = Math.ceil((p / 100) * sorted.length) - 1; - return sorted[Math.max(0, idx)]; -} - -/** Inline normalizeRoutePath impl (matches core's implementation) used in every mock below. */ -function mockNormalizeRoutePathImpl(path: string): string { - return path - .replace(/\/sessions\/[^/]+/g, "/sessions/:id") - .replace(/\/prs\/[^/]+/g, "/prs/:id"); -} - vi.mock("@composio/ao-core", () => ({ loadConfig: (...args: unknown[]) => mockLoadConfig(...args), getLogsDir: (...args: unknown[]) => mockGetLogsDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - percentile: mockPercentileImpl, - normalizeRoutePath: mockNormalizeRoutePathImpl, + parseApiLogs: (...args: unknown[]) => mockParseApiLogs(...args), + computeApiStats: (...args: unknown[]) => mockComputeApiStats(...args), LogWriter: vi.fn().mockImplementation(() => ({ append: mockLogWriterAppend, appendLine: vi.fn(), @@ -60,9 +45,8 @@ describe("logApiRequest", () => { vi.doMock("@composio/ao-core", () => ({ loadConfig: (...args: unknown[]) => mockLoadConfig(...args), getLogsDir: (...args: unknown[]) => mockGetLogsDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - percentile: mockPercentileImpl, - normalizeRoutePath: mockNormalizeRoutePathImpl, + parseApiLogs: (...args: unknown[]) => mockParseApiLogs(...args), + computeApiStats: (...args: unknown[]) => mockComputeApiStats(...args), LogWriter: vi.fn().mockImplementation(() => ({ append: mockLogWriterAppend, appendLine: vi.fn(), @@ -302,19 +286,21 @@ describe("logApiRequest", () => { }); // ── getRequestStats ─────────────────────────────────────────────────── +// +// getRequestStats is a thin delegation wrapper around parseApiLogs + computeApiStats. +// The logic is tested in @composio/ao-core's log-reader.test.ts. Here we only +// verify the delegation contract. describe("getRequestStats", () => { - // getRequestStats calls readLogsFromDir directly, no cached writer involved - let getRequestStats: GetRequestStatsFn; + let getRequestStats: (logDir: string, opts?: { since?: Date; route?: string }) => unknown; beforeEach(async () => { vi.resetModules(); vi.doMock("@composio/ao-core", () => ({ loadConfig: (...args: unknown[]) => mockLoadConfig(...args), getLogsDir: (...args: unknown[]) => mockGetLogsDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - percentile: mockPercentileImpl, - normalizeRoutePath: mockNormalizeRoutePathImpl, + parseApiLogs: (...args: unknown[]) => mockParseApiLogs(...args), + computeApiStats: (...args: unknown[]) => mockComputeApiStats(...args), LogWriter: vi.fn().mockImplementation(() => ({ append: mockLogWriterAppend, appendLine: vi.fn(), @@ -326,365 +312,40 @@ describe("getRequestStats", () => { getRequestStats = mod.getRequestStats; }); - it("computes per-route stats with count, avgMs, percentiles", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - makeLogEntry("GET", "/api/sessions", 200, 200), - makeLogEntry("GET", "/api/sessions", 200, 300), - makeLogEntry("GET", "/api/sessions", 200, 400), - ]); + it("delegates: calls parseApiLogs then computeApiStats, returns result", () => { + const fakeEntries = [{ method: "GET", path: "/api/sessions", statusCode: 200, durationMs: 42 }]; + const fakeResult = { routes: { "GET /api/sessions": { count: 1 } }, slowest: [], latestCacheStats: null }; + mockParseApiLogs.mockReturnValue(fakeEntries); + mockComputeApiStats.mockReturnValue(fakeResult); const result = getRequestStats("/tmp/logs"); - const route = result.routes["GET /api/sessions"]; - expect(route).toBeDefined(); - expect(route.count).toBe(4); - expect(route.avgMs).toBe(250); // (100+200+300+400)/4 - expect(route.errors).toBe(0); + expect(mockParseApiLogs).toHaveBeenCalledWith("/tmp/logs", undefined); + expect(mockComputeApiStats).toHaveBeenCalledWith(fakeEntries); + expect(result).toBe(fakeResult); }); - it("counts errors when statusCode >= 400", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - makeLogEntry("GET", "/api/sessions", 400, 50), - makeLogEntry("GET", "/api/sessions", 500, 200), - ]); - - const result = getRequestStats("/tmp/logs"); - - const route = result.routes["GET /api/sessions"]; - expect(route.errors).toBe(2); - }); - - it("counts errors when error field is present", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("POST", "/api/spawn", 200, 100, "something went wrong"), - ]); - - const result = getRequestStats("/tmp/logs"); - - const route = result.routes["POST /api/spawn"]; - expect(route.errors).toBe(1); - }); - - it("groups by normalized path (dynamic segments replaced)", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions/abc123", 200, 100), - makeLogEntry("GET", "/api/sessions/def456", 200, 200), - makeLogEntry("GET", "/api/prs/42/merge", 200, 50), - makeLogEntry("GET", "/api/prs/99/merge", 200, 150), - ]); - - const result = getRequestStats("/tmp/logs"); - - // Both session paths should be grouped under :id - expect(result.routes["GET /api/sessions/:id"]).toBeDefined(); - expect(result.routes["GET /api/sessions/:id"].count).toBe(2); - - // Both PR paths should be grouped under :id - expect(result.routes["GET /api/prs/:id/merge"]).toBeDefined(); - expect(result.routes["GET /api/prs/:id/merge"].count).toBe(2); - - // Original paths should NOT exist as separate routes - expect(result.routes["GET /api/sessions/abc123"]).toBeUndefined(); - expect(result.routes["GET /api/prs/42/merge"]).toBeUndefined(); - }); - - it("returns slowest requests sorted by duration (descending)", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 50), - makeLogEntry("GET", "/api/sessions", 200, 3000), - makeLogEntry("GET", "/api/sessions", 200, 500), - ]); - - const result = getRequestStats("/tmp/logs"); - - expect(result.slowest).toHaveLength(3); - expect(result.slowest[0].durationMs).toBe(3000); - expect(result.slowest[1].durationMs).toBe(500); - expect(result.slowest[2].durationMs).toBe(50); - }); - - it("limits slowest to 10 entries", () => { - const entries = []; - for (let i = 0; i < 15; i++) { - entries.push(makeLogEntry("GET", "/api/sessions", 200, (i + 1) * 10)); - } - mockReadLogsFromDir.mockReturnValue(entries); - - const result = getRequestStats("/tmp/logs"); - - expect(result.slowest).toHaveLength(10); - // The slowest should be 150ms (15*10), not 10ms (1*10) - expect(result.slowest[0].durationMs).toBe(150); - }); - - it("handles empty log directory (no entries)", () => { - mockReadLogsFromDir.mockReturnValue([]); - - const result = getRequestStats("/tmp/logs"); - - expect(result.routes).toEqual({}); - expect(result.slowest).toEqual([]); - }); - - it("passes since filter to readLogsFromDir", () => { - mockReadLogsFromDir.mockReturnValue([]); + it("forwards since and route options to parseApiLogs", () => { + mockParseApiLogs.mockReturnValue([]); + mockComputeApiStats.mockReturnValue({ routes: {}, slowest: [], latestCacheStats: null }); const since = new Date("2026-01-15T00:00:00Z"); - getRequestStats("/tmp/logs", { since }); + getRequestStats("/tmp/logs", { since, route: "sessions" }); - expect(mockReadLogsFromDir).toHaveBeenCalledWith( - "/tmp/logs", - "api", - expect.objectContaining({ since }), - ); + expect(mockParseApiLogs).toHaveBeenCalledWith("/tmp/logs", { since, route: "sessions" }); }); - it("filters by route pattern", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - makeLogEntry("GET", "/api/prs", 200, 200), - makeLogEntry("POST", "/api/sessions/abc/kill", 200, 50), - ]); - - const result = getRequestStats("/tmp/logs", { route: "sessions" }); - - // Only routes containing "sessions" should be included - expect(Object.keys(result.routes)).toEqual( - expect.arrayContaining(["GET /api/sessions"]), - ); - expect(result.routes["GET /api/prs"]).toBeUndefined(); - expect(result.slowest.every((r) => r.path.includes("sessions"))).toBe(true); - }); - - it("skips entries without method or path in data", () => { - mockReadLogsFromDir.mockReturnValue([ - { - ts: "2026-01-15T10:00:00Z", - level: "info", - source: "api", - sessionId: null, - message: "some log without method/path", - data: { statusCode: 200, durationMs: 50 }, - }, - makeLogEntry("GET", "/api/sessions", 200, 100), - ]); + it("returns computeApiStats result unchanged", () => { + const expected = { + routes: { "GET /api/sessions": { count: 5, avgMs: 100, p50Ms: 90, p95Ms: 200, p99Ms: 300, errors: 0 } }, + slowest: [], + latestCacheStats: { hits: 10, misses: 2, hitRate: 0.83, size: 12 }, + }; + mockParseApiLogs.mockReturnValue([]); + mockComputeApiStats.mockReturnValue(expected); const result = getRequestStats("/tmp/logs"); - expect(Object.keys(result.routes)).toHaveLength(1); - expect(result.routes["GET /api/sessions"].count).toBe(1); - }); - - it("handles entries with missing data object", () => { - mockReadLogsFromDir.mockReturnValue([ - { - ts: "2026-01-15T10:00:00Z", - level: "info", - source: "api", - sessionId: null, - message: "bare entry", - }, - makeLogEntry("GET", "/api/sessions", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - - expect(Object.keys(result.routes)).toHaveLength(1); - }); - - it("separates routes by HTTP method", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - makeLogEntry("POST", "/api/sessions", 201, 200), - ]); - - const result = getRequestStats("/tmp/logs"); - - expect(result.routes["GET /api/sessions"]).toBeDefined(); - expect(result.routes["POST /api/sessions"]).toBeDefined(); - expect(result.routes["GET /api/sessions"].count).toBe(1); - expect(result.routes["POST /api/sessions"].count).toBe(1); + expect(result).toBe(expected); }); }); - -// ── normalizePath (tested indirectly via getRequestStats) ───────────── - -describe("normalizePath (indirect)", () => { - let getRequestStats: GetRequestStatsFn; - - beforeEach(async () => { - vi.resetModules(); - vi.doMock("@composio/ao-core", () => ({ - loadConfig: (...args: unknown[]) => mockLoadConfig(...args), - getLogsDir: (...args: unknown[]) => mockGetLogsDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - percentile: mockPercentileImpl, - normalizeRoutePath: mockNormalizeRoutePathImpl, - LogWriter: vi.fn().mockImplementation(() => ({ - append: mockLogWriterAppend, - appendLine: vi.fn(), - close: mockLogWriterClose, - })), - })); - - const mod = await import("../request-logger.js"); - getRequestStats = mod.getRequestStats; - }); - - it("/api/sessions/abc123 normalizes to /api/sessions/:id", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions/abc123", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - expect(result.routes["GET /api/sessions/:id"]).toBeDefined(); - }); - - it("/api/prs/42/merge normalizes to /api/prs/:id/merge", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/prs/42/merge", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - expect(result.routes["GET /api/prs/:id/merge"]).toBeDefined(); - }); - - it("/api/sessions remains unchanged (no dynamic segment)", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - expect(result.routes["GET /api/sessions"]).toBeDefined(); - }); - - it("normalizes multiple dynamic segments in one path", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions/abc123/prs/42", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - // sessions/:id and prs/:id should both be replaced - expect(result.routes["GET /api/sessions/:id/prs/:id"]).toBeDefined(); - }); - - it("non-matching paths remain unchanged", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/config", 200, 100), - ]); - - const result = getRequestStats("/tmp/logs"); - expect(result.routes["GET /api/config"]).toBeDefined(); - }); -}); - -// ── percentile (tested indirectly via getRequestStats) ──────────────── - -describe("percentile (indirect)", () => { - let getRequestStats: GetRequestStatsFn; - - beforeEach(async () => { - vi.resetModules(); - vi.doMock("@composio/ao-core", () => ({ - loadConfig: (...args: unknown[]) => mockLoadConfig(...args), - getLogsDir: (...args: unknown[]) => mockGetLogsDir(...args), - readLogsFromDir: (...args: unknown[]) => mockReadLogsFromDir(...args), - percentile: mockPercentileImpl, - normalizeRoutePath: mockNormalizeRoutePathImpl, - LogWriter: vi.fn().mockImplementation(() => ({ - append: mockLogWriterAppend, - appendLine: vi.fn(), - close: mockLogWriterClose, - })), - })); - - const mod = await import("../request-logger.js"); - getRequestStats = mod.getRequestStats; - }); - - it("returns 0 for empty array (no entries)", () => { - mockReadLogsFromDir.mockReturnValue([]); - - const result = getRequestStats("/tmp/logs"); - - // No routes means no percentiles to check, but verify no crash - expect(result.routes).toEqual({}); - }); - - it("returns the single element for single-entry route", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 42), - ]); - - const result = getRequestStats("/tmp/logs"); - const route = result.routes["GET /api/sessions"]; - expect(route.p50Ms).toBe(42); - expect(route.p95Ms).toBe(42); - expect(route.p99Ms).toBe(42); - }); - - it("computes correct p50 for two elements", () => { - mockReadLogsFromDir.mockReturnValue([ - makeLogEntry("GET", "/api/sessions", 200, 100), - makeLogEntry("GET", "/api/sessions", 200, 200), - ]); - - const result = getRequestStats("/tmp/logs"); - const route = result.routes["GET /api/sessions"]; - // sorted: [100, 200] - // p50: ceil(50/100 * 2) - 1 = ceil(1) - 1 = 0 => sorted[0] = 100 - expect(route.p50Ms).toBe(100); - // p95: ceil(95/100 * 2) - 1 = ceil(1.9) - 1 = 1 => sorted[1] = 200 - expect(route.p95Ms).toBe(200); - // p99: ceil(99/100 * 2) - 1 = ceil(1.98) - 1 = 1 => sorted[1] = 200 - expect(route.p99Ms).toBe(200); - }); - - it("computes correct percentiles for a larger dataset", () => { - // 100 entries with durations 1..100 - const entries = []; - for (let i = 1; i <= 100; i++) { - entries.push(makeLogEntry("GET", "/api/sessions", 200, i)); - } - mockReadLogsFromDir.mockReturnValue(entries); - - const result = getRequestStats("/tmp/logs"); - const route = result.routes["GET /api/sessions"]; - - expect(route.count).toBe(100); - // p50: ceil(50/100 * 100) - 1 = 50 - 1 = 49 => sorted[49] = 50 - expect(route.p50Ms).toBe(50); - // p95: ceil(95/100 * 100) - 1 = 95 - 1 = 94 => sorted[94] = 95 - expect(route.p95Ms).toBe(95); - // p99: ceil(99/100 * 100) - 1 = 99 - 1 = 98 => sorted[98] = 99 - expect(route.p99Ms).toBe(99); - expect(route.avgMs).toBe(51); // Math.round(5050 / 100) = 51 (rounded up from 50.5) - }); -}); - -// ── Helpers ─────────────────────────────────────────────────────────── - -function makeLogEntry( - method: string, - path: string, - statusCode: number, - durationMs: number, - error?: string, -) { - return { - ts: "2026-01-15T10:00:00Z", - level: error ? "error" : "info", - source: "api", - sessionId: null, - message: `${method} ${path} ${statusCode} ${durationMs}ms`, - data: { - method, - path, - statusCode, - durationMs, - ...(error && { error }), - }, - }; -} diff --git a/packages/web/src/lib/request-logger.ts b/packages/web/src/lib/request-logger.ts index bb5840443..5786a7615 100644 --- a/packages/web/src/lib/request-logger.ts +++ b/packages/web/src/lib/request-logger.ts @@ -2,47 +2,23 @@ * Structured API request logging with performance timing. * * Logs each API request to {logDir}/api.jsonl with timing breakdowns. - * Provides getRequestStats() for aggregated analysis used by CLI and dashboard. + * For aggregated stats, use getRequestStats() which delegates to + * parseApiLogs + computeApiStats from @composio/ao-core. */ -import { getLogsDir, LogWriter, loadConfig, readLogsFromDir, percentile, normalizeRoutePath } from "@composio/ao-core"; +import { + getLogsDir, + LogWriter, + loadConfig, + parseApiLogs, + computeApiStats, + type ApiLogEntry, + type ApiPerfResult, +} from "@composio/ao-core"; -export interface RequestLog { - ts: string; - method: string; - path: string; - sessionId: string | null; - statusCode: number; - durationMs: number; - error?: string; - timings?: { - serviceInit?: number; - sessionList?: number; - prEnrichment?: number; - issueEnrichment?: number; - serialization?: number; - }; - cacheStats?: { - hits: number; - misses: number; - hitRate: number; - size: number; - }; -} - -export interface RouteStats { - count: number; - avgMs: number; - p50Ms: number; - p95Ms: number; - p99Ms: number; - errors: number; -} - -export interface RequestStatsResult { - routes: Record; - slowest: RequestLog[]; -} +// Re-export core types so callers don't need to import from two packages. +export type { ApiLogEntry as RequestLog, ApiPerfResult as RequestStatsResult } from "@composio/ao-core"; +export type { RouteStats } from "@composio/ao-core"; let logWriter: LogWriter | null = null; @@ -63,7 +39,7 @@ function getLogWriter(): LogWriter | null { } /** Log an API request with timing data. */ -export function logApiRequest(log: RequestLog): void { +export function logApiRequest(log: ApiLogEntry): void { const writer = getLogWriter(); if (!writer) return; @@ -89,63 +65,7 @@ export function logApiRequest(log: RequestLog): void { export function getRequestStats( logDir: string, opts?: { since?: Date; route?: string }, -): RequestStatsResult { - const entries = readLogsFromDir(logDir, "api", { - source: "api", - since: opts?.since, - }); - - // Parse request logs from entries - const requestLogs: RequestLog[] = []; - for (const entry of entries) { - const data = entry.data ?? {}; - if (!data["method"] || !data["path"]) continue; - - const log: RequestLog = { - ts: entry.ts, - method: String(data["method"]), - path: String(data["path"]), - sessionId: entry.sessionId, - statusCode: Number(data["statusCode"]) || 0, - durationMs: Number(data["durationMs"]) || 0, - error: data["error"] ? String(data["error"]) : undefined, - timings: data["timings"] as RequestLog["timings"], - cacheStats: data["cacheStats"] as RequestLog["cacheStats"], - }; - - if (opts?.route && !log.path.includes(opts.route)) continue; - requestLogs.push(log); - } - - // Group by route (normalize path params) - const byRoute = new Map(); - for (const log of requestLogs) { - const normalizedPath = normalizeRoutePath(log.path); - const key = `${log.method} ${normalizedPath}`; - const existing = byRoute.get(key) ?? []; - existing.push(log); - byRoute.set(key, existing); - } - - // Compute per-route stats - const routes: Record = {}; - for (const [route, logs] of byRoute) { - const durations = logs.map((l) => l.durationMs).sort((a, b) => a - b); - routes[route] = { - count: logs.length, - avgMs: Math.round(durations.reduce((sum, d) => sum + d, 0) / durations.length), - p50Ms: percentile(durations, 50), - p95Ms: percentile(durations, 95), - p99Ms: percentile(durations, 99), - errors: logs.filter((l) => l.error || l.statusCode >= 400).length, - }; - } - - // Find slowest requests - const slowest = requestLogs - .sort((a, b) => b.durationMs - a.durationMs) - .slice(0, 10); - - return { routes, slowest }; +): ApiPerfResult { + const entries = parseApiLogs(logDir, opts); + return computeApiStats(entries); } - diff --git a/packages/web/src/lib/with-timing.ts b/packages/web/src/lib/with-timing.ts index e77cf9d4f..cbd901199 100644 --- a/packages/web/src/lib/with-timing.ts +++ b/packages/web/src/lib/with-timing.ts @@ -5,7 +5,8 @@ * each request's duration and status to the API request log. */ -import { logApiRequest, type RequestLog } from "./request-logger.js"; +import type { ApiLogEntry } from "@composio/ao-core"; +import { logApiRequest } from "./request-logger.js"; type RouteHandler = (req: Request, ctx?: unknown) => Promise; @@ -42,7 +43,7 @@ export function withTiming(handler: RouteHandler, _routeName: string): RouteHand const durationMs = Date.now() - start; - const log: RequestLog = { + const log: ApiLogEntry = { ts: new Date().toISOString(), method, path,