diff --git a/.env.example b/.env.example index 7f0f43b..9de5c4d 100644 --- a/.env.example +++ b/.env.example @@ -1,4 +1,10 @@ +# Logging +# pretty (default): human-readable logs +# json: structured logs for log platforms +# LOG_FORMAT=pretty +# LOG_LEVEL=info + # Local / OpenAI TTS API Configuration (default) # Suggest using https://github.com/remsky/Kokoro-FastAPI # @@ -93,6 +99,8 @@ IMPORT_LIBRARY_DIRS= # EMBEDDED_NATS_STORE_DIR=docstore/nats/jetstream # `NATS_URL` here is for embedded startup only. In external worker mode, set `NATS_URL` on the worker service env. # NATS_URL=nats://127.0.0.1:4222 +# Optional worker log level: +# COMPUTE_LOG_LEVEL=info # Optional shared compute tuning: # COMPUTE_JOB_CONCURRENCY=1 # COMPUTE_WHISPER_TIMEOUT_MS=30000 diff --git a/compute/worker/.env.example b/compute/worker/.env.example index 4c36921..15472fa 100644 --- a/compute/worker/.env.example +++ b/compute/worker/.env.example @@ -14,7 +14,7 @@ # - Railway/Render/Fly/etc: platform injects PORT # COMPUTE_WORKER_HOST=0.0.0.0 # PORT=8081 -# COMPUTE_LOG_FORMAT=pretty +# LOG_FORMAT=pretty # COMPUTE_LOG_LEVEL=info # Must match app env when app uses COMPUTE_WORKER_URL diff --git a/compute/worker/src/server.ts b/compute/worker/src/server.ts index 8b82485..2b9a04b 100644 --- a/compute/worker/src/server.ts +++ b/compute/worker/src/server.ts @@ -133,7 +133,7 @@ function parseBoolEnv(name: string, fallback: boolean): boolean { } function buildLoggerConfig(): boolean | Record { - const format = (process.env.COMPUTE_LOG_FORMAT?.trim().toLowerCase() || 'pretty'); + const format = (process.env.LOG_FORMAT?.trim().toLowerCase() || 'pretty'); const level = process.env.COMPUTE_LOG_LEVEL?.trim() || 'info'; if (format === 'json') { return { diff --git a/docs-site/docs/deploy/compute-worker.md b/docs-site/docs/deploy/compute-worker.md index c95681c..4c82f4a 100644 --- a/docs-site/docs/deploy/compute-worker.md +++ b/docs-site/docs/deploy/compute-worker.md @@ -50,7 +50,7 @@ Common optional: - `S3_PREFIX=openreader` - `COMPUTE_WORKER_HOST=0.0.0.0` - `PORT=8081` (local/manual; on Railway platform injects this) -- `COMPUTE_LOG_FORMAT=pretty` (default) or `json` +- `LOG_FORMAT=pretty` (default) or `json` Advanced tuning (usually leave unset unless you need overrides): diff --git a/docs-site/docs/deploy/vercel-deployment.md b/docs-site/docs/deploy/vercel-deployment.md index 5218e81..86a9b3a 100644 --- a/docs-site/docs/deploy/vercel-deployment.md +++ b/docs-site/docs/deploy/vercel-deployment.md @@ -41,11 +41,20 @@ ADMIN_EMAILS=you@example.com # comma-separated; admins manage TTS + features in COMPUTE_WORKER_URL=https:// COMPUTE_WORKER_TOKEN=... +# Logging (recommended for Vercel log ingestion) +LOG_FORMAT=json +LOG_LEVEL=info + # First-boot seed for the TTS shared provider (optional; manage in-app afterwards) # API_KEY=your_replicate_key # API_BASE only needed for OpenAI-compatible self-hosted providers ``` +If you also run an external worker service (for example Railway), set these there too: + +- `LOG_FORMAT=json` +- `COMPUTE_LOG_LEVEL=info` + :::note Env vars vs. admin panel (important for Vercel) `API_KEY` / `API_BASE` are one-shot bootstrap seeds on first deploy. After boot, manage providers and site features in **Settings → Admin**. Changes there apply on refresh without a redeploy. See [Admin Panel](../configure/admin-panel). ::: diff --git a/docs-site/docs/reference/environment-variables.md b/docs-site/docs/reference/environment-variables.md index 0c9b5d6..b4a4078 100644 --- a/docs-site/docs/reference/environment-variables.md +++ b/docs-site/docs/reference/environment-variables.md @@ -13,12 +13,10 @@ For auth-enabled deployments, use **Settings → Admin** as the primary source o | Variable | Area | Default | When to set | | --- | --- | --- | --- | -| `ADMIN_EMAILS` | Auth/Admin | empty | Comma-separated emails auto-promoted to admin (requires auth enabled) | +| `LOG_FORMAT` | Runtime logging | `pretty` | Set `json` for structured logs; shared by app server + compute worker | +| `LOG_LEVEL` | Runtime logging | `info` | Set app server log level | | `API_BASE` | Legacy bootstrap seed | none | Optional first-boot seed into `default-openai`; then manage in Settings → Admin → Shared providers | | `API_KEY` | Legacy bootstrap seed | none | Optional first-boot seed into `default-openai`; then manage in Settings → Admin → Shared providers | -| `RUNTIME_SEED_*` runtime seeds | Legacy bootstrap seed | varies | Optional first-boot seeds for site features; then manage in Settings → Admin → Site features | -| `RUNTIME_SEED_CHANGELOG_FEED_URL` | Legacy bootstrap seed | `https://docs.openreader.richardr.dev/changelog/manifest.json` | Optional first-boot seed for changelog feed URL; then manage in Settings → Admin → Site features | -| `RUNTIME_SEED_ENABLE_USER_SIGNUPS` | Legacy bootstrap seed | `true` | Optional first-boot seed for whether new accounts can be created; then manage in Settings → Admin → Site features | | `TTS_CACHE_MAX_SIZE_BYTES` | TTS caching | `268435456` (256 MB) | Tune in-memory TTS cache size | | `TTS_CACHE_TTL_MS` | TTS caching | `1800000` (30 min) | Tune in-memory TTS cache TTL | | `TTS_MAX_RETRIES` | TTS retry | `2` | Tune retry attempts for upstream 429/5xx | @@ -38,6 +36,7 @@ For auth-enabled deployments, use **Settings → Admin** as the primary source o | `GITHUB_CLIENT_ID` | Auth/OAuth | unset | Set with `GITHUB_CLIENT_SECRET` to enable GitHub sign-in | | `GITHUB_CLIENT_SECRET` | Auth/OAuth | unset | Set with `GITHUB_CLIENT_ID` to enable GitHub sign-in | | `DISABLE_AUTH_RATE_LIMIT` | Rate limiting | `false` | Set `true` to disable auth-layer rate limiting | +| `ADMIN_EMAILS` | Auth/Admin | empty | Comma-separated emails auto-promoted to admin (requires auth enabled) | | `POSTGRES_URL` | Database | unset (SQLite mode) | Set to switch metadata/auth DB to Postgres | | `USE_EMBEDDED_WEED_MINI` | Storage | `true` when unset | Set `false` to use external S3-compatible storage only | | `WEED_MINI_DIR` | Storage | `docstore/seaweedfs` | Override embedded SeaweedFS data directory | @@ -60,6 +59,7 @@ For auth-enabled deployments, use **Settings → Admin** as the primary source o | `EMBEDDED_NATS_MONITOR_PORT` | Heavy compute backend | `8222` | Override embedded NATS monitor port | | `EMBEDDED_NATS_STORE_DIR` | Heavy compute backend | `docstore/nats/jetstream` | Override embedded JetStream storage directory | | `NATS_URL` | Heavy compute backend | `nats://127.0.0.1:4222` in embedded startup | Optional override for embedded startup or required on standalone worker service | +| `COMPUTE_LOG_LEVEL` | Heavy compute backend | `info` | Compute worker log level | | `COMPUTE_JOB_CONCURRENCY` | Heavy compute backend | `1` | Worker-side shared compute concurrency cap | | `COMPUTE_WHISPER_TIMEOUT_MS` | Heavy compute backend | `30000` | Shared whisper alignment timeout budget (worker + worker client wait budget) | | `COMPUTE_PDF_TIMEOUT_MS` | Heavy compute backend | `300000` | Shared PDF idle-timeout budget (worker + worker client wait budget) | @@ -67,9 +67,35 @@ For auth-enabled deployments, use **Settings → Admin** as the primary source o | `PDF_LAYOUT_MODEL_BASE_URL` | PDF layout model | PP-DocLayoutV3 ONNX base URL | Optional base URL override for `ensureModel()` | | `WHISPER_MODEL_BASE_URL` | Whisper ONNX model | onnx-community defaults | Optional base URL override for ONNX whisper-base_timestamped q4 downloads | | `FFMPEG_BIN` | Audio runtime | auto-detected (`ffmpeg-static`) | Override ffmpeg binary path | +| `RUNTIME_SEED_*` runtime seeds | Legacy bootstrap seed | varies | Optional first-boot seeds for site features; then manage in Settings → Admin → Site features | +| `RUNTIME_SEED_ENABLE_DOCX_CONVERSION` | Legacy bootstrap seed | `true` | Optional first-boot seed to enable/disable DOCX conversion UI | +| `RUNTIME_SEED_ENABLE_DESTRUCTIVE_DELETE_ACTIONS` | Legacy bootstrap seed | `true` | Optional first-boot seed to show/hide destructive delete actions | +| `RUNTIME_SEED_ENABLE_TTS_PROVIDERS_TAB` | Legacy bootstrap seed | `true` | Optional first-boot seed to show/hide user TTS providers tab | +| `RUNTIME_SEED_CHANGELOG_FEED_URL` | Legacy bootstrap seed | `https://docs.openreader.richardr.dev/changelog/manifest.json` | Optional first-boot seed for changelog feed URL; then manage in Settings → Admin → Site features | +| `RUNTIME_SEED_ENABLE_USER_SIGNUPS` | Legacy bootstrap seed | `true` | Optional first-boot seed for whether new accounts can be created; then manage in Settings → Admin → Site features | +| `RUNTIME_SEED_RESTRICT_USER_API_KEYS` | Legacy bootstrap seed | runtime-dependent | Optional first-boot seed to restrict per-user BYOK | +| `RUNTIME_SEED_DEFAULT_TTS_PROVIDER` | Legacy bootstrap seed | `custom-openai` | Optional first-boot seed for default TTS provider slug | +| `RUNTIME_SEED_ENABLE_AUDIOBOOK_EXPORT` | Legacy bootstrap seed | `true` | Optional first-boot seed to enable audiobook export UI | +## Runtime Logging + +### LOG_FORMAT + +Controls log output format for server-side Pino loggers. + +- Default: `pretty` +- Allowed values: `pretty`, `json` +- Applies to app server and compute worker +- Recommended in production (Vercel + external worker): `json` + +### LOG_LEVEL + +App server log level. + +- Default: `info` + ## TTS Provider and Request Behavior ### API_BASE @@ -242,6 +268,8 @@ Switches metadata/auth storage from SQLite to Postgres. - Set: Postgres mode - Related docs: [Database](../configure/database) +### Embedded SeaweedFS weed mini config + ### USE_EMBEDDED_WEED_MINI Controls embedded SeaweedFS startup. @@ -264,6 +292,8 @@ Maximum seconds to wait for embedded SeaweedFS startup. - Default: `20` - Related docs: [Object / Blob Storage](../configure/object-blob-storage) +### S3 storage config + ### S3_ACCESS_KEY_ID Access key for S3-compatible storage. @@ -410,6 +440,13 @@ NATS connection URL used by compute worker runtime. - For embedded startup, this is optional; startup supplies the default value. - Worker-side only in external mode: set on worker service env, not app/root `.env`. +### COMPUTE_LOG_LEVEL + +Compute worker log level. + +- Default: `info` +- In standalone mode, set this on the worker service env. + ### COMPUTE_JOB_CONCURRENCY Worker-side shared compute concurrency cap. diff --git a/eslint.config.mjs b/eslint.config.mjs index bc5dd4a..a63df9f 100644 --- a/eslint.config.mjs +++ b/eslint.config.mjs @@ -32,6 +32,12 @@ const eslintConfig = [ ], }, }, + { + files: ["src/app/api/**/*.ts", "src/lib/server/**/*.ts"], + rules: { + "no-console": "error", + }, + }, ]; export default eslintConfig; diff --git a/package.json b/package.json index 20f37f1..74bcfa2 100644 --- a/package.json +++ b/package.json @@ -58,6 +58,8 @@ "openai": "^6.37.0", "pdfjs-dist": "4.8.69", "pg": "^8.20.0", + "pino": "^10.3.1", + "pino-pretty": "^13.1.3", "react": "^19.2.6", "react-dnd": "^16.0.1", "react-dnd-html5-backend": "^16.0.1", diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index fdbeb0b..1cebe16 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -103,6 +103,12 @@ importers: pg: specifier: ^8.20.0 version: 8.20.0 + pino: + specifier: ^10.3.1 + version: 10.3.1 + pino-pretty: + specifier: ^13.1.3 + version: 13.1.3 react: specifier: ^19.2.6 version: 19.2.6 @@ -4081,9 +4087,6 @@ packages: resolution: {integrity: sha512-udgsAY+fTnvv7kI7aaxbqwWNb0AHiB0qBO89PZKPkoTmGOgdbrHDKD+0B2X4uTfJ/FT1R09r9gTsjUjNJotuog==} engines: {node: '>=0.10.0'} - pino-abstract-transport@2.0.0: - resolution: {integrity: sha512-F63x5tizV6WCh4R6RHyi2Ml+M70DNRXt/+HANowMflpgGFMAym/VKm6G7ZOQRjqN7XbGxK1Lg9t6ZrtzOaivMw==} - pino-abstract-transport@3.0.0: resolution: {integrity: sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==} @@ -4098,10 +4101,6 @@ packages: resolution: {integrity: sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg==} hasBin: true - pino@9.14.0: - resolution: {integrity: sha512-8OEwKp5juEvb/MjpIc4hjqfgCNysrS94RIOMXYvpYCdm/jglrKEiAYmiumbmGhCvs+IcInsphYDFwqrjr7398w==} - hasBin: true - pirates@4.0.7: resolution: {integrity: sha512-TfySrs/5nm8fQJDcBDuUng3VOUKsd7S+zqvbOTiGXHfxX4wK31ard+hoNuvkicM/2YFzlpDgABOevKSsB4G/FA==} engines: {node: '>= 6'} @@ -4680,9 +4679,6 @@ packages: thenify@3.3.1: resolution: {integrity: sha512-RVZSIV5IG10Hk3enotrhvz0T9em6cyHBLkH/YAZuKqd8hRkKhSfCGIcP2KUY0EPxndzANBmNllzWPwak+bheSw==} - thread-stream@3.1.0: - resolution: {integrity: sha512-OqyPZ9u96VohAyMfJykzmivOrY2wfMSf3C5TtFJVgN+Hm6aj+voFhlK+kZEIv2FBh1X6Xp3DlnCOfEQ3B2J86A==} - thread-stream@4.2.0: resolution: {integrity: sha512-e2zZ96wSChazBsbENf/Pcm/4swHt2cEKQ92rhUjkL9GCKiTDJIaTBenjE/m9DXi0QBmTMDkFDdOomUy20A1tDQ==} engines: {node: '>=20'} @@ -7997,7 +7993,7 @@ snapshots: fast-json-stringify: 6.4.0 find-my-way: 9.6.0 light-my-request: 6.6.0 - pino: 9.14.0 + pino: 10.3.1 process-warning: 5.0.0 rfdc: 1.4.1 secure-json-parse: 4.1.0 @@ -9133,10 +9129,6 @@ snapshots: pify@2.3.0: {} - pino-abstract-transport@2.0.0: - dependencies: - split2: 4.2.0 - pino-abstract-transport@3.0.0: dependencies: split2: 4.2.0 @@ -9173,20 +9165,6 @@ snapshots: sonic-boom: 4.2.1 thread-stream: 4.2.0 - pino@9.14.0: - dependencies: - '@pinojs/redact': 0.4.0 - atomic-sleep: 1.0.0 - on-exit-leak-free: 2.1.2 - pino-abstract-transport: 2.0.0 - pino-std-serializers: 7.1.0 - process-warning: 5.0.0 - quick-format-unescaped: 4.0.4 - real-require: 0.2.0 - safe-stable-stringify: 2.5.0 - sonic-boom: 4.2.1 - thread-stream: 3.1.0 - pirates@4.0.7: {} playwright-core@1.60.0: {} @@ -9933,10 +9911,6 @@ snapshots: dependencies: any-promise: 1.3.0 - thread-stream@3.1.0: - dependencies: - real-require: 0.2.0 - thread-stream@4.2.0: dependencies: real-require: 1.0.0 diff --git a/scripts/openreader-entrypoint.mjs b/scripts/openreader-entrypoint.mjs index 7abebf5..97dcb5d 100644 --- a/scripts/openreader-entrypoint.mjs +++ b/scripts/openreader-entrypoint.mjs @@ -318,6 +318,7 @@ async function main() { } const runtimeEnv = { ...process.env }; + runtimeEnv.LOG_FORMAT = withDefault(runtimeEnv.LOG_FORMAT, 'pretty'); let weedProc = null; let weedExitPromise = Promise.resolve(); let natsProc = null; diff --git a/src/app/api/account/delete/route.ts b/src/app/api/account/delete/route.ts index 5e59e83..87ee48a 100644 --- a/src/app/api/account/delete/route.ts +++ b/src/app/api/account/delete/route.ts @@ -4,6 +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'; export async function DELETE() { if (!isAuthEnabled() || !auth) { @@ -28,7 +29,7 @@ export async function DELETE() { try { await deleteUserStorageData(session.user.id, testNamespace); } catch (error) { - console.error('[account-delete] Failed to clean up namespaced user storage before deletion:', error); + serverLogger.error({ err: error }, '[account-delete] Failed to clean up namespaced user storage before deletion:'); } } @@ -40,7 +41,7 @@ export async function DELETE() { return NextResponse.json({ success: true }); } catch (error) { - console.error('Failed to delete account:', error); + serverLogger.error({ err: 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 2fac788..f826e48 100644 --- a/src/app/api/admin/providers/[id]/route.ts +++ b/src/app/api/admin/providers/[id]/route.ts @@ -1,5 +1,6 @@ import { NextRequest, NextResponse } from 'next/server'; import { requireAdminContext } from '@/lib/server/auth/admin'; +import { serverLogger } from '@/lib/server/logger'; import { AdminProviderError, deleteAdminProvider, @@ -41,7 +42,7 @@ export async function PUT( if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - console.error('[admin/providers/:id] update failed:', error); + serverLogger.error({ err: error }, '[admin/providers/:id] update failed:'); return NextResponse.json({ error: 'Internal error' }, { status: 500 }); } } @@ -61,7 +62,7 @@ export async function DELETE( if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - console.error('[admin/providers/:id] delete failed:', error); + serverLogger.error({ err: error }, '[admin/providers/:id] 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 a2c7d8b..e2735f0 100644 --- a/src/app/api/admin/providers/route.ts +++ b/src/app/api/admin/providers/route.ts @@ -1,5 +1,6 @@ import { NextRequest, NextResponse } from 'next/server'; import { requireAdminContext } from '@/lib/server/auth/admin'; +import { serverLogger } from '@/lib/server/logger'; import { AdminProviderError, createAdminProvider, @@ -46,7 +47,7 @@ export async function POST(req: NextRequest) { if (error instanceof AdminProviderError) { return NextResponse.json({ error: error.message }, { status: error.status }); } - console.error('[admin/providers] create failed:', error); + serverLogger.error({ err: error }, '[admin/providers] 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 83c89a5..cb25256 100644 --- a/src/app/api/audiobook/chapter/route.ts +++ b/src/app/api/audiobook/chapter/route.ts @@ -11,6 +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 { deleteAudiobookObject, getAudiobookObjectBuffer, @@ -185,7 +186,7 @@ async function runFFmpeg(args: string[], signal?: AbortSignal): Promise { } ffmpeg.stderr.on('data', (data) => { - console.error(`ffmpeg stderr: ${data}`); + serverLogger.error(`ffmpeg stderr: ${data}`); }); ffmpeg.on('close', (code) => { @@ -325,7 +326,7 @@ export async function POST(request: NextRequest) { fallbackProviderRef: runtimeConfig.defaultTtsProvider, }); if (!existingResult.settings) { - console.error('Invalid audiobook.meta.json settings payload', { bookId, storageUserId }); + serverLogger.error({ bookId, storageUserId }, 'Invalid audiobook.meta.json settings payload'); return NextResponse.json({ error: 'Invalid audiobook metadata settings' }, { status: 500 }); } normalizedExistingSettings = normalizeNativeSpeedForSettings(existingResult.settings); @@ -399,11 +400,11 @@ export async function POST(request: NextRequest) { testNamespace, ); } catch (error) { - console.warn('Failed to persist migrated audiobook metadata settings', { + serverLogger.warn({ bookId, storageUserId, error: error instanceof Error ? error.message : String(error), - }); + }, 'Failed to persist migrated audiobook metadata settings'); } } @@ -608,7 +609,7 @@ export async function POST(request: NextRequest) { request.signal, ); } catch (copyError) { - console.warn('Chapter remux failed; falling back to mp3 re-encode:', copyError); + serverLogger.warn({ err: copyError }, 'Chapter remux failed; falling back to mp3 re-encode:'); await runFFmpeg( chapterEncodeArgs(inputPath, chapterOutputTempPath, format, postSpeed, titleTag), request.signal, @@ -728,7 +729,7 @@ export async function POST(request: NextRequest) { return response; } - console.error('Error processing audio chapter:', error); + serverLogger.error({ err: error }, 'Error processing audio chapter:'); const response = NextResponse.json({ error: 'Failed to process audio chapter' }, { status: 500 }); attachDeviceIdCookie(response, deviceIdToSet, didCreateDeviceIdCookie); return response; @@ -823,7 +824,7 @@ export async function GET(request: NextRequest) { }, }); } catch (error) { - console.error('Error downloading chapter:', error); + serverLogger.error({ err: error }, 'Error downloading chapter:'); return NextResponse.json({ error: 'Failed to download chapter' }, { status: 500 }); } } @@ -891,7 +892,7 @@ export async function DELETE(request: NextRequest) { return NextResponse.json({ success: true }); } catch (error) { - console.error('Error deleting chapter:', error); + serverLogger.error({ err: error }, 'Error deleting 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 afeae62..511029e 100644 --- a/src/app/api/audiobook/route.ts +++ b/src/app/api/audiobook/route.ts @@ -7,6 +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 { audiobookPrefix, deleteAudiobookObject, @@ -115,7 +116,7 @@ async function runFFmpeg(args: string[], signal?: AbortSignal): Promise { } ffmpeg.stderr.on('data', (data) => { - console.error(`ffmpeg stderr: ${data}`); + serverLogger.error(`ffmpeg stderr: ${data}`); }); ffmpeg.on('close', (code) => { @@ -282,7 +283,7 @@ export async function GET(request: NextRequest) { request.signal, ); } catch (copyError) { - console.warn('MP3 concat copy failed; falling back to re-encode:', copyError); + serverLogger.warn({ err: 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, @@ -311,7 +312,7 @@ export async function GET(request: NextRequest) { request.signal, ); } catch (copyError) { - console.warn('M4B concat copy failed; falling back to re-encode:', copyError); + serverLogger.warn({ err: copyError }, 'M4B concat copy failed; falling back to re-encode:'); await runFFmpeg( [ '-f', @@ -360,7 +361,7 @@ export async function GET(request: NextRequest) { if ((error as Error)?.message === 'ABORTED' || request.signal.aborted) { return NextResponse.json({ error: 'cancelled' }, { status: 499 }); } - console.error('Error creating full audiobook:', error); + serverLogger.error({ err: error }, 'Error creating 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(() => {}); @@ -408,7 +409,7 @@ 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) { - console.error('Error resetting audiobook:', error); + serverLogger.error({ err: error }, 'Error resetting 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 78d0f53..fc6b93c 100644 --- a/src/app/api/audiobook/status/route.ts +++ b/src/app/api/audiobook/status/route.ts @@ -11,6 +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'; export const dynamic = 'force-dynamic'; @@ -155,7 +156,7 @@ export async function GET(request: NextRequest) { settings, }); } catch (error) { - console.error('Error fetching chapters:', error); + serverLogger.error({ err: error }, 'Error fetching 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 cbdbc7c..da0a337 100644 --- a/src/app/api/documents/[id]/parsed/events/route.ts +++ b/src/app/api/documents/[id]/parsed/events/route.ts @@ -11,6 +11,7 @@ import { normalizeParseStatus, parseDocumentParseState } from '@/lib/server/docu import { healStaleDocumentParseState } from '@/lib/server/documents/parse-state-healing'; import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; +import { createRequestLogger, errorToLog, hashForLog } from '@/lib/server/logger'; import type { PdfParseProgress, PdfParseStatus } from '@/types/parsed-pdf'; import { parseSseEventId, parseSsePayload } from '@openreader/compute-core'; import type { PdfLayoutJobResult, WorkerOperationEvent, WorkerOperationState } from '@openreader/compute-core/api-contracts'; @@ -134,6 +135,10 @@ async function syncFromDb(input: { } export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string }> }) { + const { logger, requestId } = createRequestLogger({ + route: '/api/documents/[id]/parsed/events', + request: req, + }); try { if (!isS3Configured()) return s3NotConfiguredResponse(); @@ -153,6 +158,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string const testNamespace = getOpenReaderTestNamespace(req.headers); const unclaimedUserId = getUnclaimedUserIdForNamespace(testNamespace); const storageUserId = authCtxOrRes.userId ?? unclaimedUserId; + const storageUserIdHash = hashForLog(storageUserId); const allowedUserIds = authCtxOrRes.authEnabled ? [storageUserId, unclaimedUserId] : [unclaimedUserId]; const row = await loadPreferredRow({ @@ -261,9 +267,11 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string } }).catch((error) => { if (closed) return; - console.warn('[parsed/events] db resync failed', { + logger.warn({ + event: 'documents.parsed.events.db_resync_failed', documentId: id, - storageUserId, + storageUserIdHash, + requestId, error: error instanceof Error ? error.message : String(error), }); controller.enqueue(encoder.encode(`event: error\ndata: ${JSON.stringify({ error: String(error) })}\n\n`)); @@ -292,9 +300,10 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string if (!currentOpId) { if (!loggedMissingOpId) { loggedMissingOpId = true; - console.warn('[parsed/events] missing worker opId while parse is non-terminal', { + logger.warn({ + event: 'documents.parsed.events.missing_opid_non_terminal', documentId: id, - storageUserId, + storageUserIdHash, parseStatus: current.parseStatus, requestedOpId, }); @@ -331,7 +340,8 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string if (!response.ok) { const detail = await response.text().catch(() => ''); - console.warn('[parsed/events] worker stream request failed', { + logger.warn({ + event: 'documents.parsed.events.worker_stream_request_failed', documentId: id, opId: currentOpId, status: response.status, @@ -341,7 +351,8 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string continue; } if (!response.body) { - console.warn('[parsed/events] worker stream response missing body', { + logger.warn({ + event: 'documents.parsed.events.worker_stream_missing_body', documentId: id, opId: currentOpId, }); @@ -441,9 +452,10 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string void runWorkerProxy() .catch((error) => { - console.error('[parsed/events] worker proxy crashed', { + logger.error({ + event: 'documents.parsed.events.worker_proxy_crashed', documentId: id, - error: error instanceof Error ? error.message : String(error), + error: errorToLog(error), }); if (!closed) { controller.enqueue(encoder.encode(`event: error\ndata: ${JSON.stringify({ error: String(error) })}\n\n`)); @@ -471,7 +483,10 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string }, }); } catch (error) { - console.error('Error streaming parsed PDF progress:', error); + logger.error({ + event: 'documents.parsed.events.route_failed', + error: errorToLog(error), + }); 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 2dccd90..e3d3dce 100644 --- a/src/app/api/documents/[id]/parsed/route.ts +++ b/src/app/api/documents/[id]/parsed/route.ts @@ -23,6 +23,7 @@ import { import { healStaleDocumentParseState } from '@/lib/server/documents/parse-state-healing'; import { getOpenReaderTestNamespace, getUnclaimedUserIdForNamespace } from '@/lib/server/testing/test-namespace'; import { isS3Configured } from '@/lib/server/storage/s3'; +import { createRequestLogger, errorToLog, hashForLog, type ServerLogger } from '@/lib/server/logger'; import type { ParsedPdfDocument } from '@/types/parsed-pdf'; import type { PdfLayoutJobResult, WorkerOperationState } from '@openreader/compute-core/api-contracts'; @@ -92,6 +93,7 @@ async function finalizeFromWorkerState(input: { workerState: WorkerOperationState; row: ParseRow; namespace: string | null; + logger: ServerLogger; }): Promise { const snapshot = snapshotFromWorkerState(input.workerState); @@ -159,9 +161,10 @@ async function finalizeFromWorkerState(input: { } if (!hasAnyParsedBlocks(parsedDoc)) { - console.warn('[documents/parsed] parsed doc has no blocks', { + input.logger.warn({ + event: 'documents.parsed.no_blocks_in_output', documentId: input.row.id, - userId: input.row.userId, + userIdHash: hashForLog(input.row.userId), parsedJsonKey, }); } @@ -176,6 +179,10 @@ async function finalizeFromWorkerState(input: { } export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string }> }) { + const { logger } = createRequestLogger({ + route: '/api/documents/[id]/parsed', + request: req, + }); try { if (!isS3Configured()) return s3NotConfiguredResponse(); @@ -208,11 +215,13 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string workerState, row, namespace: testNamespace, + logger, }); } - console.warn('[documents/parsed:get] requested opId unavailable', { + logger.warn({ + event: 'documents.parsed.requested_op_unavailable', documentId: id, - userId: row.userId, + userIdHash: hashForLog(row.userId), opId: requestedOpId, }); } @@ -235,6 +244,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string workerState, row, namespace: testNamespace, + logger, }); } } @@ -273,9 +283,10 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string } if (!hasAnyParsedBlocks(parsedDoc)) { - console.warn('[documents/parsed] parsed doc has no blocks', { + logger.warn({ + event: 'documents.parsed.no_blocks_from_blob', documentId: id, - userId: row.userId, + userIdHash: hashForLog(row.userId), parsedJsonKey: row.parsedJsonKey, }); } @@ -294,12 +305,19 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string throw error; } } catch (error) { - console.error('Error reading parsed PDF:', error); + logger.error({ + event: 'documents.parsed.get_failed', + error: errorToLog(error), + }); return NextResponse.json({ error: 'Failed to read parsed PDF' }, { status: 500 }); } } export async function POST(req: NextRequest, ctx: { params: Promise<{ id: string }> }) { + const { logger } = createRequestLogger({ + route: '/api/documents/[id]/parsed', + request: req, + }); try { if (!isS3Configured()) return s3NotConfiguredResponse(); @@ -367,7 +385,10 @@ export async function POST(req: NextRequest, ctx: { params: Promise<{ id: string opId: created.opId, }, { status: 202 }); } catch (error) { - console.error('Error forcing parsed PDF refresh:', error); + logger.error({ + event: 'documents.parsed.force_refresh_failed', + error: errorToLog(error), + }); 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 a63d423..e01c82c 100644 --- a/src/app/api/documents/[id]/settings/route.ts +++ b/src/app/api/documents/[id]/settings/route.ts @@ -7,6 +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'; export const dynamic = 'force-dynamic'; @@ -92,7 +93,7 @@ export async function GET(req: NextRequest, ctx: { params: Promise<{ id: string hasStoredSettings: Boolean(row), }); } catch (error) { - console.error('Error loading document settings:', error); + serverLogger.error({ err: error }, 'Error loading document settings:'); return NextResponse.json({ error: 'Failed to load document settings' }, { status: 500 }); } } @@ -161,7 +162,7 @@ export async function PUT(req: NextRequest, ctx: { params: Promise<{ id: string applied: true, }); } catch (error) { - console.error('Error updating document settings:', error); + serverLogger.error({ err: error }, 'Error updating 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 3049db4..b8c183d 100644 --- a/src/app/api/documents/blob/get/fallback/route.ts +++ b/src/app/api/documents/blob/get/fallback/route.ts @@ -7,6 +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'; export const dynamic = 'force-dynamic'; @@ -44,7 +45,7 @@ export async function GET(req: NextRequest) { return NextResponse.json({ error: 'Invalid id' }, { status: 400 }); } - console.info('[blob-fallback] download proxy used', { id }); + serverLogger.info({ id }, '[blob-fallback] download proxy used'); const rows = (await db .select({ id: documents.id, userId: documents.userId, name: documents.name }) @@ -81,7 +82,7 @@ export async function GET(req: NextRequest) { throw error; } } catch (error) { - console.error('Error loading document content fallback:', error); + serverLogger.error({ err: error }, 'Error loading 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 a63753e..ae2dc9b 100644 --- a/src/app/api/documents/blob/get/presign/route.ts +++ b/src/app/api/documents/blob/get/presign/route.ts @@ -6,6 +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'; export const dynamic = 'force-dynamic'; @@ -50,7 +51,7 @@ 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) { - console.warn('[blob-fallback] presign download unavailable, redirecting to proxy fallback', { id: doc.id }); + serverLogger.warn({ id: doc.id }, '[blob-fallback] presign download unavailable, redirecting to proxy fallback'); return NextResponse.redirect(fallbackUrl, { status: 307, headers: { 'Cache-Control': 'no-store' }, @@ -62,7 +63,7 @@ export async function GET(req: NextRequest) { headers: { 'Cache-Control': 'no-store' }, }); } catch (error) { - console.error('Error creating document download signature:', error); + serverLogger.error({ err: error }, 'Error creating 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 186ee98..1c5a4cb 100644 --- a/src/app/api/documents/blob/preview/ensure/route.ts +++ b/src/app/api/documents/blob/preview/ensure/route.ts @@ -2,6 +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'; export const dynamic = 'force-dynamic'; @@ -50,7 +51,7 @@ export async function GET(req: NextRequest) { }, ); } catch (error) { - console.error('Error ensuring document preview:', error); + serverLogger.error({ err: error }, 'Error ensuring 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 44fc4dd..8496e8a 100644 --- a/src/app/api/documents/blob/preview/fallback/route.ts +++ b/src/app/api/documents/blob/preview/fallback/route.ts @@ -3,6 +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 { getDocumentRange, isMissingBlobError as isMissingDocumentBlobError, @@ -65,10 +66,10 @@ export async function GET(req: NextRequest) { return NextResponse.json({ error: 'Invalid id' }, { status: 400 }); } - console.info('[blob-fallback] preview proxy used', { + serverLogger.info({ id, snippetRequested, - }); + }, '[blob-fallback] preview proxy used'); const rows = (await db .select({ @@ -175,7 +176,7 @@ export async function GET(req: NextRequest) { throw error; } } catch (error) { - console.error('Error loading document preview fallback:', error); + serverLogger.error({ err: error }, 'Error loading 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 26ed7e8..8061eab 100644 --- a/src/app/api/documents/blob/preview/presign/route.ts +++ b/src/app/api/documents/blob/preview/presign/route.ts @@ -2,6 +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'; export const dynamic = 'force-dynamic'; @@ -37,7 +38,7 @@ export async function GET(req: NextRequest) { const directUrl = await presignDocumentPreviewGet(doc.id, testNamespace).catch(() => null); if (!directUrl) { - console.warn('[blob-fallback] presign preview unavailable, redirecting to proxy fallback', { id: doc.id }); + serverLogger.warn({ id: doc.id }, '[blob-fallback] presign preview unavailable, redirecting to proxy fallback'); return NextResponse.redirect(fallbackUrl, { status: 307, headers: { 'Cache-Control': 'no-store' }, @@ -49,7 +50,7 @@ export async function GET(req: NextRequest) { headers: { 'Cache-Control': 'no-store' }, }); } catch (error) { - console.error('Error creating document preview signature:', error); + serverLogger.error({ err: error }, 'Error creating 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 04a3105..f0764e3 100644 --- a/src/app/api/documents/blob/upload/fallback/route.ts +++ b/src/app/api/documents/blob/upload/fallback/route.ts @@ -3,6 +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'; export const dynamic = 'force-dynamic'; @@ -42,15 +43,15 @@ export async function PUT(req: NextRequest) { } } - console.info('[blob-fallback] upload proxy used', { + serverLogger.info({ id, contentType, bytes: body.byteLength, - }); + }, '[blob-fallback] upload proxy used'); return NextResponse.json({ success: true, id }); } catch (error) { - console.error('Error proxy-uploading document blob:', error); + serverLogger.error({ err: error }, 'Error proxy-uploading 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 9f66b7e..d6268d1 100644 --- a/src/app/api/documents/blob/upload/presign/route.ts +++ b/src/app/api/documents/blob/upload/presign/route.ts @@ -3,6 +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'; export const dynamic = 'force-dynamic'; @@ -65,7 +66,7 @@ export async function POST(req: NextRequest) { return NextResponse.json({ uploads: signed }); } catch (error) { - console.error('Error creating document upload signatures:', error); + serverLogger.error({ err: error }, 'Error creating 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 2aeeb7e..666596e 100644 --- a/src/app/api/documents/docx-to-pdf/upload/route.ts +++ b/src/app/api/documents/docx-to-pdf/upload/route.ts @@ -15,6 +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'; const DOCSTORE_DIR = path.join(process.cwd(), 'docstore'); const TEMP_DIR = path.join(DOCSTORE_DIR, 'tmp'); @@ -162,7 +163,7 @@ export async function POST(req: NextRequest) { }, testNamespace, ).catch((error) => { - console.error(`Failed to enqueue preview for converted DOCX ${id}:`, error); + serverLogger.error({ err: error }, `Failed to enqueue preview for converted DOCX ${id}:`); }); enqueueParsePdfJob({ @@ -184,7 +185,7 @@ export async function POST(req: NextRequest) { await rm(jobDir, { recursive: true, force: true }).catch(() => {}); } } catch (error) { - console.error('Error converting/uploading DOCX:', error); + serverLogger.error({ err: error }, 'Error 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 72741f0..a2f99dd 100644 --- a/src/app/api/documents/library/route.ts +++ b/src/app/api/documents/library/route.ts @@ -5,6 +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'; export const dynamic = 'force-dynamic'; @@ -111,7 +112,7 @@ export async function GET(req: NextRequest) { return NextResponse.json({ error: 'Unauthorized' }, { status: 401 }); } } catch (error) { - console.error('Error checking auth:', error); + serverLogger.error({ err: error }, 'Error checking auth:'); 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 433738c..aee4780 100644 --- a/src/app/api/documents/route.ts +++ b/src/app/api/documents/route.ts @@ -4,6 +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 { cleanupDocumentPreviewArtifacts, deleteDocumentPreviewRows, @@ -172,7 +173,7 @@ export async function POST(req: NextRequest) { }, testNamespace, ).catch((error) => { - console.error(`Failed to enqueue preview for document ${doc.id}:`, error); + serverLogger.error({ err: error }, `Failed to enqueue preview for document ${doc.id}:`); }); if (doc.type === 'pdf') { @@ -186,7 +187,7 @@ export async function POST(req: NextRequest) { return NextResponse.json({ success: true, stored }); } catch (error) { - console.error('Error registering documents:', error); + serverLogger.error({ err: error }, 'Error registering documents:'); return NextResponse.json({ error: 'Failed to register documents' }, { status: 500 }); } } @@ -262,7 +263,7 @@ export async function GET(req: NextRequest) { return NextResponse.json({ documents: results }); } catch (error) { - console.error('Error loading document metadata:', error); + serverLogger.error({ err: error }, 'Error loading document metadata:'); return NextResponse.json({ error: 'Failed to load documents' }, { status: 500 }); } } @@ -342,21 +343,21 @@ export async function DELETE(req: NextRequest) { await deleteDocumentBlob(id, testNamespace); } catch (error) { if (!isMissingBlobError(error)) { - console.error(`[best-effort] Failed to delete blob for document ${id}, orphaned blob may need manual cleanup:`, error); + serverLogger.error({ err: error }, `[best-effort] Failed to delete blob for document ${id}, orphaned blob may need manual cleanup:`); } } await cleanupDocumentPreviewArtifacts(id, testNamespace).catch((error) => { - console.error(`Failed to cleanup preview artifacts for document ${id}:`, error); + serverLogger.error({ err: error }, `Failed to cleanup preview artifacts for document ${id}:`); }); await deleteDocumentPreviewRows(id, testNamespace).catch((error) => { - console.error(`Failed to cleanup preview rows for document ${id}:`, error); + serverLogger.error({ err: error }, `Failed to cleanup preview rows for document ${id}:`); }); } return NextResponse.json({ success: true, deleted: deletedRows.length }); } catch (error) { - console.error('Error deleting documents:', error); + serverLogger.error({ err: error }, 'Error deleting 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 27015a1..58d7a6c 100644 --- a/src/app/api/rate-limit/status/route.ts +++ b/src/app/api/rate-limit/status/route.ts @@ -6,6 +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'; export const dynamic = 'force-dynamic'; @@ -84,7 +85,7 @@ export async function GET(req: NextRequest) { return response; } catch (error) { - console.error('Error getting rate limit status:', error); + serverLogger.error({ err: error }, 'Error getting 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 d658546..a32c822 100644 --- a/src/app/api/tts/segments/audio/fallback/route.ts +++ b/src/app/api/tts/segments/audio/fallback/route.ts @@ -7,10 +7,15 @@ import { ttsSegmentsS3NotConfiguredResponse, } from '@/lib/server/tts/segments-audio'; import { getTtsSegmentAudioObjectStream } from '@/lib/server/tts/segments-blobstore'; +import { createRequestLogger, errorToLog } from '@/lib/server/logger'; export const dynamic = 'force-dynamic'; export async function GET(request: NextRequest) { + const { logger } = createRequestLogger({ + route: '/api/tts/segments/audio/fallback', + request, + }); try { if (!isS3Configured()) return ttsSegmentsS3NotConfiguredResponse(); @@ -45,7 +50,10 @@ export async function GET(request: NextRequest) { headers, }); } catch (error) { - console.error('Error serving TTS segment audio fallback:', error); + logger.error({ + event: 'tts.segments.audio_fallback_failed', + error: errorToLog(error), + }); 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 642c62c..2e45536 100644 --- a/src/app/api/tts/segments/clear/route.ts +++ b/src/app/api/tts/segments/clear/route.ts @@ -1,6 +1,7 @@ import { NextRequest, NextResponse } from 'next/server'; import { resolveSegmentDocumentScope } from '@/lib/server/tts/segments-auth'; import { clearTtsSegmentCache } from '@/lib/server/tts/segments-cache'; +import { createRequestLogger, errorToLog } from '@/lib/server/logger'; export const runtime = 'nodejs'; export const dynamic = 'force-dynamic'; @@ -13,6 +14,10 @@ function parseBody(value: unknown): { documentId: string } | null { } export async function POST(request: NextRequest) { + const { logger } = createRequestLogger({ + route: '/api/tts/segments/clear', + request, + }); try { const parsed = parseBody(await request.json().catch(() => null)); if (!parsed) { @@ -34,7 +39,10 @@ export async function POST(request: NextRequest) { ...cleared, }); } catch (error) { - console.error('Error clearing TTS segment cache:', error); + logger.error({ + event: 'tts.segments.clear_failed', + error: errorToLog(error), + }); 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 a3bab48..32f961a 100644 --- a/src/app/api/tts/segments/ensure/route.ts +++ b/src/app/api/tts/segments/ensure/route.ts @@ -1,5 +1,4 @@ import { NextRequest, NextResponse } from 'next/server'; -import { randomUUID } from 'node:crypto'; import { and, eq, inArray } from 'drizzle-orm'; import { db } from '@/db'; import { ttsSegmentEntries, ttsSegmentVariants } from '@/db/schema'; @@ -35,6 +34,7 @@ import { userWhisperAlignJob } from '@/lib/server/jobs/user-whisper-align-job'; import { getResolvedRuntimeConfig } from '@/lib/server/runtime-config'; import { resolveTtsModelForProvider } from '@/lib/shared/tts-provider-policy'; import { resolveSegmentAudioUrls } from '@/lib/server/tts/segment-audio-urls'; +import { createRequestLogger, errorToLog } from '@/lib/server/logger'; import type { TTSSegmentInput, TTSSegmentManifestItem, @@ -152,7 +152,10 @@ async function deleteEntryIfUnused(userId: string, segmentEntryId: string): Prom export async function POST(request: NextRequest) { let didCreateDeviceIdCookie = false; let deviceIdToSet: string | null = null; - const requestId = randomUUID(); + const { logger, requestId } = createRequestLogger({ + route: '/api/tts/segments/ensure', + request, + }); const requestStartedAt = Date.now(); try { if (!isS3Configured()) return s3NotConfiguredResponse(); @@ -326,7 +329,8 @@ export async function POST(request: NextRequest) { for (const segment of normalized) { if (request.signal.aborted) { - console.info('[tts-segments/ensure] request aborted; stopping remaining segment processing', { + logger.info({ + event: 'tts.segments.ensure.request_aborted', requestId, documentId: parsed.documentId, completedSoFar: manifest.length, @@ -412,9 +416,11 @@ export async function POST(request: NextRequest) { } } catch (alignError) { const aborted = isAbortLikeError(alignError) || request.signal.aborted; - const log = aborted ? console.info : console.warn; - log('Whisper alignment still unavailable for completed segment; continuing without word highlights.', { + const level = aborted ? 'info' : 'warn'; + logger[level]({ + event: 'tts.segments.ensure.self_heal_alignment_unavailable', requestId, + documentId: parsed.documentId, segmentId: segment.segmentId, aborted, error: alignError instanceof Error ? alignError.message : String(alignError), @@ -652,9 +658,11 @@ export async function POST(request: NextRequest) { stageTimings.whisperAlignMs = Date.now() - alignStartedAt; } catch (alignError) { const aborted = isAbortLikeError(alignError) || request.signal.aborted; - const log = aborted ? console.info : console.warn; - log('Whisper alignment unavailable for segment; continuing without word highlights.', { + const level = aborted ? 'info' : 'warn'; + logger[level]({ + event: 'tts.segments.ensure.alignment_unavailable', requestId, + documentId: parsed.documentId, segmentId: segment.segmentId, aborted, error: alignError instanceof Error ? alignError.message : String(alignError), @@ -711,8 +719,9 @@ export async function POST(request: NextRequest) { : upstreamStatus && upstreamStatus >= 500 ? 'UPSTREAM_TTS_ERROR' : 'TTS_SEGMENT_GENERATION_FAILED'; - const segmentFailureLog = aborted ? console.info : console.error; - segmentFailureLog('[tts-segments/ensure] segment failed', { + const level = aborted ? 'info' : 'error'; + logger[level]({ + event: 'tts.segments.ensure.segment_failed', requestId, documentId: parsed.documentId, segmentId: segment.segmentId, @@ -762,7 +771,8 @@ export async function POST(request: NextRequest) { }); if (aborted || request.signal.aborted) { - console.info('[tts-segments/ensure] stopping remaining segments after abort', { + logger.info({ + event: 'tts.segments.ensure.stop_after_abort', requestId, documentId: parsed.documentId, segmentId: segment.segmentId, @@ -778,7 +788,8 @@ export async function POST(request: NextRequest) { const pendingCount = manifest.filter((s) => s.status === 'pending').length; const errorItems = manifest.filter((s) => s.status === 'error'); if (errorItems.length > 0) { - console.error('[tts-segments/ensure] partial result', { + logger.error({ + event: 'tts.segments.ensure.partial_result', requestId, documentId: parsed.documentId, total: manifest.length, @@ -803,7 +814,10 @@ export async function POST(request: NextRequest) { attachDeviceIdCookie(response, deviceIdToSet, didCreateDeviceIdCookie); return response; } catch (error) { - console.error('Error ensuring TTS segments:', error); + logger.error({ + event: 'tts.segments.ensure.route_failed', + error: errorToLog(error), + }); 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 313a8ec..cd5415c 100644 --- a/src/app/api/tts/segments/manifest/route.ts +++ b/src/app/api/tts/segments/manifest/route.ts @@ -20,6 +20,7 @@ import type { import { isTtsProviderType } from '@/lib/shared/tts-provider-catalog'; import { resolveEffectiveProviderType } from '@/lib/shared/tts-provider-policy'; import { resolveSegmentAudioUrls } from '@/lib/server/tts/segment-audio-urls'; +import { createRequestLogger, errorToLog } from '@/lib/server/logger'; export const runtime = 'nodejs'; export const dynamic = 'force-dynamic'; @@ -178,6 +179,10 @@ function cursorFromGroupRow(row: ManifestGroupRow): TTSSegmentManifestCursor { } export async function GET(request: NextRequest) { + const { logger } = createRequestLogger({ + route: '/api/tts/segments/manifest', + request, + }); try { const documentIdRaw = request.nextUrl.searchParams.get('documentId'); const documentId = documentIdRaw?.trim().toLowerCase(); @@ -381,7 +386,10 @@ export async function GET(request: NextRequest) { }; return NextResponse.json(response); } catch (error) { - console.error('Error listing TTS segments manifest:', error); + logger.error({ + event: 'tts.segments.manifest.list_failed', + error: errorToLog(error), + }); 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 1b8bb28..6be24bd 100644 --- a/src/app/api/tts/shared-providers/route.ts +++ b/src/app/api/tts/shared-providers/route.ts @@ -2,6 +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'; export const dynamic = 'force-dynamic'; @@ -23,7 +24,7 @@ export async function GET(req: NextRequest) { const visible = all.filter((p) => p.enabled).map(toPublic); return NextResponse.json({ providers: visible }); } catch (error) { - console.warn('[tts/shared-providers] list failed:', error); + serverLogger.warn({ err: error }, '[tts/shared-providers] list failed:'); return NextResponse.json({ providers: [] }); } } diff --git a/src/app/api/tts/voices/route.ts b/src/app/api/tts/voices/route.ts index e0cee34..28e9233 100644 --- a/src/app/api/tts/voices/route.ts +++ b/src/app/api/tts/voices/route.ts @@ -5,6 +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'; export async function GET(req: NextRequest) { try { @@ -61,7 +62,7 @@ export async function GET(req: NextRequest) { }); return NextResponse.json({ voices }); } catch (error) { - console.error('Error in voices endpoint:', error); + serverLogger.error({ err: error }, 'Error in voices endpoint:'); 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 c958c90..496148a 100644 --- a/src/app/api/user/claim/route.ts +++ b/src/app/api/user/claim/route.ts @@ -5,6 +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'; async function checkClaimMigrationReadiness(): Promise { const [legacyRows] = await db @@ -56,7 +57,7 @@ export async function GET(req: NextRequest) { const counts = await getClaimableCounts(unclaimedUserId); return NextResponse.json({ success: true, ...counts }); } catch (error) { - console.error('Error checking claimable data:', error); + serverLogger.error({ err: error }, 'Error checking claimable data:'); return NextResponse.json({ error: 'Internal Server Error' }, { status: 500 }); } } @@ -83,7 +84,7 @@ export async function POST(req: NextRequest) { }); } catch (error) { - console.error('Error claiming data:', error); + serverLogger.error({ err: error }, 'Error claiming 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 d68dd50..2499c79 100644 --- a/src/app/api/user/export/route.ts +++ b/src/app/api/user/export/route.ts @@ -11,6 +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'; export const dynamic = 'force-dynamic'; @@ -77,7 +78,7 @@ export async function GET(req: NextRequest) { archive.on('warning', (warning) => { if ((warning as NodeJS.ErrnoException).code !== 'ENOENT') { - console.error('User export warning:', warning); + serverLogger.error({ err: warning }, 'User export warning:'); } }); @@ -129,7 +130,7 @@ export async function GET(req: NextRequest) { await archive.finalize(); } } catch (error) { - console.error('Export generation failed:', error); + serverLogger.error({ err: 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 e4b4e0c..b97e724 100644 --- a/src/app/api/user/state/changelog/version-check/route.ts +++ b/src/app/api/user/state/changelog/version-check/route.ts @@ -5,6 +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 { deserializeUserPreferencesPayload, extractUserPreferencesMeta, @@ -80,7 +81,7 @@ export async function POST(req: NextRequest) { lastSeenVersion, }); } catch (error) { - console.error('Error checking changelog version:', error); + serverLogger.error({ err: error }, 'Error checking 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 34c5e54..e3ff630 100644 --- a/src/app/api/user/state/preferences/route.ts +++ b/src/app/api/user/state/preferences/route.ts @@ -9,6 +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 { deserializeUserPreferencesPayload, extractUserPreferencesMeta, @@ -241,7 +242,7 @@ export async function GET(req: NextRequest) { hasStoredPreferences: Boolean(row), }); } catch (error) { - console.error('Error loading user preferences:', error); + serverLogger.error({ err: error }, 'Error loading user preferences:'); return NextResponse.json({ error: 'Failed to load user preferences' }, { status: 500 }); } } @@ -315,7 +316,7 @@ export async function PUT(req: NextRequest) { applied: true, }); } catch (error) { - console.error('Error updating user preferences:', error); + serverLogger.error({ err: error }, 'Error updating 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 f34953e..d2e2acb 100644 --- a/src/app/api/user/state/progress/route.ts +++ b/src/app/api/user/state/progress/route.ts @@ -6,6 +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'; export const dynamic = 'force-dynamic'; @@ -62,7 +63,7 @@ export async function GET(req: NextRequest) { }, }); } catch (error) { - console.error('Error loading user progress:', error); + serverLogger.error({ err: error }, 'Error loading user progress:'); return NextResponse.json({ error: 'Failed to load user progress' }, { status: 500 }); } } @@ -172,7 +173,7 @@ export async function PUT(req: NextRequest) { applied: true, }); } catch (error) { - console.error('Error updating user progress:', error); + serverLogger.error({ err: error }, 'Error updating 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 584a015..6a179bc 100644 --- a/src/lib/server/admin/email-sync.ts +++ b/src/lib/server/admin/email-sync.ts @@ -1,5 +1,6 @@ import { eq } from 'drizzle-orm'; import { db } from '@/db'; +import { 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. @@ -60,7 +61,7 @@ export async function syncAdminFlag( await db.update(user).set({ isAdmin: shouldBeAdmin }).where(eq(user.id, userId)); return shouldBeAdmin; } catch (error) { - console.warn('[admin] Failed to sync isAdmin flag for user', userId, error); + serverLogger.warn({ userId: userId, err: error }, '[admin] 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 7cbc2cc..3a4efc8 100644 --- a/src/lib/server/admin/seed.ts +++ b/src/lib/server/admin/seed.ts @@ -3,6 +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 { RUNTIME_CONFIG_SCHEMA, seedRuntimeConfigFromEnv, @@ -30,7 +31,7 @@ let seedPromise: Promise | null = null; export async function ensureAdminSeed(): Promise { if (!seedPromise) { seedPromise = runSeed().catch((error) => { - console.warn('[admin-seed] failed:', error); + serverLogger.warn({ err: error }, '[admin-seed] failed:'); // Reset so a subsequent call can retry (e.g. once migrations run). seedPromise = null; throw error; @@ -58,7 +59,7 @@ async function seedDefaultAdminProvider(): Promise { try { existing = await db.select({ id: adminProviders.id }).from(adminProviders).limit(1); } catch (error) { - console.warn('[admin-seed] could not check admin_providers (table missing?)', error); + serverLogger.warn({ err: error }, '[admin-seed] could not check admin_providers (table missing?)'); return; } if (existing.length > 0) return; @@ -85,17 +86,14 @@ async function seedDefaultAdminProvider(): Promise { updatedAt: now, }) .onConflictDoNothing({ target: adminSettings.key }); - console.warn( + serverLogger.warn( '[admin-seed] API_KEY present but AUTH_SECRET missing; defaulting restrictUserApiKeys=false so BYOK remains available', ); } catch (fallbackError) { - console.warn( - '[admin-seed] failed to write restrictUserApiKeys fallback after encryption failure', - fallbackError, - ); + serverLogger.warn({ err: fallbackError }, '[admin-seed] failed to write restrictUserApiKeys fallback after encryption failure'); } } - console.warn('[admin-seed] failed to encrypt default provider API key', error); + serverLogger.warn({ err: error }, '[admin-seed] failed to encrypt default provider API key'); return; } @@ -114,9 +112,9 @@ async function seedDefaultAdminProvider(): Promise { createdAt: now, updatedAt: now, }); - console.log('[admin-seed] created default-openai admin provider from env'); + serverLogger.info('[admin-seed] created default-openai admin provider from env'); } catch (error) { - console.warn('[admin-seed] failed to insert default-openai provider', error); + serverLogger.warn({ err: error }, '[admin-seed] failed to insert default-openai provider'); } } @@ -140,7 +138,7 @@ async function cleanupLegacyDefaultTtsProviderSeedRow(): Promise { ), ); } catch (error) { - console.warn('[admin-seed] failed to cleanup legacy defaultTtsProvider seed row', error); + serverLogger.warn({ err: error }, '[admin-seed] failed to cleanup legacy defaultTtsProvider seed row'); } } @@ -150,6 +148,6 @@ async function cleanupLegacyDefaultTtsModelRows(): Promise { .delete(adminSettings) .where(eq(adminSettings.key, 'defaultTtsModel')); } catch (error) { - console.warn('[admin-seed] failed to cleanup legacy defaultTtsModel rows', error); + serverLogger.warn({ err: error }, '[admin-seed] failed to cleanup legacy defaultTtsModel rows'); } } diff --git a/src/lib/server/admin/settings.ts b/src/lib/server/admin/settings.ts index eb2a77f..04eeab6 100644 --- a/src/lib/server/admin/settings.ts +++ b/src/lib/server/admin/settings.ts @@ -2,6 +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'; /** * Runtime config: site-wide settings that used to live in build-time env vars. @@ -113,7 +114,7 @@ async function resolveImplicitDefaultTtsProvider(): Promise .limit(1); return rows[0]?.slug; } catch (error) { - console.warn('[runtime-config] implicit defaultTtsProvider lookup failed:', error); + serverLogger.warn({ err: error }, '[runtime-config] implicit defaultTtsProvider lookup failed:'); return undefined; } } @@ -141,7 +142,7 @@ 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 - console.log("Password reset requested for:", data.user.email); + serverLogger.info({ err: data.user.email }, "Password reset requested for:"); }, }, user: { @@ -90,7 +91,7 @@ const createAuth = () => betterAuth({ const { deleteUserStorageData } = await import('@/lib/server/user/data-cleanup'); await deleteUserStorageData(user.id, null); } catch (error) { - console.error('[auth] Failed to clean up user storage before deletion:', error); + serverLogger.error({ err: error }, '[auth] 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. } @@ -145,11 +146,11 @@ const createAuth = () => betterAuth({ onLinkAccount: async ({ anonymousUser, newUser }) => { try { // Log when anonymous user links to a real account - console.log("Anonymous user linked to account:", { + serverLogger.info({ anonymousUserId: anonymousUser.user.id, newUserId: newUser.user.id, newUserEmail: newUser.user.email, - }); + }, "Anonymous user linked to account:"); // Lazy-load heavy modules only when account linking actually happens const [{ rateLimiter }, claimData] = await Promise.all([ @@ -160,9 +161,9 @@ 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); - console.log(`Successfully transferred rate limit data from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info(`Successfully transferred rate limit data from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); } catch (error) { - console.error("Error transferring rate limit data during account linking:", error); + serverLogger.error({ err: error }, "Error transferring rate limit data during account linking:"); // Don't throw here to prevent blocking the account linking process } @@ -170,10 +171,10 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserAudiobooks(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - console.log(`Successfully transferred ${transferred} audiobook(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info(`Successfully transferred ${transferred} audiobook(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); } } catch (error) { - console.error("Error transferring audiobooks during account linking:", error); + serverLogger.error({ err: error }, "Error transferring audiobooks during account linking:"); // Don't throw here to prevent blocking the account linking process } @@ -181,10 +182,10 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserDocuments(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - console.log(`Successfully transferred ${transferred} document(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info(`Successfully transferred ${transferred} document(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); } } catch (error) { - console.error("Error transferring documents during account linking:", error); + serverLogger.error({ err: error }, "Error transferring documents during account linking:"); // Don't throw here to prevent blocking the account linking process } @@ -192,10 +193,10 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserPreferences(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - console.log(`Successfully transferred preferences from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info(`Successfully transferred preferences from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); } } catch (error) { - console.error("Error transferring preferences during account linking:", error); + serverLogger.error({ err: error }, "Error transferring preferences during account linking:"); // Don't throw here to prevent blocking the account linking process } @@ -203,14 +204,14 @@ const createAuth = () => betterAuth({ try { const transferred = await claimData.transferUserProgress(anonymousUser.user.id, newUser.user.id); if (transferred > 0) { - console.log(`Successfully transferred ${transferred} progress row(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); + serverLogger.info(`Successfully transferred ${transferred} progress row(s) from anonymous user ${anonymousUser.user.id} to user ${newUser.user.id}`); } } catch (error) { - console.error("Error transferring reading progress during account linking:", error); + serverLogger.error({ err: error }, "Error transferring reading progress during account linking:"); // Don't throw here to prevent blocking the account linking process } } catch (error) { - console.error("Error in onLinkAccount callback:", error); + serverLogger.error({ err: error }, "Error in onLinkAccount callback:"); // 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 e1c76b6..a27318d 100644 --- a/src/lib/server/compute/worker-op-state.ts +++ b/src/lib/server/compute/worker-op-state.ts @@ -1,5 +1,6 @@ import { getWorkerClientConfigFromEnv } from '@/lib/server/compute/worker'; import type { WorkerOperationState } from '@openreader/compute-core/api-contracts'; +import { serverLogger } from '@/lib/server/logger'; const WORKER_OP_REQUEST_TIMEOUT_MS = 2_500; @@ -13,10 +14,10 @@ export async function fetchWorkerOperationState( try { cfg = getWorkerClientConfigFromEnv(); } catch (error) { - console.warn('[worker-op-state] worker client env missing/invalid', { + serverLogger.warn({ opId: normalized, error: error instanceof Error ? error.message : String(error), - }); + }, '[worker-op-state] worker client env missing/invalid'); return null; } @@ -36,26 +37,26 @@ export async function fetchWorkerOperationState( if (!res.ok) { const detail = await res.text().catch(() => ''); - console.warn('[worker-op-state] worker op request failed', { + serverLogger.warn({ opId: normalized, status: res.status, detail, - }); + }, '[worker-op-state] worker op request failed'); return null; } const parsed = await res.json() as WorkerOperationState; if (!parsed || typeof parsed !== 'object' || parsed.opId !== normalized) { - console.warn('[worker-op-state] worker op response invalid', { + serverLogger.warn({ opId: normalized, - }); + }, '[worker-op-state] worker op response invalid'); return null; } return parsed; } catch (error) { - console.warn('[worker-op-state] worker op request threw', { + serverLogger.warn({ opId: normalized, error: error instanceof Error ? error.message : String(error), - }); + }, '[worker-op-state] 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 3f4dcf5..2885e20 100644 --- a/src/lib/server/compute/worker.ts +++ b/src/lib/server/compute/worker.ts @@ -2,6 +2,7 @@ import { createHash, randomUUID } from 'node:crypto'; import type { ComputeBackend, PdfLayoutInput, WhisperAlignInput, WhisperAlignResult } from '@/lib/server/compute/types'; import { parseSseEventId, parseSsePayload } from '@openreader/compute-core'; import { getWorkerClientWaitTimeoutMs } from '@openreader/compute-core'; +import { serverLogger } from '@/lib/server/logger'; import type { PdfLayoutJobRequest, PdfLayoutJobResult, @@ -70,14 +71,14 @@ function logWorker(level: WorkerLogLevel, event: string, fields: Record { diff --git a/src/lib/server/documents/previews.ts b/src/lib/server/documents/previews.ts index 9e7000a..a84a1ed 100644 --- a/src/lib/server/documents/previews.ts +++ b/src/lib/server/documents/previews.ts @@ -2,6 +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 { DOCUMENT_PREVIEW_CONTENT_TYPE, DOCUMENT_PREVIEW_VARIANT, @@ -374,7 +375,7 @@ export async function ensureDocumentPreview(doc: PreviewSourceDocument, namespac eTag: head.eTag, }); } catch (error) { - console.error(`[document-previews] Preview generation failed for ${doc.id} (type=${doc.type}):`, error); + serverLogger.error({ err: error }, `[document-previews] Preview generation failed for ${doc.id} (type=${doc.type}):`); 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 348a9ec..e970e03 100644 --- a/src/lib/server/jobs/user-pdf-layout-job.ts +++ b/src/lib/server/jobs/user-pdf-layout-job.ts @@ -2,6 +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 { parseDocumentParseState, stringifyDocumentParseState, @@ -348,18 +349,18 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise readerType: 'pdf', }).then((cleared) => { if (cleared.warning) { - console.warn('[parsePdfJob] cache invalidation warning', { + serverLogger.warn({ documentId: input.documentId, userId, warning: cleared.warning, - }); + }, '[parsePdfJob] cache invalidation warning'); } }).catch((cacheError) => { - console.warn('[parsePdfJob] cache invalidation failed', { + serverLogger.warn({ documentId: input.documentId, userId, error: cacheError instanceof Error ? cacheError.message : String(cacheError), - }); + }, '[parsePdfJob] cache invalidation failed'); }); } } catch (error) { @@ -383,19 +384,19 @@ export async function parsePdfJob(input: UserPdfLayoutJobRequest): Promise parseState: stringifyDocumentParseState(failedState), }); } catch (statusError) { - console.error('[parsePdfJob] failed to write parse status', { + serverLogger.error({ documentId: input.documentId, parseStatus, error: statusError instanceof Error ? statusError.message : String(statusError), - }); + }, '[parsePdfJob] failed to write parse status'); } - console.error('[parsePdfJob] failed', { + serverLogger.error({ documentId: input.documentId, parseStatus, error: message, ...(stack ? { stack } : {}), ...(cause ? { cause: String(cause) } : {}), - }); + }, '[parsePdfJob] failed'); } finally { running.delete(key); } @@ -405,6 +406,6 @@ export function enqueueParsePdfJob(input: UserPdfLayoutJobRequest): void { Promise.resolve() .then(() => parsePdfJob(input)) .catch((error) => { - console.error('[parsePdfJob] uncaught error', error); + serverLogger.error({ err: error }, '[parsePdfJob] uncaught error'); }); } diff --git a/src/lib/server/logger.ts b/src/lib/server/logger.ts new file mode 100644 index 0000000..ae1b8da --- /dev/null +++ b/src/lib/server/logger.ts @@ -0,0 +1,78 @@ +import { createHash, randomUUID } from 'node:crypto'; +import type { NextRequest } from 'next/server'; +import pino, { type Logger } from 'pino'; +import pinoPretty from 'pino-pretty'; + +export type ServerLogger = Logger; + +const LOG_FORMAT = process.env.LOG_FORMAT?.trim().toLowerCase() || 'pretty'; +const LOG_LEVEL = process.env.LOG_LEVEL?.trim() || 'info'; + +function buildLoggerConfig(): pino.LoggerOptions { + return { + level: LOG_LEVEL, + base: undefined, + timestamp: pino.stdTimeFunctions.isoTime, + formatters: { + level(label) { + return { level: label }; + }, + }, + }; +} + +function createServerLogger(): ServerLogger { + const config = buildLoggerConfig(); + if (LOG_FORMAT === 'json') { + return pino(config); + } + + const prettyStream = pinoPretty({ + colorize: true, + translateTime: 'SYS:standard', + ignore: 'pid,hostname', + }); + return pino(config, prettyStream); +} + +export const serverLogger: ServerLogger = createServerLogger(); + +export function errorToLog(error: unknown): Record { + if (error instanceof Error) { + return { + name: error.name, + message: error.message, + stack: error.stack, + }; + } + return { message: String(error) }; +} + +export function hashForLog(value: string | null | undefined): string | null { + const normalized = typeof value === 'string' ? value.trim() : ''; + if (!normalized) return null; + return createHash('sha256').update(normalized).digest('hex').slice(0, 12); +} + +export function getRequestId(request: NextRequest): string { + const fromHeader = request.headers.get('x-request-id') + || request.headers.get('x-vercel-id'); + const normalized = fromHeader?.trim(); + return normalized || randomUUID(); +} + +export function createRequestLogger(input: { + route: string; + request: NextRequest; + requestId?: string; + fields?: Record; +}): { logger: ServerLogger; requestId: string } { + const requestId = input.requestId || getRequestId(input.request); + const logger = serverLogger.child({ + route: input.route, + method: input.request.method, + requestId, + ...(input.fields || {}), + }); + return { logger, requestId }; +} diff --git a/src/lib/server/rate-limit/rate-limiter.ts b/src/lib/server/rate-limit/rate-limiter.ts index cf96e47..48f2dab 100644 --- a/src/lib/server/rate-limit/rate-limiter.ts +++ b/src/lib/server/rate-limit/rate-limiter.ts @@ -3,6 +3,7 @@ import { userTtsChars } from '@/db/schema'; import { isAuthEnabled } from '@/lib/server/auth/config'; import { eq, and, lt, sql } from 'drizzle-orm'; import { nextUtcMidnightTimestampMs, nowTimestampMs } from '@/lib/shared/timestamps'; +import { serverLogger } from '@/lib/server/logger'; function readPositiveIntEnv(name: string, fallback: number): number { const raw = process.env[name]; @@ -10,7 +11,7 @@ function readPositiveIntEnv(name: string, fallback: number): number { const parsed = Number(raw); if (!Number.isFinite(parsed) || parsed <= 0) { - console.warn(`[rate-limiter] Invalid ${name}=${raw}; using default ${fallback}`); + serverLogger.warn(`[rate-limiter] Invalid ${name}=${raw}; using default ${fallback}`); return fallback; } diff --git a/src/lib/server/tts/segments-cache.ts b/src/lib/server/tts/segments-cache.ts index d893f5c..fa271af 100644 --- a/src/lib/server/tts/segments-cache.ts +++ b/src/lib/server/tts/segments-cache.ts @@ -3,6 +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'; type ClearTtsSegmentCacheInput = { userId: string; @@ -65,11 +66,11 @@ export async function clearTtsSegmentCache( } } catch (error) { warning = error instanceof Error ? error.message : 'Failed deleting some audio objects'; - console.warn('Failed clearing some TTS segment audio objects:', { + serverLogger.warn({ documentId: input.documentId, userId: input.userId, error: warning, - }); + }, '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 be936c7..52ea085 100644 --- a/src/lib/server/tts/voice-resolution.ts +++ b/src/lib/server/tts/voice-resolution.ts @@ -1,4 +1,5 @@ import { LRUCache } from 'lru-cache'; +import { serverLogger } from '@/lib/server/logger'; import { resolveProviderModels, type ReplicateVoiceInputKey, @@ -192,7 +193,7 @@ async function fetchReplicateOpenApiSchema(apiKey: string, model: string): Promi if (error instanceof DOMException && error.name === 'AbortError') { return null; } - console.error('Error fetching Replicate model schema:', error); + serverLogger.error({ err: error }, 'Error fetching Replicate model schema:'); return null; } finally { clearTimeout(timeoutId); @@ -283,7 +284,7 @@ async function fetchDeepinfraVoices(apiKey: string): Promise { if (error instanceof DOMException && error.name === 'AbortError') { return []; } - console.error('Error fetching Deepinfra voices:', error); + serverLogger.error({ err: error }, 'Error fetching Deepinfra voices:'); return []; } finally { clearTimeout(timeoutId); @@ -315,7 +316,7 @@ async function fetchCustomOpenAiVoices(baseUrl: string, apiKey: string): Promise ? data.voices : null; } catch { - console.log('Custom endpoint does not support voices, using defaults'); + serverLogger.info('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 29e39e1..c17c66c 100644 --- a/src/lib/server/user/data-cleanup.ts +++ b/src/lib/server/user/data-cleanup.ts @@ -13,6 +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'; type DocumentRow = { id: string }; type AudiobookRow = { id: string }; @@ -49,13 +50,13 @@ export async function deleteUserStorageData( await deleteDocumentBlob(doc.id, namespace); docsDeleted++; } catch (error) { - console.error(`[user-data-cleanup] Failed to delete document blob ${doc.id}:`, error); + serverLogger.error({ err: error }, `[user-data-cleanup] Failed to delete document blob ${doc.id}:`); } try { await deleteDocumentPreviewArtifacts(doc.id, namespace); } catch (error) { - console.error(`[user-data-cleanup] Failed to delete preview for ${doc.id}:`, error); + serverLogger.error({ err: error }, `[user-data-cleanup] Failed to delete preview for ${doc.id}:`); } } @@ -63,7 +64,7 @@ export async function deleteUserStorageData( try { await deleteDocumentPreviewRows(doc.id, namespace); } catch (error) { - console.error(`[user-data-cleanup] Failed to delete preview rows for ${doc.id}:`, error); + serverLogger.error({ err: error }, `[user-data-cleanup] Failed to delete preview rows for ${doc.id}:`); } } @@ -82,7 +83,7 @@ export async function deleteUserStorageData( await deleteAudiobookPrefix(prefix); booksDeleted++; } catch (error) { - console.error(`[user-data-cleanup] Failed to delete audiobook blobs ${book.id}:`, error); + serverLogger.error({ err: error }, `[user-data-cleanup] Failed to delete audiobook blobs ${book.id}:`); } } @@ -97,12 +98,12 @@ export async function deleteUserStorageData( segmentsDeleted += await deleteTtsSegmentPrefix(ttsPrefixV1); segmentsDeleted += await deleteTtsSegmentPrefix(ttsPrefixV2); } catch (error) { - console.error(`[user-data-cleanup] Failed to delete TTS segment blobs for user ${userId}:`, error); + serverLogger.error({ err: error }, `[user-data-cleanup] Failed to delete TTS segment blobs for user ${userId}:`); } } if (docsDeleted > 0 || booksDeleted > 0 || segmentsDeleted > 0) { - console.log( + serverLogger.info( `[user-data-cleanup] Cleaned up S3 data for user ${userId}: ` + `${docsDeleted}/${userDocs.length} document(s), ` + `${booksDeleted}/${userBooks.length} audiobook(s), ` +