From fbb2fe95c8b04a1e4bd23e8c356c183af6847faf Mon Sep 17 00:00:00 2001 From: duffyduck Date: Tue, 29 Sep 2026 12:02:30 +0200 Subject: [PATCH] move mails without Message-ID; log the reason for failed actions A spam mail matched stefanhacker@gmx.de but "Aktion fehlgeschlagen" every time: it has no Message-ID header, and the safe move refused to proceed because it verifies the copy by Message-ID. So every mail without that header stayed in INBOX forever, and the log didn't say why. Verification now falls back when there is no Message-ID: - COPYUID from the COPY response when the server supports UIDPLUS - otherwise count mails in the target with the same exact size and sender before and after COPY; exactly one more means it arrived The source is still only flagged/expunged after verification, and move_mail now refuses to run without source_folder (the verification selects the target, so STORE could otherwise hit the wrong folder). Checked against a simulated IMAP server for success, rejected COPY, copy not arriving, and missing source folder. IMAPClient.last_error carries the reason (rejected COPY with server text, copy not found incl. how it was checked, missing target folder, no SMTP config, ...); the scheduler appends it to the log message. "Fehlgeschlagene neu einlesen" now also retries failed actions, not only fetch errors. Co-Authored-By: Claude Opus 5.5 --- app/routers/filters.py | 14 +-- app/services/filter_engine.py | 9 +- app/services/imap_client.py | 161 +++++++++++++++++++++++----------- app/services/scheduler.py | 3 +- app/templates/logs.html | 4 +- 5 files changed, 131 insertions(+), 60 deletions(-) diff --git a/app/routers/filters.py b/app/routers/filters.py index 17ffddd..9a77c9e 100644 --- a/app/routers/filters.py +++ b/app/routers/filters.py @@ -1,5 +1,5 @@ from fastapi import APIRouter, Depends, HTTPException -from sqlalchemy import func, text +from sqlalchemy import func, or_, text from sqlalchemy.orm import Session import logging @@ -92,13 +92,17 @@ def reset_all_processed(db: Session = Depends(get_db)): @router.post("/retry-failed") def retry_failed_fetches(account_id: int | None = None, db: Session = Depends(get_db)): - """Löscht ProcessedMail-Einträge für UIDs, für die es einen ERROR-Log - mit 'Fehler beim Abrufen' gibt — damit der Scheduler sie beim nächsten - Poll neu versucht (z.B. nach einem Codec-Fix).""" + """Löscht ProcessedMail-Einträge für UIDs, bei denen das Abrufen oder eine + Aktion (z.B. Verschieben) fehlgeschlagen ist — damit der Scheduler sie beim + nächsten Poll neu versucht (z.B. nach einem Fix). Schon verschobene Mails + liegen nicht mehr im Quellordner und werden daher nicht doppelt verarbeitet.""" try: log_q = db.query(FilterLog.mail_uid, FilterLog.account_id).filter( FilterLog.level == LogLevel.ERROR, - FilterLog.message.like("Fehler beim Abrufen%"), + or_( + FilterLog.message.like("Fehler beim Abrufen%"), + FilterLog.message.like("Aktion fehlgeschlagen%"), + ), FilterLog.mail_uid.isnot(None), ) if account_id is not None: diff --git a/app/services/filter_engine.py b/app/services/filter_engine.py index a895c8b..e601f73 100644 --- a/app/services/filter_engine.py +++ b/app/services/filter_engine.py @@ -189,7 +189,8 @@ def execute_action( match action.action_type: case ActionType.MOVE: if not action.parameter: - logger.error("Kein Zielordner für Move-Aktion angegeben") + imap_client.last_error = "Kein Zielordner in der Regel angegeben" + logger.error(imap_client.last_error) return False return imap_client.move_mail( mail.uid, action.parameter, source_folder=source_folder @@ -203,7 +204,11 @@ def execute_action( return imap_client.mark_as_read(mail.uid) case ActionType.FORWARD: if not action.parameter or not smtp_config: - logger.error("Forward-Aktion: Zieladresse oder SMTP-Config fehlt") + imap_client.last_error = ( + "Keine Zieladresse angegeben" if not action.parameter + else "Für dieses Konto ist kein SMTP-Server konfiguriert" + ) + logger.error("Forward-Aktion: %s", imap_client.last_error) return False return imap_client.forward_mail( uid=mail.uid, diff --git a/app/services/imap_client.py b/app/services/imap_client.py index a50dd75..e8d819a 100644 --- a/app/services/imap_client.py +++ b/app/services/imap_client.py @@ -175,6 +175,8 @@ class IMAPClient: self.password = password self.use_ssl = use_ssl self._conn: imaplib.IMAP4 | None = None + # Grund des letzten fehlgeschlagenen Aktions-Aufrufs, fürs Verarbeitungslog + self.last_error: str | None = None def connect(self) -> None: # Ohne Timeout blockiert ein Socket ewig, wenn der Server (oder eine @@ -347,69 +349,126 @@ class IMAPClient: logger.error("Fehler bei Verifikation in '%s': %s", folder, e) return False + def _fail(self, reason: str) -> bool: + """Merkt den Grund des letzten Fehlschlags (für das Verarbeitungslog).""" + self.last_error = reason + logger.error(reason) + return False + + def _fingerprint(self, uid: str) -> tuple[int, str | None] | None: + """Größe in Bytes und Absenderadresse der Mail — Ersatz-Anker für die + Verifikation, wenn die Mail keine Message-ID hat (typisch für Spam).""" + status, data = self.conn.uid("FETCH", uid, "(RFC822.SIZE BODY.PEEK[HEADER.FIELDS (FROM)])") + if status != "OK" or not data: + return None + size, sender = None, None + for part in data: + meta = part[0] if isinstance(part, tuple) else part + if isinstance(meta, (bytes, bytearray)): + m = re.search(rb"RFC822\.SIZE (\d+)", meta) + if m: + size = int(m.group(1)) + if isinstance(part, tuple) and len(part) >= 2: + text = _safe_decode(part[1], None) + m = re.search(r"[\w.+-]+@[\w-]+(?:\.[\w-]+)+", text) + if m: + sender = m.group(0) + return (size, sender) if size is not None else None + + def _count_fingerprint(self, folder: str, size: int, sender: str | None) -> int | None: + status, _ = self.conn.select(_quote_mailbox(folder), readonly=True) + if status != "OK": + return None + criteria = ["LARGER", str(size - 1), "SMALLER", str(size + 1)] + if sender and sender.isascii(): + criteria += ["FROM", f'"{sender}"'] + status, data = self.conn.uid("SEARCH", None, *criteria) + if status != "OK": + return None + return len(data[0].split()) if data and data[0] else 0 + def move_mail( self, uid: str, target_folder: str, source_folder: str | None = None, ) -> bool: - """Sicheres Verschieben: COPY → Verifikation per Message-ID im Ziel → erst dann - Quelle löschen. Schlägt die Verifikation fehl, bleibt die Mail in der Quelle. + """Sicheres Verschieben: COPY → Verifikation im Ziel → erst dann Quelle + löschen. Schlägt die Verifikation fehl, bleibt die Mail in der Quelle. - Wenn source_folder gesetzt ist, wird der Ordner nach der Verifikation wieder - selektiert (da die Verifikation den Zielordner aktiv schaltet).""" + Verifikation, in dieser Reihenfolge: + 1. Message-ID im Zielordner suchen + 2. ohne Message-ID: COPYUID aus der Server-Antwort (UIDPLUS) prüfen + 3. sonst: Mails mit gleicher Größe + Absender im Ziel vor und nach dem + COPY zählen — genau eine mehr heißt: angekommen. + + source_folder ist nötig, weil die Verifikation den Zielordner selektiert; + ohne erneutes Selektieren der Quelle würde STORE/EXPUNGE im falschen + Ordner landen.""" + self.last_error = None + if not source_folder: + return self._fail(f"Mail {uid}: Quellordner unbekannt — Verschieben abgebrochen") try: - # 1. Message-ID aus der Quelle merken (vor COPY!) — Anker für die Verifikation message_id = self._read_message_id(uid) + fingerprint, count_before = None, None if not message_id: - logger.error( - "Mail %s hat keine Message-ID — sicheres Verschieben nicht möglich, " - "Quelle wird NICHT angetastet (Ziel: '%s')", - uid, target_folder, - ) - return False - - # 2. COPY in den Zielordner - copy_status, copy_data = self.conn.uid( - "COPY", uid, _quote_mailbox(target_folder) - ) - if copy_status != "OK": - logger.error( - "COPY fehlgeschlagen für Mail %s nach '%s': %s %s — " - "Quelle bleibt unangetastet", - uid, target_folder, copy_status, copy_data, - ) - # Quell-Ordner sicherheitshalber neu selektieren - if source_folder: - self.conn.select(_quote_mailbox(source_folder)) - return False - - # 3. Verifikation: Mail im Zielordner per Message-ID suchen - verified = self._mail_exists_in_folder(target_folder, message_id) - - # 4. Quell-Ordner wieder aktivieren (Verifikation hat ihn umgeschaltet) - if source_folder: + fingerprint = self._fingerprint(uid) + if fingerprint: + count_before = self._count_fingerprint(target_folder, *fingerprint) self.conn.select(_quote_mailbox(source_folder)) + if count_before is None and "UIDPLUS" not in self.conn.capabilities: + return self._fail( + f"Mail {uid} hat keine Message-ID und konnte im Ziel '{target_folder}' " + "nicht anders wiedererkannt werden — Mail bleibt in der Quelle" + ) + + copy_status, copy_data = self.conn.uid("COPY", uid, _quote_mailbox(target_folder)) + if copy_status != "OK": + self.conn.select(_quote_mailbox(source_folder)) + detail = b" ".join(d for d in copy_data if isinstance(d, bytes)).decode(errors="replace") + return self._fail( + f"Server hat das Kopieren nach '{target_folder}' abgelehnt: {copy_status} {detail}".strip() + ) + + if message_id: + verified = self._mail_exists_in_folder(target_folder, message_id) + how = f"Message-ID {message_id}" + else: + copyuid = re.search( + r"COPYUID \d+ \S+ (\d+)", + " ".join(d.decode(errors="replace") for d in copy_data if isinstance(d, bytes)), + ) + if copyuid: + self.conn.select(_quote_mailbox(target_folder), readonly=True) + st, data = self.conn.uid("SEARCH", None, "UID", copyuid.group(1)) + verified = st == "OK" and bool(data and data[0]) + how = f"COPYUID {copyuid.group(1)}" + elif fingerprint and count_before is not None: + count_after = self._count_fingerprint(target_folder, *fingerprint) + verified = count_after is not None and count_after == count_before + 1 + how = f"Größe {fingerprint[0]} B + Absender {fingerprint[1] or '?'} ({count_before}→{count_after})" + else: + verified = False + how = "keine Wiedererkennung möglich (weder Message-ID noch COPYUID)" + + self.conn.select(_quote_mailbox(source_folder)) if not verified: - logger.error( - "VERIFIKATION FEHLGESCHLAGEN: Mail %s (Message-ID %s) " - "nicht in '%s' gefunden — Quelle wird NICHT gelöscht", - uid, message_id, target_folder, + return self._fail( + f"Kopie von Mail {uid} im Ziel '{target_folder}' nicht gefunden " + f"(geprüft über {how}) — Mail bleibt in der Quelle" ) - return False - # 5. Erst nach erfolgreicher Verifikation aus Quelle löschen self.conn.uid("STORE", uid, "+FLAGS", "(\\Deleted)") self.conn.expunge() - logger.info( - "Mail %s sicher verschoben nach '%s' (verifiziert: %s)", - uid, target_folder, message_id, - ) + logger.info("Mail %s sicher verschoben nach '%s' (verifiziert über %s)", uid, target_folder, how) return True except Exception as e: - logger.error("Fehler beim Verschieben von Mail %s: %s", uid, e) - return False + try: + self.conn.select(_quote_mailbox(source_folder)) + except Exception: + pass + return self._fail(f"Fehler beim Verschieben von Mail {uid} nach '{target_folder}': {e}") def delete_mail( self, @@ -420,13 +479,15 @@ class IMAPClient: return self.move_mail(uid, trash_folder, source_folder=source_folder) def mark_as_read(self, uid: str) -> bool: + self.last_error = None try: - self.conn.uid("STORE", uid, "+FLAGS", "(\\Seen)") + status, data = self.conn.uid("STORE", uid, "+FLAGS", "(\\Seen)") + if status != "OK": + return self._fail(f"Server hat 'als gelesen markieren' abgelehnt: {status} {data}") logger.info("Mail %s als gelesen markiert", uid) return True except Exception as e: - logger.error("Fehler beim Markieren von Mail %s: %s", uid, e) - return False + return self._fail(f"Fehler beim Markieren von Mail {uid}: {e}") def forward_mail( self, @@ -437,11 +498,12 @@ class IMAPClient: smtp_username: str, smtp_password: str, ) -> bool: + self.last_error = None try: status, msg_data = self.conn.uid("FETCH", uid, "(BODY.PEEK[])") raw = _fetch_payload(msg_data) if status == "OK" else None if raw is None: - return False + return self._fail(f"Mail {uid} konnte zum Weiterleiten nicht geladen werden") original = email.message_from_bytes(raw) subject = _decode_header_value(original.get("Subject")) body = _extract_body(original) @@ -462,8 +524,7 @@ class IMAPClient: logger.info("Mail %s weitergeleitet an %s", uid, to_address) return True except Exception as e: - logger.error("Fehler beim Weiterleiten von Mail %s: %s", uid, e) - return False + return self._fail(f"Fehler beim Weiterleiten von Mail {uid} an {to_address}: {e}") async def async_test_connection( diff --git a/app/services/scheduler.py b/app/services/scheduler.py index 6391191..e130a72 100644 --- a/app/services/scheduler.py +++ b/app/services/scheduler.py @@ -246,8 +246,9 @@ def _poll_account_sync(account_id: int) -> None: ) else: total_errors += 1 + reason = client.last_error or "unbekannter Grund" write_log( - message=f"Aktion fehlgeschlagen: {action_label}", + message=f"Aktion fehlgeschlagen: {action_label} — {reason}"[:1000], level=LogLevel.ERROR, account_id=account.id, account_name=account.name, diff --git a/app/templates/logs.html b/app/templates/logs.html index 28a22ac..f2fe449 100644 --- a/app/templates/logs.html +++ b/app/templates/logs.html @@ -25,7 +25,7 @@ @@ -435,7 +435,7 @@ async function clearLogs() { async function retryFailed() { document.querySelector('.head-menu').open = false; - if (!confirm('Alle Mails mit "Fehler beim Abrufen" für den nächsten Poll neu vormerken?')) return; + if (!confirm('Alle Mails, bei denen Abrufen oder eine Aktion (z.B. Verschieben) fehlgeschlagen ist, für den nächsten Poll neu vormerken?')) return; const acc = document.getElementById('log-account').value; const resp = await fetch(`/api/filters/retry-failed${acc ? `?account_id=${acc}` : ''}`, {method: 'POST'}); const d = await readJson(resp);