Files
parking_solution/apps/server/src/log-service.ts
T
julian c21babf293
Build & push images / images (push) Successful in 2m54s
CI / check (push) Successful in 41s
feat(logging): ~2-month container rotation, ISO timestamps, level names
Operator asked for bounded container logs (~2 months of history), human-
readable timestamps, and clarity on levels. Levels already existed (LOG_LEVEL
env → pino, default info; warn+ teed into app_logs, queryable at /setup/logs)
— the "level":30 / epoch-ms "time" in docker logs were pino defaults.

- server.ts logger: stamp ISO-8601 UTC time (timestamp fn) and level NAMES
  (formatters.level) so `docker logs` reads human.
- log-service.ts pinoDbStream: accept BOTH level encodings (name + numeric) —
  the label switch would otherwise have silently stopped warn+ persistence
  into app_logs. New log-service-stream.test.ts pins both encodings, the
  info-stays-stdout-only rule, and the never-throws fallback.
- docker-compose.prod.yml: json-file caps resized from 10m×3 (≈30 MB — days,
  not months) to ≈2 months by volume: server 20m×30, vision 20m×10, proxy
  10m×5. json-file rotates by SIZE; time-based isn't a driver feature —
  comment says to revisit if `docker logs` holds under ~60 days.
- app_logs retention default aligned 30→60 days (LOG_RETENTION_DAYS still
  overrides).

Wiki: app-logs.md gains the container-log store section (rotation, format,
LOG_LEVEL knob) + retention update; log.md entry.

Suite 282 green.

Claude-Session: https://claude.ai/code/session_01Xcm6ikLgGoCxxHrxtjkk5V
2026-07-04 19:47:53 +02:00

246 lines
8.8 KiB
TypeScript

