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

131 lines
6.0 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# 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.