IMP-04: fehlerbehandlung-nicht-konformer-server

Defensive Fehlerbehandlung für nicht-RFC-konforme Mailserver beim
Import, mit dokumentierten Fallback-Pfaden statt Abbruch.

- client_real.go: resolveUIDValidity behandelt UIDVALIDITY=0 (bekannte
  archivmail-Abweichung, known-issues #5) und fehlende UIDVALIDITY-Angabe
  als definierten Fallback statt Sync-Abbruch — deterministisch aus dem
  Postfachnamen abgeleitet (FNV-1a), stabil bei wiederholten Läufen.
  parseFetchLines überspringt kaputte/unerwartete FETCH-Zeilen einzeln
  und protokolliert sie, statt den gesamten Lauf zu stoppen. Neuer
  Logger/WithLogger für nachvollziehbares Support-Logging.
- Echten Bug behoben: die getaggte Abschlusszeile enthält ebenfalls
  "FETCH " und wurde zunächst fälschlich als unerwartete Antwort
  geloggt — jetzt nur echte Untagged-Zeilen (Präfix "* ") betrachtet.

Prüfungen (alle real durchgeführt, siehe mail/docs/IMP-04-PRUEFPROTOKOLL.md):
1. TestResolveUIDValidity_ZeroTriggersDefinedFallbackNotAbort: Server
   meldet real UIDVALIDITY=0, Sync liefert real Fallback statt Fehler.
2. TestParseFetchLines_UnexpectedResponseSkippedRestContinue: 2 kaputte
   Zeilen real übersprungen+protokolliert, übrige Nachrichten kommen an.
3. TestResolveUIDValidity_RegressionGuardAgainstZeroAbort: direkter
   Regressionsschutz gegen den ursprünglichen UIDVALIDITY-Bug.

Kein Umbau: imap/folderstate/scheduler.go unverändert.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HhgFcLS8tYMhDJpP74C6AQ
This commit is contained in:
sysops
2026-08-31 23:55:38 +02:00
co-authored by Claude Sonnet 5
parent e9947b1e28
commit 03c47d98f4
3 changed files with 352 additions and 34 deletions
+58
View File
@@ -0,0 +1,58 @@
# IMP-04 Prüfprotokoll: Fehlerbehandlung nicht-konformer Server
Voraussetzung IMP-01 (Fertig).
## Umsetzung
- `mail/internal/imapimport/client_real.go` erweitert:
- `resolveUIDValidity`: eine gemeldete `UIDVALIDITY=0` (bekannte
Abweichung nicht-konformer Server, known-issues-archivmail.md #5)
oder eine ganz fehlende UIDVALIDITY-Angabe löst KEINEN Abbruch mehr
aus, sondern einen definierten Fallback (Akzeptanzkriterium 1):
`fallbackUIDValidity` leitet deterministisch (FNV-1a, gleiche Technik
wie `search.DocumentID`) einen von 0 verschiedenen Ersatzwert aus dem
Postfachnamen ab — bei wiederholten Läufen gegen denselben
nicht-konformen Server bleibt der Fallback STABIL, kein unnötiger
Voll-Resync bei jedem einzelnen Lauf.
- `parseFetchLines`/`parseSingleFetchLine`: eine einzelne unerwartete
oder kaputte `FETCH`-Zeile wird protokolliert und übersprungen, alle
übrigen, korrekt lesbaren Nachrichten werden trotzdem geliefert
(Akzeptanzkriterium 2) — der gesamte Lauf bricht dafür nicht ab.
- `Logger`/`RealClient.WithLogger`: jede erkannte Abweichung läuft über
ein protokollierbares, austauschbares Logging-Ziel mit festem,
durchsuchbarem Präfix (Akzeptanzkriterium 3: für Support
nachvollziehbar) — Standard ist `log.Printf`.
- Dabei einen echten, durch die neue Logging-Logik selbst eingeführten
Bug gefunden und behoben: die getaggte Kommando-Abschlusszeile (z. B.
`"C3 OK UID FETCH completed"`) enthält ebenfalls die Zeichenfolge
`"FETCH "` und wurde beim ersten Anlauf fälschlich als "unerwartete
Serverantwort" geloggt — behoben, indem nur echte Untagged-Zeilen
(Präfix `"* "`) überhaupt als FETCH-Zeile in Betracht gezogen werden.
- Kein Umbau: `mail/internal/imap` (ING-01)/`folderstate` (ING-05)/
`imapimport/scheduler.go` (IMP-01) unverändert — IMP-04 erweitert
ausschließlich `client_real.go`.
## Prüfungen
| # | Prüfung | Ergebnis |
|---|---|---|
| 1 | Test simuliert Server mit UIDVALIDITY=0 und bestätigt greifenden Fallback | **bestanden** `TestResolveUIDValidity_ZeroTriggersDefinedFallbackNotAbort`: hand-gesteuerter Fake-Server meldet real `UIDVALIDITY=0`, `Sync` schlägt real NICHT fehl, liefert real einen von 0 verschiedenen, deterministischen Fallback-Wert und alle 3 Nachrichten, Fallback-Hinweis real protokolliert |
| 2 | Test mit unerwarteter/kaputter Serverantwort bestätigt Weiterlauf für übrige Nachrichten | **bestanden** `TestParseFetchLines_UnexpectedResponseSkippedRestContinue`: 2 bewusst kaputte Zeilen zwischen 2 korrekten real gesendet — `Sync` liefert real trotzdem beide korrekt lesbaren Nachrichten, beide kaputten Zeilen real protokolliert und übersprungen, kein Abbruch |
| 3 | Regressionstest verhindert Wiederauftreten des UIDVALIDITY-Bugs | **bestanden** `TestResolveUIDValidity_RegressionGuardAgainstZeroAbort`: direkter, vom Netzwerkpfad unabhängiger Test von `resolveUIDValidity` mit `UIDVALIDITY=0` UND mit gänzlich fehlender Angabe — beide liefern real keinen Fehler und einen Fallback-Wert != 0 |
## Build/Test-Ergebnis (192.168.1.131)
```
go build ./... -> clean
go vet ./... -> clean
golangci-lint run ./... -> 0 issues
TEST_TENANT_DSN=... go test ./internal/imapimport/... -v -timeout 60s -> 7/7 bestanden
TEST_TENANT_DSN=... TEST_MANTICORE_URL=... go test ./... -p 1
-> alle 15 Pakete bestanden, keine Regression
```
## Gesamtergebnis
**Bestanden.** Alle drei Akzeptanzkriterien und alle drei Pflichtprüfungen
real erfüllt. Entsperrt IMP-08 (gemeinsam mit QA-02, bleibt weiterhin
blockiert bis dessen übrige Abhängigkeiten fertig sind).
+130 -34
View File
@@ -1,17 +1,43 @@
// IMP-04: defensive Fehlerbehandlung nicht-konformer Server. Bekannten
// Fehler vermeiden (siehe known-issues-archivmail.md #5): UIDVALIDITY=0
// führte in einer früheren Implementierung zu einem Resync-Abbruch —
// dieses Paket behandelt eine gemeldete UIDVALIDITY=0 als bekannte
// Serverabweichung mit definiertem Fallback (deterministisch aus dem
// Postfachnamen abgeleitet, siehe fallbackUIDValidity), NICHT als
// Fehlerabbruch. Unerwartete/kaputte Serverantworten (einzelne
// FETCH-Zeilen) werden übersprungen und protokolliert, statt den
// gesamten Abgleich zu stoppen (siehe parseFetchLines).
//
// Fallback-Verhalten für Support (Akzeptanzkriterium 3): jede erkannte
// Abweichung läuft über Logger — Standard-Logging-Ziel ist der
// Prozess-Log (log.Printf), bei Bedarf per WithLogger umleitbar/
// abschaltbar. Log-Präfix ist immer "imapimport: unerwartete
// server-antwort" bzw. "imapimport: UIDVALIDITY=0 gemeldet" für
// durchsuchbare Nachvollziehbarkeit.
package imapimport
import (
"bufio"
"context"
"fmt"
"hash/fnv"
"log"
"net"
"strconv"
"strings"
)
// Logger protokolliert erkannte Serverabweichungen (Akzeptanzkriterium
// 3: nachvollziehbar für Support). Signatur kompatibel mit log.Printf.
type Logger func(format string, args ...any)
func defaultLogger(format string, args ...any) {
log.Printf(format, args...)
}
// RealClient spricht echtes IMAP4rev1 (RFC 3501) über TCP — genutzt für
// den realistischen Testpostfach-Nachweis (Pflichtprüfung 3) gegen den
// echten ING-01-Server, und produktiv gegen jeden RFC-3501-konformen
// den realistischen Testpostfach-Nachweis (IMP-01 Pflichtprüfung 3) gegen
// den echten ING-01-Server, und produktiv gegen jeden RFC-3501-konformen
// IMAP-Server. Bewusst minimal: nur der für RunOnce nötige Ablauf
// (LOGIN, SELECT, UID FETCH ALL, LOGOUT), keine generische
// IMAP-Client-Bibliothek.
@@ -20,10 +46,24 @@ type RealClient struct {
username string
password string
dialer net.Dialer
logger Logger
}
func NewRealClient(addr, username, password string) *RealClient {
return &RealClient{addr: addr, username: username, password: password}
return &RealClient{addr: addr, username: username, password: password, logger: defaultLogger}
}
// WithLogger ersetzt das Standard-Logging-Ziel (z. B. für Tests, die die
// protokollierten Meldungen prüfen wollen, oder um es abzuschalten).
func (c *RealClient) WithLogger(logger Logger) *RealClient {
c.logger = logger
return c
}
func (c *RealClient) log(format string, args ...any) {
if c.logger != nil {
c.logger(format, args...)
}
}
func (c *RealClient) Sync(ctx context.Context, mailbox string) (uint64, []RemoteMessage, error) {
@@ -51,7 +91,7 @@ func (c *RealClient) Sync(ctx context.Context, mailbox string) (uint64, []Remote
if err != nil {
return 0, nil, fmt.Errorf("imapimport: select: %w", err)
}
uidvalidity, err := extractUIDValidity(selectLines)
uidvalidity, err := c.resolveUIDValidity(selectLines, mailbox)
if err != nil {
return 0, nil, err
}
@@ -60,7 +100,7 @@ func (c *RealClient) Sync(ctx context.Context, mailbox string) (uint64, []Remote
if err != nil {
return 0, nil, fmt.Errorf("imapimport: uid fetch: %w", err)
}
messages := parseFetchLines(fetchLines)
messages := c.parseFetchLines(fetchLines)
_, _ = sendCommand(conn, reader, 4, "LOGOUT")
@@ -99,7 +139,45 @@ func sendCommand(conn net.Conn, reader *bufio.Reader, tagN int, command string)
}
}
func extractUIDValidity(lines []string) (uint64, error) {
// resolveUIDValidity liest UIDVALIDITY aus der SELECT-Antwort
// (Akzeptanzkriterium 1). Eine gemeldete UIDVALIDITY=0 — bekannte
// Abweichung nicht-konformer Server (known-issues-archivmail.md #5) —
// löst einen definierten Fallback aus statt eines Abbruchs: ein
// deterministisch aus dem Postfachnamen abgeleiteter Ersatzwert, der bei
// wiederholten Läufen gegen denselben nicht-konformen Server STABIL
// bleibt (kein unnötiger Voll-Resync bei jedem einzelnen Lauf).
func (c *RealClient) resolveUIDValidity(lines []string, mailbox string) (uint64, error) {
v, found := extractUIDValidity(lines)
if !found {
c.log("imapimport: unerwartete server-antwort: keine UIDVALIDITY in SELECT-Antwort für %q gefunden, verwende fallback", mailbox)
return fallbackUIDValidity(mailbox), nil
}
if v == 0 {
c.log("imapimport: UIDVALIDITY=0 gemeldet für postfach %q (bekannte abweichung nicht-konformer server) — verwende definierten fallback statt sync-abbruch", mailbox)
return fallbackUIDValidity(mailbox), nil
}
return v, nil
}
// fallbackUIDValidity leitet einen deterministischen, garantiert von 0
// verschiedenen Ersatzwert aus dem Postfachnamen ab (FNV-1a, gleiche
// Technik wie mail/internal/search.DocumentID).
func fallbackUIDValidity(mailbox string) uint64 {
h := fnv.New64a()
_, _ = h.Write([]byte("imap-fallback-uidvalidity:"))
_, _ = h.Write([]byte(mailbox))
v := h.Sum64()
if v == 0 {
v = 1
}
return v
}
// extractUIDValidity sucht "UIDVALIDITY <n>" in den SELECT-Antwortzeilen.
// found=false, wenn keine UIDVALIDITY-Angabe vorhanden ODER sie nicht als
// Zahl lesbar ist (beides bekannte Serverabweichungen, siehe
// resolveUIDValidity — kein Fehlerabbruch an dieser Stelle).
func extractUIDValidity(lines []string) (value uint64, found bool) {
for _, line := range lines {
idx := strings.Index(line, "UIDVALIDITY ")
if idx == -1 {
@@ -112,44 +190,62 @@ func extractUIDValidity(lines []string) (uint64, error) {
}
v, err := strconv.ParseUint(rest[:end], 10, 64)
if err != nil {
return 0, fmt.Errorf("imapimport: uidvalidity parsen: %w", err)
return 0, false
}
return v, nil
return v, true
}
return 0, fmt.Errorf("imapimport: keine UIDVALIDITY in SELECT-Antwort gefunden")
return 0, false
}
// parseFetchLines parst Zeilen der Form
// "* <seq> FETCH (UID <uid> FLAGS (<flags>))" (siehe mail/internal/imap
// writeFetchResults).
func parseFetchLines(lines []string) []RemoteMessage {
// writeFetchResults). Akzeptanzkriterium 2: eine einzelne unerwartete/
// kaputte Zeile wird protokolliert und übersprungen, alle übrigen,
// korrekt lesbaren Nachrichten werden trotzdem geliefert — der gesamte
// Lauf bricht dafür NICHT ab.
func (c *RealClient) parseFetchLines(lines []string) []RemoteMessage {
var messages []RemoteMessage
for _, line := range lines {
if !strings.Contains(line, "FETCH (UID ") {
if !strings.HasPrefix(line, "* ") {
continue // getaggte Abschlusszeile ("C3 OK ..."), kein Untagged-FETCH
}
if !strings.Contains(line, "FETCH ") {
continue // anderweitiges Untagged (z. B. künftig "* OK ..."), nichts zu parsen
}
msg, ok := parseSingleFetchLine(line)
if !ok {
c.log("imapimport: unerwartete server-antwort übersprungen: %q", line)
continue
}
uidIdx := strings.Index(line, "UID ") + len("UID ")
rest := line[uidIdx:]
spaceIdx := strings.IndexByte(rest, ' ')
if spaceIdx == -1 {
continue
}
uid, err := strconv.ParseUint(rest[:spaceIdx], 10, 32)
if err != nil {
continue
}
var flags []string
flagsStart := strings.Index(line, "FLAGS (")
flagsEnd := strings.LastIndex(line, ")")
if flagsStart != -1 && flagsEnd > flagsStart {
inner := line[flagsStart+len("FLAGS (") : flagsEnd]
if inner != "" {
flags = strings.Split(inner, " ")
}
}
messages = append(messages, RemoteMessage{UID: uint32(uid), Flags: flags})
messages = append(messages, msg)
}
return messages
}
func parseSingleFetchLine(line string) (RemoteMessage, bool) {
if !strings.Contains(line, "FETCH (UID ") {
return RemoteMessage{}, false
}
uidIdx := strings.Index(line, "UID ") + len("UID ")
rest := line[uidIdx:]
spaceIdx := strings.IndexByte(rest, ' ')
if spaceIdx == -1 {
return RemoteMessage{}, false
}
uid, err := strconv.ParseUint(rest[:spaceIdx], 10, 32)
if err != nil {
return RemoteMessage{}, false
}
var flags []string
flagsStart := strings.Index(line, "FLAGS (")
flagsEnd := strings.LastIndex(line, ")")
if flagsStart != -1 && flagsEnd > flagsStart {
inner := line[flagsStart+len("FLAGS (") : flagsEnd]
if inner != "" {
flags = strings.Split(inner, " ")
}
}
return RemoteMessage{UID: uint32(uid), Flags: flags}, true
}
@@ -0,0 +1,164 @@
// IMP-04: Fehlerbehandlung nicht-konformer Server. Baut einen minimalen,
// hand-gesteuerten Fake-Server (roher TCP, KEIN mail/internal/imap) auf,
// der bewusst nicht-konforme Antworten sendet — echte Kontrolle über
// genau das Fehlerszenario, das getestet werden soll.
package imapimport
import (
"bufio"
"context"
"fmt"
"net"
"strings"
"testing"
)
// scriptedServer nimmt EINE Verbindung an und sendet exakt die
// vorgegebenen Zeilen als Antwort auf jedes eingehende Kommando (in
// Reihenfolge) — genug Kontrolle, um nicht-konforme Serverantworten
// exakt zu reproduzieren.
type scriptedServer struct {
responses [][]string // je eingehendem Kommando eine Antwortzeilen-Liste
}
func (s *scriptedServer) start(t *testing.T) (addr string) {
t.Helper()
listener, err := net.Listen("tcp", "127.0.0.1:0")
if err != nil {
t.Fatalf("listener: %v", err)
}
go func() {
conn, err := listener.Accept()
if err != nil {
return
}
defer func() { _ = conn.Close() }()
reader := bufio.NewReader(conn)
_, _ = conn.Write([]byte("* OK IMAP4rev1 Service Ready\r\n"))
for _, respLines := range s.responses {
if _, err := reader.ReadString('\n'); err != nil {
return
}
for _, line := range respLines {
if _, err := conn.Write([]byte(line + "\r\n")); err != nil {
return
}
}
}
}()
t.Cleanup(func() { _ = listener.Close() })
return listener.Addr().String()
}
// TestResolveUIDValidity_ZeroTriggersDefinedFallbackNotAbort ist die
// geforderte Pflichtprüfung 1: Test simuliert Server mit UIDVALIDITY=0
// und bestätigt greifenden Fallback.
func TestResolveUIDValidity_ZeroTriggersDefinedFallbackNotAbort(t *testing.T) {
srv := &scriptedServer{responses: [][]string{
{"C1 OK LOGIN completed"},
{"* 3 EXISTS", "* OK [UIDVALIDITY 0] UIDs valid", "C2 OK [READ-WRITE] SELECT completed"},
{"* 1 FETCH (UID 1 FLAGS ())", "* 2 FETCH (UID 2 FLAGS ())", "* 3 FETCH (UID 3 FLAGS ())", "C3 OK UID FETCH completed"},
{"C4 OK LOGOUT completed"},
}}
addr := srv.start(t)
var loggedFallback bool
client := NewRealClient(addr, "user", "pass").WithLogger(func(format string, args ...any) {
msg := fmt.Sprintf(format, args...)
if strings.Contains(msg, "UIDVALIDITY=0") {
loggedFallback = true
}
})
uidvalidity, messages, err := client.Sync(context.Background(), "INBOX")
if err != nil {
// Akzeptanzkriterium 1: KEIN Sync-Abbruch bei UIDVALIDITY=0.
t.Fatalf("erwartete erfolgreichen sync trotz UIDVALIDITY=0, habe fehler: %v", err)
}
if uidvalidity == 0 {
t.Fatal("erwartete definierten fallback-wert != 0, habe weiterhin 0")
}
if len(messages) != 3 {
t.Fatalf("erwartete 3 nachrichten trotz UIDVALIDITY=0, habe %d", len(messages))
}
if !loggedFallback {
t.Fatal("erwartete protokollierten fallback-hinweis (akzeptanzkriterium 3: nachvollziehbar)")
}
// Fallback ist deterministisch für dasselbe Postfach — ein zweiter
// Aufruf gegen einen erneut nicht-konformen Server liefert real
// denselben Ersatzwert, löst also keinen unnötigen Voll-Resync bei
// jedem einzelnen Lauf aus.
if fallbackUIDValidity("INBOX") != uidvalidity {
t.Fatalf("erwartete deterministischen fallback, habe %d vs %d", fallbackUIDValidity("INBOX"), uidvalidity)
}
}
// TestParseFetchLines_UnexpectedResponseSkippedRestContinue ist die
// geforderte Pflichtprüfung 2: Test mit unerwarteter/kaputter
// Serverantwort bestätigt Weiterlauf für übrige Nachrichten.
func TestParseFetchLines_UnexpectedResponseSkippedRestContinue(t *testing.T) {
srv := &scriptedServer{responses: [][]string{
{"C1 OK LOGIN completed"},
{"* 3 EXISTS", "* OK [UIDVALIDITY 42] UIDs valid", "C2 OK [READ-WRITE] SELECT completed"},
{
"* 1 FETCH (UID 1 FLAGS ())",
"* GARBAGE NOT EVEN A FETCH LINE AT ALL", // kaputte/unerwartete Antwort
"* 2 FETCH SOMETHING UNPARSEABLE HERE (UID)", // ebenfalls kaputt
"* 3 FETCH (UID 3 FLAGS (\\Seen))",
"C3 OK UID FETCH completed",
},
{"C4 OK LOGOUT completed"},
}}
addr := srv.start(t)
var skippedCount int
client := NewRealClient(addr, "user", "pass").WithLogger(func(format string, args ...any) {
msg := fmt.Sprintf(format, args...)
if strings.Contains(msg, "unerwartete server-antwort übersprungen") {
skippedCount++
}
})
uidvalidity, messages, err := client.Sync(context.Background(), "INBOX")
if err != nil {
t.Fatalf("erwartete erfolgreichen sync trotz kaputter zeilen, habe fehler: %v", err)
}
if uidvalidity != 42 {
t.Fatalf("erwartete uidvalidity=42, habe %d", uidvalidity)
}
// Akzeptanzkriterium 2: die BEIDEN kaputten Zeilen werden übersprungen
// UND protokolliert, die ÜBRIGEN (real 2) Nachrichten kommen trotzdem an.
if len(messages) != 2 {
t.Fatalf("erwartete 2 lesbare nachrichten trotz kaputter zeilen, habe %d: %+v", len(messages), messages)
}
if skippedCount != 2 {
t.Fatalf("erwartete 2 protokollierte übersprungene zeilen, habe %d", skippedCount)
}
}
// TestResolveUIDValidity_RegressionGuardAgainstZeroAbort ist die
// geforderte Pflichtprüfung 3: Regressionstest verhindert
// Wiederauftreten des UIDVALIDITY-Bugs — prüft die Fallback-Funktion
// isoliert und direkt, unabhängig vom Netzwerkpfad.
func TestResolveUIDValidity_RegressionGuardAgainstZeroAbort(t *testing.T) {
client := NewRealClient("unused:0", "u", "p")
value, err := client.resolveUIDValidity([]string{"* OK [UIDVALIDITY 0] UIDs valid"}, "INBOX")
if err != nil {
t.Fatalf("regression: UIDVALIDITY=0 löste real einen fehler aus (der genau vermiedene bug): %v", err)
}
if value == 0 {
t.Fatal("regression: fallback lieferte weiterhin 0 — bug erneut aufgetreten")
}
// Fehlende UIDVALIDITY-Angabe (noch nicht-konformer als 0) darf
// ebenfalls nicht abbrechen.
value2, err := client.resolveUIDValidity([]string{"C2 OK SELECT completed"}, "INBOX")
if err != nil {
t.Fatalf("regression: fehlende UIDVALIDITY löste real einen fehler aus: %v", err)
}
if value2 == 0 {
t.Fatal("regression: fallback bei fehlender UIDVALIDITY lieferte 0")
}
}