From 034c1f03a4f6b3092188e195d5fc3b0432795fbd Mon Sep 17 00:00:00 2001 From: Richard R Date: Wed, 27 May 2026 04:54:52 -0600 Subject: [PATCH] logging: complete phase 5 contract and enforce via eslint rules --- eslint.config.mjs | 33 ++++++ src/app/api/account/delete/route.ts | 15 ++- src/app/api/admin/providers/[id]/route.ts | 14 ++- src/app/api/admin/providers/route.ts | 7 +- src/app/api/audiobook/chapter/route.ts | 40 +++++-- src/app/api/audiobook/route.ts | 33 +++++- src/app/api/audiobook/status/route.ts | 7 +- .../api/documents/[id]/parsed/events/route.ts | 12 +- src/app/api/documents/[id]/parsed/route.ts | 10 +- src/app/api/documents/[id]/settings/route.ts | 12 +- .../api/documents/blob/get/fallback/route.ts | 14 ++- .../api/documents/blob/get/presign/route.ts | 14 ++- .../documents/blob/preview/ensure/route.ts | 7 +- .../documents/blob/preview/fallback/route.ts | 14 ++- .../documents/blob/preview/presign/route.ts | 14 ++- .../documents/blob/upload/fallback/route.ts | 14 ++- .../documents/blob/upload/presign/route.ts | 8 +- .../api/documents/docx-to-pdf/upload/route.ts | 15 ++- src/app/api/documents/library/route.ts | 7 +- src/app/api/documents/route.ts | 49 ++++++-- src/app/api/rate-limit/status/route.ts | 7 +- .../api/tts/segments/audio/fallback/route.ts | 2 +- src/app/api/tts/segments/clear/route.ts | 2 +- src/app/api/tts/segments/ensure/route.ts | 8 +- src/app/api/tts/segments/manifest/route.ts | 2 +- src/app/api/tts/shared-providers/route.ts | 9 +- src/app/api/tts/voices/route.ts | 7 +- src/app/api/user/claim/route.ts | 12 +- src/app/api/user/export/route.ts | 14 ++- .../state/changelog/version-check/route.ts | 7 +- src/app/api/user/state/preferences/route.ts | 12 +- src/app/api/user/state/progress/route.ts | 12 +- src/lib/server/admin/email-sync.ts | 9 +- src/lib/server/admin/seed.ts | 58 ++++++++-- src/lib/server/admin/settings.ts | 21 +++- src/lib/server/auth/auth.ts | 108 +++++++++++++++--- src/lib/server/compute/worker-op-state.ts | 22 ++-- src/lib/server/compute/worker.ts | 26 +++-- src/lib/server/documents/previews.ts | 9 +- src/lib/server/jobs/user-pdf-layout-job.ts | 28 +++-- src/lib/server/logger.ts | 39 +++++++ src/lib/server/rate-limit/rate-limiter.ts | 8 +- src/lib/server/tts/segments-cache.ts | 9 +- src/lib/server/tts/voice-resolution.ts | 18 ++- src/lib/server/user/data-cleanup.ts | 61 ++++++++-- 45 files changed, 666 insertions(+), 183 deletions(-) diff --git a/eslint.config.mjs b/eslint.config.mjs index a63df9f..faab7be 100644 --- a/eslint.config.mjs +++ b/eslint.config.mjs @@ -36,6 +36,39 @@ const eslintConfig = [ files: ["src/app/api/**/*.ts", "src/lib/server/**/*.ts"], rules: { "no-console": "error", + "no-restricted-syntax": [ + "error", + { + selector: + ":matches(CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.name=/^(logger|serverLogger)$/],CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.property.name='logger'])[arguments.length<2]", + message: + "Server logger calls must pass context + message: logger.({ event, ...ctx }, 'message').", + }, + { + selector: + ":matches(CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.name=/^(logger|serverLogger)$/],CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.property.name='logger'])[arguments.0.type='Literal']", + message: + "Server logger first argument must be an object with an event field, not a string literal.", + }, + { + selector: + ":matches(CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.name=/^(logger|serverLogger)$/],CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.property.name='logger'])[arguments.0.type='TemplateLiteral']", + message: + "Server logger first argument must be an object with an event field, not a template string.", + }, + { + selector: + ":matches(CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.name=/^(logger|serverLogger)$/],CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.property.name='logger'])[arguments.0.type='ObjectExpression']:not(:has(Property[key.name='event']))", + message: + "Server logger context object must include an event field.", + }, + { + selector: + ":matches(CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.name=/^(logger|serverLogger)$/],CallExpression[callee.property.name=/^(trace|debug|info|warn|error|fatal)$/][callee.object.property.name='logger']) > ObjectExpression:first-child > Property[key.name='err']", + message: + "Use `error` (typically from errorToLog(...)) instead of `err` in server logs.", + }, + ], }, }, ]; diff --git a/src/app/api/account/delete/route.ts b/src/app/api/account/delete/route.ts index 7b5af66..c54505b 100644 --- a/src/app/api/account/delete/route.ts +++ b/src/app/api/account/delete/route.ts @@ -4,7 +4,7 @@ import { auth } from '@/lib/server/auth/auth'; import { isAuthEnabled } from '@/lib/server/auth/config'; import { getOpenReaderTestNamespace } from '@/lib/server/testing/test-namespace'; import { deleteUserStorageData } from '@/lib/server/user/data-cleanup'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, hashForLog, serverLogger } from '@/lib/server/logger'; export async function DELETE() { if (!isAuthEnabled() || !auth) { @@ -29,7 +29,13 @@ export async function DELETE() { try { await deleteUserStorageData(session.user.id, testNamespace); } catch (error) { - serverLogger.warn({ err: error }, '[account-delete] Failed to clean up namespaced user storage before deletion:'); + serverLogger.warn({ + event: 'account.delete.storage_cleanup_failed', + degraded: true, + step: 'namespaced_storage_cleanup', + userIdHash: hashForLog(session.user.id), + error: errorToLog(error), + }, 'Failed to clean up namespaced user storage before deletion'); } } @@ -41,7 +47,10 @@ export async function DELETE() { return NextResponse.json({ success: true }); } catch (error) { - serverLogger.error({ err: error }, 'Failed to delete account:'); + serverLogger.error({ + event: 'account.delete.failed', + error: errorToLog(error), + }, 'Failed to delete account'); return NextResponse.json( { error: 'Failed to delete account' }, { status: 500 } diff --git a/src/app/api/admin/providers/[id]/route.ts b/src/app/api/admin/providers/[id]/route.ts index f826e48..a3be4fb 100644 --- a/src/app/api/admin/providers/[id]/route.ts +++ b/src/app/api/admin/providers/[id]/route.ts @@ -1,6 +1,6 @@ import { NextRequest, NextResponse } from 'next/server'; import { requireAdminContext } from '@/lib/server/auth/admin'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { AdminProviderError, deleteAdminProvider, @@ -42,7 +42,11 @@ export async function PUT( if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - serverLogger.error({ err: error }, '[admin/providers/:id] update failed:'); + serverLogger.error({ + event: 'admin.providers.update.failed', + providerId: id, + error: errorToLog(error), + }, 'Admin provider update failed'); return NextResponse.json({ error: 'Internal error' }, { status: 500 }); } } @@ -62,7 +66,11 @@ export async function DELETE( if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - serverLogger.error({ err: error }, '[admin/providers/:id] delete failed:'); + serverLogger.error({ + event: 'admin.providers.delete.failed', + providerId: id, + error: errorToLog(error), + }, 'Admin provider delete failed'); return NextResponse.json({ error: 'Internal error' }, { status: 500 }); } } diff --git a/src/app/api/admin/providers/route.ts b/src/app/api/admin/providers/route.ts index e2735f0..778a6f7 100644 --- a/src/app/api/admin/providers/route.ts +++ b/src/app/api/admin/providers/route.ts @@ -1,6 +1,6 @@ import { NextRequest, NextResponse } from 'next/server'; import { requireAdminContext } from '@/lib/server/auth/admin'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { AdminProviderError, createAdminProvider, @@ -47,7 +47,10 @@ export async function POST(req: NextRequest) { if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - serverLogger.error({ err: error }, '[admin/providers] create failed:'); + serverLogger.error({ + event: 'admin.providers.create.failed', + error: errorToLog(error), + }, 'Admin provider create failed'); return NextResponse.json({ error: 'Internal error' }, { status: 500 }); } } diff --git a/src/app/api/audiobook/chapter/route.ts b/src/app/api/audiobook/chapter/route.ts index a979971..a1e91b7 100644 --- a/src/app/api/audiobook/chapter/route.ts +++ b/src/app/api/audiobook/chapter/route.ts @@ -11,7 +11,7 @@ import { requireAuthContext } from '@/lib/server/auth/auth'; import { rateLimiter, RATE_LIMITS, isTtsRateLimitEnabled } from '@/lib/server/rate-limit/rate-limiter'; import { getClientIp } from '@/lib/server/rate-limit/request-ip'; import { getOrCreateDeviceId, setDeviceIdCookie } from '@/lib/server/rate-limit/device-id'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { deleteAudiobookObject, getAudiobookObjectBuffer, @@ -186,7 +186,12 @@ async function runFFmpeg(args: string[], signal?: AbortSignal): Promise { } ffmpeg.stderr.on('data', (data) => { - serverLogger.warn(`ffmpeg stderr: ${data}`); + serverLogger.warn({ + event: 'audiobook.chapter.ffmpeg.stderr', + degraded: true, + step: 'ffmpeg', + stderr: String(data), + }, 'ffmpeg stderr'); }); ffmpeg.on('close', (code) => { @@ -326,7 +331,11 @@ export async function POST(request: NextRequest) { fallbackProviderRef: runtimeConfig.defaultTtsProvider, }); if (!existingResult.settings) { - serverLogger.error({ bookId, storageUserId }, 'Invalid audiobook.meta.json settings payload'); + serverLogger.error({ + event: 'audiobook.chapter.meta_settings.invalid', + bookId, + storageUserId, + }, 'Invalid audiobook.meta.json settings payload'); return NextResponse.json({ error: 'Invalid audiobook metadata settings' }, { status: 500 }); } normalizedExistingSettings = normalizeNativeSpeedForSettings(existingResult.settings); @@ -401,6 +410,9 @@ export async function POST(request: NextRequest) { ); } catch (error) { serverLogger.warn({ + event: 'audiobook.chapter.meta_settings.persist_migration_failed', + degraded: true, + step: 'persist_migrated_settings', bookId, storageUserId, error: error instanceof Error ? error.message : String(error), @@ -609,7 +621,12 @@ export async function POST(request: NextRequest) { request.signal, ); } catch (copyError) { - serverLogger.warn({ err: copyError }, 'Chapter remux failed; falling back to mp3 re-encode:'); + serverLogger.warn({ + event: 'audiobook.chapter.remux.failed', + degraded: true, + fallbackPath: 'mp3_reencode', + error: errorToLog(copyError), + }, 'Chapter remux failed; falling back to mp3 re-encode'); await runFFmpeg( chapterEncodeArgs(inputPath, chapterOutputTempPath, format, postSpeed, titleTag), request.signal, @@ -729,7 +746,10 @@ export async function POST(request: NextRequest) { return response; } - serverLogger.error({ err: error }, 'Error processing audio chapter:'); + serverLogger.error({ + event: 'audiobook.chapter.process.failed', + error: errorToLog(error), + }, 'Failed to process audio chapter'); const response = NextResponse.json({ error: 'Failed to process audio chapter' }, { status: 500 }); attachDeviceIdCookie(response, deviceIdToSet, didCreateDeviceIdCookie); return response; @@ -824,7 +844,10 @@ export async function GET(request: NextRequest) { }, }); } catch (error) { - serverLogger.error({ err: error }, 'Error downloading chapter:'); + serverLogger.error({ + event: 'audiobook.chapter.download.failed', + error: errorToLog(error), + }, 'Failed to download chapter'); return NextResponse.json({ error: 'Failed to download chapter' }, { status: 500 }); } } @@ -892,7 +915,10 @@ export async function DELETE(request: NextRequest) { return NextResponse.json({ success: true }); } catch (error) { - serverLogger.error({ err: error }, 'Error deleting chapter:'); + serverLogger.error({ + event: 'audiobook.chapter.delete.failed', + error: errorToLog(error), + }, 'Failed to delete chapter'); return NextResponse.json({ error: 'Failed to delete chapter' }, { status: 500 }); } } diff --git a/src/app/api/audiobook/route.ts b/src/app/api/audiobook/route.ts index 6694bba..d8e5aea 100644 --- a/src/app/api/audiobook/route.ts +++ b/src/app/api/audiobook/route.ts @@ -7,7 +7,7 @@ import { and, eq, inArray } from 'drizzle-orm'; import { db } from '@/db'; import { audiobooks, audiobookChapters } from '@/db/schema'; import { requireAuthContext } from '@/lib/server/auth/auth'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { audiobookPrefix, deleteAudiobookObject, @@ -116,7 +116,12 @@ async function runFFmpeg(args: string[], signal?: AbortSignal): Promise { } ffmpeg.stderr.on('data', (data) => { - serverLogger.warn(`ffmpeg stderr: ${data}`); + serverLogger.warn({ + event: 'audiobook.ffmpeg.stderr', + degraded: true, + step: 'ffmpeg', + stderr: String(data), + }, 'ffmpeg stderr'); }); ffmpeg.on('close', (code) => { @@ -283,7 +288,12 @@ export async function GET(request: NextRequest) { request.signal, ); } catch (copyError) { - serverLogger.warn({ err: copyError }, 'MP3 concat copy failed; falling back to re-encode:'); + serverLogger.warn({ + event: 'audiobook.concat_copy.mp3.failed', + degraded: true, + fallbackPath: 'reencode', + error: errorToLog(copyError), + }, 'MP3 concat copy failed; falling back to re-encode'); await runFFmpeg( ['-f', 'concat', '-safe', '0', '-i', listPath, '-c:a', 'libmp3lame', '-b:a', '64k', outputPath], request.signal, @@ -312,7 +322,12 @@ export async function GET(request: NextRequest) { request.signal, ); } catch (copyError) { - serverLogger.warn({ err: copyError }, 'M4B concat copy failed; falling back to re-encode:'); + serverLogger.warn({ + event: 'audiobook.concat_copy.m4b.failed', + degraded: true, + fallbackPath: 'reencode', + error: errorToLog(copyError), + }, 'M4B concat copy failed; falling back to re-encode'); await runFFmpeg( [ '-f', @@ -361,7 +376,10 @@ export async function GET(request: NextRequest) { if ((error as Error)?.message === 'ABORTED' || request.signal.aborted) { return NextResponse.json({ error: 'cancelled' }, { status: 499 }); } - serverLogger.error({ err: error }, 'Error creating full audiobook:'); + serverLogger.error({ + event: 'audiobook.create.failed', + error: errorToLog(error), + }, 'Failed to create full audiobook'); return NextResponse.json({ error: 'Failed to create full audiobook file' }, { status: 500 }); } finally { if (workDir) await rm(workDir, { recursive: true, force: true }).catch(() => {}); @@ -409,7 +427,10 @@ export async function DELETE(request: NextRequest) { const deleted = await deleteAudiobookPrefix(audiobookPrefix(bookId, storageUserId, testNamespace)).catch(() => 0); return NextResponse.json({ success: true, existed: deleted > 0 }); } catch (error) { - serverLogger.error({ err: error }, 'Error resetting audiobook:'); + serverLogger.error({ + event: 'audiobook.reset.failed', + error: errorToLog(error), + }, 'Failed to reset audiobook'); return NextResponse.json({ error: 'Failed to reset audiobook' }, { status: 500 }); } } diff --git a/src/app/api/audiobook/status/route.ts b/src/app/api/audiobook/status/route.ts index fc6b93c..49e30dc 100644 --- a/src/app/api/audiobook/status/route.ts +++ b/src/app/api/audiobook/status/route.ts @@ -11,7 +11,7 @@ import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/li import { buildAllowedAudiobookUserIds, pickAudiobookOwner } from '@/lib/server/audiobooks/user-scope'; import type { AudiobookGenerationSettings } from '@/types/client'; import type { TTSAudiobookChapter, TTSAudiobookFormat } from '@/types/tts'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -156,7 +156,10 @@ export async function GET(request: NextRequest) { settings, }); } catch (error) { - serverLogger.error({ err: error }, 'Error fetching chapters:'); + serverLogger.error({ + event: 'audiobook.status.fetch.failed', + error: errorToLog(error), + }, 'Failed to fetch audiobook chapters'); return NextResponse.json({ error: 'Failed to fetch chapters' }, { status: 500 }); } } diff --git a/src/app/api/documents/[id]/parsed/events/route.ts b/src/app/api/documents/[id]/parsed/events/route.ts index da0a337..b6f3a62 100644 --- a/src/app/api/documents/[id]/parsed/events/route.ts +++ b/src/app/api/documents/[id]/parsed/events/route.ts @@ -273,7 +273,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string storageUserIdHash, requestId, error: error instanceof Error ? error.message : String(error), - }); + }, 'SSE DB resync failed'); controller.enqueue(encoder.encode(`event: error\ndata: ${JSON.stringify({ error: String(error) })}\n\n`)); }); }, SSE_RESYNC_INTERVAL_MS); @@ -306,7 +306,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string storageUserIdHash, parseStatus: current.parseStatus, requestedOpId, - }); + }, 'Parse stream running without opId and non-terminal status'); } } else if (loggedMissingOpId) { loggedMissingOpId = false; @@ -346,7 +346,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string opId: currentOpId, status: response.status, detail, - }); + }, 'Worker stream request failed'); await sleep(500); continue; } @@ -355,7 +355,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string event: 'documents.parsed.events.worker_stream_missing_body', documentId: id, opId: currentOpId, - }); + }, 'Worker stream response missing body'); await sleep(500); continue; } @@ -456,7 +456,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string event: 'documents.parsed.events.worker_proxy_crashed', documentId: id, error: errorToLog(error), - }); + }, 'Worker proxy crashed while streaming parse events'); if (!closed) { controller.enqueue(encoder.encode(`event: error\ndata: ${JSON.stringify({ error: String(error) })}\n\n`)); } @@ -486,7 +486,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string logger.error({ event: 'documents.parsed.events.route_failed', error: errorToLog(error), - }); + }, 'Parsed events route failed'); return NextResponse.json({ error: 'Failed to stream parsed PDF progress' }, { status: 500 }); } } diff --git a/src/app/api/documents/[id]/parsed/route.ts b/src/app/api/documents/[id]/parsed/route.ts index e3d3dce..fa6fc74 100644 --- a/src/app/api/documents/[id]/parsed/route.ts +++ b/src/app/api/documents/[id]/parsed/route.ts @@ -166,7 +166,7 @@ async function finalizeFromWorkerState(input: { documentId: input.row.id, userIdHash: hashForLog(input.row.userId), parsedJsonKey, - }); + }, 'Worker output parsed successfully but contained no blocks'); } return new NextResponse(new Uint8Array(json), { @@ -223,7 +223,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string documentId: id, userIdHash: hashForLog(row.userId), opId: requestedOpId, - }); + }, 'Requested worker operation id was unavailable'); } let state = parseDocumentParseState(row.parseState); @@ -288,7 +288,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string documentId: id, userIdHash: hashForLog(row.userId), parsedJsonKey: row.parsedJsonKey, - }); + }, 'Parsed document blob contained no blocks'); } return new NextResponse(new Uint8Array(json), { @@ -308,7 +308,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string logger.error({ event: 'documents.parsed.get_failed', error: errorToLog(error), - }); + }, 'Failed to read parsed PDF'); return NextResponse.json({ error: 'Failed to read parsed PDF' }, { status: 500 }); } } @@ -388,7 +388,7 @@ export async function POST(req: NextRequest, ctx: { params: Promise<{ id: string logger.error({ event: 'documents.parsed.force_refresh_failed', error: errorToLog(error), - }); + }, 'Failed to force PDF refresh'); return NextResponse.json({ error: 'Failed to force PDF refresh' }, { status: 500 }); } } diff --git a/src/app/api/documents/[id]/settings/route.ts b/src/app/api/documents/[id]/settings/route.ts index e01c82c..594da97 100644 --- a/src/app/api/documents/[id]/settings/route.ts +++ b/src/app/api/documents/[id]/settings/route.ts @@ -7,7 +7,7 @@ import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/li import { mergeDocumentSettings } from '@/lib/shared/document-settings'; import { DEFAULT_DOCUMENT_SETTINGS, type DocumentSettings } from '@/types/document-settings'; import { coerceTimestampMs, nowTimestampMs } from '@/lib/shared/timestamps'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -93,7 +93,10 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string hasStoredSettings: Boolean(row), }); } catch (error) { - serverLogger.error({ err: error }, 'Error loading document settings:'); + serverLogger.error({ + event: 'documents.settings.load.failed', + error: errorToLog(error), + }, 'Failed to load document settings'); return NextResponse.json({ error: 'Failed to load document settings' }, { status: 500 }); } } @@ -162,7 +165,10 @@ export async function PUT(req: NextRequest, ctx: { params: Promise<{ id: string applied: true, }); } catch (error) { - serverLogger.error({ err: error }, 'Error updating document settings:'); + serverLogger.error({ + event: 'documents.settings.update.failed', + error: errorToLog(error), + }, 'Failed to update document settings'); return NextResponse.json({ error: 'Failed to update document settings' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/get/fallback/route.ts b/src/app/api/documents/blob/get/fallback/route.ts index b8c183d..75e6f18 100644 --- a/src/app/api/documents/blob/get/fallback/route.ts +++ b/src/app/api/documents/blob/get/fallback/route.ts @@ -7,7 +7,7 @@ import { contentTypeForName } from '@/lib/server/storage/library-mount'; import { getDocumentBlob, isMissingBlobError, isValidDocumentId } from '@/lib/server/documents/blobstore'; import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -45,7 +45,12 @@ export async function GET(req: NextRequest) { return NextResponse.json({ error: 'Invalid id' }, { status: 400 }); } - serverLogger.info({ id }, '[blob-fallback] download proxy used'); + serverLogger.info({ + event: 'documents.blob.get.fallback.proxy_used', + degraded: true, + fallbackPath: 'download_proxy', + documentId: id, + }, 'Document download fallback proxy used'); const rows = (await db .select({ id: documents.id, userId: documents.userId, name: documents.name }) @@ -82,7 +87,10 @@ export async function GET(req: NextRequest) { throw error; } } catch (error) { - serverLogger.error({ err: error }, 'Error loading document content fallback:'); + serverLogger.error({ + event: 'documents.blob.get.fallback.failed', + error: errorToLog(error), + }, 'Failed to load document content fallback'); return NextResponse.json({ error: 'Failed to load document content' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/get/presign/route.ts b/src/app/api/documents/blob/get/presign/route.ts index ae2dc9b..b6c30e8 100644 --- a/src/app/api/documents/blob/get/presign/route.ts +++ b/src/app/api/documents/blob/get/presign/route.ts @@ -6,7 +6,7 @@ import { requireAuthContext } from '@/lib/server/auth/auth'; import { isValidDocumentId, presignGet } from '@/lib/server/documents/blobstore'; import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -51,7 +51,12 @@ export async function GET(req: NextRequest) { const fallbackUrl = `/api/documents/blob/get/fallback?id=${encodeURIComponent(doc.id)}`; const directUrl = await presignGet(doc.id, testNamespace).catch(() => null); if (!directUrl) { - serverLogger.warn({ id: doc.id }, '[blob-fallback] presign download unavailable, redirecting to proxy fallback'); + serverLogger.warn({ + event: 'documents.blob.get.presign.unavailable', + degraded: true, + fallbackPath: 'download_proxy', + documentId: doc.id, + }, 'Presigned document download unavailable, redirecting to proxy fallback'); return NextResponse.redirect(fallbackUrl, { status: 307, headers: { 'Cache-Control': 'no-store' }, @@ -63,7 +68,10 @@ export async function GET(req: NextRequest) { headers: { 'Cache-Control': 'no-store' }, }); } catch (error) { - serverLogger.error({ err: error }, 'Error creating document download signature:'); + serverLogger.error({ + event: 'documents.blob.get.presign.failed', + error: errorToLog(error), + }, 'Failed to create document download signature'); return NextResponse.json({ error: 'Failed to prepare document download' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/preview/ensure/route.ts b/src/app/api/documents/blob/preview/ensure/route.ts index 1c5a4cb..802a868 100644 --- a/src/app/api/documents/blob/preview/ensure/route.ts +++ b/src/app/api/documents/blob/preview/ensure/route.ts @@ -2,7 +2,7 @@ import { NextRequest, NextResponse } from 'next/server'; import { presignDocumentPreviewGet } from '@/lib/server/documents/previews-blobstore'; import { ensureDocumentPreview } from '@/lib/server/documents/previews'; import { validatePreviewRequest } from '../utils'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -51,7 +51,10 @@ export async function GET(req: NextRequest) { }, ); } catch (error) { - serverLogger.error({ err: error }, 'Error ensuring document preview:'); + serverLogger.error({ + event: 'documents.preview.ensure.failed', + error: errorToLog(error), + }, 'Failed to ensure document preview'); return NextResponse.json({ error: 'Failed to ensure document preview' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/preview/fallback/route.ts b/src/app/api/documents/blob/preview/fallback/route.ts index 8496e8a..09f0851 100644 --- a/src/app/api/documents/blob/preview/fallback/route.ts +++ b/src/app/api/documents/blob/preview/fallback/route.ts @@ -3,7 +3,7 @@ import { and, eq, inArray } from 'drizzle-orm'; import { db } from '@/db'; import { documents } from '@/db/schema'; import { requireAuthContext } from '@/lib/server/auth/auth'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { getDocumentRange, isMissingBlobError as isMissingDocumentBlobError, @@ -67,9 +67,12 @@ export async function GET(req: NextRequest) { } serverLogger.info({ - id, + event: 'documents.preview.fallback.proxy_used', + degraded: true, + fallbackPath: 'preview_proxy', + documentId: id, snippetRequested, - }, '[blob-fallback] preview proxy used'); + }, 'Document preview fallback proxy used'); const rows = (await db .select({ @@ -176,7 +179,10 @@ export async function GET(req: NextRequest) { throw error; } } catch (error) { - serverLogger.error({ err: error }, 'Error loading document preview fallback:'); + serverLogger.error({ + event: 'documents.preview.fallback.failed', + error: errorToLog(error), + }, 'Failed to load document preview fallback'); return NextResponse.json({ error: 'Failed to load document preview' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/preview/presign/route.ts b/src/app/api/documents/blob/preview/presign/route.ts index 8061eab..8c98c49 100644 --- a/src/app/api/documents/blob/preview/presign/route.ts +++ b/src/app/api/documents/blob/preview/presign/route.ts @@ -2,7 +2,7 @@ import { NextRequest, NextResponse } from 'next/server'; import { presignDocumentPreviewGet } from '@/lib/server/documents/previews-blobstore'; import { ensureDocumentPreview } from '@/lib/server/documents/previews'; import { validatePreviewRequest } from '../utils'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -38,7 +38,12 @@ export async function GET(req: NextRequest) { const directUrl = await presignDocumentPreviewGet(doc.id, testNamespace).catch(() => null); if (!directUrl) { - serverLogger.warn({ id: doc.id }, '[blob-fallback] presign preview unavailable, redirecting to proxy fallback'); + serverLogger.warn({ + event: 'documents.preview.presign.unavailable', + degraded: true, + fallbackPath: 'preview_proxy', + documentId: doc.id, + }, 'Presigned document preview unavailable, redirecting to proxy fallback'); return NextResponse.redirect(fallbackUrl, { status: 307, headers: { 'Cache-Control': 'no-store' }, @@ -50,7 +55,10 @@ export async function GET(req: NextRequest) { headers: { 'Cache-Control': 'no-store' }, }); } catch (error) { - serverLogger.error({ err: error }, 'Error creating document preview signature:'); + serverLogger.error({ + event: 'documents.preview.presign.failed', + error: errorToLog(error), + }, 'Failed to create document preview signature'); return NextResponse.json({ error: 'Failed to prepare document preview' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/upload/fallback/route.ts b/src/app/api/documents/blob/upload/fallback/route.ts index f0764e3..c3d7a9f 100644 --- a/src/app/api/documents/blob/upload/fallback/route.ts +++ b/src/app/api/documents/blob/upload/fallback/route.ts @@ -3,7 +3,7 @@ import { requireAuthContext } from '@/lib/server/auth/auth'; import { isValidDocumentId, putDocumentBlob } from '@/lib/server/documents/blobstore'; import { isS3Configured } from '@/lib/server/storage/s3'; import { getOpenReaderTestNamespace } from '@/lib/server/testing/test-namespace'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -44,14 +44,20 @@ export async function PUT(req: NextRequest) { } serverLogger.info({ - id, + event: 'documents.blob.upload.fallback.proxy_used', + degraded: true, + fallbackPath: 'upload_proxy', + documentId: id, contentType, bytes: body.byteLength, - }, '[blob-fallback] upload proxy used'); + }, 'Document upload fallback proxy used'); return NextResponse.json({ success: true, id }); } catch (error) { - serverLogger.error({ err: error }, 'Error proxy-uploading document blob:'); + serverLogger.error({ + event: 'documents.blob.upload.fallback.failed', + error: errorToLog(error), + }, 'Failed to proxy-upload document blob'); return NextResponse.json({ error: 'Failed to upload document blob' }, { status: 500 }); } } diff --git a/src/app/api/documents/blob/upload/presign/route.ts b/src/app/api/documents/blob/upload/presign/route.ts index d6268d1..a05e6eb 100644 --- a/src/app/api/documents/blob/upload/presign/route.ts +++ b/src/app/api/documents/blob/upload/presign/route.ts @@ -3,7 +3,7 @@ import { requireAuthContext } from '@/lib/server/auth/auth'; import { isValidDocumentId, presignPut } from '@/lib/server/documents/blobstore'; import { getOpenReaderTestNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -66,8 +66,10 @@ export async function POST(req: NextRequest) { return NextResponse.json({ uploads: signed }); } catch (error) { - serverLogger.error({ err: error }, 'Error creating document upload signatures:'); + serverLogger.error({ + event: 'documents.blob.upload.presign.failed', + error: errorToLog(error), + }, 'Failed to create document upload signatures'); return NextResponse.json({ error: 'Failed to presign uploads' }, { status: 500 }); } } - diff --git a/src/app/api/documents/docx-to-pdf/upload/route.ts b/src/app/api/documents/docx-to-pdf/upload/route.ts index 5ed9eb2..e427c78 100644 --- a/src/app/api/documents/docx-to-pdf/upload/route.ts +++ b/src/app/api/documents/docx-to-pdf/upload/route.ts @@ -15,7 +15,7 @@ import { stringifyDocumentParseState } from '@/lib/server/documents/parse-state' import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; import { putDocumentBlob } from '@/lib/server/documents/blobstore'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; const DOCSTORE_DIR = path.join(process.cwd(), 'docstore'); const TEMP_DIR = path.join(DOCSTORE_DIR, 'tmp'); @@ -163,7 +163,13 @@ export async function POST(req: NextRequest) { }, testNamespace, ).catch((error) => { - serverLogger.warn({ err: error }, `Failed to enqueue preview for converted DOCX ${id}:`); + serverLogger.warn({ + event: 'documents.docx.preview_enqueue.failed', + degraded: true, + fallbackPath: 'skip_preview_enqueue', + documentId: id, + error: errorToLog(error), + }, 'Failed to enqueue preview for converted DOCX'); }); enqueueParsePdfJob({ @@ -185,7 +191,10 @@ export async function POST(req: NextRequest) { await rm(jobDir, { recursive: true, force: true }).catch(() => {}); } } catch (error) { - serverLogger.error({ err: error }, 'Error converting/uploading DOCX:'); + serverLogger.error({ + event: 'documents.docx.convert_upload.failed', + error: errorToLog(error), + }, 'Failed converting/uploading DOCX'); return NextResponse.json({ error: 'Failed to convert document' }, { status: 500 }); } } diff --git a/src/app/api/documents/library/route.ts b/src/app/api/documents/library/route.ts index a2f99dd..f66686c 100644 --- a/src/app/api/documents/library/route.ts +++ b/src/app/api/documents/library/route.ts @@ -5,7 +5,7 @@ import { NextRequest, NextResponse } from 'next/server'; import { parseLibraryRoots } from '@/lib/server/storage/library-mount'; import type { DocumentType } from '@/types/documents'; import { auth } from '@/lib/server/auth/auth'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -112,7 +112,10 @@ export async function GET(req: NextRequest) { return NextResponse.json({ error: 'Unauthorized' }, { status: 401 }); } } catch (error) { - serverLogger.error({ err: error }, 'Error checking auth:'); + serverLogger.error({ + event: 'documents.library.auth_check.failed', + error: errorToLog(error), + }, 'Failed to check auth for library route'); return NextResponse.json({ error: 'Error checking auth' }, { status: 500 }); } diff --git a/src/app/api/documents/route.ts b/src/app/api/documents/route.ts index ed613ca..141812b 100644 --- a/src/app/api/documents/route.ts +++ b/src/app/api/documents/route.ts @@ -4,7 +4,7 @@ import { db } from '@/db'; import { documents } from '@/db/schema'; import { requireAuthContext } from '@/lib/server/auth/auth'; import { safeDocumentName, toDocumentTypeFromName } from '@/lib/server/documents/utils'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { cleanupDocumentPreviewArtifacts, deleteDocumentPreviewRows, @@ -173,7 +173,13 @@ export async function POST(req: NextRequest) { }, testNamespace, ).catch((error) => { - serverLogger.warn({ err: error }, `Failed to enqueue preview for document ${doc.id}:`); + serverLogger.warn({ + event: 'documents.preview.enqueue.failed', + degraded: true, + fallbackPath: 'skip_preview_enqueue', + documentId: doc.id, + error: errorToLog(error), + }, 'Failed to enqueue document preview'); }); if (doc.type === 'pdf') { @@ -187,7 +193,10 @@ export async function POST(req: NextRequest) { return NextResponse.json({ success: true, stored }); } catch (error) { - serverLogger.error({ err: error }, 'Error registering documents:'); + serverLogger.error({ + event: 'documents.register.failed', + error: errorToLog(error), + }, 'Failed to register documents'); return NextResponse.json({ error: 'Failed to register documents' }, { status: 500 }); } } @@ -263,7 +272,10 @@ export async function GET(req: NextRequest) { return NextResponse.json({ documents: results }); } catch (error) { - serverLogger.error({ err: error }, 'Error loading document metadata:'); + serverLogger.error({ + event: 'documents.list.failed', + error: errorToLog(error), + }, 'Failed to load document metadata'); return NextResponse.json({ error: 'Failed to load documents' }, { status: 500 }); } } @@ -343,21 +355,42 @@ export async function DELETE(req: NextRequest) { await deleteDocumentBlob(id, testNamespace); } catch (error) { if (!isMissingBlobError(error)) { - serverLogger.warn({ err: error }, `[best-effort] Failed to delete blob for document ${id}, orphaned blob may need manual cleanup:`); + serverLogger.warn({ + event: 'documents.delete.blob_cleanup_failed', + degraded: true, + step: 'delete_document_blob', + documentId: id, + error: errorToLog(error), + }, 'Failed to delete document blob during cleanup'); } } await cleanupDocumentPreviewArtifacts(id, testNamespace).catch((error) => { - serverLogger.warn({ err: error }, `Failed to cleanup preview artifacts for document ${id}:`); + serverLogger.warn({ + event: 'documents.delete.preview_artifacts_cleanup_failed', + degraded: true, + step: 'delete_preview_artifacts', + documentId: id, + error: errorToLog(error), + }, 'Failed to cleanup preview artifacts'); }); await deleteDocumentPreviewRows(id, testNamespace).catch((error) => { - serverLogger.warn({ err: error }, `Failed to cleanup preview rows for document ${id}:`); + serverLogger.warn({ + event: 'documents.delete.preview_rows_cleanup_failed', + degraded: true, + step: 'delete_preview_rows', + documentId: id, + error: errorToLog(error), + }, 'Failed to cleanup preview rows'); }); } return NextResponse.json({ success: true, deleted: deletedRows.length }); } catch (error) { - serverLogger.error({ err: error }, 'Error deleting documents:'); + serverLogger.error({ + event: 'documents.delete.failed', + error: errorToLog(error), + }, 'Failed to delete documents'); return NextResponse.json({ error: 'Failed to delete documents' }, { status: 500 }); } } diff --git a/src/app/api/rate-limit/status/route.ts b/src/app/api/rate-limit/status/route.ts index 58d7a6c..e8d3bbc 100644 --- a/src/app/api/rate-limit/status/route.ts +++ b/src/app/api/rate-limit/status/route.ts @@ -6,7 +6,7 @@ import { isAuthEnabled } from '@/lib/server/auth/config'; import { getClientIp } from '@/lib/server/rate-limit/request-ip'; import { getOrCreateDeviceId, setDeviceIdCookie } from '@/lib/server/rate-limit/device-id'; import { nextUtcMidnightTimestampMs } from '@/lib/shared/timestamps'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -85,7 +85,10 @@ export async function GET(req: NextRequest) { return response; } catch (error) { - serverLogger.error({ err: error }, 'Error getting rate limit status:'); + serverLogger.error({ + event: 'rate_limit.status.get.failed', + error: errorToLog(error), + }, 'Failed to get rate limit status'); return NextResponse.json( { error: 'Failed to get rate limit status' }, { status: 500 } diff --git a/src/app/api/tts/segments/audio/fallback/route.ts b/src/app/api/tts/segments/audio/fallback/route.ts index a32c822..159713d 100644 --- a/src/app/api/tts/segments/audio/fallback/route.ts +++ b/src/app/api/tts/segments/audio/fallback/route.ts @@ -53,7 +53,7 @@ export async function GET(request: NextRequest) { logger.error({ event: 'tts.segments.audio_fallback_failed', error: errorToLog(error), - }); + }, 'Failed to load segment audio from fallback route'); return NextResponse.json({ error: 'Failed to load segment audio' }, { status: 500 }); } } diff --git a/src/app/api/tts/segments/clear/route.ts b/src/app/api/tts/segments/clear/route.ts index 2e45536..c794bbf 100644 --- a/src/app/api/tts/segments/clear/route.ts +++ b/src/app/api/tts/segments/clear/route.ts @@ -42,7 +42,7 @@ export async function POST(request: NextRequest) { logger.error({ event: 'tts.segments.clear_failed', error: errorToLog(error), - }); + }, 'Failed to clear TTS segment cache'); return NextResponse.json({ error: 'Failed to clear TTS segment cache' }, { status: 500 }); } } diff --git a/src/app/api/tts/segments/ensure/route.ts b/src/app/api/tts/segments/ensure/route.ts index 32f961a..c7b4a75 100644 --- a/src/app/api/tts/segments/ensure/route.ts +++ b/src/app/api/tts/segments/ensure/route.ts @@ -335,7 +335,7 @@ export async function POST(request: NextRequest) { documentId: parsed.documentId, completedSoFar: manifest.length, totalRequested: normalized.length, - }); + }, 'TTS segment ensure request aborted'); break; } @@ -778,7 +778,7 @@ export async function POST(request: NextRequest) { segmentId: segment.segmentId, completedSoFar: manifest.length, totalRequested: normalized.length, - }); + }, 'Stopping segment ensure after abort'); break; } } @@ -804,7 +804,7 @@ export async function POST(request: NextRequest) { upstreamStatus: item.error?.upstreamStatus ?? null, retryAfterSeconds: item.error?.retryAfterSeconds ?? null, })), - }); + }, 'TTS segment ensure completed with partial errors'); } const response = NextResponse.json({ @@ -817,7 +817,7 @@ export async function POST(request: NextRequest) { logger.error({ event: 'tts.segments.ensure.route_failed', error: errorToLog(error), - }); + }, 'TTS segments ensure route failed'); const response = NextResponse.json({ error: 'Failed to ensure TTS segments' }, { status: 500 }); attachDeviceIdCookie(response, deviceIdToSet, didCreateDeviceIdCookie); return response; diff --git a/src/app/api/tts/segments/manifest/route.ts b/src/app/api/tts/segments/manifest/route.ts index cd5415c..b8cad65 100644 --- a/src/app/api/tts/segments/manifest/route.ts +++ b/src/app/api/tts/segments/manifest/route.ts @@ -389,7 +389,7 @@ export async function GET(request: NextRequest) { logger.error({ event: 'tts.segments.manifest.list_failed', error: errorToLog(error), - }); + }, 'Failed to list TTS segments'); return NextResponse.json({ error: 'Failed to list TTS segments' }, { status: 500 }); } } diff --git a/src/app/api/tts/shared-providers/route.ts b/src/app/api/tts/shared-providers/route.ts index 6be24bd..e778cff 100644 --- a/src/app/api/tts/shared-providers/route.ts +++ b/src/app/api/tts/shared-providers/route.ts @@ -2,7 +2,7 @@ import { NextRequest, NextResponse } from 'next/server'; import { auth } from '@/lib/server/auth/auth'; import { isAuthEnabled } from '@/lib/server/auth/config'; import { listAdminProviders, toPublic } from '@/lib/server/admin/providers'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -24,7 +24,12 @@ export async function GET(req: NextRequest) { const visible = all.filter((p) => p.enabled).map(toPublic); return NextResponse.json({ providers: visible }); } catch (error) { - serverLogger.warn({ err: error }, '[tts/shared-providers] list failed:'); + serverLogger.warn({ + event: 'tts.shared_providers.list.failed', + degraded: true, + fallbackPath: 'empty_provider_list', + error: errorToLog(error), + }, 'Failed to list shared providers'); return NextResponse.json({ providers: [] }); } } diff --git a/src/app/api/tts/voices/route.ts b/src/app/api/tts/voices/route.ts index 28e9233..f024431 100644 --- a/src/app/api/tts/voices/route.ts +++ b/src/app/api/tts/voices/route.ts @@ -5,7 +5,7 @@ import { defaultModelForProviderType, resolveTtsModelForProvider, resolveTtsProv import { resolveVoices } from '@/lib/server/tts/voice-resolution'; import { resolveTtsCredentials } from '@/lib/server/admin/resolve-credentials'; import { getResolvedRuntimeConfig } from '@/lib/server/runtime-config'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export async function GET(req: NextRequest) { try { @@ -62,7 +62,10 @@ export async function GET(req: NextRequest) { }); return NextResponse.json({ voices }); } catch (error) { - serverLogger.error({ err: error }, 'Error in voices endpoint:'); + serverLogger.error({ + event: 'tts.voices.resolve.failed', + error: errorToLog(error), + }, 'Failed to resolve voices'); const providerRef = req.headers.get('x-tts-provider') || 'openai'; const model = req.headers.get('x-tts-model') || 'tts-1'; const provider = isBuiltInTtsProviderId(providerRef) ? providerRef : 'openai'; diff --git a/src/app/api/user/claim/route.ts b/src/app/api/user/claim/route.ts index 496148a..d299d1b 100644 --- a/src/app/api/user/claim/route.ts +++ b/src/app/api/user/claim/route.ts @@ -5,7 +5,7 @@ import { db } from '@/db'; import { audiobooks, documents, userDocumentProgress, userPreferences } from '@/db/schema'; import { count, eq, ne } from 'drizzle-orm'; import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; async function checkClaimMigrationReadiness(): Promise { const [legacyRows] = await db @@ -57,7 +57,10 @@ export async function GET(req: NextRequest) { const counts = await getClaimableCounts(unclaimedUserId); return NextResponse.json({ success: true, ...counts }); } catch (error) { - serverLogger.error({ err: error }, 'Error checking claimable data:'); + serverLogger.error({ + event: 'user.claim.status.failed', + error: errorToLog(error), + }, 'Failed checking claimable data'); return NextResponse.json({ error: 'Internal Server Error' }, { status: 500 }); } } @@ -84,7 +87,10 @@ export async function POST(req: NextRequest) { }); } catch (error) { - serverLogger.error({ err: error }, 'Error claiming data:'); + serverLogger.error({ + event: 'user.claim.execute.failed', + error: errorToLog(error), + }, 'Failed claiming anonymous data'); return NextResponse.json({ error: 'Internal Server Error' }, { status: 500 }); } } diff --git a/src/app/api/user/export/route.ts b/src/app/api/user/export/route.ts index a74ea48..98e7552 100644 --- a/src/app/api/user/export/route.ts +++ b/src/app/api/user/export/route.ts @@ -11,7 +11,7 @@ import { getAudiobookObjectStream, listAudiobookObjects } from '@/lib/server/aud import { isS3Configured } from '@/lib/server/storage/s3'; import { getOpenReaderTestNamespace } from '@/lib/server/testing/test-namespace'; import { nowTimestampMs } from '@/lib/shared/timestamps'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -78,7 +78,12 @@ export async function GET(req: NextRequest) { archive.on('warning', (warning) => { if ((warning as NodeJS.ErrnoException).code !== 'ENOENT') { - serverLogger.warn({ err: warning }, 'User export warning:'); + serverLogger.warn({ + event: 'user.export.archive.warning', + degraded: true, + step: 'archive_warning', + error: errorToLog(warning), + }, 'User export warning'); } }); @@ -130,7 +135,10 @@ export async function GET(req: NextRequest) { await archive.finalize(); } } catch (error) { - serverLogger.error({ err: error }, 'Export generation failed:'); + serverLogger.error({ + event: 'user.export.generate.failed', + error: errorToLog(error), + }, 'Export generation failed'); archive.abort(); output.destroy(error instanceof Error ? error : new Error('Failed to generate export archive')); } finally { diff --git a/src/app/api/user/state/changelog/version-check/route.ts b/src/app/api/user/state/changelog/version-check/route.ts index b97e724..47c7adc 100644 --- a/src/app/api/user/state/changelog/version-check/route.ts +++ b/src/app/api/user/state/changelog/version-check/route.ts @@ -5,7 +5,7 @@ import { userPreferences } from '@/db/schema'; import { normalizeVersion, shouldOpenChangelogForVersionChange } from '@/lib/shared/changelog'; import { nowTimestampMs } from '@/lib/shared/timestamps'; import { resolveUserStateScope } from '@/lib/server/user/resolve-state-scope'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { deserializeUserPreferencesPayload, extractUserPreferencesMeta, @@ -81,7 +81,10 @@ export async function POST(req: NextRequest) { lastSeenVersion, }); } catch (error) { - serverLogger.error({ err: error }, 'Error checking changelog version:'); + serverLogger.error({ + event: 'user.changelog.version_check.failed', + error: errorToLog(error), + }, 'Failed to check changelog version'); return NextResponse.json({ error: 'Failed to check changelog version' }, { status: 500 }); } } diff --git a/src/app/api/user/state/preferences/route.ts b/src/app/api/user/state/preferences/route.ts index e3ff630..19f10b4 100644 --- a/src/app/api/user/state/preferences/route.ts +++ b/src/app/api/user/state/preferences/route.ts @@ -9,7 +9,7 @@ import { isTtsProviderType, type TtsProviderId } from '@/lib/shared/tts-provider import { listAdminProviders } from '@/lib/server/admin/providers'; import { getResolvedRuntimeConfig } from '@/lib/server/runtime-config'; import { normalizeLegacyProviderRef, resolveProviderDefaults } from '@/lib/shared/tts-provider-policy'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { deserializeUserPreferencesPayload, extractUserPreferencesMeta, @@ -242,7 +242,10 @@ export async function GET(req: NextRequest) { hasStoredPreferences: Boolean(row), }); } catch (error) { - serverLogger.error({ err: error }, 'Error loading user preferences:'); + serverLogger.error({ + event: 'user.preferences.load.failed', + error: errorToLog(error), + }, 'Failed to load user preferences'); return NextResponse.json({ error: 'Failed to load user preferences' }, { status: 500 }); } } @@ -316,7 +319,10 @@ export async function PUT(req: NextRequest) { applied: true, }); } catch (error) { - serverLogger.error({ err: error }, 'Error updating user preferences:'); + serverLogger.error({ + event: 'user.preferences.update.failed', + error: errorToLog(error), + }, 'Failed to update user preferences'); return NextResponse.json({ error: 'Failed to update user preferences' }, { status: 500 }); } } diff --git a/src/app/api/user/state/progress/route.ts b/src/app/api/user/state/progress/route.ts index d2e2acb..7e4d377 100644 --- a/src/app/api/user/state/progress/route.ts +++ b/src/app/api/user/state/progress/route.ts @@ -6,7 +6,7 @@ import type { ReaderType } from '@/types/user-state'; import { isValidDocumentId } from '@/lib/server/documents/blobstore'; import { resolveUserStateScope } from '@/lib/server/user/resolve-state-scope'; import { coerceTimestampMs, nowTimestampMs } from '@/lib/shared/timestamps'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; @@ -63,7 +63,10 @@ export async function GET(req: NextRequest) { }, }); } catch (error) { - serverLogger.error({ err: error }, 'Error loading user progress:'); + serverLogger.error({ + event: 'user.progress.load.failed', + error: errorToLog(error), + }, 'Failed to load user progress'); return NextResponse.json({ error: 'Failed to load user progress' }, { status: 500 }); } } @@ -173,7 +176,10 @@ export async function PUT(req: NextRequest) { applied: true, }); } catch (error) { - serverLogger.error({ err: error }, 'Error updating user progress:'); + serverLogger.error({ + event: 'user.progress.update.failed', + error: errorToLog(error), + }, 'Failed to update user progress'); return NextResponse.json({ error: 'Failed to update user progress' }, { status: 500 }); } } diff --git a/src/lib/server/admin/email-sync.ts b/src/lib/server/admin/email-sync.ts index 6a179bc..3085584 100644 --- a/src/lib/server/admin/email-sync.ts +++ b/src/lib/server/admin/email-sync.ts @@ -1,6 +1,6 @@ import { eq } from 'drizzle-orm'; import { db } from '@/db'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, hashForLog, serverLogger } from '@/lib/server/logger'; // We only need the `user` table here. Better Auth manages its own schema files; // we import them lazily to avoid coupling this module to a single dialect. @@ -61,7 +61,12 @@ export async function syncAdminFlag( await db.update(user).set({ isAdmin: shouldBeAdmin }).where(eq(user.id, userId)); return shouldBeAdmin; } catch (error) { - serverLogger.warn({ userId: userId, err: error }, '[admin] Failed to sync isAdmin flag for user'); + serverLogger.warn({ + event: 'admin.email_sync.user_flag_update.failed', + userIdHash: hashForLog(userId), + degraded: true, + error: errorToLog(error), + }, 'Failed to sync isAdmin flag for user'); return currentIsAdmin; } } diff --git a/src/lib/server/admin/seed.ts b/src/lib/server/admin/seed.ts index 3a4efc8..5057201 100644 --- a/src/lib/server/admin/seed.ts +++ b/src/lib/server/admin/seed.ts @@ -3,7 +3,7 @@ import { adminProviders, adminSettings } from '@/db/schema'; import { encryptSecret, apiKeyLast4 } from '@/lib/server/crypto/secrets'; import { randomUUID } from 'node:crypto'; import { and, eq } from 'drizzle-orm'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { RUNTIME_CONFIG_SCHEMA, seedRuntimeConfigFromEnv, @@ -31,7 +31,11 @@ let seedPromise: Promise | null = null; export async function ensureAdminSeed(): Promise { if (!seedPromise) { seedPromise = runSeed().catch((error) => { - serverLogger.warn({ err: error }, '[admin-seed] failed:'); + serverLogger.warn({ + event: 'admin.seed.run.failed', + degraded: true, + error: errorToLog(error), + }, 'Admin seed run failed'); // Reset so a subsequent call can retry (e.g. once migrations run). seedPromise = null; throw error; @@ -59,7 +63,11 @@ async function seedDefaultAdminProvider(): Promise { try { existing = await db.select({ id: adminProviders.id }).from(adminProviders).limit(1); } catch (error) { - serverLogger.warn({ err: error }, '[admin-seed] could not check admin_providers (table missing?)'); + serverLogger.warn({ + event: 'admin.seed.providers.check_failed', + degraded: true, + error: errorToLog(error), + }, 'Could not check admin_providers'); return; } if (existing.length > 0) return; @@ -86,14 +94,24 @@ async function seedDefaultAdminProvider(): Promise { updatedAt: now, }) .onConflictDoNothing({ target: adminSettings.key }); - serverLogger.warn( - '[admin-seed] API_KEY present but AUTH_SECRET missing; defaulting restrictUserApiKeys=false so BYOK remains available', - ); + serverLogger.warn({ + event: 'admin.seed.restrict_user_api_keys.defaulted', + degraded: true, + step: 'set_restrict_user_api_keys_fallback', + }, 'API_KEY present but AUTH_SECRET missing; defaulting restrictUserApiKeys=false'); } catch (fallbackError) { - serverLogger.warn({ err: fallbackError }, '[admin-seed] failed to write restrictUserApiKeys fallback after encryption failure'); + serverLogger.warn({ + event: 'admin.seed.restrict_user_api_keys.fallback_write_failed', + degraded: true, + error: errorToLog(fallbackError), + }, 'Failed to write restrictUserApiKeys fallback after encryption failure'); } } - serverLogger.warn({ err: error }, '[admin-seed] failed to encrypt default provider API key'); + serverLogger.warn({ + event: 'admin.seed.provider_key_encrypt.failed', + degraded: true, + error: errorToLog(error), + }, 'Failed to encrypt default provider API key'); return; } @@ -112,9 +130,17 @@ async function seedDefaultAdminProvider(): Promise { createdAt: now, updatedAt: now, }); - serverLogger.info('[admin-seed] created default-openai admin provider from env'); + serverLogger.info({ + event: 'admin.seed.provider_insert.succeeded', + providerSlug: 'default-openai', + }, 'Created default-openai admin provider from env'); } catch (error) { - serverLogger.warn({ err: error }, '[admin-seed] failed to insert default-openai provider'); + serverLogger.warn({ + event: 'admin.seed.provider_insert.failed', + degraded: true, + providerSlug: 'default-openai', + error: errorToLog(error), + }, 'Failed to insert default-openai provider'); } } @@ -138,7 +164,11 @@ async function cleanupLegacyDefaultTtsProviderSeedRow(): Promise { ), ); } catch (error) { - serverLogger.warn({ err: error }, '[admin-seed] failed to cleanup legacy defaultTtsProvider seed row'); + serverLogger.warn({ + event: 'admin.seed.legacy_default_provider_cleanup.failed', + degraded: true, + error: errorToLog(error), + }, 'Failed to cleanup legacy defaultTtsProvider seed row'); } } @@ -148,6 +178,10 @@ async function cleanupLegacyDefaultTtsModelRows(): Promise { .delete(adminSettings) .where(eq(adminSettings.key, 'defaultTtsModel')); } catch (error) { - serverLogger.warn({ err: error }, '[admin-seed] failed to cleanup legacy defaultTtsModel rows'); + serverLogger.warn({ + event: 'admin.seed.legacy_default_model_cleanup.failed', + degraded: true, + error: errorToLog(error), + }, 'Failed to cleanup legacy defaultTtsModel rows'); } } diff --git a/src/lib/server/admin/settings.ts b/src/lib/server/admin/settings.ts index 04eeab6..471f502 100644 --- a/src/lib/server/admin/settings.ts +++ b/src/lib/server/admin/settings.ts @@ -2,7 +2,7 @@ import { and, eq } from 'drizzle-orm'; import { db } from '@/db'; import { adminProviders, adminSettings } from '@/db/schema'; import { isAuthEnabled } from '@/lib/server/auth/config'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; /** * Runtime config: site-wide settings that used to live in build-time env vars. @@ -114,7 +114,11 @@ async function resolveImplicitDefaultTtsProvider(): Promise .limit(1); return rows[0]?.slug; } catch (error) { - serverLogger.warn({ err: error }, '[runtime-config] implicit defaultTtsProvider lookup failed:'); + serverLogger.warn({ + event: 'admin.runtime_config.default_provider_lookup.failed', + degraded: true, + error: errorToLog(error), + }, 'Implicit defaultTtsProvider lookup failed'); return undefined; } } @@ -142,7 +146,11 @@ async function readAllRows(): Promise betterAuth({ requireEmailVerification: false, // Set to true in production async sendResetPassword(data) { // Send an email to the user with a link to reset their password - serverLogger.info({ err: data.user.email }, "Password reset requested for:"); + serverLogger.info({ + event: 'auth.password_reset.requested', + userEmailHash: hashForLog(data.user.email), + }, 'Password reset requested'); }, }, user: { @@ -91,7 +94,13 @@ const createAuth = () => betterAuth({ const { deleteUserStorageData } = await import('@/lib/server/user/data-cleanup'); await deleteUserStorageData(user.id, null); } catch (error) { - serverLogger.warn({ err: error }, '[auth] Failed to clean up user storage before deletion:'); + serverLogger.warn({ + event: 'auth.user_delete.storage_cleanup_failed', + degraded: true, + step: 'delete_user_storage', + userIdHash: hashForLog(user.id), + error: errorToLog(error), + }, 'Failed to clean up user storage before deletion'); // Don't throw – allow the user deletion to proceed even if S3 cleanup fails. // Orphaned blobs are preferable to a blocked account deletion. } @@ -147,10 +156,11 @@ const createAuth = () => betterAuth({ try { // Log when anonymous user links to a real account serverLogger.info({ - anonymousUserId: anonymousUser.user.id, - newUserId: newUser.user.id, - newUserEmail: newUser.user.email, - }, "Anonymous user linked to account:"); + event: 'auth.link_account.started', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + newUserEmailHash: hashForLog(newUser.user.email), + }, 'Anonymous user linked to account'); // Lazy-load heavy modules only when account linking actually happens const [{ rateLimiter }, claimData] = await Promise.all([ @@ -161,9 +171,20 @@ const createAuth = () => betterAuth({ // Transfer rate limiting data (TTS char counts) from anonymous user to authenticated user try { await rateLimiter.transferAnonymousUsage(anonymousUser.user.id, newUser.user.id); - serverLogger.info(`Successfully transferred rate limit data from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info({ + event: 'auth.link_account.transfer.rate_limit.succeeded', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + }, 'Transferred rate limit data during account linking'); } catch (error) { - serverLogger.warn({ err: error }, "Error transferring rate limit data during account linking:"); + serverLogger.warn({ + event: 'auth.link_account.transfer.rate_limit.failed', + degraded: true, + step: 'transfer_rate_limit', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + error: errorToLog(error), + }, 'Failed transferring rate limit data during account linking'); // Don't throw here to prevent blocking the account linking process } @@ -171,10 +192,22 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserAudiobooks(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - serverLogger.info(`Successfully transferred ${transferred} audiobook(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info({ + event: 'auth.link_account.transfer.audiobooks.succeeded', + transferred, + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + }, 'Transferred audiobooks during account linking'); } } catch (error) { - serverLogger.warn({ err: error }, "Error transferring audiobooks during account linking:"); + serverLogger.warn({ + event: 'auth.link_account.transfer.audiobooks.failed', + degraded: true, + step: 'transfer_audiobooks', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + error: errorToLog(error), + }, 'Failed transferring audiobooks during account linking'); // Don't throw here to prevent blocking the account linking process } @@ -182,10 +215,22 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserDocuments(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - serverLogger.info(`Successfully transferred ${transferred} document(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info({ + event: 'auth.link_account.transfer.documents.succeeded', + transferred, + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + }, 'Transferred documents during account linking'); } } catch (error) { - serverLogger.warn({ err: error }, "Error transferring documents during account linking:"); + serverLogger.warn({ + event: 'auth.link_account.transfer.documents.failed', + degraded: true, + step: 'transfer_documents', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + error: errorToLog(error), + }, 'Failed transferring documents during account linking'); // Don't throw here to prevent blocking the account linking process } @@ -193,10 +238,22 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserPreferences(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - serverLogger.info(`Successfully transferred preferences from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info({ + event: 'auth.link_account.transfer.preferences.succeeded', + transferred, + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + }, 'Transferred preferences during account linking'); } } catch (error) { - serverLogger.warn({ err: error }, "Error transferring preferences during account linking:"); + serverLogger.warn({ + event: 'auth.link_account.transfer.preferences.failed', + degraded: true, + step: 'transfer_preferences', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + error: errorToLog(error), + }, 'Failed transferring preferences during account linking'); // Don't throw here to prevent blocking the account linking process } @@ -204,14 +261,29 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserProgress(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - serverLogger.info(`Successfully transferred ${transferred} progress row(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info({ + event: 'auth.link_account.transfer.progress.succeeded', + transferred, + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + }, 'Transferred reading progress during account linking'); } } catch (error) { - serverLogger.warn({ err: error }, "Error transferring reading progress during account linking:"); + serverLogger.warn({ + event: 'auth.link_account.transfer.progress.failed', + degraded: true, + step: 'transfer_progress', + anonymousUserIdHash: hashForLog(anonymousUser.user.id), + newUserIdHash: hashForLog(newUser.user.id), + error: errorToLog(error), + }, 'Failed transferring reading progress during account linking'); // Don't throw here to prevent blocking the account linking process } } catch (error) { - serverLogger.error({ err: error }, "Error in onLinkAccount callback:"); + serverLogger.error({ + event: 'auth.link_account.failed', + error: errorToLog(error), + }, 'onLinkAccount callback failed'); // Don't throw here to prevent blocking the account linking process } // Note: Anonymous user will be automatically deleted after this callback completes diff --git a/src/lib/server/compute/worker-op-state.ts b/src/lib/server/compute/worker-op-state.ts index a27318d..a5e0e61 100644 --- a/src/lib/server/compute/worker-op-state.ts +++ b/src/lib/server/compute/worker-op-state.ts @@ -1,6 +1,6 @@ import { getWorkerClientConfigFromEnv } from '@/lib/server/compute/worker'; import type { WorkerOperationState } from '@openreader/compute-core/api-contracts'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; const WORKER_OP_REQUEST_TIMEOUT_MS = 2_500; @@ -15,9 +15,11 @@ export async function fetchWorkerOperationState( cfg = getWorkerClientConfigFromEnv(); } catch (error) { serverLogger.warn({ + event: 'compute.worker_op_state.config.invalid', opId: normalized, - error: error instanceof Error ? error.message : String(error), - }, '[worker-op-state] worker client env missing/invalid'); + degraded: true, + error: errorToLog(error), + }, 'Worker client env missing/invalid'); return null; } @@ -38,25 +40,31 @@ export async function fetchWorkerOperationState( if (!res.ok) { const detail = await res.text().catch(() => ''); serverLogger.warn({ + event: 'compute.worker_op_state.fetch.failed', opId: normalized, status: res.status, detail, - }, '[worker-op-state] worker op request failed'); + degraded: true, + }, 'Worker op request failed'); return null; } const parsed = await res.json() as WorkerOperationState; if (!parsed || typeof parsed !== 'object' || parsed.opId !== normalized) { serverLogger.warn({ + event: 'compute.worker_op_state.response.invalid', opId: normalized, - }, '[worker-op-state] worker op response invalid'); + degraded: true, + }, 'Worker op response invalid'); return null; } return parsed; } catch (error) { serverLogger.warn({ + event: 'compute.worker_op_state.fetch.error', opId: normalized, - error: error instanceof Error ? error.message : String(error), - }, '[worker-op-state] worker op request threw'); + degraded: true, + error: errorToLog(error), + }, 'Worker op request threw'); return null; } finally { clearTimeout(timeout); diff --git a/src/lib/server/compute/worker.ts b/src/lib/server/compute/worker.ts index 2885e20..866f900 100644 --- a/src/lib/server/compute/worker.ts +++ b/src/lib/server/compute/worker.ts @@ -25,7 +25,6 @@ class WorkerHttpError extends Error { } const DEFAULT_RETRIES = 2; -const LOG_PREFIX = '[compute-worker-client]'; const MAX_LOG_DETAIL_CHARS = 600; const LOG_EVENTS = new Set([ 'align.request.failed', @@ -63,22 +62,27 @@ function errorToLog(error: unknown): Record { function logWorker(level: WorkerLogLevel, event: string, fields: Record): void { if (!LOG_EVENTS.has(event)) return; - - const payload = { - ts: new Date().toISOString(), - event, - ...fields, - }; - const line = `${LOG_PREFIX} ${JSON.stringify(payload)}`; if (level === 'error') { - serverLogger.error(line); + serverLogger.error({ + event: `compute.worker_client.${event}`, + operation: 'compute_worker_client', + ...fields, + }, `Worker client ${event}`); return; } if (level === 'warn') { - serverLogger.warn(line); + serverLogger.warn({ + event: `compute.worker_client.${event}`, + operation: 'compute_worker_client', + ...fields, + }, `Worker client ${event}`); return; } - serverLogger.info(line); + serverLogger.info({ + event: `compute.worker_client.${event}`, + operation: 'compute_worker_client', + ...fields, + }, `Worker client ${event}`); } function opSummary(value: unknown): Record { diff --git a/src/lib/server/documents/previews.ts b/src/lib/server/documents/previews.ts index a84a1ed..3ed21dc 100644 --- a/src/lib/server/documents/previews.ts +++ b/src/lib/server/documents/previews.ts @@ -2,7 +2,7 @@ import { randomUUID } from 'crypto'; import { and, eq, inArray, lt, or, sql } from 'drizzle-orm'; import { db } from '@/db'; import { documentPreviews } from '@/db/schema'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { DOCUMENT_PREVIEW_CONTENT_TYPE, DOCUMENT_PREVIEW_VARIANT, @@ -375,7 +375,12 @@ export async function ensureDocumentPreview(doc: PreviewSourceDocument, namespac eTag: head.eTag, }); } catch (error) { - serverLogger.error({ err: error }, `[document-previews] Preview generation failed for ${doc.id} (type=${doc.type}):`); + serverLogger.error({ + event: 'documents.preview.generate.failed', + documentId: doc.id, + documentType: doc.type, + error: errorToLog(error), + }, 'Preview generation failed'); await markPreviewFailed(doc.id, namespaceKey, error); } } diff --git a/src/lib/server/jobs/user-pdf-layout-job.ts b/src/lib/server/jobs/user-pdf-layout-job.ts index e970e03..851ce62 100644 --- a/src/lib/server/jobs/user-pdf-layout-job.ts +++ b/src/lib/server/jobs/user-pdf-layout-job.ts @@ -2,7 +2,7 @@ import { and, eq, inArray, isNull } from 'drizzle-orm'; import { db } from '@/db'; import { documents } from '@/db/schema'; import { documentKey, putParsedDocumentBlob } from '@/lib/server/documents/blobstore'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { parseDocumentParseState, stringifyDocumentParseState, @@ -350,17 +350,23 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise }).then((cleared) => { if (cleared.warning) { serverLogger.warn({ + event: 'documents.parse.cache_invalidation.warning', + degraded: true, + step: 'clear_tts_segment_cache', documentId: input.documentId, userId, warning: cleared.warning, - }, '[parsePdfJob] cache invalidation warning'); + }, 'Parse cache invalidation warning'); } }).catch((cacheError) => { serverLogger.warn({ + event: 'documents.parse.cache_invalidation.failed', + degraded: true, + step: 'clear_tts_segment_cache', documentId: input.documentId, userId, - error: cacheError instanceof Error ? cacheError.message : String(cacheError), - }, '[parsePdfJob] cache invalidation failed'); + error: errorToLog(cacheError), + }, 'Parse cache invalidation failed'); }); } } catch (error) { @@ -385,18 +391,20 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise }); } catch (statusError) { serverLogger.error({ + event: 'documents.parse.status_write.failed', documentId: input.documentId, parseStatus, - error: statusError instanceof Error ? statusError.message : String(statusError), - }, '[parsePdfJob] failed to write parse status'); + error: errorToLog(statusError), + }, 'Failed to write parse status'); } serverLogger.error({ + event: 'documents.parse.job.failed', documentId: input.documentId, parseStatus, error: message, ...(stack ? { stack } : {}), ...(cause ? { cause: String(cause) } : {}), - }, '[parsePdfJob] failed'); + }, 'Parse job failed'); } finally { running.delete(key); } @@ -406,6 +414,10 @@ export function enqueueParsePdfJob(input: UserPdfLayoutJobRequest): void { Promise.resolve() .then(() => parsePdfJob(input)) .catch((error) => { - serverLogger.error({ err: error }, '[parsePdfJob] uncaught error'); + serverLogger.error({ + event: 'documents.parse.job.uncaught_error', + documentId: input.documentId, + error: errorToLog(error), + }, 'Parse job uncaught error'); }); } diff --git a/src/lib/server/logger.ts b/src/lib/server/logger.ts index ae1b8da..7a6498d 100644 --- a/src/lib/server/logger.ts +++ b/src/lib/server/logger.ts @@ -4,6 +4,34 @@ import pino, { type Logger } from 'pino'; import pinoPretty from 'pino-pretty'; export type ServerLogger = Logger; +export type ServerLogLevel = 'error' | 'warn' | 'info'; + +export type ServerErrorClass = + | 'validation' + | 'auth' + | 'permission' + | 'upstream' + | 'storage' + | 'db' + | 'timeout' + | 'unknown'; + +export type ServerErrorContract = { + errorCode: string; + errorClass: ServerErrorClass; + retryable: boolean; + httpStatus: number; + operation: string; + degraded: boolean; + cause?: unknown; +}; + +export type ServerApiErrorBody = { + error: string; + errorCode: string; + retryable?: boolean; + details?: Record; +}; const LOG_FORMAT = process.env.LOG_FORMAT?.trim().toLowerCase() || 'pretty'; const LOG_LEVEL = process.env.LOG_LEVEL?.trim() || 'info'; @@ -48,6 +76,17 @@ export function errorToLog(error: unknown): Record { return { message: String(error) }; } +export function apiErrorBody( + input: Omit & { errorCode: string }, +): ServerApiErrorBody { + return { + error: input.error, + errorCode: input.errorCode, + ...(typeof input.retryable === 'boolean' ? { retryable: input.retryable } : {}), + ...(input.details ? { details: input.details } : {}), + }; +} + export function hashForLog(value: string | null | undefined): string | null { const normalized = typeof value === 'string' ? value.trim() : ''; if (!normalized) return null; diff --git a/src/lib/server/rate-limit/rate-limiter.ts b/src/lib/server/rate-limit/rate-limiter.ts index 48f2dab..5c8f730 100644 --- a/src/lib/server/rate-limit/rate-limiter.ts +++ b/src/lib/server/rate-limit/rate-limiter.ts @@ -11,7 +11,13 @@ function readPositiveIntEnv(name: string, fallback: number): number { const parsed = Number(raw); if (!Number.isFinite(parsed) || parsed <= 0) { - serverLogger.warn(`[rate-limiter] Invalid ${name}=${raw}; using default ${fallback}`); + serverLogger.warn({ + event: 'rate_limit.config.invalid_env', + degraded: true, + envVar: name, + envValue: raw, + fallbackValue: fallback, + }, 'Invalid rate limiter env value; using default'); return fallback; } diff --git a/src/lib/server/tts/segments-cache.ts b/src/lib/server/tts/segments-cache.ts index fa271af..858bef9 100644 --- a/src/lib/server/tts/segments-cache.ts +++ b/src/lib/server/tts/segments-cache.ts @@ -3,7 +3,7 @@ import { db } from '@/db'; import { ttsSegmentEntries, ttsSegmentVariants } from '@/db/schema'; import { deleteTtsSegmentAudioObjects } from '@/lib/server/tts/segments-blobstore'; import type { ReaderType } from '@/types/user-state'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; type ClearTtsSegmentCacheInput = { userId: string; @@ -67,10 +67,13 @@ export async function clearTtsSegmentCache( } catch (error) { warning = error instanceof Error ? error.message : 'Failed deleting some audio objects'; serverLogger.warn({ + event: 'tts.segments.cache.audio_cleanup_failed', + degraded: true, + step: 'delete_tts_audio_objects', documentId: input.documentId, userId: input.userId, - error: warning, - }, 'Failed clearing some TTS segment audio objects:'); + error: errorToLog(error), + }, 'Failed clearing some TTS segment audio objects'); } } diff --git a/src/lib/server/tts/voice-resolution.ts b/src/lib/server/tts/voice-resolution.ts index 52ea085..e0d014d 100644 --- a/src/lib/server/tts/voice-resolution.ts +++ b/src/lib/server/tts/voice-resolution.ts @@ -1,5 +1,5 @@ import { LRUCache } from 'lru-cache'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, serverLogger } from '@/lib/server/logger'; import { resolveProviderModels, type ReplicateVoiceInputKey, @@ -193,7 +193,10 @@ async function fetchReplicateOpenApiSchema(apiKey: string, model: string): Promi if (error instanceof DOMException && error.name === 'AbortError') { return null; } - serverLogger.error({ err: error }, 'Error fetching Replicate model schema:'); + serverLogger.error({ + event: 'tts.voice_resolution.replicate_schema_fetch.failed', + error: errorToLog(error), + }, 'Failed fetching Replicate model schema'); return null; } finally { clearTimeout(timeoutId); @@ -284,7 +287,10 @@ async function fetchDeepinfraVoices(apiKey: string): Promise { if (error instanceof DOMException && error.name === 'AbortError') { return []; } - serverLogger.error({ err: error }, 'Error fetching Deepinfra voices:'); + serverLogger.error({ + event: 'tts.voice_resolution.deepinfra_voices_fetch.failed', + error: errorToLog(error), + }, 'Failed fetching Deepinfra voices'); return []; } finally { clearTimeout(timeoutId); @@ -316,7 +322,11 @@ async function fetchCustomOpenAiVoices(baseUrl: string, apiKey: string): Promise ? data.voices : null; } catch { - serverLogger.info('Custom endpoint does not support voices, using defaults'); + serverLogger.info({ + event: 'tts.voice_resolution.custom_endpoint.voices_unsupported', + degraded: true, + fallbackPath: 'provider_default_voices', + }, 'Custom endpoint does not support voices, using defaults'); return null; } finally { clearTimeout(timeoutId); diff --git a/src/lib/server/user/data-cleanup.ts b/src/lib/server/user/data-cleanup.ts index 88d3dae..54aa488 100644 --- a/src/lib/server/user/data-cleanup.ts +++ b/src/lib/server/user/data-cleanup.ts @@ -13,7 +13,7 @@ import { deleteDocumentPreviewArtifacts } from '@/lib/server/documents/previews- import { deleteDocumentPreviewRows } from '@/lib/server/documents/previews'; import { audiobookPrefix, deleteAudiobookPrefix } from '@/lib/server/audiobooks/blobstore'; import { deleteTtsSegmentPrefix } from '@/lib/server/tts/segments-blobstore'; -import { serverLogger } from '@/lib/server/logger'; +import { errorToLog, hashForLog, serverLogger } from '@/lib/server/logger'; type DocumentRow = { id: string }; type AudiobookRow = { id: string }; @@ -50,13 +50,27 @@ export async function deleteUserStorageData( await deleteDocumentBlob(doc.id, namespace); docsDeleted++; } catch (error) { - serverLogger.warn({ err: error }, `[user-data-cleanup] Failed to delete document blob ${doc.id}:`); + serverLogger.warn({ + event: 'user.data_cleanup.document_blob_delete.failed', + degraded: true, + step: 'delete_document_blob', + documentId: doc.id, + userIdHash: hashForLog(userId), + error: errorToLog(error), + }, 'Failed to delete document blob'); } try { await deleteDocumentPreviewArtifacts(doc.id, namespace); } catch (error) { - serverLogger.warn({ err: error }, `[user-data-cleanup] Failed to delete preview for ${doc.id}:`); + serverLogger.warn({ + event: 'user.data_cleanup.document_preview_delete.failed', + degraded: true, + step: 'delete_document_preview_artifacts', + documentId: doc.id, + userIdHash: hashForLog(userId), + error: errorToLog(error), + }, 'Failed to delete preview artifacts'); } } @@ -64,7 +78,14 @@ export async function deleteUserStorageData( try { await deleteDocumentPreviewRows(doc.id, namespace); } catch (error) { - serverLogger.warn({ err: error }, `[user-data-cleanup] Failed to delete preview rows for ${doc.id}:`); + serverLogger.warn({ + event: 'user.data_cleanup.document_preview_rows_delete.failed', + degraded: true, + step: 'delete_document_preview_rows', + documentId: doc.id, + userIdHash: hashForLog(userId), + error: errorToLog(error), + }, 'Failed to delete preview rows'); } } @@ -83,7 +104,14 @@ export async function deleteUserStorageData( await deleteAudiobookPrefix(prefix); booksDeleted++; } catch (error) { - serverLogger.warn({ err: error }, `[user-data-cleanup] Failed to delete audiobook blobs ${book.id}:`); + serverLogger.warn({ + event: 'user.data_cleanup.audiobook_blobs_delete.failed', + degraded: true, + step: 'delete_audiobook_prefix', + bookId: book.id, + userIdHash: hashForLog(userId), + error: errorToLog(error), + }, 'Failed to delete audiobook blobs'); } } @@ -98,16 +126,25 @@ export async function deleteUserStorageData( segmentsDeleted += await deleteTtsSegmentPrefix(ttsPrefixV1); segmentsDeleted += await deleteTtsSegmentPrefix(ttsPrefixV2); } catch (error) { - serverLogger.warn({ err: error }, `[user-data-cleanup] Failed to delete TTS segment blobs for user ${userId}:`); + serverLogger.warn({ + event: 'user.data_cleanup.tts_segments_delete.failed', + degraded: true, + step: 'delete_tts_segment_prefixes', + userIdHash: hashForLog(userId), + error: errorToLog(error), + }, 'Failed to delete TTS segment blobs'); } } if (docsDeleted > 0 || booksDeleted > 0 || segmentsDeleted > 0) { - serverLogger.info( - `[user-data-cleanup] Cleaned up S3 data for user ${userId}: ` + - `${docsDeleted}/${userDocs.length} document(s), ` + - `${booksDeleted}/${userBooks.length} audiobook(s), ` + - `${segmentsDeleted} tts segment object(s)`, - ); + serverLogger.info({ + event: 'user.data_cleanup.completed', + userIdHash: hashForLog(userId), + docsDeleted, + totalDocs: userDocs.length, + booksDeleted, + totalBooks: userBooks.length, + segmentsDeleted, + }, 'Completed user storage cleanup'); } }