Skip to content
Kumiko

Infrastruktur: Logging, Error Handling, Request Context, Shutdown

Querschnitt-Themen die im Framework-Core stecken — keine Features, sondern automatisch da.

Logging

Logger Interface (Server + Client gleich)

type Logger = {
  info(msg: string, data?: Record<string, unknown>): void;
  warn(msg: string, data?: Record<string, unknown>): void;
  error(msg: string, data?: Record<string, unknown>): void;
  debug(msg: string, data?: Record<string, unknown>): void;
  child(context: Record<string, unknown>): Logger;
};

Der Entwickler schreibt ueberall ctx.log.info("message") — egal ob Server oder Client.

Implementierungen

UmgebungImplementierungTransport
Server (Bun)pino (schnellster JSON Logger)stdout → Logfile/Cloud
Client (Expo)Leichter Wrapper, gleiche APIConsole (Dev), POST /log an Server (Prod)

Automatischer Context

Framework erstellt pro Request/Job einen Child Logger mit Context:

// In der Pipeline — automatisch, kein Code vom Entwickler:
const requestLogger = log.child({
  requestId: "req-abc-123",
  tenantId: 42,
  userId: 7,
  handler: "orders.order.create",
});


// Im Handler — der Entwickler schreibt nur:
ctx.log.info("Order created", { orderId: 123 });


// Ausgabe (JSON):
// {"level":"info","requestId":"req-abc-123","tenantId":42,"userId":7,
//  "handler":"orders.order.create","msg":"Order created","orderId":123}

Correlation: Request → Job → Event

Request-ID propagiert automatisch durch die gesamte Kette:

Request req-abc-123
  → WriteHandler (ctx.log hat requestId)
    → SharedEvent (requestId im Payload)
      → Job (ctx.log hat origRequestId)
        → Delivery (ctx.log hat origRequestId)

Alle Logs zu einem User-Klick sind ueber die Request-ID filterbar.

Client-Logs in Production

Client schickt Logs an POST /log — Framework sammelt und loggt server-seitig:

// Client (automatisch im Logger-Wrapper):
await fetch("/log", {
  method: "POST",
  body: JSON.stringify({
    level: "error",
    msg: "Failed to load order",
    screen: "orderDetail",
    orderId: 123,
  }),
});
// → Server loggt mit tenantId + userId aus JWT

Dev vs. Production

UmgebungFormatLevel
DevHuebsch (pino-pretty)debug
ProductionJSON (structured)info

Konfigurierbar via ENV: LOG_LEVEL=debug, LOG_FORMAT=pretty.

Error Handling

Error-Klassen

Framework liefert typisierte Error-Klassen die automatisch auf HTTP Status gemappt werden:

// Im Handler — der Entwickler wirft nur:
throw new NotFoundError("order", orderId);                          // → 404
throw new AccessDeniedError("order.create");                        // → 403
throw new ValidationError([{ field: "email", error: "invalid" }]);  // → 422
throw new ConflictError("version_conflict");                        // → 409
throw new PipelineError("custom message", 400);                     // → beliebiger Status

Automatische Error-Response

Hono Middleware faengt alle Errors und liefert einheitliche Responses:

// Client bekommt immer:
{
  "error": "not_found",
  "message": "order 123 not found",
  "requestId": "req-abc-123"
}


// Bei ValidationError zusaetzlich:
{
  "error": "validation_error",
  "message": "Validation failed",
  "requestId": "req-abc-123",
  "fields": [
    { "field": "email", "error": "invalid" }
  ]
}

Automatisches Logging

Jeder Error wird automatisch geloggt — der Entwickler muss kein try/catch mit Logging bauen:

Error-TypLog-LevelStack Trace
ValidationError (422)warnNein
NotFoundError (404)warnNein
AccessDeniedError (403)warnNein
ConflictError (409)warnNein
Unbekannter Error (500)errorJa (nur Server-Log, nie an Client)

Dev vs. Production

UmgebungError-Response
DevError + Message + Stack Trace
ProductionError + Message + RequestId (kein Stack Trace)

Request Context

Zwei Mechanismen

MechanismusWoWofuer
AsyncLocalStorageUeberall (auch ohne ctx)Logger, Request-ID
PipelineContext (ctx)Handler, Hooks, JobsAlles explizite

PipelineContext (erweitert)

type PipelineContext = {
  // Schon da:
  readonly db: DrizzleInstance;
  readonly user: PipelineUser;


  // Neu:
  readonly log: Logger;              // Child Logger mit Request Context
  readonly requestId: string;        // Correlation-ID
  readonly config: ConfigAccessor;   // ctx.config("feature.key")
  readonly delivery: DeliveryAccessor; // ctx.delivery.send(...)
};

Request-ID Generierung

// Hono Middleware:
app.use("*", async (c, next) => {
  // Aus Header uebernehmen (Proxy/Load Balancer) oder generieren
  const requestId = c.req.header("X-Request-ID") ?? generateRequestId();
  c.header("X-Request-ID", requestId);


  // AsyncLocalStorage setzen
  await requestContext.run({ requestId, tenantId, userId }, next);
});

Request Cancellation (ctx.signal)

