diff --git a/.env.example b/.env.example index 04a87ae..c1a0592 100644 --- a/.env.example +++ b/.env.example @@ -11,10 +11,18 @@ PGID=1000 PORT=3000 CORS_ORIGINS=http://localhost:4174 -LOG_LEVEL=info +LOG_LEVEL=warn # Levels: debug, info, warn, error, silent # Controls: backend Fastify logging, frontend nginx access logs (Docker), # and frontend browser console (via build-time injection) +# +# Behavior per level: +# debug — all app logs + all HTTP request logs (including polling endpoints) +# info — all app logs + HTTP request logs, EXCEPT high-frequency polling +# (GET /doses/taken, GET /share/:token/doses, GET /health are hidden) +# warn — only warnings and errors +# error — only errors +# silent — no logs # Rate limit: max requests per minute per IP (default: 100) # Increase for development/testing environments @@ -32,6 +40,9 @@ AUTH_ENABLED=false # Allow new user registrations (auto-enabled when no users exist) # REGISTRATION_ENABLED=false +# Disable username/password form login (useful for OIDC-only setups) +# FORM_LOGIN_ENABLED=true + # JWT Secrets - REQUIRED when AUTH_ENABLED=true # Generate with: openssl rand -hex 32 # JWT_SECRET= diff --git a/backend/package-lock.json b/backend/package-lock.json index cc296ea..7631048 100644 --- a/backend/package-lock.json +++ b/backend/package-lock.json @@ -33,6 +33,7 @@ "@types/supertest": "^6.0.2", "@vitest/coverage-v8": "^4.0.18", "drizzle-kit": "^0.31.9", + "pino-pretty": "^13.1.3", "supertest": "^7.2.2", "tsx": "^4.19.0", "typescript": "^5.5.4", @@ -3017,6 +3018,13 @@ "node": ">=18" } }, + "node_modules/colorette": { + "version": "2.0.20", + "resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz", + "integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==", + "dev": true, + "license": "MIT" + }, "node_modules/combined-stream": { "version": "1.0.8", "resolved": "https://registry.npmjs.org/combined-stream/-/combined-stream-1.0.8.tgz", @@ -3161,6 +3169,16 @@ "node": ">= 12" } }, + "node_modules/dateformat": { + "version": "4.6.3", + "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz", + "integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==", + "dev": true, + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/debug": { "version": "4.4.3", "resolved": "https://registry.npmjs.org/debug/-/debug-4.4.3.tgz", @@ -3888,6 +3906,16 @@ "safe-buffer": "^5.0.1" } }, + "node_modules/end-of-stream": { + "version": "1.4.5", + "resolved": "https://registry.npmjs.org/end-of-stream/-/end-of-stream-1.4.5.tgz", + "integrity": "sha512-ooEGc6HP26xXq/N+GCGOT0JKCLDGrq2bQUZrQ7gyrJiZANJ/8YDTxTpQBXGMn+WbIQXNVpyWymm7KYVICQnyOg==", + "dev": true, + "license": "MIT", + "dependencies": { + "once": "^1.4.0" + } + }, "node_modules/es-define-property": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/es-define-property/-/es-define-property-1.0.1.tgz", @@ -4025,6 +4053,13 @@ "node": ">=12.0.0" } }, + "node_modules/fast-copy": { + "version": "4.0.2", + "resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.0.2.tgz", + "integrity": "sha512-ybA6PDXIXOXivLJK/z9e+Otk7ve13I4ckBvGO5I2RRmBU1gMHLVDJYEuJYhGwez7YNlYji2M2DvVU+a9mSFDlw==", + "dev": true, + "license": "MIT" + }, "node_modules/fast-decode-uri-component": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/fast-decode-uri-component/-/fast-decode-uri-component-1.0.1.tgz", @@ -4500,6 +4535,13 @@ "node": ">=18.0.0" } }, + "node_modules/help-me": { + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz", + "integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==", + "dev": true, + "license": "MIT" + }, "node_modules/html-escaper": { "version": "2.0.2", "resolved": "https://registry.npmjs.org/html-escaper/-/html-escaper-2.0.2.tgz", @@ -4611,6 +4653,16 @@ "url": "https://github.com/sponsors/panva" } }, + "node_modules/joycon": { + "version": "3.1.1", + "resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz", + "integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/js-base64": { "version": "3.7.8", "resolved": "https://registry.npmjs.org/js-base64/-/js-base64-3.7.8.tgz", @@ -4852,6 +4904,16 @@ "url": "https://github.com/sponsors/isaacs" } }, + "node_modules/minimist": { + "version": "1.2.8", + "resolved": "https://registry.npmjs.org/minimist/-/minimist-1.2.8.tgz", + "integrity": "sha512-2yyAR8qBkN3YuheJanUpWC5U3bb5osDywNB8RzDVlDwDHbocAJveqqj1u8+SVD7jkWT4yvsHCpWqqWqAxb0zCA==", + "dev": true, + "license": "MIT", + "funding": { + "url": "https://github.com/sponsors/ljharb" + } + }, "node_modules/minipass": { "version": "7.1.2", "resolved": "https://registry.npmjs.org/minipass/-/minipass-7.1.2.tgz", @@ -5117,6 +5179,41 @@ "split2": "^4.0.0" } }, + "node_modules/pino-pretty": { + "version": "13.1.3", + "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.1.3.tgz", + "integrity": "sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==", + "dev": true, + "license": "MIT", + "dependencies": { + "colorette": "^2.0.7", + "dateformat": "^4.6.3", + "fast-copy": "^4.0.0", + "fast-safe-stringify": "^2.1.1", + "help-me": "^5.0.0", + "joycon": "^3.1.1", + "minimist": "^1.2.6", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pump": "^3.0.0", + "secure-json-parse": "^4.0.0", + "sonic-boom": "^4.0.1", + "strip-json-comments": "^5.0.2" + }, + "bin": { + "pino-pretty": "bin.js" + } + }, + "node_modules/pino-pretty/node_modules/pino-abstract-transport": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz", + "integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==", + "dev": true, + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, "node_modules/pino-std-serializers": { "version": "7.0.0", "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.0.0.tgz", @@ -5174,6 +5271,17 @@ "integrity": "sha512-7nJ6v5lnJsXwGprnGXga4wx6d1POjvi5Qmf1ivTRxTjH4Z/9Czja/UCMLVmB9N93GeWOU93XaFaEt6jbuoagNw==", "license": "ISC" }, + "node_modules/pump": { + "version": "3.0.3", + "resolved": "https://registry.npmjs.org/pump/-/pump-3.0.3.tgz", + "integrity": "sha512-todwxLMY7/heScKmntwQG8CXVkWUOdYxIvY2s0VWAAMh/nd8SoYiRaKjlr7+iCs984f2P8zvrfWcDDYVb73NfA==", + "dev": true, + "license": "MIT", + "dependencies": { + "end-of-stream": "^1.1.0", + "once": "^1.3.1" + } + }, "node_modules/qs": { "version": "6.14.2", "resolved": "https://registry.npmjs.org/qs/-/qs-6.14.2.tgz", @@ -5630,6 +5738,19 @@ "reusify": "^1.0.0" } }, + "node_modules/strip-json-comments": { + "version": "5.0.3", + "resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz", + "integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=14.16" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } + }, "node_modules/superagent": { "version": "10.3.0", "resolved": "https://registry.npmjs.org/superagent/-/superagent-10.3.0.tgz", diff --git a/backend/package.json b/backend/package.json index 301867b..782a804 100644 --- a/backend/package.json +++ b/backend/package.json @@ -42,6 +42,7 @@ "@types/supertest": "^6.0.2", "@vitest/coverage-v8": "^4.0.18", "drizzle-kit": "^0.31.9", + "pino-pretty": "^13.1.3", "supertest": "^7.2.2", "tsx": "^4.19.0", "typescript": "^5.5.4", diff --git a/backend/src/db/client.ts b/backend/src/db/client.ts index ba96ab4..94e7e15 100644 --- a/backend/src/db/client.ts +++ b/backend/src/db/client.ts @@ -78,10 +78,6 @@ async function runMigrations() { const migrateResult = await runDrizzleMigrations(db); if (!migrateResult.success) { log.error(`[DB] Migration error: ${migrateResult.error}`); - } else if (migrateResult.warning) { - log.warn(`[DB] Migration warning: ${migrateResult.warning}`); - } else { - log.debug(`[DB] Drizzle migrations completed`); } // Run ALTER TABLE migrations for backward compatibility diff --git a/backend/src/db/db-utils.ts b/backend/src/db/db-utils.ts index 277de07..67d230b 100644 --- a/backend/src/db/db-utils.ts +++ b/backend/src/db/db-utils.ts @@ -88,13 +88,12 @@ export async function runDrizzleMigrations( await migrate(database, { migrationsFolder }); return { success: true }; } catch (err: unknown) { - // If the error is about existing schema objects, the DB is already up-to-date - // This happens when ALTER migrations in client.ts have already added the columns, - // or when tables were created before drizzle migrations were introduced - if ((err as Error).message?.includes("duplicate column") || (err as Error).message?.includes("already exists")) { - return { success: true, warning: `Schema already up-to-date: ${(err as Error).message}` }; + const msg = (err as Error).message ?? ""; + // Duplicate column / already exists = DB is already up-to-date (expected for existing DBs) + if (msg.includes("duplicate column") || msg.includes("already exists")) { + return { success: true }; } - return { success: false, error: (err as Error).message }; + return { success: false, error: msg }; } } diff --git a/backend/src/index.ts b/backend/src/index.ts index d6c8f23..29ac7ac 100644 --- a/backend/src/index.ts +++ b/backend/src/index.ts @@ -58,10 +58,18 @@ function sanitizeCorrelationId(headers: IncomingHttpHeaders): string | null { } function buildLoggerOptions(level: string) { - return { + const base = { level, timestamp: () => `,"time":"${new Date().toISOString()}"`, }; + // Human-readable logs in development; structured JSON in production/test + if (process.env.NODE_ENV !== "production" && process.env.NODE_ENV !== "test") { + return { + ...base, + transport: { target: "pino-pretty", options: { translateTime: "SYS:yyyy-mm-dd HH:MM:ss.l" } }, + }; + } + return base; } /** Create and configure Fastify app (without starting) */ diff --git a/backend/src/routes/doses.ts b/backend/src/routes/doses.ts index bc10151..eaaebcb 100644 --- a/backend/src/routes/doses.ts +++ b/backend/src/routes/doses.ts @@ -137,8 +137,9 @@ async function validateShareDoseId(share: typeof shareTokens.$inferSelect, doseI export async function doseRoutes(app: FastifyInstance) { // --------------------------------------------------------------------------- // GET /doses/taken - PROTECTED: Get all taken doses for the user + // Suppress request logs — polled every 5s by frontend // --------------------------------------------------------------------------- - app.get("/doses/taken", { preHandler: requireAuth }, async (request, reply) => { + app.get("/doses/taken", { preHandler: requireAuth, logLevel: "warn" }, async (request, reply) => { const userId = await getUserId(request, reply); // Get all taken doses for this user (no time limit) @@ -304,8 +305,9 @@ export async function doseRoutes(app: FastifyInstance) { // --------------------------------------------------------------------------- // GET /share/:token/doses - PUBLIC: Get taken doses for a share link + // Suppress request logs — polled every 5s by SharedSchedule // --------------------------------------------------------------------------- - app.get<{ Params: { token: string } }>("/share/:token/doses", async (request, reply) => { + app.get<{ Params: { token: string } }>("/share/:token/doses", { logLevel: "warn" }, async (request, reply) => { const { token } = request.params; const { share, reason } = await getActiveShareToken(token); diff --git a/backend/src/routes/health.ts b/backend/src/routes/health.ts index c2e8e56..a06fa0b 100644 --- a/backend/src/routes/health.ts +++ b/backend/src/routes/health.ts @@ -10,11 +10,10 @@ const packageJson = JSON.parse(readFileSync(packageJsonPath, "utf-8")); const backendVersion = packageJson.version || "unknown"; export async function healthRoutes(app: FastifyInstance) { - // Exempt from rate limit - lightweight health check - app.get("/health", { config: { rateLimit: false } }, async () => ({ + // Exempt from rate limit + suppress request logs (called every 30s by Docker healthcheck) + app.get("/health", { config: { rateLimit: false }, logLevel: "warn" }, async () => ({ status: "ok", version: backendVersion, smtpConfigured: Boolean(process.env.SMTP_HOST), - shoutrrrConfigured: Boolean(process.env.SHOUTRRR_URL), })); } diff --git a/backend/src/routes/settings.ts b/backend/src/routes/settings.ts index 4242fa8..dc50e97 100644 --- a/backend/src/routes/settings.ts +++ b/backend/src/routes/settings.ts @@ -284,7 +284,8 @@ export async function settingsRoutes(app: FastifyInstance) { } // Get settings for current user - app.get("/settings", async (request, reply) => { + // Suppress request logs — polled every 30s for reminder status refresh + app.get("/settings", { logLevel: "warn" }, async (request, reply) => { const userId = await getUserId(request, reply); const settings = await getOrCreateUserSettings(userId); diff --git a/backend/src/test/e2e-routes.test.ts b/backend/src/test/e2e-routes.test.ts index 77d3504..230e410 100644 --- a/backend/src/test/e2e-routes.test.ts +++ b/backend/src/test/e2e-routes.test.ts @@ -868,7 +868,6 @@ describe("E2E Tests with Real Routes", () => { const json = response.json(); expect(json.status).toBe("ok"); expect(typeof json.smtpConfigured).toBe("boolean"); - expect(typeof json.shoutrrrConfigured).toBe("boolean"); }); }); @@ -1289,7 +1288,6 @@ describe("E2E Tests with Real Routes", () => { const json = response.json(); expect(json.status).toBe("ok"); expect(typeof json.smtpConfigured).toBe("boolean"); - expect(typeof json.shoutrrrConfigured).toBe("boolean"); }); }); diff --git a/backend/src/utils/logger.ts b/backend/src/utils/logger.ts index c70ce6e..b6a8983 100644 --- a/backend/src/utils/logger.ts +++ b/backend/src/utils/logger.ts @@ -23,18 +23,22 @@ function shouldLog(level: string): boolean { return LOG_LEVELS[level] >= getLevel(); } +function ts(): string { + return new Date().toISOString(); +} + export const log = { debug(msg: string): void { - if (shouldLog("debug")) console.log(msg); + if (shouldLog("debug")) console.log(`[${ts()}] [DEBUG] ${msg}`); }, info(msg: string): void { - if (shouldLog("info")) console.log(msg); + if (shouldLog("info")) console.log(`[${ts()}] [INFO] ${msg}`); }, warn(msg: string): void { - if (shouldLog("warn")) console.warn(msg); + if (shouldLog("warn")) console.warn(`[${ts()}] [WARN] ${msg}`); }, error(msg: string): void { - if (shouldLog("error")) console.error(msg); + if (shouldLog("error")) console.error(`[${ts()}] [ERROR] ${msg}`); }, }; diff --git a/frontend/nginx-entrypoint.sh b/frontend/nginx-entrypoint.sh index e6d9978..94c668e 100755 --- a/frontend/nginx-entrypoint.sh +++ b/frontend/nginx-entrypoint.sh @@ -4,21 +4,30 @@ # Translates LOG_LEVEL into nginx access log control before # delegating to the standard nginx-unprivileged entrypoint. # -# LOG_LEVEL=debug|info → access logs enabled (default) -# LOG_LEVEL=warn|error|fatal|silent → access logs suppressed +# LOG_LEVEL=debug → all access logs enabled (including polling) +# LOG_LEVEL=info → access logs enabled, polling endpoints suppressed (default) +# LOG_LEVEL=warn|error|fatal|silent → all access logs suppressed # ============================================================================= # Normalize: lowercase + trim whitespace level=$(printf '%s' "${LOG_LEVEL:-info}" | tr '[:upper:]' '[:lower:]' | tr -d '[:space:]') case "$level" in + debug) + export NGINX_ACCESS_LOG="/dev/stdout timed" + export NGINX_POLLING_LOG="/dev/stdout timed" + echo "[nginx-entrypoint] LOG_LEVEL=${LOG_LEVEL} → access_log on (all requests)" + ;; warn|error|fatal|silent) export NGINX_ACCESS_LOG="off" + export NGINX_POLLING_LOG="off" echo "[nginx-entrypoint] LOG_LEVEL=${LOG_LEVEL} → access_log off" ;; *) - export NGINX_ACCESS_LOG="/dev/stdout" - echo "[nginx-entrypoint] LOG_LEVEL=${LOG_LEVEL:-info} → access_log /dev/stdout" + # info (default): log everything except high-frequency polling endpoints + export NGINX_ACCESS_LOG="/dev/stdout timed" + export NGINX_POLLING_LOG="off" + echo "[nginx-entrypoint] LOG_LEVEL=${LOG_LEVEL:-info} → access_log on (polling suppressed)" ;; esac diff --git a/frontend/nginx.conf b/frontend/nginx.conf index eb274e7..57f74f9 100644 --- a/frontend/nginx.conf +++ b/frontend/nginx.conf @@ -6,6 +6,9 @@ server { root /usr/share/nginx/html; index index.html; + # Custom log format with ISO timestamps + log_format timed '$time_iso8601 $status $request_method $request_uri ($request_time s)'; + # Access log control (suppressed when LOG_LEVEL is warn or higher) access_log ${NGINX_ACCESS_LOG}; @@ -24,6 +27,52 @@ server { try_files $uri /index.html; } + # ------------------------------------------------------------------------- + # High-frequency polling endpoints — suppress access logs at info level + # (visible at debug level via NGINX_POLLING_LOG) + # ------------------------------------------------------------------------- + location = /api/doses/taken { + access_log ${NGINX_POLLING_LOG}; + resolver 127.0.0.11 valid=10s ipv6=off; + set $backend_upstream ${BACKEND_URL}; + rewrite ^/api/(.*)$ /$1 break; + proxy_pass http://$backend_upstream; + proxy_set_header Host $host; + proxy_set_header X-Real-IP $remote_addr; + proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; + proxy_set_header X-Forwarded-Proto $scheme; + proxy_pass_header Set-Cookie; + proxy_cookie_path / /; + } + + location ~ ^/api/share/[^/]+/doses$ { + access_log ${NGINX_POLLING_LOG}; + resolver 127.0.0.11 valid=10s ipv6=off; + set $backend_upstream ${BACKEND_URL}; + rewrite ^/api/(.*)$ /$1 break; + proxy_pass http://$backend_upstream; + proxy_set_header Host $host; + proxy_set_header X-Real-IP $remote_addr; + proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; + proxy_set_header X-Forwarded-Proto $scheme; + proxy_pass_header Set-Cookie; + proxy_cookie_path / /; + } + + location = /api/health { + access_log ${NGINX_POLLING_LOG}; + resolver 127.0.0.11 valid=10s ipv6=off; + set $backend_upstream ${BACKEND_URL}; + rewrite ^/api/(.*)$ /$1 break; + proxy_pass http://$backend_upstream; + proxy_set_header Host $host; + proxy_set_header X-Real-IP $remote_addr; + proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for; + proxy_set_header X-Forwarded-Proto $scheme; + proxy_pass_header Set-Cookie; + proxy_cookie_path / /; + } + location /api/ { # Use variable for runtime DNS resolution (nginx resolves at startup by default) # Docker embedded DNS (127.0.0.11) with 10s cache