Logging

Der Fehler-Handler aus der letzten Lektion schreibt „nach innen alles”. Nur wohin genau, und in welcher Form? Darauf gibt es eine erstaunlich klare Antwort, und sie folgt aus einer einzigen Frage: Was soll das Log leisten?

Es soll eine Frage von gestern beantworten. „Warum hat die Bestellung 4711 keine Bestätigung bekommen?” „Seit wann sind die Antworten langsam?” „Was ist um 3:14 Uhr passiert?” Wer sich das vor Augen hält, braucht keine weiteren Regeln, denn alle folgenden ergeben sich daraus.

01 / 05Sätze sind für Menschen, Zeilen sind für Werkzeuge

const ereignisse = [
  { anfrageId: "a1b2c3", pfad: "/api/buecher", status: 201, dauerMs: 1830 },
  { anfrageId: "d4e5f6", pfad: "/api/buecher/7", status: 200, dauerMs: 12 },
  { anfrageId: "g7h8i9", pfad: "/api/kaufen", status: 500, dauerMs: 2400 },
];

console.log("So, wenn du es selbst liest:");
for (const e of ereignisse) {
  console.log(`  Anfrage an ${e.pfad} war nach ${e.dauerMs} ms mit ${e.status} fertig`);
}

console.log("\nSo, wenn es jemand auswerten soll:");
const zeilen = ereignisse.map((e) =>
  JSON.stringify({ zeit: "2026-08-14T09:12:00.000Z", level: e.status >= 500 ? "error" : "info", ...e })
);
for (const zeile of zeilen) console.log(`  ${zeile}`);

// Die Frage von gestern: welche Anfragen brauchten laenger als eine Sekunde?
const langsam = zeilen.map((z) => JSON.parse(z)).filter((z) => z.dauerMs > 1000);
console.log(`\nLangsamer als 1000 ms: ${langsam.map((z) => z.anfrageId).join(", ")}`);

Die erste Form liest sich besser. Sie ist trotzdem die schlechtere, sobald mehr als ein Mensch das Log liest oder mehr als drei Zeilen darin stehen.

Der Grund steht am Ende des Beispiels. Die Frage „welche Anfragen brauchten länger als eine Sekunde” ist auf der strukturierten Form eine Zeile Code. Auf der Satzform ist sie ein regulärer Ausdruck, der kaputtgeht, sobald jemand den Satz umformuliert.

Deshalb: eine Zeile je Eintrag, JSON, ohne Einrückung. Eine Zeile deshalb, weil jedes Werkzeug, das Logs einsammelt, zeilenweise arbeitet. Ein über fünf Zeilen eingerücktes JSON wird dabei zu fünf zusammenhanglosen Einträgen.

02 / 05Was in jeden Eintrag gehört

Vier Dinge, jedes Mal:

• Zeitstempel, als ISO-Zeichenkette in UTC. Nicht in Ortszeit, sonst passen zwei Server nicht zusammen, und einmal im Jahr gibt es eine Stunde doppelt.
• Stufe, also debug, info, warn oder error.
• Meldung, kurz und stabil. Am besten ein Ereignisname wie bestellung_angelegt statt eines Satzes, der sich morgen ändert.
• Anfragekennung, damit zusammengehörende Zeilen zusammenfinden. Die hast du in Lektion 10.2 schon gebaut und in die Kopfzeile X-Anfrage-Id gelegt. Hier bekommt sie ihren eigentlichen Sinn: Sie ist der Faden, an dem du zwanzig Zeilen aus einer Anfrage aus zehntausend anderen herausziehst.

Alles Weitere sind Felder, und Felder sind billig. Pfad, Methode, Statuscode, Dauer, Kennung des betroffenen Datensatzes.

03 / 05Stufen sind zum Filtern da, nicht zum Schmücken

// Von leise nach laut. Die Reihenfolge ist der ganze Filter.
const STUFEN = ["debug", "info", "warn", "error"];

function laut(stufe) {
  return STUFEN.indexOf(stufe) >= STUFEN.indexOf(process.env.LOG_LEVEL ?? "info");
}

for (const grenze of ["debug", "info", "error"]) {
  process.env.LOG_LEVEL = grenze;
  const durch = STUFEN.filter((stufe) => laut(stufe));
  console.log(`LOG_LEVEL=${grenze.padEnd(6)} laesst durch: ${durch.join(", ")}`);
}

