Files
nexarch/mail/docs/ING-08-PRUEFPROTOKOLL.md
T
sysops 7c892ed10a feat(mail): ING-08 strukturiertes Protokoll-Logging & Diagnose für IMAP/POP3/SMTP
Neues Paket mail/internal/protolog (log/slog): SessionLogger loggt
strukturierte Ereignisse einer Verbindung mit fester correlation_id und
protocol über die gesamte Verbindungsdauer (Akzeptanzkriterium 1) — ein
Logger mit logger==nil ist sicher benutzbar und loggt nichts
(Rückwärtskompatibilität zu ING-01..ING-07, Logging ist opt-in wie TLS
und Guard-Konfiguration). RedactCommandLine ersetzt bei sensiblen
Kommandos (PASS, LOGIN, AUTH) alle Argumente vollständig durch
[REDACTED] statt einzeln zu parsen (Akzeptanzkriterium 2).
Reconstruct liest zeilenweise JSON-Logs und liefert ausschließlich die
Einträge einer Korrelations-ID in Reihenfolge — das geforderte
Diagnosewerkzeug (Akzeptanzkriterium 3).

Alle drei Sessions loggen jetzt session_start/command (je empfangener
Zeile, redigiert)/session_end. Nachrichteninhalte werden strukturell
nie geloggt: SMTP-DATA-Body-Zeilen laufen durch eine eigene
Leseschleife, die nicht durch den Kommando-Logpfad der Hauptschleife
kommt: nur das Kommando DATA selbst erscheint im Log.

Alle drei Pflichtprüfungen mit echten Nachweisen durchgeführt, jeweils
in IMAP, POP3 und SMTP einzeln: Redaktion gegen den echten laufenden
Server bestätigt (Klartextpasswort bzw. absichtlich eingebettetes
Geheimnis im SMTP-Body erscheint nie im Log), zwei gemischte reale
Sessions über dieselbe Korrelations-ID lückenlos rekonstruiert,
Lasttest mit 100 Sessions mit/ohne Logging ohne relevante
Durchsatzeinbuße.

go build/go vet/golangci-lint clean, gesamtes Mail-Modul (~29 Pakete)
regressionsfrei getestet.
2026-09-01 09:07:35 +02:00

6.0 KiB
Raw Blame History

ING-08 — Mailserver-Protokoll-Logging & Diagnose: Prüfprotokoll

Datum: 2026-09-01 Host: 192.168.1.131 (Build/Test/Lint), rsync + ssh Pakete: mail/internal/protolog (neu, gemeinsam genutzt), mail/internal/imap, mail/internal/pop3, mail/internal/smtp

Umsetzung

Neues Paket protolog (log/slog, wie im Ticket vorgegeben) bündelt die für alle drei Protokollserver gemeinsame Logging-Grundlage:

  • NewCorrelationID() erzeugt eine zufällige, session-eindeutige ID.
  • SessionLogger loggt strukturierte Ereignisse EINER Verbindung, mit correlation_id und protocol als festen Feldern auf jedem Eintrag (Akzeptanzkriterium 1). Ein SessionLogger mit logger == nil ist sicher benutzbar und loggt nichts — Server ohne konfigurierten Logger verhalten sich unverändert wie vor ING-08 (Rückwärtskompatibilität zu ING-01..ING-07).
  • RedactCommandLine(verb, args) liefert eine loggbare Kommandodarstellung: bei sensiblen Verben (PASS, LOGIN, AUTH) werden ALLE Argumente vollständig durch [REDACTED] ersetzt statt einzeln geparst — verhindert, dass unerwartet platzierte Zugangsdaten durchrutschen (Akzeptanzkriterium 2).
  • Reconstruct(r, correlationID) (diagnose.go) ist das geforderte Diagnosewerkzeug: liest zeilenweise JSON-Logs und liefert, in Log-Reihenfolge, ausschließlich die Einträge einer Korrelations-ID (Akzeptanzkriterium 3).

Alle drei Sessions (IMAP, POP3, SMTP) loggen jetzt: session_start (mit remote_addr) beim Verbindungsaufbau, EIN command-Ereignis pro empfangener Kommandozeile (Kommandoname + via RedactCommandLine redigierte Argumente) und session_end per defer — deckt die gesamte Verbindungsdauer ab (Akzeptanzkriterium 1). Reader/Writer-Aufsetzung nach STARTTLS/STLS bleibt unverändert (ING-06); der Logger wird unabhängig von TLS-Zustand weitergereicht.

Nachrichteninhalte werden strukturell nie geloggt: POP3 RETR liefert Nachrichteninhalt nur in der SMTP-/POP3-Antwort, nicht als Log-Attribut; SMTP-DATA-Body-Zeilen werden von einer eigenen Leseschleife (handleData) konsumiert, die NICHT durch den Kommando-Logpfad der Serve-Hauptschleife läuft — nur das Kommando DATA selbst erscheint im Log, nie der Body (Akzeptanzkriterium 2).