import { randomUUID } from "node:crypto";
import { and, appLogs, desc, eq, sql, type Db } from "@parking/db";
import {
LOG_LEVEL_ORDER,
type AppLogRecord,
type ClientLogInput,
type LogLevel,
type LogSource,
} from "@parking/shared";
// Application/diagnostic LOG SINK — the host-side store behind the third log stream
// (app_logs), distinct from the signed ledger and device telemetry. It persists:
// - BACKEND warn/error/fatal, fed by a pino stream (see pinoDbStream) so any
// app.log.warn/error lands in the DB without changing call sites.
// - FRONTEND errors POSTed to /api/logs (failed requests, uncaught errors).
// Everything here is UNSIGNED + prunable. Pruned by age AND a row cap so an offline
// appliance with finite disk can't be filled by a log storm. See
// wiki/concepts/app-logs.md, decisions/event-streams-split.md.
/** Only warn and above are persisted from the backend (info/debug stay stdout-only). */
const BACKEND_PERSIST_MIN: LogLevel = "warn";
/** Defensive caps so one runaway log can't bloat a row (chars). */
const MAX_MESSAGE = 4_000;
const MAX_STACK = 16_000;
const MAX_CONTEXT_JSON = 16_000;
export interface LogRetention {
/** Delete logs older than this many days. */
readonly maxAgeDays: number;
/** Hard cap on total rows — the oldest beyond this are pruned. */
readonly maxRows: number;
}
export const DEFAULT_RETENTION: LogRetention = {
// 60 days (~2 months) — the operator's chosen diagnostic window (2026-07-04),
// matched by the container-log rotation caps in docker-compose.prod.yml. The row
// cap below still bounds a burst regardless of age.
maxAgeDays: Number(process.env.LOG_RETENTION_DAYS ?? 60),
maxRows: Number(process.env.LOG_RETENTION_MAX_ROWS ?? 50_000),
};
function clamp(s: string | null | undefined, max: number): string | null {
if (s == null) return null;
return s.length > max ? s.slice(0, max) : s;
}
/** Serialize context to JSON, bounded — never throw on a circular/huge object. */
function safeContext(ctx: Record<string, unknown> | null | undefined): Record<string, unknown> | null {
if (ctx == null) return null;
try {
const json = JSON.stringify(ctx);
if (json.length <= MAX_CONTEXT_JSON) return ctx;
return { _truncated: true, preview: json.slice(0, MAX_CONTEXT_JSON) };
} catch {
return { _unserializable: true };
}
}
export class LogService {
readonly #db: Db;
readonly #retention: LogRetention;
/** Reentrancy guard: never let persisting a log itself emit a persisted log. */
#writing = false;
constructor(db: Db, retention: LogRetention = DEFAULT_RETENTION) {
this.#db = db;
this.#retention = retention;
}
/** Low-level insert. Best-effort: a logging failure must never break a request or
* recurse (a DB error here would otherwise log → insert → error → log …). */
#insert(row: {
level: LogLevel;
source: LogSource;
message: string;
context?: Record<string, unknown> | null;
httpStatus?: number | null;
path?: string | null;
stack?: string | null;
userId?: string | null;
userAgent?: string | null;
createdAt?: string;
}): void {
if (this.#writing) return;
this.#writing = true;
try {
this.#db
.insert(appLogs)
.values({
id: randomUUID(),
level: row.level,
source: row.source,
message: clamp(row.message, MAX_MESSAGE) ?? "",
context: safeContext(row.context),
httpStatus: row.httpStatus ?? null,
path: clamp(row.path, 512),
stack: clamp(row.stack, MAX_STACK),
userId: row.userId ?? null,
userAgent: clamp(row.userAgent, 512),
createdAt: row.createdAt ?? new Date().toISOString(),
})
.run();
} catch {
// Swallow — diagnostics must never take down the path they observe. (Can't log
// it; that's the recursion we're guarding against.)
} finally {
this.#writing = false;
}
}
/** Persist a BACKEND log line (called by the pino stream). Below warn is dropped. */
recordBackend(level: LogLevel, message: string, context?: Record<string, unknown> | null): void {
if (LOG_LEVEL_ORDER[level] < LOG_LEVEL_ORDER[BACKEND_PERSIST_MIN]) return;
this.#insert({ level, source: "backend", message, context });
}
/** Persist a FRONTEND-reported log (from POST /api/logs). The server stamps the
* user + receive time; the client supplies level/message/context. */
recordClient(
input: ClientLogInput,
meta: { userId?: string | null; userAgent?: string | null },
): void {
this.#insert({
level: input.level,
source: "frontend",
message: input.message,
context: input.context ?? null,
httpStatus: input.httpStatus ?? null,
path: input.path ?? null,
stack: input.stack ?? null,
userId: meta.userId ?? null,
userAgent: meta.userAgent ?? null,
// Keep the client's capture time in context for ordering; createdAt is server time.
createdAt: new Date().toISOString(),
});
}
/** Read recent logs, newest first, with optional level/source/since filters. */
query(opts: {
limit: number;
level?: LogLevel;
source?: LogSource;
since?: string;
}): AppLogRecord[] {
const conds = [];
if (opts.level) conds.push(eq(appLogs.level, opts.level));
if (opts.source) conds.push(eq(appLogs.source, opts.source));
if (opts.since) conds.push(sql`${appLogs.createdAt} >= ${opts.since}`);
const rows = this.#db
.select()
.from(appLogs)
.where(conds.length ? and(...conds) : undefined)
.orderBy(desc(appLogs.createdAt))
.limit(opts.limit)
.all();
return rows as unknown as AppLogRecord[];
}
/** Prune by age then by row cap. Returns how many rows were deleted. Safe to call
* on a timer; cheap (indexed on created_at). */
prune(): number {
let deleted = 0;
try {
const cutoff = new Date(Date.now() - this.#retention.maxAgeDays * 86_400_000).toISOString();
const byAge = this.#db.delete(appLogs).where(sql`${appLogs.createdAt} < ${cutoff}`).run();
deleted += byAge.changes ?? 0;
// Row cap: keep the newest maxRows, delete the rest. One subquery — find the
// created_at boundary of the keep-window, delete older.
const total = this.#db.select({ c: sql<number>`count(*)` }).from(appLogs).get();
const count = total?.c ?? 0;
if (count > this.#retention.maxRows) {
const boundary = this.#db
.select({ createdAt: appLogs.createdAt })
.from(appLogs)
.orderBy(desc(appLogs.createdAt))
.limit(1)
.offset(this.#retention.maxRows - 1)
.get();
if (boundary) {
const byCap = this.#db
.delete(appLogs)
.where(sql`${appLogs.createdAt} < ${boundary.createdAt}`)
.run();
deleted += byCap.changes ?? 0;
}
}
} catch {
// best-effort
}
return deleted;
}
}
/**
* A pino-compatible write stream that forwards BACKEND warn+ lines into the LogService.
* Pino writes one JSON object per line to this stream; we parse, resolve the level
* (name or numeric encoding), and persist. Returned as `{ write }` so it can be passed
* as pino's stream. stdout still receives the same line (we tee), so console logging is
* unchanged.
*/
export function pinoDbStream(
service: LogService,
tee: NodeJS.WritableStream,
): { write: (line: string) => void } {
const NUM_TO_LEVEL: Record<number, LogLevel> = {
10: "trace",
20: "debug",
30: "info",
40: "warn",
50: "error",
60: "fatal",
};
return {
write(line: string): void {
// Always tee to the original destination first (don't lose stdout logging).
try {
tee.write(line);
} catch {
/* ignore */
}
try {
const obj = JSON.parse(line) as {
level?: number | string;
msg?: string;
err?: { stack?: string; message?: string };
[k: string]: unknown;
};
// The logger emits level NAMES (formatters.level in server.ts, for human-
// readable container logs); a default pino config emits numbers. Accept both.
const level: LogLevel =
typeof obj.level === "string" && obj.level in LOG_LEVEL_ORDER
? (obj.level as LogLevel)
: NUM_TO_LEVEL[typeof obj.level === "number" ? obj.level : 30] ?? "info";
if (LOG_LEVEL_ORDER[level] < LOG_LEVEL_ORDER[BACKEND_PERSIST_MIN]) return;
// Strip pino's noisy standard fields from the persisted context.
const { level: _l, time: _t, pid: _p, hostname: _h, msg, ...rest } = obj;
service.recordBackend(level, typeof msg === "string" ? msg : "", rest);
} catch {
// A non-JSON line (shouldn't happen with pino) — ignore for persistence.
}
},
};
}