Add configurable structured logging

Adds a leveled JSON logger (error/warn/info/verbose/debug, controlled via
LOG_LEVEL) wired into the Express API (access log, error middleware,
crash handlers, memory heartbeat) and the Next.js server (page-request
proxy, instrumentation crash handlers, heartbeat). LOG_LEVEL is exposed
through compose.yaml, and both services now rotate their Docker logs
(json-file, 20m x 10 files) instead of growing unbounded. Intended to
capture long-running diagnostic data for the intermittent 502s seen on
the Docker host.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

compose.yaml

@@ -11,7 +11,13 @@ services:
     environment:
       PORT: "3000"
       CHOKIDAR_USEPOLLING: "true"
+      LOG_LEVEL: "${LOG_LEVEL:-info}"
     init: true
+    logging:
+      driver: json-file
+      options:
+        max-size: "20m"
+        max-file: "10"
     ports:
       - "3000:3000"
     volumes:
@@ -45,7 +51,13 @@ services:
       API_INTERNAL_URL: http://api:3000
       WATCHPACK_POLLING: "true"
       NEXT_TELEMETRY_DISABLED: "1"
+      LOG_LEVEL: "${LOG_LEVEL:-info}"
     init: true
+    logging:
+      driver: json-file
+      options:
+        max-size: "20m"
+        max-file: "10"
     depends_on:
       api:
         condition: service_healthy

docs/deployment.md

@@ -26,10 +26,39 @@ Verwendete Umgebungsvariablen:
 - `NEXT_TELEMETRY_DISABLED=1`
 - `CHOKIDAR_USEPOLLING=true` und `WATCHPACK_POLLING=true` für lokale
   Dateibeobachtung in Docker
+- `LOG_LEVEL` – steuert für beide Dienste die Ausgabestufe des strukturierten
+  JSON-Loggers (`error`, `warn`, `info`, `verbose`, `debug`), Standard `info`.
+  Setzbar über eine `.env`-Datei neben `compose.yaml` oder
+  `LOG_LEVEL=verbose docker compose up`.
 
 Beim API-Start laufen zuerst `npm run db:migrate` und
 `npm run db:verify:circuit-schema`.
 
+## Logging
+
+Beide Dienste schreiben strukturierte, einzeilige JSON-Log-Zeilen nach
+stdout/stderr (`docker compose logs --follow`). Jede Zeile enthält
+`timestamp`, `level`, `scope` und `message`. `compose.yaml` konfiguriert für
+beide Dienste den `json-file`-Treiber mit Rotation (`max-size: 20m`,
+`max-file: 10`, also bis zu 200 MB je Dienst); ohne diese Einstellung würde
+Docker mit der Standardkonfiguration unbegrenzt in eine einzelne Datei unter
+`/var/lib/docker/containers/<container-id>/` schreiben. Die Logs überleben
+einen Container-Neustart (`docker compose restart`), aber nicht das Entfernen
+des Containers (`docker compose down` gefolgt von `up` erzeugt neue
+Container und damit neue, leere Logdateien); für ein echtes Langzeitarchiv
+über Rebuilds hinweg müssten die Zeilen zusätzlich in eine Datei im
+gemounteten `./data`-Verzeichnis oder an ein externes Log-System geschrieben
+werden. Die Express-API protokolliert
+jede abgeschlossene Anfrage (Methode, Pfad, Status, Dauer; `/health` wird
+nicht mitgeloggt) sowie unbehandelte Exceptions/Promise-Rejections. Das
+Next.js-Frontend protokolliert Seitenanfragen (Navigation) über
+`src/proxy.ts` und unbehandelte Fehler über `src/instrumentation.ts`.
+Beide Prozesse schreiben zusätzlich alle fünf Minuten einen `verbose`-Heartbeat
+mit Laufzeit und Speicherverbrauch – nützlich, um Speicherlecks oder Hänger vor
+einem 502 über einen längeren Zeitraum nachzuvollziehen. Für die Detailsuche
+`LOG_LEVEL=debug` setzen; das protokolliert zusätzlich den Start jeder
+API-Anfrage und macht damit hängende (nie abgeschlossene) Requests sichtbar.
+
 ## Voraussetzungen für ein späteres Produktionssetup
 
 Vor einer produktiven Installation werden mindestens benötigt:

