From fca109a5c646dd5f633ffdf57fb9ad26cc6457e5 Mon Sep 17 00:00:00 2001 From: Christiaan Arnoldus Date: Thu, 6 Aug 2026 12:30:01 +0200 Subject: [PATCH 1/4] fix(admin): ensure request log ZIPs finalize --- .../api-request-log/download/route.test.ts | 105 ++++++++++++++++++ .../api/api-request-log/download/route.ts | 91 +++++++++++---- 2 files changed, 175 insertions(+), 21 deletions(-) create mode 100644 apps/web/src/app/admin/api/api-request-log/download/route.test.ts diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts new file mode 100644 index 0000000000..ce67d2661d --- /dev/null +++ b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts @@ -0,0 +1,105 @@ +import { NextRequest } from 'next/server'; +import { randomBytes } from 'node:crypto'; +import { eq } from 'drizzle-orm'; +import { strFromU8, unzipSync } from 'fflate'; +import { api_request_log } from '@kilocode/db/schema'; +import { db } from '@/lib/drizzle'; +import { getUserFromAuth } from '@/lib/user/server'; +import { defineTestUser } from '@/tests/helpers/user.helper'; +import { GET, maxDuration } from './route'; + +jest.mock('next/server', () => { + const actual = jest.requireActual('next/server'); + return { ...actual, connection: jest.fn() }; +}); + +jest.mock('@/lib/user/server', () => ({ + getUserFromAuth: jest.fn(), +})); + +const mockedGetUserFromAuth = jest.mocked(getUserFromAuth); +const TEST_USER_ID = 'api-request-log-download-test-user'; +const TEST_MODEL = 'poolside/laguna-s-2.1:free'; +const BATCH_SIZE = 100; + +function createRequest() { + const params = new URLSearchParams({ + userId: TEST_USER_ID, + startDate: '2026-08-01', + endDate: '2026-08-01', + model: TEST_MODEL, + }); + return new NextRequest(`http://localhost:3000/admin/api/api-request-log/download?${params}`); +} + +function readEntry(entries: Record, suffix: string): string { + const name = Object.keys(entries).find(entryName => entryName.endsWith(suffix)); + if (!name) throw new Error(`Missing archive entry ending in ${suffix}`); + return strFromU8(entries[name]); +} + +describe('GET /admin/api/api-request-log/download', () => { + beforeEach(() => { + mockedGetUserFromAuth.mockResolvedValue({ + user: defineTestUser({ is_admin: true }), + authFailedResponse: null, + }); + }); + + afterEach(async () => { + await db.delete(api_request_log).where(eq(api_request_log.kilo_user_id, TEST_USER_ID)); + }); + + it('streams a complete ZIP from a bounded result set across backpressured DB batches', async () => { + // The first batch must exceed both the Node and web stream queues. This + // keeps page two blocked until the test starts consuming the response. + const payload = randomBytes(32 * 1024).toString('base64'); + const rows = await db + .insert(api_request_log) + .values( + Array.from({ length: BATCH_SIZE + 1 }, (_, index) => ({ + created_at: '2026-08-01T12:00:00.000Z', + kilo_user_id: TEST_USER_ID, + provider: 'test-provider', + model: TEST_MODEL, + request: { index }, + response: JSON.stringify({ output: index, payload }), + })) + ) + .returning({ id: api_request_log.id }); + + const response = await GET(createRequest()); + + await db.insert(api_request_log).values({ + created_at: '2026-08-01T12:01:00.000Z', + kilo_user_id: TEST_USER_ID, + provider: 'test-provider', + model: TEST_MODEL, + request: { index: 'inserted-after-ceiling' }, + response: JSON.stringify({ output: 'inserted-after-ceiling' }), + }); + + expect(maxDuration).toBe(800); + expect(response.status).toBe(200); + expect(response.headers.get('Content-Type')).toBe('application/zip'); + expect(response.headers.get('Content-Disposition')).toBe( + 'attachment; filename="api-request-log_api-request-log-download-test-user_2026-08-01_2026-08-01_poolside-laguna-s-2.1-free.zip"' + ); + + const bytes = new Uint8Array(await response.arrayBuffer()); + expect(Array.from(bytes.subarray(0, 4))).toEqual([0x50, 0x4b, 0x03, 0x04]); + + const entries = unzipSync(bytes); + expect(Object.keys(entries)).toHaveLength((BATCH_SIZE + 1) * 2); + expect(readEntry(entries, `_${rows[0].id}_request.json`)).toBe( + JSON.stringify({ index: 0 }, null, 2) + ); + expect(JSON.parse(readEntry(entries, `_${rows[BATCH_SIZE].id}_response.json`))).toEqual({ + output: BATCH_SIZE, + payload, + }); + expect( + Object.values(entries).some(entry => strFromU8(entry).includes('inserted-after-ceiling')) + ).toBe(false); + }); +}); diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.ts b/apps/web/src/app/admin/api/api-request-log/download/route.ts index 70777cb5f2..cc382dedbf 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.ts @@ -2,15 +2,14 @@ import { connection, type NextRequest } from 'next/server'; import { getUserFromAuth } from '@/lib/user/server'; import { db } from '@/lib/drizzle'; import { api_request_log } from '@kilocode/db/schema'; -import { and, gte, lte, eq, asc, gt, count, or, isNotNull, type SQL } from 'drizzle-orm'; +import { and, gte, lte, eq, asc, desc, gt, or, isNotNull, type SQL } from 'drizzle-orm'; import archiver from 'archiver'; import { Readable } from 'node:stream'; -// Downloading all logs for a heavy user can take a while. Without a raised -// maxDuration the Vercel function was killed mid-stream, producing a ZIP -// without a central directory record. macOS Archive Utility then refused to -// extract it ("Error 79 - Inappropriate file type or format"). -export const maxDuration = 300; +// The central directory is written only when the archive finishes. Give large +// exports the longest function budget used by the app so Vercel does not cut +// the stream off with an invalid ZIP. +export const maxDuration = 800; const BATCH_SIZE = 100; @@ -122,12 +121,60 @@ export async function GET(request: NextRequest) { const filter = buildFilter(userId, parsedStart, parsedEnd, model, sessionId, errorsOnly); - const [result] = await db.select({ total: count() }).from(api_request_log).where(filter); - if (result.total === 0) { + // Bound pagination before streaming starts so newly inserted logs cannot + // keep extending a busy export toward the function timeout. + const [ceiling] = await db + .select({ lastId: api_request_log.id }) + .from(api_request_log) + .where(filter) + .orderBy(desc(api_request_log.id)) + .limit(1); + if (!ceiling) { return jsonError('No records found for the given criteria', 404); } - const archive = archiver('zip', { zlib: { level: 6 } }); + // Request logs are large and text-heavy. Level 1 retains useful compression + // while reducing the chance that CPU time prevents the ZIP from finalizing. + const archive = archiver('zip', { zlib: { level: 1 } }); + let totalAppendedEntries = 0; + let totalProcessedEntries = 0; + + archive.on('entry', () => { + totalProcessedEntries += 1; + }); + + const waitForEntries = (target: number) => { + if (totalProcessedEntries >= target) return Promise.resolve(); + if (archive.destroyed) { + return Promise.reject(new Error('Archive closed before all entries were processed')); + } + + return new Promise((resolve, reject) => { + const cleanup = () => { + archive.off('entry', onEntry); + archive.off('error', onError); + archive.off('close', onClose); + }; + const onEntry = () => { + if (totalProcessedEntries >= target) { + cleanup(); + resolve(); + } + }; + const onError = (error: Error) => { + cleanup(); + reject(error); + }; + const onClose = () => { + cleanup(); + reject(new Error('Archive closed before all entries were processed')); + }; + + archive.on('entry', onEntry); + archive.once('error', onError); + archive.once('close', onClose); + }); + }; // Fetch and archive rows in batches using cursor-based pagination to // avoid loading the entire result set into memory at once. @@ -137,7 +184,13 @@ export async function GET(request: NextRequest) { const rows = await db .select() .from(api_request_log) - .where(cursor ? and(filter, gt(api_request_log.id, cursor)) : filter) + .where( + and( + filter, + lte(api_request_log.id, ceiling.lastId), + cursor ? gt(api_request_log.id, cursor) : undefined + ) + ) .orderBy(asc(api_request_log.id)) .limit(BATCH_SIZE); @@ -150,18 +203,21 @@ export async function GET(request: NextRequest) { const requestExt = isJson(row.request) ? 'json' : 'txt'; const requestContent = tryFormatJson(row.request); if (requestContent) { + totalAppendedEntries += 1; archive.append(requestContent, { name: `${ts}_${id}_request.${requestExt}` }); } const responseExt = isJson(row.response) ? 'json' : 'txt'; const responseContent = tryFormatJson(row.response); if (responseContent) { + totalAppendedEntries += 1; archive.append(responseContent, { name: `${ts}_${id}_response.${responseExt}` }); } if (row.error !== null && row.error !== undefined) { const errorContent = tryFormatJson(row.error); if (errorContent) { + totalAppendedEntries += 1; archive.append(errorContent, { name: `${ts}_${id}_error.json` }); } } @@ -169,17 +225,10 @@ export async function GET(request: NextRequest) { cursor = rows[rows.length - 1].id; - // Yield between batches while the archive's readable buffer is above - // its high-water mark, so we don't buffer unbounded data in memory. - // Polling via setImmediate rather than waiting on a single 'drain' - // event: archiver's internal queue pauses once it's out of entries, so - // after we stop appending its writable side may never go back above - // HWM and 'drain' would never fire again - listening for it would - // deadlock the stream. - const hwm = archive.readableHighWaterMark ?? 16 * 1024; - while (archive.readableLength > hwm) { - await new Promise(resolve => setImmediate(resolve)); - } + // Archiver maintains its own input queue, which is not reflected by the + // readable stream's high-water mark. Wait until this batch is emitted so + // large exports remain bounded even when compression is slower than DB reads. + await waitForEntries(totalAppendedEntries); } await archive.finalize(); From a421e840f277bdb7ee1d8445663db71e26d4aa44 Mon Sep 17 00:00:00 2001 From: Christiaan Arnoldus Date: Thu, 6 Aug 2026 12:43:08 +0200 Subject: [PATCH 2/4] refactor(admin): separate request log timeout change --- .../app/admin/api/api-request-log/download/route.test.ts | 3 +-- .../src/app/admin/api/api-request-log/download/route.ts | 9 +++++---- 2 files changed, 6 insertions(+), 6 deletions(-) diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts index ce67d2661d..2c7e5d32e2 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts @@ -6,7 +6,7 @@ import { api_request_log } from '@kilocode/db/schema'; import { db } from '@/lib/drizzle'; import { getUserFromAuth } from '@/lib/user/server'; import { defineTestUser } from '@/tests/helpers/user.helper'; -import { GET, maxDuration } from './route'; +import { GET } from './route'; jest.mock('next/server', () => { const actual = jest.requireActual('next/server'); @@ -79,7 +79,6 @@ describe('GET /admin/api/api-request-log/download', () => { response: JSON.stringify({ output: 'inserted-after-ceiling' }), }); - expect(maxDuration).toBe(800); expect(response.status).toBe(200); expect(response.headers.get('Content-Type')).toBe('application/zip'); expect(response.headers.get('Content-Disposition')).toBe( diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.ts b/apps/web/src/app/admin/api/api-request-log/download/route.ts index cc382dedbf..35a694ba77 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.ts @@ -6,10 +6,11 @@ import { and, gte, lte, eq, asc, desc, gt, or, isNotNull, type SQL } from 'drizz import archiver from 'archiver'; import { Readable } from 'node:stream'; -// The central directory is written only when the archive finishes. Give large -// exports the longest function budget used by the app so Vercel does not cut -// the stream off with an invalid ZIP. -export const maxDuration = 800; +// Downloading all logs for a heavy user can take a while. Without a raised +// maxDuration the Vercel function was killed mid-stream, producing a ZIP +// without a central directory record. macOS Archive Utility then refused to +// extract it ("Error 79 - Inappropriate file type or format"). +export const maxDuration = 300; const BATCH_SIZE = 100; From 14b548ea9ef8f497e5f282647edf1cdecf4a2d44 Mon Sep 17 00:00:00 2001 From: Christiaan Arnoldus Date: Thu, 6 Aug 2026 13:28:30 +0200 Subject: [PATCH 3/4] fix(admin): reduce request log export memory --- .../src/app/admin/api/api-request-log/download/route.test.ts | 4 ++-- apps/web/src/app/admin/api/api-request-log/download/route.ts | 2 +- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts index 2c7e5d32e2..0adfd28d1b 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts @@ -20,7 +20,7 @@ jest.mock('@/lib/user/server', () => ({ const mockedGetUserFromAuth = jest.mocked(getUserFromAuth); const TEST_USER_ID = 'api-request-log-download-test-user'; const TEST_MODEL = 'poolside/laguna-s-2.1:free'; -const BATCH_SIZE = 100; +const BATCH_SIZE = 25; function createRequest() { const params = new URLSearchParams({ @@ -53,7 +53,7 @@ describe('GET /admin/api/api-request-log/download', () => { it('streams a complete ZIP from a bounded result set across backpressured DB batches', async () => { // The first batch must exceed both the Node and web stream queues. This // keeps page two blocked until the test starts consuming the response. - const payload = randomBytes(32 * 1024).toString('base64'); + const payload = randomBytes(128 * 1024).toString('base64'); const rows = await db .insert(api_request_log) .values( diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.ts b/apps/web/src/app/admin/api/api-request-log/download/route.ts index 35a694ba77..72e85d2244 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.ts @@ -12,7 +12,7 @@ import { Readable } from 'node:stream'; // extract it ("Error 79 - Inappropriate file type or format"). export const maxDuration = 300; -const BATCH_SIZE = 100; +const BATCH_SIZE = 25; function formatTimestamp(isoString: string): string { return isoString.replaceAll(':', '-').replaceAll(' ', '_'); From ab7bab957bc60a838a95e09a7c78f9b87e63e29a Mon Sep 17 00:00:00 2001 From: Christiaan Arnoldus Date: Thu, 6 Aug 2026 13:32:57 +0200 Subject: [PATCH 4/4] refactor(admin): scope request log fix to memory --- .../api-request-log/download/route.test.ts | 14 +---------- .../api/api-request-log/download/route.ts | 25 ++++--------------- 2 files changed, 6 insertions(+), 33 deletions(-) diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts index 0adfd28d1b..9010f9bdcc 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.test.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.test.ts @@ -50,7 +50,7 @@ describe('GET /admin/api/api-request-log/download', () => { await db.delete(api_request_log).where(eq(api_request_log.kilo_user_id, TEST_USER_ID)); }); - it('streams a complete ZIP from a bounded result set across backpressured DB batches', async () => { + it('streams a complete ZIP across backpressured DB batches', async () => { // The first batch must exceed both the Node and web stream queues. This // keeps page two blocked until the test starts consuming the response. const payload = randomBytes(128 * 1024).toString('base64'); @@ -70,15 +70,6 @@ describe('GET /admin/api/api-request-log/download', () => { const response = await GET(createRequest()); - await db.insert(api_request_log).values({ - created_at: '2026-08-01T12:01:00.000Z', - kilo_user_id: TEST_USER_ID, - provider: 'test-provider', - model: TEST_MODEL, - request: { index: 'inserted-after-ceiling' }, - response: JSON.stringify({ output: 'inserted-after-ceiling' }), - }); - expect(response.status).toBe(200); expect(response.headers.get('Content-Type')).toBe('application/zip'); expect(response.headers.get('Content-Disposition')).toBe( @@ -97,8 +88,5 @@ describe('GET /admin/api/api-request-log/download', () => { output: BATCH_SIZE, payload, }); - expect( - Object.values(entries).some(entry => strFromU8(entry).includes('inserted-after-ceiling')) - ).toBe(false); }); }); diff --git a/apps/web/src/app/admin/api/api-request-log/download/route.ts b/apps/web/src/app/admin/api/api-request-log/download/route.ts index aa2d727e96..17170fe7dc 100644 --- a/apps/web/src/app/admin/api/api-request-log/download/route.ts +++ b/apps/web/src/app/admin/api/api-request-log/download/route.ts @@ -2,7 +2,7 @@ import { connection, type NextRequest } from 'next/server'; import { getUserFromAuth } from '@/lib/user/server'; import { db } from '@/lib/drizzle'; import { api_request_log } from '@kilocode/db/schema'; -import { and, gte, lte, eq, asc, desc, gt, or, isNotNull, type SQL } from 'drizzle-orm'; +import { and, gte, lte, eq, asc, gt, count, or, isNotNull, type SQL } from 'drizzle-orm'; import archiver from 'archiver'; import { Readable } from 'node:stream'; @@ -122,21 +122,12 @@ export async function GET(request: NextRequest) { const filter = buildFilter(userId, parsedStart, parsedEnd, model, sessionId, errorsOnly); - // Bound pagination before streaming starts so newly inserted logs cannot - // keep extending a busy export toward the function timeout. - const [ceiling] = await db - .select({ lastId: api_request_log.id }) - .from(api_request_log) - .where(filter) - .orderBy(desc(api_request_log.id)) - .limit(1); - if (!ceiling) { + const [result] = await db.select({ total: count() }).from(api_request_log).where(filter); + if (result.total === 0) { return jsonError('No records found for the given criteria', 404); } - // Request logs are large and text-heavy. Level 1 retains useful compression - // while reducing the chance that CPU time prevents the ZIP from finalizing. - const archive = archiver('zip', { zlib: { level: 1 } }); + const archive = archiver('zip', { zlib: { level: 6 } }); let totalAppendedEntries = 0; let totalProcessedEntries = 0; @@ -185,13 +176,7 @@ export async function GET(request: NextRequest) { const rows = await db .select() .from(api_request_log) - .where( - and( - filter, - lte(api_request_log.id, ceiling.lastId), - cursor ? gt(api_request_log.id, cursor) : undefined - ) - ) + .where(cursor ? and(filter, gt(api_request_log.id, cursor)) : filter) .orderBy(asc(api_request_log.id)) .limit(BATCH_SIZE);