Mobile- und Web-Clients brechen Requests häufig ab — User navigiert weg, Tab wird zu, Mobile-App geht in den Hintergrund. Ohne Propagation läuft der Server-Side-Handler bis zum Ende und produziert Bytes / DB-Last die niemand mehr lesen wird. ctx.signal macht den Browser-Abort sichtbar im Handler.

Wie es fließt

  1. HTTP-Layer: Hono exponiert c.req.raw.signal (Fetch-Standard AbortSignal). requestIdMiddleware extrahiert es und legt es in den requestContext (AsyncLocalStorage).
  2. Dispatcher: Beim Bauen der HandlerContext zieht der Dispatcher signal aus requestContext.get() und setzt ctx.signal — nur wenn vorhanden (kein Phantom-Signal für Background-Jobs / MSP-Applies).
  3. Handler: Liest ctx.signal?.throwIfAborted() an Stellen wo es sich lohnt (Loops, Multi-Step-Workflows). Kurze Handler ignorieren es einfach — kein Boilerplate-Zwang.

Wann nutzen

r.queryHandler("export:big-csv", schema, async (q, ctx) => {
  for (const row of bigDataset) {
    ctx.signal?.throwIfAborted();    // ← pro-Iteration check
    await processRow(row);
  }
});

Faustregel: Wenn dein Handler in irgendeiner Schleife > 100ms verbringt, einen Check rein. Sonst: ignorieren — der Pipeline-Layer (DB-Wrapper, streamAllEventsByType, rebuildProjection) honoriert ctx.signal automatisch wo es Sinn macht.

Was NICHT enthalten ist (Stand Sprint G.3)

  • Aktiver Postgres-Query-Cancel: Eine bereits laufende DB-Query wird nicht abgebrochen. postgres-js connection-cancel ist riskant für den Connection-Pool — eigener Sprint wenn 30s+-Queries auftauchen.
  • Job-Runner / MSP-Apply Cancellation: Background-Pfade haben anderes Failure-Modell (Retry, Dead-Letter), brauchen kein HTTP-style cancel.
  • Per-Query Pre-Flight: Stufe 1 wird in einem Folge-Sprint nachgezogen — TenantDb checkt signal?.throwIfAborted() vor jedem await der nächsten Query, sodass Handler mit 10 sequentiellen Queries nach Abort nur die erste auslaufen lassen.

Graceful Shutdown

Ausfuehrlich in lifecycle.md. Kurz: SIGTERM → draining-State → /health/ready 503 → LB zieht Traffic → In-Flight-Requests drainiert → Background-Worker gestoppt → DB/Redis geschlossen → Observability-Flush → Exit. Default-Timeouts: 3s Linger + 30s Drain + Rest, gesamt 40s.

Framework handled automatisch, Feature-Code muss nichts tun.

Idempotency + Event Dedup

Ein Pattern, zwei Stellen: Writes und Events. Beide nutzen Redis SETNX mit TTL.

Writes (Client → Server)

User klickt doppelt, Client retried bei Timeout → requestId verhindert doppelte Verarbeitung.

Write kommt rein: requestId = "req-xyz-789"
  → Redis: SETNX "dedup:req-xyz-789" "1" EX 300
  → Key neu → verarbeiten
  → Key existiert → skip, cached Result zurueckgeben

Haben wir schon gebaut.

Events (Server → Handler/Job)

Redis Pub/Sub Reconnect, Worker Crash + Restart → eventId verhindert doppelte Verarbeitung.

Event kommt rein: eventId = "evt-abc-123"
  → Redis: SETNX "dedup:evt-abc-123" "1" EX 300
  → Key neu → verarbeiten
  → Key existiert → skip

Automatische IDs

Framework generiert automatisch:

// SharedEvent bekommt eventId:
await broker.emit({
  kind: "shared",
  type: "order.stateChanged",
  eventId: "evt-abc-123",       // Framework generiert automatisch
  payload: { ... },
  causedBy: "req-xyz-789",      // Request-ID die das Event ausgeloest hat
});


// Job bekommt jobId:
// BullMQ nutzt eigene Job-IDs — bei gleichem Job-Namen + Payload → Dedup

Correlation Chain

requestId: "req-xyz-789" (User klickt)
  → eventId: "evt-abc-123" (SharedEvent, causedBy: req-xyz-789)
    → jobId: "job-def-456" (Job, causedBy: evt-abc-123)
      → eventId: "evt-ghi-789" (Neues Event aus Job, causedBy: job-def-456)

Alle IDs sind im Log — kompletter Trace von User-Klick bis zum letzten Side-Effect.

SETNX ist atomar

Auch bei 10 Worker-Instanzen gleichzeitig: genau einer verarbeitet das Event. Redis garantiert das.

Was der Entwickler tut vs. was das Framework tut

ThemaEntwicklerFramework
Loggingctx.log.info("message")Context (requestId, tenant, user), JSON Format, Transport
Errorsthrow new NotFoundError(...)Fangen, HTTP Status mappen, Response formatieren, Loggen
Request ContextNichtsRequest-ID generieren, propagieren, in ctx bereitstellen
IdempotencyrequestId im Write mitgebenDedup via Redis SETNX, eventId automatisch
ShutdownNichtsSignals fangen, Connections schliessen, Jobs pausieren