src/instrumentation-node.ts

@@ -0,0 +1,25 @@
+import { createLogger, toErrorMeta } from "./shared/logging/logger";
+
+export function registerNodeInstrumentation() {
+  const logger = createLogger("web");
+  const heartbeatIntervalMs = 5 * 60 * 1000;
+
+  logger.info("web server starting", { pid: process.pid });
+
+  process.on("uncaughtException", (error) => {
+    logger.error("uncaught exception", toErrorMeta(error));
+  });
+
+  process.on("unhandledRejection", (reason) => {
+    logger.error("unhandled rejection", toErrorMeta(reason));
+  });
+
+  setInterval(() => {
+    const memory = process.memoryUsage();
+    logger.verbose("heartbeat", {
+      uptimeSeconds: Math.round(process.uptime()),
+      rssMb: Math.round(memory.rss / 1024 / 1024),
+      heapUsedMb: Math.round(memory.heapUsed / 1024 / 1024),
+    });
+  }, heartbeatIntervalMs).unref();
+}

src/instrumentation.ts

@@ -0,0 +1,8 @@
+export async function register() {
+  if (process.env.NEXT_RUNTIME !== "nodejs") {
+    return;
+  }
+
+  const { registerNodeInstrumentation } = await import("./instrumentation-node");
+  registerNodeInstrumentation();
+}

src/proxy.ts

@@ -0,0 +1,17 @@
+import { NextResponse } from "next/server";
+import type { NextRequest } from "next/server";
+import { createLogger } from "./shared/logging/logger";
+
+const logger = createLogger("web:navigation");
+
+export function proxy(request: NextRequest) {
+  logger.info("page request", {
+    method: request.method,
+    path: request.nextUrl.pathname,
+  });
+  return NextResponse.next();
+}
+
+export const config = {
+  matcher: ["/((?!_next/static|_next/image|favicon.ico|api).*)"],
+};

src/server/index.ts

@@ -4,12 +4,36 @@ import { globalDeviceRouter } from "./routes/global-device.routes.js";
 import { projectDeviceRouter } from "./routes/project-device.routes.js";
 import { projectRouter } from "./routes/project.routes.js";
 import { errorMiddleware } from "./middleware/error.middleware.js";
+import { createLogger, toErrorMeta } from "../shared/logging/logger.js";
 
+const logger = createLogger("api");
 const app = express();
 const port = Number(process.env.PORT || 3000);
+const heartbeatIntervalMs = 5 * 60 * 1000;
 
 app.use(express.json({ limit: "25mb" }));
 
+app.use((req, res, next) => {
+  if (req.path === "/health") {
+    next();
+    return;
+  }
+  const startedAt = Date.now();
+  logger.debug("request started", { method: req.method, path: req.originalUrl });
+  res.on("finish", () => {
+    const meta = {
+      method: req.method,
+      path: req.originalUrl,
+      status: res.statusCode,
+      durationMs: Date.now() - startedAt,
+    };
+    if (res.statusCode >= 500) logger.error("request completed", meta);
+    else if (res.statusCode >= 400) logger.warn("request completed", meta);
+    else logger.info("request completed", meta);
+  });
+  next();
+});
+
 app.get("/health", (_req, res) => {
   res.json({ ok: true });
 });
@@ -21,6 +45,26 @@ app.use("/api/project-devices", projectDeviceRouter);
 
 app.use(errorMiddleware);
 