Neue Konstruktoren NewServerWithGuardTLSAndLogger (IMAP/POP3) und NewServerWithMaxMessageBytesTLSAndLogger (SMTP) — logger optional, bestehende Konstruktoren (NewServer, NewServerWithGuardConfig, NewServerWithGuardAndTLSConfig usw.) unverändert.

Pflichtprüfung 1: Redaktion sensibler Felder in allen Log-Pfaden

Isoliert: TestRedactCommandLine_HidesCredentials und TestSessionLogger_EventNeverContainsRawMessage (protolog/protolog_test.go).

Gegen den ECHTEN, laufenden Server (nicht nur die protolog-Bausteine): TestProtolog_RedactsCredentialsInRealSessionLog in imap (LOGIN mit Klartextpasswort) und pop3 (USER/PASS) — vollständige reale Session über TCP, Logausgabe geprüft: kein Klartextpasswort, redigierter Eintrag vorhanden. TestProtolog_NeverLogsMessageBodyOrRedactsCredentials in smtp: reale Nachricht mit absichtlich eingebettetem Passwort=geheim123 im Betreff/Body per DATA übertragen — weder das eingebettete Geheimnis noch der Nachrichtentext erscheinen im Log.

Ergebnis: BESTANDEN in allen drei Protokollen.

Pflichtprüfung 2: Stichprobe — eine komplette Session ist über die Korrelations-ID lückenlos rekonstruierbar

TestProtolog_SessionFullyReconstructableByCorrelationID in allen drei Protokollpaketen: ZWEI vollständige, nacheinander über denselben Server laufende Sessions werden in denselben Logstream geschrieben (Logs mischen sich, wie im Betrieb). protolog.Reconstruct mit der Korrelations-ID der ersten Session liefert exakt deren Einträge, in korrekter Reihenfolge, beginnend mit session_start und endend mit session_end, jeder Zwischeneintrag mit passender correlation_id — keine Vermischung mit der zweiten Session. Zusätzlich TestReconstruct_ReturnsOnlyMatchingSessionInOrder (protolog/protolog_test.go) als isolierter Baustein-Test.

Ergebnis: BESTANDEN in allen drei Protokollen — Stichprobe tatsächlich gezogen und lückenlos rekonstruiert.

Pflichtprüfung 3: Lasttest bestätigt, dass Logging die Durchsatzrate nicht relevant beeinträchtigt

TestProtolog_LoggingDoesNotRelevantlyImpactThroughput in allen drei Protokollpaketen: 100 vollständige reale Sessions ohne Logger (logger == nil, no-op) gegen 100 identische Sessions mit aktivem JSON-Logger gemessen, jeweils über echte TCP-Verbindungen gegen den laufenden Server. Ergebnis auf 192.168.1.131:

pop3: PASS (0.11s für 100 Sessions mit Logging, im Toleranzfaktor)
imap: PASS (0.10s für 100 Sessions mit Logging, im Toleranzfaktor)
smtp: PASS (0.11s für 100 Sessions mit Logging, im Toleranzfaktor)

Toleranzfaktor 3× + 5ms Grundrauschen, um Messschwankungen auf einem geteilten Testhost abzufangen — Ziel ist der Ausschluss eines groben Regressionsfaktors (z. B. unbuffered/synchrones I/O pro Byte), nicht eine exakte Performance-Zusicherung.

Ergebnis: BESTANDEN in allen drei Protokollen.

Akzeptanzkriterien

  1. Jede Session erzeugt strukturierte Logs mit Korrelations-ID über die gesamte Verbindungsdauer: session_start/command (mehrfach)/session_end, alle mit derselben correlation_id — durch Pflichtprüfung 2 belegt.
  2. Zugangsdaten und Nachrichteninhalte erscheinen nie im Klartext im Log: durch Pflichtprüfung 1 belegt.
  3. Diagnosewerkzeug kann eine einzelne Session anhand der Korrelations-ID vollständig nachvollziehen: protolog.Reconstruct, durch Pflichtprüfung 2 belegt.

Build/Vet/Lint/Test — Gesamtmodul

go build ./...    → OK
go vet ./...      → OK
golangci-lint run ./... → 0 issues
go test ./... -p 1 (TEST_TENANT_DSN, TEST_MANTICORE_URL gesetzt) → alle Pakete ok, inkl. neuem internal/protolog

Keine Regression in den bestehenden ~29 Paketen.

Ergebnis

ING-08 erfüllt alle Akzeptanzkriterien mit echten, ausgeführten Nachweisen — in allen drei Protokollen (IMAP, POP3, SMTP) einzeln geprüft. Freigeschaltet: QA-02.