Vier Stufen, eine Reihenfolge, ein Vergleich. Mehr ist der ganze Filter nicht.

Der eigentliche Punkt ist, wozu die Stufen da sind. Nicht dazu, wichtige Zeilen zu betonen, sondern dazu, in der Produktion weglassen zu können, was du beim Entwickeln brauchst. debug ist großzügig und darf alles enthalten, weil es normalerweise nicht mitläuft. error ist teuer, weil jemand es liest.

Die Grenze kommt aus der Umgebung und nicht aus dem Code. Sie zu ändern muss ohne neues Deployment gehen: Wenn du nachts um drei mehr sehen willst, willst du eine Variable ändern und neu starten, nicht einen Pull Request schreiben.

Kurz zur Aufteilung der Kanäle: warn und alles darunter geht auf stdout, error auf stderr. Das ist genau die Trennung aus Lektion 4.3, und console.log und console.error machen sie von selbst.

04 / 05Was nie hineingehört

Jetzt der Teil, der wehtut. Die häufigste Datenpanne mit Passwörtern ist kein Angriff, sondern ein Log. Niemand bricht ein, es steht einfach da, in einer Datei, auf die viel mehr Leute Zugriff haben als auf die Datenbank, und oft länger aufbewahrt als alles andere.

const GEHEIM = ["passwort", "token", "authorization", "cookie"];

function entschaerfe(felder) {
  const sauber = {};
  for (const [name, wert] of Object.entries(felder)) {
    sauber[name] = GEHEIM.includes(name.toLowerCase()) ? "[entfernt]" : wert;
  }
  return sauber;
}

// So sieht eine Anmeldung aus, wenn man den ganzen Koerper protokolliert.
const koerper = { email: "test@beispiel.de", passwort: "einlangesgeheimnis", merken: true };
console.log(`ungefiltert: ${JSON.stringify(koerper)}`);
console.log(`entschaerft: ${JSON.stringify(entschaerfe(koerper))}`);

// Und so, wenn das Geheimnis eine Ebene tiefer liegt.
const verschachtelt = { nutzer: { email: "test@beispiel.de", passwort: "einlangesgeheimnis" } };
console.log(`verschachtelt: ${JSON.stringify(entschaerfe(verschachtelt))}`);

Der Auslöser ist fast immer derselbe: Jemand protokolliert den ganzen Anfragekörper, um zu sehen, was ankommt. Bei einer Anmeldung steht das Passwort mit drin. Bei einer Zahlung die Kartendaten. Bei den Kopfzeilen das Sitzungscookie und der Authorization-Header, und mit dem kann sich jeder als dieser Nutzer ausgeben, solange er gilt.

Die Gegenmaßnahme ist eine Liste von Feldnamen, die durch einen Platzhalter ersetzt werden, und zwar im Logger selbst. Nicht an jeder Aufrufstelle: Genau eine wird vergessen, und dann ist es dieselbe Lage wie vorher.

Der ehrliche Vorbehalt steht in der dritten Zeile der Ausgabe. Diese Entschärfung schaut nur auf die oberste Ebene. Liegt das Passwort in einem verschachtelten Objekt, geht es durch. In echt läuft die Ersetzung deshalb rekursiv, oder man protokolliert von vornherein nur ausgewählte Felder statt ganzer Objekte. Die zweite Lösung ist die bessere: Eine Allowlist bleibt richtig, auch wenn morgen jemand ein neues Feld hinzufügt.

05 / 05Wohin geschrieben wird

Auf stdout und stderr. Sonst nirgendwohin.

Das klingt nach zu wenig und ist genau richtig. Ein Programm, das selbst in eine Datei schreibt, muss sich um Dinge kümmern, die es nichts angehen: Wohin genau, wer darf das Verzeichnis lesen, was passiert bei einem Neustart, wie wird die Datei rotiert, bevor die Platte voll ist, und was machen zwei gleichzeitig laufende Instanzen mit derselben Datei? Genau so eine Datei ist in Lektion 7.6 entstanden, und dort war sie ein Übungsstück und keine Empfehlung.

Die Umgebung kann das alles besser. Sie sammelt stdout und stderr ein und schiebt sie dorthin, wo Logs eben liegen. Dein Programm schreibt Zeilen und ist fertig, und das ist nebenbei der Grund, warum diese Regel unabhängig davon gilt, ob du auf einem Server, in einem Container oder in einer Funktion läufst.