diff --git a/app/api/history/route.ts b/app/api/history/route.ts index 46ca169..4f6f60e 100644 --- a/app/api/history/route.ts +++ b/app/api/history/route.ts @@ -4,6 +4,21 @@ import logger from '@/lib/log'; import { getRequestId, jsonResponse, PRIVATE_NO_STORE, readContentLength } from '@/lib/request'; import { LIMITS, validateHistorySaveRequest } from '@/lib/validation'; +function hasOwn(input: Record, key: string): boolean { + return Object.prototype.hasOwnProperty.call(input, key); +} + +function isPlainObject(value: unknown): value is Record { + return !!value && typeof value === 'object' && !Array.isArray(value); +} + +function getFieldType(value: unknown): string | null { + if (value === undefined) return null; + if (value === null) return 'null'; + if (Array.isArray(value)) return 'array'; + return typeof value; +} + export async function GET(req: Request) { const requestId = getRequestId(req); const start = Date.now(); @@ -40,44 +55,85 @@ export async function GET(req: Request) { export async function POST(req: Request) { const requestId = getRequestId(req); const start = Date.now(); + const requestBytes = readContentLength(req); + const ctx: Record = { + requestId, + user: null, + status: null, + requestBytes, + hasIdField: false, + idFieldType: null, + requestedId: null, + savedId: null, + requestedOp: null, + resolvedOp: null, + ciphertextChars: null, + ciphertextBytes: null, + ivChars: null, + updated: null, + inserted: null, + updateRows: null, + error: null, + }; try { const session = await auth(); if (!session?.user?.email) { - logger.warn({ requestId, durationMs: Date.now() - start }, 'history.save.unauthenticated'); + ctx.status = 401; + ctx.error = 'Unauthorized'; return jsonResponse({ error: 'Unauthorized' }, { status: 401 }, { requestId, cacheControl: PRIVATE_NO_STORE }); } + ctx.user = session.user.email; - const contentLength = readContentLength(req); + const contentLength = requestBytes; if (contentLength !== null && contentLength > LIMITS.historyBodyBytes) { - logger.warn({ requestId, user: session.user.email, durationMs: Date.now() - start, contentLength }, 'history.save.too_large'); + ctx.status = 413; + ctx.error = 'Request too large'; return jsonResponse({ error: 'Request too large' }, { status: 413 }, { requestId, cacheControl: PRIVATE_NO_STORE }); } - const parsed = validateHistorySaveRequest(await req.json()); + const body = await req.json(); + if (isPlainObject(body)) { + ctx.hasIdField = hasOwn(body, 'id'); + ctx.idFieldType = getFieldType(body.id); + ctx.requestedId = typeof body.id === 'string' ? body.id : null; + ctx.requestedOp = hasOwn(body, 'id') ? 'update' : 'insert'; + ctx.ivChars = typeof body.iv === 'string' ? body.iv.length : null; + ctx.ciphertextChars = typeof body.ciphertext === 'string' ? body.ciphertext.length : null; + ctx.ciphertextBytes = typeof body.ciphertext === 'string' + ? Math.round((body.ciphertext.length ?? 0) * 0.75) + : null; + } + + const parsed = validateHistorySaveRequest(body); if (!parsed.ok) { - logger.warn({ requestId, user: session.user.email, durationMs: Date.now() - start, error: parsed.error }, 'history.save.invalid'); + ctx.status = parsed.status; + ctx.error = parsed.error; return jsonResponse({ error: parsed.error }, { status: parsed.status }, { requestId, cacheControl: PRIVATE_NO_STORE }); } const ciphertextBytes = Math.round((parsed.value.ciphertext.length ?? 0) * 0.75); + ctx.requestedId = parsed.value.id ?? null; + ctx.requestedOp = parsed.value.id ? 'update' : 'insert'; + ctx.ivChars = parsed.value.iv.length; + ctx.ciphertextChars = parsed.value.ciphertext.length; + ctx.ciphertextBytes = ciphertextBytes; if (parsed.value.id) { const upd = await query( 'UPDATE chat_histories SET iv = $1, ciphertext = $2, updated_at = now() WHERE id = $3 AND user_email = $4', [parsed.value.iv, parsed.value.ciphertext, parsed.value.id, session.user.email], ); + ctx.updateRows = upd.rowCount ?? 0; if ((upd.rowCount ?? 0) > 0) { - logger.info({ - requestId, - user: session.user.email, - id: parsed.value.id, - op: 'update', - durationMs: Date.now() - start, - ciphertextBytes, - }, 'history.save'); + ctx.status = 200; + ctx.savedId = parsed.value.id; + ctx.resolvedOp = 'update'; + ctx.updated = true; + ctx.inserted = false; return jsonResponse({ id: parsed.value.id }, {}, { requestId, cacheControl: PRIVATE_NO_STORE }); } + ctx.updated = false; } const result = await query( @@ -86,17 +142,20 @@ export async function POST(req: Request) { RETURNING id`, [session.user.email, parsed.value.iv, parsed.value.ciphertext], ); - logger.info({ - requestId, - user: session.user.email, - id: result.rows[0].id, - op: 'insert', - durationMs: Date.now() - start, - ciphertextBytes, - }, 'history.save'); + ctx.status = 200; + ctx.savedId = result.rows[0].id; + ctx.resolvedOp = 'insert'; + ctx.inserted = true; return jsonResponse({ id: result.rows[0].id }, {}, { requestId, cacheControl: PRIVATE_NO_STORE }); } catch (error) { - logger.error({ requestId, durationMs: Date.now() - start, error: String(error).slice(0, 200) }, 'history.save.failed'); + ctx.status = 500; + ctx.error = String(error).slice(0, 200); return jsonResponse({ error: 'Internal Server Error' }, { status: 500 }, { requestId, cacheControl: PRIVATE_NO_STORE }); + } finally { + const fields = { ...ctx, durationMs: Date.now() - start }; + const status = typeof ctx.status === 'number' ? ctx.status : 500; + if (status >= 500) logger.error(fields, 'history.save'); + else if (status >= 400) logger.warn(fields, 'history.save'); + else logger.info(fields, 'history.save'); } } diff --git a/app/page.tsx b/app/page.tsx index 620798b..3e7f5af 100644 --- a/app/page.tsx +++ b/app/page.tsx @@ -777,11 +777,16 @@ export default function Home() { const toSave = stripMessageHtml(finalMsgs); const { iv, ciphertext } = await encrypt(key, { messages: toSave, model: requestModel, systemPrompt: requestSystemPrompt, title }); const ciphertextBytes = Math.round((ciphertext.length ?? 0) * 0.75); - const body = JSON.stringify({ id: chatIdRef.current, iv, ciphertext }); + const currentHistoryId = chatIdRef.current; + const body = JSON.stringify( + currentHistoryId + ? { id: currentHistoryId, iv, ciphertext } + : { iv, ciphertext }, + ); const bodyBytes = new TextEncoder().encode(body).length; if (bodyBytes > LIMITS.historyBodyBytes || ciphertextBytes > LIMITS.maxCiphertextBytes) { logClientEvent('history.save_too_large', 'warn', { - id: chatIdRef.current, + id: currentHistoryId, msgs: toSave.length, bodyBytes, maxBodyBytes: LIMITS.historyBodyBytes, @@ -795,17 +800,17 @@ export default function Home() { headers: { 'Content-Type': 'application/json' }, body, }); - if (!res.ok) { - const error = (await res.text()).slice(0, LIMITS.maxClientEventValueChars); - logClientEvent('history.save_failed', 'warn', { - status: res.status, - requestId: res.headers.get('x-request-id'), - id: chatIdRef.current, - msgs: toSave.length, - bodyBytes, - ciphertextBytes, - error, - }); + if (!res.ok) { + const error = (await res.text()).slice(0, LIMITS.maxClientEventValueChars); + logClientEvent('history.save_failed', 'warn', { + status: res.status, + requestId: res.headers.get('x-request-id'), + id: currentHistoryId, + msgs: toSave.length, + bodyBytes, + ciphertextBytes, + error, + }); return; } const { id } = await res.json(); diff --git a/tests/unit.test.ts b/tests/unit.test.ts index 0ac4825..c6d6c42 100644 --- a/tests/unit.test.ts +++ b/tests/unit.test.ts @@ -476,6 +476,16 @@ test('history save logs meaningful failure details before and after the network pageSource.includes('if (!key) return;'), 'history saves should skip only after the readiness helper decides saving is not possible', ); + assert.ok( + pageSource.includes('const currentHistoryId = chatIdRef.current;'), + 'history saves should snapshot the current saved-chat id before building the request body', + ); + assert.ok( + pageSource.includes(`currentHistoryId + ? { id: currentHistoryId, iv, ciphertext } + : { iv, ciphertext }`), + 'history saves should omit id entirely for new chats so the API creates a new history row', + ); assert.ok( pageSource.includes('const bodyBytes = new TextEncoder().encode(body).length;'), 'history saves should measure request size before posting so oversized chats are diagnosable', @@ -502,6 +512,61 @@ test('history save logs meaningful failure details before and after the network ); }); +test('history save route emits one wide canonical history.save log per POST attempt', () => { + const source = readFileSync(join(import.meta.dirname, '../app/api/history/route.ts'), 'utf8'); + assert.ok( + source.includes('const ctx: Record = {'), + 'history save route should collect request/save metadata in one canonical logging context', + ); + assert.ok( + source.includes('const requestBytes = readContentLength(req);') && + source.includes('requestBytes,'), + 'history save route should log request size metadata', + ); + assert.ok( + source.includes('hasIdField: false,'), + 'history save route should log whether the request included an id field at all', + ); + assert.ok( + source.includes('ctx.idFieldType = getFieldType(body.id);'), + 'history save route should log the type of the incoming id field for debugging invalid payloads', + ); + assert.ok( + source.includes('ctx.requestedId = typeof body.id === \'string\' ? body.id : null;'), + 'history save route should capture the requested id before validation', + ); + assert.ok( + source.includes('ctx.savedId = result.rows[0].id;'), + 'history save route should log the final saved history id', + ); + assert.ok( + source.includes('ctx.resolvedOp = \'insert\';'), + 'history save route should log whether the request resolved as an insert', + ); + assert.ok( + source.includes('ctx.resolvedOp = \'update\';'), + 'history save route should log whether the request resolved as an update', + ); + assert.ok( + source.includes("if (status >= 500) logger.error(fields, 'history.save');"), + 'history save route should emit error-level canonical logs for 5xx outcomes', + ); + assert.ok( + source.includes("else if (status >= 400) logger.warn(fields, 'history.save');"), + 'history save route should emit warn-level canonical logs for 4xx outcomes', + ); + assert.ok( + source.includes("else logger.info(fields, 'history.save');"), + 'history save route should emit info-level canonical logs for successful saves', + ); + assert.ok( + !source.includes("'history.save.invalid'") && + !source.includes("'history.save.failed'") && + !source.includes("'history.save.too_large'"), + 'history save POST logging should use the canonical history.save event name instead of fragmented sub-events', + ); +}); + // ── settings validation ──────────────────────────────────────────────────────── test('validateSettingsRequest: validates and defaults girlMode', () => {