-app.listen(port, () => {
+process.on("uncaughtException", (error) => {
-  console.log(`Server running on http://localhost:${port}`);
+  logger.error("uncaught exception", toErrorMeta(error));
+});
+
+process.on("unhandledRejection", (reason) => {
+  logger.error("unhandled rejection", toErrorMeta(reason));
+});
+
+process.on("SIGTERM", () => logger.info("received SIGTERM"));
+process.on("SIGINT", () => logger.info("received SIGINT"));
+
+setInterval(() => {
+  const memory = process.memoryUsage();
+  logger.verbose("heartbeat", {
+    uptimeSeconds: Math.round(process.uptime()),
+    rssMb: Math.round(memory.rss / 1024 / 1024),
+    heapUsedMb: Math.round(memory.heapUsed / 1024 / 1024),
+  });
+}, heartbeatIntervalMs).unref();
+
+app.listen(port, () => {
+  logger.info("server started", { port });
 });

src/server/middleware/error.middleware.ts

@@ -1,12 +1,19 @@
 import type { NextFunction, Request, Response } from "express";
+import { createLogger, toErrorMeta } from "../../shared/logging/logger.js";
+
+const logger = createLogger("api");
 
 export function errorMiddleware(
   error: unknown,
-  _req: Request,
+  req: Request,
   res: Response,
   _next: NextFunction
 ) {
-  console.error(error);
+  logger.error("request handler threw", {
+    method: req.method,
+    path: req.originalUrl,
+    ...toErrorMeta(error),
+  });
   res.status(500).json({ error: "Internal Server Error" });
 }
 

src/shared/logging/logger.ts

@@ -0,0 +1,71 @@
+export type LogLevel = "error" | "warn" | "info" | "verbose" | "debug";
+
+const LEVEL_SEVERITY: Record<LogLevel, number> = {
+  error: 0,
+  warn: 1,
+  info: 2,
+  verbose: 3,
+  debug: 4,
+};
+
+const DEFAULT_LEVEL: LogLevel = "info";
+
+export function resolveLogLevel(raw: string | undefined): LogLevel {
+  const candidate = raw?.trim().toLowerCase();
+  if (candidate && candidate in LEVEL_SEVERITY) {
+    return candidate as LogLevel;
+  }
+  return DEFAULT_LEVEL;
+}
+
+export function toErrorMeta(error: unknown): Record<string, unknown> {
+  if (error instanceof Error) {
+    return {
+      errorName: error.name,
+      errorMessage: error.message,
+      stack: error.stack,
+    };
+  }
+  return { error: typeof error === "string" ? error : JSON.stringify(error) };
+}
+
+export interface Logger {
+  error(message: string, meta?: Record<string, unknown>): void;
+  warn(message: string, meta?: Record<string, unknown>): void;
+  info(message: string, meta?: Record<string, unknown>): void;
+  verbose(message: string, meta?: Record<string, unknown>): void;
+  debug(message: string, meta?: Record<string, unknown>): void;
+}
+
+export function createLogger(
+  scope: string,
+  options?: { level?: LogLevel }
+): Logger {
+  const threshold = options?.level ?? resolveLogLevel(process.env.LOG_LEVEL);
+
+  const write = (level: LogLevel, message: string, meta?: Record<string, unknown>) => {
+    if (LEVEL_SEVERITY[level] > LEVEL_SEVERITY[threshold]) {
+      return;
+    }
+    const line = JSON.stringify({
+      timestamp: new Date().toISOString(),
+      level,
+      scope,
+      message,
+      ...meta,
+    });
+    if (level === "error" || level === "warn") {
+      console.error(line);
+    } else {
+      console.log(line);
+    }
+  };
+
+  return {
+    error: (message, meta) => write("error", message, meta),
+    warn: (message, meta) => write("warn", message, meta),
+    info: (message, meta) => write("info", message, meta),
+    verbose: (message, meta) => write("verbose", message, meta),
+    debug: (message, meta) => write("debug", message, meta),
+  };
+}

tests/logger.test.ts

@@ -0,0 +1,83 @@
+import assert from "node:assert/strict";
+import { describe, it } from "node:test";
+import { createLogger, resolveLogLevel } from "../src/shared/logging/logger.js";
+
+describe("resolveLogLevel", () => {
+  it("defaults to info for missing or unknown values", () => {
+    assert.equal(resolveLogLevel(undefined), "info");
+    assert.equal(resolveLogLevel(""), "info");
+    assert.equal(resolveLogLevel("nonsense"), "info");
+  });
+
+  it("accepts known levels case-insensitively", () => {
+    assert.equal(resolveLogLevel("DEBUG"), "debug");
+    assert.equal(resolveLogLevel(" verbose "), "verbose");
+    assert.equal(resolveLogLevel("warn"), "warn");
+  });
+});
+
+describe("createLogger", () => {
+  it("suppresses levels below the configured threshold", () => {
+    const infoLines: string[] = [];
+    const originalLog = console.log;
+    console.log = (line: string) => {
+      infoLines.push(line);
+    };
+    try {
+      const logger = createLogger("test", { level: "warn" });
+      logger.info("should not appear");
+      logger.debug("should not appear");
+      logger.verbose("should not appear");
+    } finally {
+      console.log = originalLog;
+    }
+    assert.equal(infoLines.length, 0);
+  });
+
+  it("emits enabled levels as structured JSON with scope and meta", () => {
+    const errorLines: string[] = [];
+    const originalError = console.error;
+    console.error = (line: string) => {
+      errorLines.push(line);
+    };
+    try {
+      const logger = createLogger("test", { level: "warn" });
+      logger.warn("something happened", { code: 42 });
+    } finally {
+      console.error = originalError;
+    }
+    assert.equal(errorLines.length, 1);
+    const parsed = JSON.parse(errorLines[0]);
+    assert.equal(parsed.level, "warn");
+    assert.equal(parsed.scope, "test");
+    assert.equal(parsed.message, "something happened");
+    assert.equal(parsed.code, 42);
+    assert.equal(typeof parsed.timestamp, "string");
+  });
+
+  it("routes debug/verbose/info to console.log and error/warn to console.error", () => {
+    const logLines: string[] = [];
+    const errorLines: string[] = [];
+    const originalLog = console.log;
+    const originalError = console.error;
+    console.log = (line: string) => {
+      logLines.push(line);
+    };
+    console.error = (line: string) => {
+      errorLines.push(line);
+    };
+    try {
+      const logger = createLogger("test", { level: "debug" });
+      logger.debug("d");
+      logger.verbose("v");
+      logger.info("i");
+      logger.warn("w");
+      logger.error("e");
+    } finally {
+      console.log = originalLog;
+      console.error = originalError;
+    }
+    assert.equal(logLines.length, 3);
+    assert.equal(errorLines.length, 2);
+  });
+});

tsconfig.json

@@ -11,5 +11,11 @@
     "resolveJsonModule": true
   },
   "include": ["src/**/*.ts"],
-  "exclude": ["node_modules", "dist"]
+  "exclude": [
+    "node_modules",
+    "dist",
+    "src/proxy.ts",
+    "src/instrumentation.ts",
+    "src/instrumentation-node.ts"
+  ]
 }

tsconfig.next.json

@@ -18,6 +18,9 @@
     "src/app/**/*.tsx",
     "src/frontend/**/*.ts",
     "src/frontend/**/*.tsx",
+    "src/proxy.ts",
+    "src/instrumentation.ts",
+    "src/instrumentation-node.ts",
     ".next/types/**/*.ts"
   ],
   "exclude": ["node_modules", "dist"]

tsconfig.scripts.json

@@ -5,5 +5,11 @@
     "rootDir": "."
   },
   "include": ["scripts/**/*.ts", "src/**/*.ts"],
-  "exclude": ["node_modules", "dist"]
+  "exclude": [
+    "node_modules",
+    "dist",
+    "src/proxy.ts",
+    "src/instrumentation.ts",
+    "src/instrumentation-node.ts"
+  ]
 }