feat(logging): ~2-month container rotation, ISO timestamps, level names
Build & push images / images (push) Successful in 2m54s
CI / check (push) Successful in 41s

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
This commit is contained in:
2026-07-04 19:47:53 +02:00
parent 43c1f45e29
commit c21babf293
6 changed files with 120 additions and 15 deletions
@@ -0,0 +1,54 @@
import { beforeEach, describe, expect, it } from "vitest";
import { appLogs, type Db } from "@parking/db";
import { createTestDb } from "@parking/db/testing";
import { LogService, pinoDbStream } from "./log-service.js";
// pinoDbStream feeds backend warn+ lines into app_logs. Since 2026-07-04 the logger
// emits level NAMES ("warn") instead of pino's numeric codes (40) — for human-readable
// container logs — and the stream must accept BOTH encodings (numeric covers any
// default-configured pino). A level the tee can't resolve falls back to info → not
// persisted, never a crash.
let db: Db;
let stream: { write: (line: string) => void };
let teed: string[];
beforeEach(() => {
({ db } = createTestDb());
teed = [];
stream = pinoDbStream(new LogService(db), {
write: (line: string) => {
teed.push(line);
return true;
},
} as unknown as NodeJS.WritableStream);
});
const rows = () => db.select().from(appLogs).all();
describe("pinoDbStream level encodings", () => {
it("persists a LABEL-level warn line (the current logger format)", () => {
stream.write(`{"level":"warn","time":"2026-07-04T18:14:11.453Z","msg":"label warn"}\n`);
expect(rows()).toHaveLength(1);
expect(rows()[0]).toMatchObject({ level: "warn", source: "backend", message: "label warn" });
});
it("still persists a NUMERIC-level error line (legacy/default pino)", () => {
stream.write(`{"level":50,"time":1783179038453,"msg":"numeric error"}\n`);
expect(rows()[0]).toMatchObject({ level: "error", message: "numeric error" });
});
it("info stays stdout-only in both encodings (teed, not persisted)", () => {
stream.write(`{"level":"info","msg":"label info"}\n`);
stream.write(`{"level":30,"msg":"numeric info"}\n`);
expect(rows()).toHaveLength(0);
expect(teed).toHaveLength(2); // stdout tee always happens
});
it("an unresolvable level falls back to info (dropped), never throws", () => {
stream.write(`{"level":"loud","msg":"weird"}\n`);
stream.write(`not json at all\n`);
expect(rows()).toHaveLength(0);
expect(teed).toHaveLength(2);
});
});
+15 -6
View File
@@ -33,7 +33,10 @@ export interface LogRetention {
} }
export const DEFAULT_RETENTION: LogRetention = { export const DEFAULT_RETENTION: LogRetention = {
maxAgeDays: Number(process.env.LOG_RETENTION_DAYS ?? 30), // 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), maxRows: Number(process.env.LOG_RETENTION_MAX_ROWS ?? 50_000),
}; };
@@ -192,9 +195,10 @@ export class LogService {
/** /**
* A pino-compatible write stream that forwards BACKEND warn+ lines into the LogService. * 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, map the numeric level * Pino writes one JSON object per line to this stream; we parse, resolve the level
* to a name, and persist. Returned as `{ write }` so it can be passed as pino's stream. * (name or numeric encoding), and persist. Returned as `{ write }` so it can be passed
* stdout still receives the same line (we tee), so console logging is unchanged. * as pino's stream. stdout still receives the same line (we tee), so console logging is
* unchanged.
*/ */
export function pinoDbStream( export function pinoDbStream(
service: LogService, service: LogService,
@@ -218,12 +222,17 @@ export function pinoDbStream(
} }
try { try {
const obj = JSON.parse(line) as { const obj = JSON.parse(line) as {
level?: number; level?: number | string;
msg?: string; msg?: string;
err?: { stack?: string; message?: string }; err?: { stack?: string; message?: string };
[k: string]: unknown; [k: string]: unknown;
}; };
const level = NUM_TO_LEVEL[obj.level ?? 30] ?? "info"; // 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; if (LOG_LEVEL_ORDER[level] < LOG_LEVEL_ORDER[BACKEND_PERSIST_MIN]) return;
// Strip pino's noisy standard fields from the persisted context. // Strip pino's noisy standard fields from the persisted context.
const { level: _l, time: _t, pid: _p, hostname: _h, msg, ...rest } = obj; const { level: _l, time: _t, pid: _p, hostname: _h, msg, ...rest } = obj;
+7
View File
@@ -71,7 +71,14 @@ export async function buildServer(opts: BuildOptions = {}): Promise<FastifyInsta
const logService = new LogService(db); const logService = new LogService(db);
const app = Fastify({ const app = Fastify({
logger: { logger: {
// Level knob: trace|debug|info|warn|error|fatal (pino). Default info; a booth
// being diagnosed can run LOG_LEVEL=debug without a code change.
level: process.env.LOG_LEVEL ?? "info", level: process.env.LOG_LEVEL ?? "info",
// Container logs are read by humans (`docker logs` / Komodo), so stamp
// ISO-8601 UTC instead of pino's epoch-ms, and level NAMES instead of the
// numeric codes (30/40/50). pinoDbStream accepts both encodings.
timestamp: () => `,"time":"${new Date().toISOString()}"`,
formatters: { level: (label) => ({ level: label }) },
stream: pinoDbStream(logService, process.stdout), stream: pinoDbStream(logService, process.stdout),
}, },
}); });
+13 -5
View File
@@ -26,11 +26,12 @@ services:
- caddy-config:/config - caddy-config:/config
depends_on: depends_on:
- server - server
# ≈2 months (see the server note): Caddy logs errors only — 10 MB × 5 is plenty.
logging: logging:
driver: json-file driver: json-file
options: options:
max-size: "10m" max-size: "10m"
max-file: "3" max-file: "5"
server: server:
restart: always restart: always
@@ -73,11 +74,17 @@ services:
- /dev/usb:/dev/usb - /dev/usb:/dev/usb
device_cgroup_rules: device_cgroup_rules:
- "c 180:* rmw" - "c 180:* rmw"
# LOG ROTATION (2026-07-04). Docker's json-file driver rotates by SIZE, not time —
# these caps are sized to hold ≈2 MONTHS at observed booth rates (the operator's
# chosen diagnostic window; revisit if `docker logs` shows less than ~60 days of
# history). Server gets the most (request + device chatter): 20 MB × 30 = 600 MB
# ceiling. NB: `docker logs` only reaches back as far as these files. The queryable
# warn+ store (app_logs, /setup/logs) has its own matching 60-day retention.
logging: logging:
driver: json-file driver: json-file
options: options:
max-size: "10m" max-size: "20m"
max-file: "3" max-file: "30"
vision: vision:
restart: always restart: always
@@ -89,11 +96,12 @@ services:
VISION_RECOGNIZER: fast_alpr VISION_RECOGNIZER: fast_alpr
ports: ports:
- "127.0.0.1:8089:8089" - "127.0.0.1:8089:8089"
# ≈2 months (see the server note): vision logs less — 20 MB × 10 = 200 MB ceiling.
logging: logging:
driver: json-file driver: json-file
options: options:
max-size: "10m" max-size: "20m"
max-file: "3" max-file: "10"
volumes: volumes:
caddy-data: caddy-data:
+21 -4
View File
@@ -2,7 +2,7 @@
type: concept type: concept
tags: [parking, observability, diagnostics, logging, frontend, backend] tags: [parking, observability, diagnostics, logging, frontend, backend]
sources: [] sources: []
updated: 2026-06-19 updated: 2026-07-04
status: open status: open
--- ---
@@ -66,9 +66,26 @@ column — the failed request, error name, component stack, anything), plus pull
## Retention (offline appliance ⇒ must be bounded) ## Retention (offline appliance ⇒ must be bounded)
Pruned by **age AND a row cap** (a burst could blow past an age-only window): delete older than Pruned by **age AND a row cap** (a burst could blow past an age-only window): delete older than
`LOG_RETENTION_DAYS` (default 30) **and** keep only the newest `LOG_RETENTION_MAX_ROWS` (default `LOG_RETENTION_DAYS` (default **60** — the operator's ≈2-month diagnostic window, 2026-07-04;
50 000). Runs **hourly** (unref'd timer) + once at startup. Both env-configurable. Same "prunable, was 30) **and** keep only the newest `LOG_RETENTION_MAX_ROWS` (default 50 000). Runs **hourly**
not precious" durability class as `device_events` — the opposite of the append-only ledger. (unref'd timer) + once at startup. Both env-configurable. Same "prunable, not precious"
durability class as `device_events` — the opposite of the append-only ledger.
## Container (stdout) logs — the OTHER log store (2026-07-04)
`docker logs` is a separate, size-bounded store from `app_logs` — it holds **everything**
(info/debug too), while `app_logs` keeps only warn+. Three knobs, all set 2026-07-04:
- **Rotation:** Docker's json-file driver rotates by SIZE, not time; the caps in
`docker-compose.prod.yml` are sized to hold **≈2 months** at observed booth rates (server
20 MB × 30, vision 20 MB × 10, proxy 10 MB × 5). `docker logs` reaches back only that far —
revisit the caps if it shows under ~60 days. (Dev compose is uncapped — laptop concern only.)
- **Human-readable lines:** the pino logger stamps **ISO-8601 UTC** `time` (was epoch-ms) and
**level NAMES** (`"warn"`, was `40`) via `timestamp` + `formatters.level` in `server.ts`.
`pinoDbStream` accepts BOTH level encodings, so the app_logs tee survives either config.
- **Level knob:** `LOG_LEVEL` env (trace|debug|info|warn|error|fatal; default `info`) — a booth
under diagnosis runs `LOG_LEVEL=debug` with no code change; warn+ persistence is unaffected
(it filters independently in the tee).
## The booth viewer ## The booth viewer
+10
View File
@@ -2272,3 +2272,13 @@ card, unknown SUB- code) still signs the normal anomaly; enrolled credentials ma
filter and can never be hidden by it. Works for legacy unprefixed reads too, so the feed cleans up filter and can never be hidden by it. Works for legacy unprefixed reads too, so the feed cleans up
before the vendor-tool visit. 6 new tests; suite 278 green. Also this session: reader channel before the vendor-tool visit. 6 new tests; suite 278 green. Also this session: reader channel
tagging (clone defense) — see the prior entry. tagging (clone defense) — see the prior entry.
## [2026-07-04] update | Logging: 2-month rotation, ISO timestamps, level names
Operator asked for bounded container logs (~2 months), human-readable timestamps, and clarity on
levels. Findings + changes on [[app-logs]]: levels EXISTED (LOG_LEVEL env, pino, warn+ teed to
app_logs); the "level":30 numbers and epoch-ms times were pino defaults — the logger now stamps
ISO-8601 UTC + level names (pinoDbStream hardened to accept both encodings so the DB tee can't
silently break). Rotation: docker json-file caps in docker-compose.prod.yml resized from 10m×3
(≈30 MB!) 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). app_logs retention default aligned 30→60 days.