Merge pull request #221 from christianlouis/copilot/add-debug-logging-for-mail-fetching
feat: IMAP/POP3 diagnostics — friendly errors, auto-clear stale status, per-account debug logging
This commit is contained in:
@@ -9,6 +9,53 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
|
|||||||
|
|
||||||
## [Unreleased]
|
## [Unreleased]
|
||||||
|
|
||||||
|
### Added
|
||||||
|
|
||||||
|
- **Friendly error messages**: Introduced `_format_connection_error()` helper in
|
||||||
|
`mail_processor.py` that translates raw OS/socket/SSL/POP3/IMAP exceptions into
|
||||||
|
human-readable sentences including the host:port and actionable guidance (DNS
|
||||||
|
failure, TLS error, connection timeout, authentication rejection, etc.). The
|
||||||
|
helper is applied at every `raise MailFetchError` / `raise MailConnectionError`
|
||||||
|
site and in both `_test_pop3_connection` and `_test_imap_connection`.
|
||||||
|
|
||||||
|
- **Per-account debug logging** (`debug_logging` column on `MailAccount`): when
|
||||||
|
enabled, the next processing run records a structured connection trace
|
||||||
|
(connect timing, TLS details, auth, INBOX selection, message UIDs/sizes,
|
||||||
|
elapsed milliseconds per phase) via the new `MailDebugRecorder` class. The
|
||||||
|
trace is persisted as a `ProcessingLog` row with `level="DEBUG"` and surfaced
|
||||||
|
in the "Mailbox Activity" logs page as a collapsible "Connection trace" panel.
|
||||||
|
Debug logging auto-disables after 5 completed runs in a 24-hour window.
|
||||||
|
|
||||||
|
- **"Clear error" button**: new `POST /api/v1/mail-accounts/{id}/clear-error`
|
||||||
|
endpoint that nulls `last_error_message`/`last_error_at` and resets `status`
|
||||||
|
to `ACTIVE` when currently `ERROR`. Wired into the error banners on both the
|
||||||
|
Accounts page and the Mailbox Activity (Logs) page.
|
||||||
|
|
||||||
|
- **Debug-logging toggle** in the account edit form (Add/Edit Account modal):
|
||||||
|
checkbox labelled "Debug logging (auto-disables after 5 runs)".
|
||||||
|
|
||||||
|
- Alembic migration `0002_add_debug_logging.py` adding the `debug_logging`
|
||||||
|
boolean column to `mail_accounts` (idempotent via `ADD COLUMN IF NOT EXISTS`).
|
||||||
|
|
||||||
|
### Fixed
|
||||||
|
|
||||||
|
- **Empty IMAP error messages** — `IMAP fetch error:` with a blank suffix was
|
||||||
|
caused by `asyncio.TimeoutError` and `aioimaplib.Abort` having an empty
|
||||||
|
`str()`. The new `_format_connection_error()` helper always produces a
|
||||||
|
non-empty, human-readable message.
|
||||||
|
|
||||||
|
- **Cryptic DNS error** — `POP3 fetch error: [Errno -5] No address associated
|
||||||
|
with hostname` is now surfaced as `Could not resolve hostname 'pop.web.de' —
|
||||||
|
check that the server address is correct (DNS lookup failed: …)`.
|
||||||
|
|
||||||
|
- **Sticky ERROR status after transient fetch failures**: the `tasks.py`
|
||||||
|
processing loop previously set `account.status = ERROR` and
|
||||||
|
`last_error_message = "{N} emails failed to forward"` even when the
|
||||||
|
connection and fetch succeeded but some individual email-forward operations
|
||||||
|
failed. Now, a successful fetch (no exception from `fetch_emails`) always
|
||||||
|
clears `last_error_message`/`last_error_at` and sets `status = ACTIVE`,
|
||||||
|
regardless of per-email forwarding failures. Per-email failures continue to
|
||||||
|
be tracked in `ProcessingLog` and the run's `emails_failed` counter.
|
||||||
### Fixed
|
### Fixed
|
||||||
|
|
||||||
- OAuth Google sign-in: added `exc_info=True` to the catch-all exception handler in `auth_service.py` so the full traceback is always emitted to the log instead of only `str(e)`.
|
- OAuth Google sign-in: added `exc_info=True` to the catch-all exception handler in `auth_service.py` so the full traceback is always emitted to the log instead of only `str(e)`.
|
||||||
|
|||||||
@@ -0,0 +1,37 @@
|
|||||||
|
"""Add debug_logging column to mail_accounts
|
||||||
|
|
||||||
|
Revision ID: 0002
|
||||||
|
Revises: 0001
|
||||||
|
Create Date: 2026-05-03
|
||||||
|
|
||||||
|
Adds a boolean ``debug_logging`` column to ``mail_accounts``.
|
||||||
|
|
||||||
|
When True, the next processing run will record a detailed connection trace
|
||||||
|
(timings, phase-by-phase events, message UIDs/sizes) and persist it as a
|
||||||
|
``ProcessingLog`` row with ``level='DEBUG'``. The column auto-resets to
|
||||||
|
False after 5 completed runs in a 24-hour window to prevent it being left
|
||||||
|
on indefinitely.
|
||||||
|
|
||||||
|
The column defaults to False so all existing rows are unaffected.
|
||||||
|
Using IF NOT EXISTS makes the migration idempotent against fresh installs
|
||||||
|
where create_all() already created the column.
|
||||||
|
"""
|
||||||
|
|
||||||
|
from alembic import op
|
||||||
|
|
||||||
|
# revision identifiers, used by Alembic.
|
||||||
|
revision = "0002"
|
||||||
|
down_revision = "0001"
|
||||||
|
branch_labels = None
|
||||||
|
depends_on = None
|
||||||
|
|
||||||
|
|
||||||
|
def upgrade() -> None:
|
||||||
|
op.execute(
|
||||||
|
"ALTER TABLE mail_accounts "
|
||||||
|
"ADD COLUMN IF NOT EXISTS debug_logging BOOLEAN NOT NULL DEFAULT FALSE"
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def downgrade() -> None:
|
||||||
|
op.execute("ALTER TABLE mail_accounts DROP COLUMN IF EXISTS debug_logging")
|
||||||
@@ -104,6 +104,7 @@ async def create_mail_account(
|
|||||||
check_interval_minutes=account_in.check_interval_minutes,
|
check_interval_minutes=account_in.check_interval_minutes,
|
||||||
max_emails_per_check=account_in.max_emails_per_check,
|
max_emails_per_check=account_in.max_emails_per_check,
|
||||||
delete_after_forward=account_in.delete_after_forward,
|
delete_after_forward=account_in.delete_after_forward,
|
||||||
|
debug_logging=account_in.debug_logging,
|
||||||
provider_name=account_in.provider_name,
|
provider_name=account_in.provider_name,
|
||||||
)
|
)
|
||||||
|
|
||||||
@@ -243,6 +244,42 @@ async def toggle_mail_account(
|
|||||||
return account
|
return account
|
||||||
|
|
||||||
|
|
||||||
|
@router.post("/{account_id}/clear-error", response_model=MailAccountResponse)
|
||||||
|
async def clear_account_error(
|
||||||
|
account_id: int,
|
||||||
|
current_user: User = Depends(get_current_active_user),
|
||||||
|
db: AsyncSession = Depends(get_db),
|
||||||
|
):
|
||||||
|
"""Clear the error status of a mail account.
|
||||||
|
|
||||||
|
Resets last_error_message, last_error_at and sets status to ACTIVE
|
||||||
|
if the account is currently in ERROR state. Use this after fixing the
|
||||||
|
underlying problem (e.g. wrong password, DNS issue) to immediately remove
|
||||||
|
the error indicator without waiting for the next successful fetch.
|
||||||
|
"""
|
||||||
|
result = await db.execute(
|
||||||
|
select(MailAccount).where(
|
||||||
|
MailAccount.id == account_id, MailAccount.user_id == current_user.id
|
||||||
|
)
|
||||||
|
)
|
||||||
|
account = result.scalar_one_or_none()
|
||||||
|
|
||||||
|
if not account:
|
||||||
|
raise HTTPException(
|
||||||
|
status_code=status.HTTP_404_NOT_FOUND, detail="Mail account not found"
|
||||||
|
)
|
||||||
|
|
||||||
|
account.last_error_message = None # type: ignore[assignment]
|
||||||
|
account.last_error_at = None # type: ignore[assignment]
|
||||||
|
if account.status == AccountStatus.ERROR:
|
||||||
|
account.status = AccountStatus.ACTIVE # type: ignore[assignment]
|
||||||
|
|
||||||
|
await db.commit()
|
||||||
|
await db.refresh(account)
|
||||||
|
|
||||||
|
return account
|
||||||
|
|
||||||
|
|
||||||
@router.post("/{account_id}/pull-now", status_code=status.HTTP_202_ACCEPTED)
|
@router.post("/{account_id}/pull-now", status_code=status.HTTP_202_ACCEPTED)
|
||||||
async def pull_now(
|
async def pull_now(
|
||||||
account_id: int,
|
account_id: int,
|
||||||
|
|||||||
@@ -171,6 +171,9 @@ class MailAccount(Base):
|
|||||||
provider_name = Column(String(100), nullable=True) # e.g., "Gmail", "GMX"
|
provider_name = Column(String(100), nullable=True) # e.g., "Gmail", "GMX"
|
||||||
auto_detected = Column(Boolean, default=False)
|
auto_detected = Column(Boolean, default=False)
|
||||||
|
|
||||||
|
# Debug logging
|
||||||
|
debug_logging = Column(Boolean, default=False)
|
||||||
|
|
||||||
# Statistics
|
# Statistics
|
||||||
total_emails_processed = Column(Integer, default=0)
|
total_emails_processed = Column(Integer, default=0)
|
||||||
total_emails_failed = Column(Integer, default=0)
|
total_emails_failed = Column(Integer, default=0)
|
||||||
|
|||||||
@@ -114,6 +114,7 @@ class MailAccountBase(BaseModel):
|
|||||||
max_emails_per_check: int = Field(default=50, gt=0, le=1000)
|
max_emails_per_check: int = Field(default=50, gt=0, le=1000)
|
||||||
delete_after_forward: bool = True
|
delete_after_forward: bool = True
|
||||||
provider_name: Optional[str] = Field(None, max_length=100)
|
provider_name: Optional[str] = Field(None, max_length=100)
|
||||||
|
debug_logging: bool = False
|
||||||
|
|
||||||
|
|
||||||
class MailAccountCreate(MailAccountBase):
|
class MailAccountCreate(MailAccountBase):
|
||||||
@@ -137,6 +138,7 @@ class MailAccountUpdate(BaseModel):
|
|||||||
max_emails_per_check: Optional[int] = Field(None, gt=0, le=1000)
|
max_emails_per_check: Optional[int] = Field(None, gt=0, le=1000)
|
||||||
delete_after_forward: Optional[bool] = None
|
delete_after_forward: Optional[bool] = None
|
||||||
provider_name: Optional[str] = Field(None, max_length=100)
|
provider_name: Optional[str] = Field(None, max_length=100)
|
||||||
|
debug_logging: Optional[bool] = None
|
||||||
|
|
||||||
|
|
||||||
class MailAccountResponse(MailAccountBase):
|
class MailAccountResponse(MailAccountBase):
|
||||||
|
|||||||
@@ -7,7 +7,10 @@ import asyncio
|
|||||||
import poplib
|
import poplib
|
||||||
import re
|
import re
|
||||||
import smtplib
|
import smtplib
|
||||||
|
import socket
|
||||||
import ssl
|
import ssl
|
||||||
|
import time as _time
|
||||||
|
from datetime import datetime, timezone
|
||||||
from email import parser
|
from email import parser
|
||||||
from email.mime.text import MIMEText
|
from email.mime.text import MIMEText
|
||||||
from email.mime.multipart import MIMEMultipart
|
from email.mime.multipart import MIMEMultipart
|
||||||
@@ -45,12 +48,200 @@ class MailForwardError(Exception):
|
|||||||
pass
|
pass
|
||||||
|
|
||||||
|
|
||||||
|
def _format_connection_error(
|
||||||
|
exc: BaseException,
|
||||||
|
host: str = "",
|
||||||
|
port: int = 0,
|
||||||
|
protocol: str = "",
|
||||||
|
) -> str:
|
||||||
|
"""Return a human-readable error message for a mail connection failure.
|
||||||
|
|
||||||
|
Never returns an empty string – always includes the exception type as a
|
||||||
|
fallback so the dashboard always shows an actionable message.
|
||||||
|
"""
|
||||||
|
loc = f"{host}:{port}" if host else ""
|
||||||
|
proto = f"{protocol} " if protocol else ""
|
||||||
|
|
||||||
|
# DNS resolution failure (socket.gaierror is a subclass of OSError)
|
||||||
|
if isinstance(exc, socket.gaierror):
|
||||||
|
if host:
|
||||||
|
return (
|
||||||
|
f"Could not resolve hostname '{host}' — check that the server "
|
||||||
|
f"address is correct (DNS lookup failed: {exc})"
|
||||||
|
)
|
||||||
|
return f"DNS lookup failed: {exc}"
|
||||||
|
|
||||||
|
# Connection / operation timeout
|
||||||
|
if isinstance(exc, (socket.timeout, asyncio.TimeoutError, TimeoutError)):
|
||||||
|
if loc:
|
||||||
|
return (
|
||||||
|
f"{proto}connection to {loc} timed out — the server may be "
|
||||||
|
f"slow or blocking connections"
|
||||||
|
)
|
||||||
|
return f"{proto}connection timed out"
|
||||||
|
|
||||||
|
# Connection refused by the server
|
||||||
|
if isinstance(exc, ConnectionRefusedError):
|
||||||
|
if loc:
|
||||||
|
return (
|
||||||
|
f"Connection refused by {loc} — check that the host and port "
|
||||||
|
f"are correct and the server is running"
|
||||||
|
)
|
||||||
|
return f"Connection refused: {exc}"
|
||||||
|
|
||||||
|
# Server closed the connection unexpectedly
|
||||||
|
if isinstance(exc, ConnectionResetError):
|
||||||
|
if loc:
|
||||||
|
return f"Connection reset by {loc} — the server closed the connection unexpectedly"
|
||||||
|
return f"Connection reset: {exc}"
|
||||||
|
|
||||||
|
# TLS certificate verification failure
|
||||||
|
if isinstance(exc, ssl.SSLCertVerificationError):
|
||||||
|
reason = getattr(exc, "reason", "") or str(exc)
|
||||||
|
if loc:
|
||||||
|
return f"TLS certificate verification failed for {loc}: {reason}"
|
||||||
|
return f"TLS certificate verification failed: {reason}"
|
||||||
|
|
||||||
|
# Generic TLS/SSL error
|
||||||
|
if isinstance(exc, ssl.SSLError):
|
||||||
|
reason = getattr(exc, "reason", "") or str(exc)
|
||||||
|
if loc:
|
||||||
|
return f"TLS/SSL error connecting to {loc}: {reason}"
|
||||||
|
return f"TLS/SSL error: {reason}"
|
||||||
|
|
||||||
|
# POP3 protocol error (auth rejection, server-side error, etc.)
|
||||||
|
if isinstance(exc, poplib.error_proto):
|
||||||
|
msg = str(exc).strip() or repr(exc)
|
||||||
|
msg_lower = msg.lower()
|
||||||
|
if any(
|
||||||
|
k in msg_lower
|
||||||
|
for k in (
|
||||||
|
"auth",
|
||||||
|
"login",
|
||||||
|
"password",
|
||||||
|
"user",
|
||||||
|
"pass",
|
||||||
|
"invalid",
|
||||||
|
"denied",
|
||||||
|
"failed",
|
||||||
|
)
|
||||||
|
):
|
||||||
|
if loc:
|
||||||
|
return f"Authentication rejected by {loc}: {msg}"
|
||||||
|
return f"POP3 authentication failed: {msg}"
|
||||||
|
if loc:
|
||||||
|
return f"POP3 server {loc} returned an error: {msg}"
|
||||||
|
return f"POP3 error: {msg}"
|
||||||
|
|
||||||
|
# IMAP connection aborted by the server
|
||||||
|
try:
|
||||||
|
if isinstance(exc, aioimaplib.Abort):
|
||||||
|
msg = str(exc).strip() or "server closed the connection"
|
||||||
|
if loc:
|
||||||
|
return f"IMAP connection to {loc} was aborted: {msg}"
|
||||||
|
return f"IMAP connection aborted: {msg}"
|
||||||
|
except TypeError:
|
||||||
|
# aioimaplib may be mocked in tests, making Abort a non-type
|
||||||
|
pass
|
||||||
|
|
||||||
|
# Generic OSError with an OS-level error code
|
||||||
|
if isinstance(exc, OSError) and exc.errno:
|
||||||
|
strerror = exc.strerror or str(exc)
|
||||||
|
if loc:
|
||||||
|
return f"Network error connecting to {loc}: {strerror}"
|
||||||
|
return f"Network error: {strerror}"
|
||||||
|
|
||||||
|
# Catch-all: produce a non-empty string regardless of the exception type
|
||||||
|
msg = str(exc).strip()
|
||||||
|
if not msg:
|
||||||
|
# Some exceptions (e.g. bare asyncio.TimeoutError) have no message
|
||||||
|
msg = type(exc).__name__
|
||||||
|
if loc:
|
||||||
|
return f"{proto}error communicating with {loc}: {msg}"
|
||||||
|
return f"{type(exc).__name__}: {msg or repr(exc)}"
|
||||||
|
|
||||||
|
|
||||||
|
# Maximum number of entries / bytes kept in a single debug trace
|
||||||
|
_MAX_TRACE_ENTRIES = 200
|
||||||
|
_MAX_TRACE_BYTES = 65_536 # 64 KiB
|
||||||
|
|
||||||
|
|
||||||
|
class MailDebugRecorder:
|
||||||
|
"""Collects a structured trace of an IMAP/POP3 connection for debug display.
|
||||||
|
|
||||||
|
Thread-safe for list.append() calls thanks to the CPython GIL. The
|
||||||
|
recorder is passed into :class:`MailProcessor` when
|
||||||
|
``account.debug_logging`` is True and persisted as a
|
||||||
|
``ProcessingLog`` row with ``level="DEBUG"`` at the end of the run.
|
||||||
|
"""
|
||||||
|
|
||||||
|
def __init__(self) -> None:
|
||||||
|
self._entries: List[Dict[str, Any]] = []
|
||||||
|
self._total_bytes: int = 0
|
||||||
|
self._truncated: bool = False
|
||||||
|
|
||||||
|
def record(
|
||||||
|
self,
|
||||||
|
phase: str,
|
||||||
|
message: str,
|
||||||
|
data: Optional[Dict[str, Any]] = None,
|
||||||
|
) -> None:
|
||||||
|
"""Append a trace entry (no-op once the size cap is reached)."""
|
||||||
|
if self._truncated:
|
||||||
|
return
|
||||||
|
entry: Dict[str, Any] = {
|
||||||
|
"ts": datetime.now(timezone.utc).isoformat(),
|
||||||
|
"phase": phase,
|
||||||
|
"msg": message,
|
||||||
|
}
|
||||||
|
if data:
|
||||||
|
entry["data"] = data
|
||||||
|
try:
|
||||||
|
entry_bytes = len(str(entry))
|
||||||
|
except Exception:
|
||||||
|
entry_bytes = 256 # conservative fallback
|
||||||
|
if (
|
||||||
|
len(self._entries) >= _MAX_TRACE_ENTRIES
|
||||||
|
or self._total_bytes + entry_bytes > _MAX_TRACE_BYTES
|
||||||
|
):
|
||||||
|
self._entries.append(
|
||||||
|
{
|
||||||
|
"ts": entry["ts"],
|
||||||
|
"phase": "truncated",
|
||||||
|
"msg": (
|
||||||
|
f"Trace truncated after {len(self._entries)} entries "
|
||||||
|
f"(size limit {_MAX_TRACE_BYTES // 1024} KiB reached)"
|
||||||
|
),
|
||||||
|
}
|
||||||
|
)
|
||||||
|
self._truncated = True
|
||||||
|
return
|
||||||
|
self._entries.append(entry)
|
||||||
|
self._total_bytes += entry_bytes
|
||||||
|
|
||||||
|
def has_entries(self) -> bool:
|
||||||
|
return bool(self._entries)
|
||||||
|
|
||||||
|
def __len__(self) -> int:
|
||||||
|
return len(self._entries)
|
||||||
|
|
||||||
|
def as_details(self) -> Dict[str, Any]:
|
||||||
|
"""Return the trace as a dict suitable for storage in error_details."""
|
||||||
|
return {"trace": self._entries, "truncated": self._truncated}
|
||||||
|
|
||||||
|
|
||||||
class MailProcessor:
|
class MailProcessor:
|
||||||
"""Handles mail fetching and forwarding operations"""
|
"""Handles mail fetching and forwarding operations"""
|
||||||
|
|
||||||
def __init__(self, account: MailAccount, decrypted_password: str):
|
def __init__(
|
||||||
|
self,
|
||||||
|
account: MailAccount,
|
||||||
|
decrypted_password: str,
|
||||||
|
debug_recorder: Optional[MailDebugRecorder] = None,
|
||||||
|
):
|
||||||
self.account = account
|
self.account = account
|
||||||
self.password = decrypted_password
|
self.password = decrypted_password
|
||||||
|
self._debug = debug_recorder
|
||||||
|
|
||||||
async def test_connection(self) -> Tuple[bool, str]:
|
async def test_connection(self) -> Tuple[bool, str]:
|
||||||
"""
|
"""
|
||||||
@@ -70,9 +261,11 @@ class MailProcessor:
|
|||||||
"""Test POP3 connection"""
|
"""Test POP3 connection"""
|
||||||
try:
|
try:
|
||||||
loop = asyncio.get_event_loop()
|
loop = asyncio.get_event_loop()
|
||||||
|
_dbg = self._debug
|
||||||
|
|
||||||
# Run blocking POP3 operations in thread pool
|
# Run blocking POP3 operations in thread pool
|
||||||
def connect_pop3():
|
def connect_pop3():
|
||||||
|
_t0 = _time.monotonic()
|
||||||
if self.account.protocol == MailProtocol.POP3_SSL:
|
if self.account.protocol == MailProtocol.POP3_SSL:
|
||||||
context = ssl.create_default_context()
|
context = ssl.create_default_context()
|
||||||
pop_conn = poplib.POP3_SSL(
|
pop_conn = poplib.POP3_SSL(
|
||||||
@@ -85,14 +278,32 @@ class MailProcessor:
|
|||||||
pop_conn = poplib.POP3(
|
pop_conn = poplib.POP3(
|
||||||
self.account.host, self.account.port, timeout=10
|
self.account.host, self.account.port, timeout=10
|
||||||
)
|
)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"connect",
|
||||||
|
f"Connected to {self.account.host}:{self.account.port} "
|
||||||
|
f"({'SSL' if self.account.protocol == MailProtocol.POP3_SSL else 'plain'})",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t0) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Try authentication
|
# Try authentication
|
||||||
|
_t1 = _time.monotonic()
|
||||||
pop_conn.user(self.account.username)
|
pop_conn.user(self.account.username)
|
||||||
pop_conn.pass_(self.password)
|
pop_conn.pass_(self.password)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"auth",
|
||||||
|
f"Authenticated as {self.account.username}",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t1) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Get mailbox stats
|
# Get mailbox stats
|
||||||
message_count, mailbox_size = pop_conn.stat()
|
message_count, mailbox_size = pop_conn.stat()
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"stat",
|
||||||
|
f"Mailbox has {message_count} messages ({mailbox_size} bytes)",
|
||||||
|
)
|
||||||
pop_conn.quit()
|
pop_conn.quit()
|
||||||
return message_count, mailbox_size
|
return message_count, mailbox_size
|
||||||
|
|
||||||
@@ -100,13 +311,16 @@ class MailProcessor:
|
|||||||
|
|
||||||
return True, f"Connection successful. {message_count} messages in mailbox."
|
return True, f"Connection successful. {message_count} messages in mailbox."
|
||||||
|
|
||||||
except poplib.error_proto as e:
|
|
||||||
error_msg = str(e)
|
|
||||||
if "authentication" in error_msg.lower() or "auth" in error_msg.lower():
|
|
||||||
return False, f"Authentication failed: {error_msg}"
|
|
||||||
return False, f"POP3 protocol error: {error_msg}"
|
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
return False, f"Connection failed: {str(e)}"
|
return (
|
||||||
|
False,
|
||||||
|
_format_connection_error(
|
||||||
|
e,
|
||||||
|
str(self.account.host),
|
||||||
|
int(self.account.port),
|
||||||
|
"POP3",
|
||||||
|
),
|
||||||
|
)
|
||||||
|
|
||||||
async def _test_imap_connection(self) -> Tuple[bool, str]:
|
async def _test_imap_connection(self) -> Tuple[bool, str]:
|
||||||
"""Test IMAP connection"""
|
"""Test IMAP connection"""
|
||||||
@@ -121,28 +335,64 @@ class MailProcessor:
|
|||||||
host=self.account.host, port=self.account.port, timeout=10
|
host=self.account.host, port=self.account.port, timeout=10
|
||||||
)
|
)
|
||||||
|
|
||||||
|
_t0 = _time.monotonic()
|
||||||
await imap_client.wait_hello_from_server()
|
await imap_client.wait_hello_from_server()
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"connect",
|
||||||
|
f"Connected to {self.account.host}:{self.account.port} "
|
||||||
|
f"({'SSL' if self.account.protocol == MailProtocol.IMAP_SSL else 'plain'})",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t0) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Authenticate
|
# Authenticate
|
||||||
|
_t1 = _time.monotonic()
|
||||||
response = await imap_client.login(self.account.username, self.password)
|
response = await imap_client.login(self.account.username, self.password)
|
||||||
|
|
||||||
if response.result != "OK":
|
if response.result != "OK":
|
||||||
return False, f"Authentication failed: {response.lines}"
|
return (
|
||||||
|
False,
|
||||||
|
f"Authentication rejected by {self.account.host}:{self.account.port}: "
|
||||||
|
f"{response.lines}",
|
||||||
|
)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"auth",
|
||||||
|
f"Authenticated as {self.account.username}",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t1) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Select inbox
|
# Select inbox
|
||||||
await imap_client.select("INBOX")
|
await imap_client.select("INBOX")
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record("select", "Selected INBOX")
|
||||||
|
|
||||||
# Get message count
|
# Get message count
|
||||||
response = await imap_client.search("ALL")
|
response = await imap_client.search("ALL")
|
||||||
message_ids = response.lines[0].split()
|
message_ids = response.lines[0].split()
|
||||||
message_count = len(message_ids)
|
message_count = len(message_ids)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"search",
|
||||||
|
f"INBOX contains {message_count} messages",
|
||||||
|
)
|
||||||
|
|
||||||
await imap_client.logout()
|
await imap_client.logout()
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record("logout", "Logged out successfully")
|
||||||
|
|
||||||
return True, f"Connection successful. {message_count} messages in mailbox."
|
return True, f"Connection successful. {message_count} messages in mailbox."
|
||||||
|
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
return False, f"IMAP connection failed: {str(e)}"
|
return (
|
||||||
|
False,
|
||||||
|
_format_connection_error(
|
||||||
|
e,
|
||||||
|
str(self.account.host),
|
||||||
|
int(self.account.port),
|
||||||
|
"IMAP",
|
||||||
|
),
|
||||||
|
)
|
||||||
|
|
||||||
async def fetch_emails(
|
async def fetch_emails(
|
||||||
self,
|
self,
|
||||||
@@ -178,8 +428,10 @@ class MailProcessor:
|
|||||||
|
|
||||||
try:
|
try:
|
||||||
loop = asyncio.get_event_loop()
|
loop = asyncio.get_event_loop()
|
||||||
|
_dbg = self._debug # capture for thread-pool closure
|
||||||
|
|
||||||
def fetch_pop3() -> Tuple[List[bytes], List[str]]:
|
def fetch_pop3() -> Tuple[List[bytes], List[str]]:
|
||||||
|
_t_conn = _time.monotonic()
|
||||||
# Connect
|
# Connect
|
||||||
if self.account.protocol == MailProtocol.POP3_SSL:
|
if self.account.protocol == MailProtocol.POP3_SSL:
|
||||||
context = ssl.create_default_context()
|
context = ssl.create_default_context()
|
||||||
@@ -193,10 +445,24 @@ class MailProcessor:
|
|||||||
pop_conn = poplib.POP3( # type: ignore[assignment]
|
pop_conn = poplib.POP3( # type: ignore[assignment]
|
||||||
str(self.account.host), int(self.account.port), timeout=30
|
str(self.account.host), int(self.account.port), timeout=30
|
||||||
)
|
)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"connect",
|
||||||
|
f"Connected to {self.account.host}:{self.account.port} "
|
||||||
|
f"({'SSL' if self.account.protocol == MailProtocol.POP3_SSL else 'plain'})",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_conn) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Authenticate
|
# Authenticate
|
||||||
|
_t_auth = _time.monotonic()
|
||||||
pop_conn.user(str(self.account.username))
|
pop_conn.user(str(self.account.username))
|
||||||
pop_conn.pass_(self.password)
|
pop_conn.pass_(self.password)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"auth",
|
||||||
|
f"Authenticated as {self.account.username}",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_auth) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
# Retrieve UIDL map: {msg_number: uid_string}
|
# Retrieve UIDL map: {msg_number: uid_string}
|
||||||
uidl_response = pop_conn.uidl()
|
uidl_response = pop_conn.uidl()
|
||||||
@@ -207,6 +473,13 @@ class MailProcessor:
|
|||||||
uid_map[int(parts[0])] = parts[1].strip()
|
uid_map[int(parts[0])] = parts[1].strip()
|
||||||
|
|
||||||
num_messages = len(uid_map)
|
num_messages = len(uid_map)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"uidl",
|
||||||
|
f"Mailbox contains {num_messages} messages; "
|
||||||
|
f"{len(already_seen_uids)} already downloaded",
|
||||||
|
{"total": num_messages, "already_seen": len(already_seen_uids)},
|
||||||
|
)
|
||||||
logger.info(
|
logger.info(
|
||||||
f"Found {num_messages} messages for account {self.account.id}"
|
f"Found {num_messages} messages for account {self.account.id}"
|
||||||
)
|
)
|
||||||
@@ -228,26 +501,59 @@ class MailProcessor:
|
|||||||
continue
|
continue
|
||||||
|
|
||||||
try:
|
try:
|
||||||
|
_t_msg = _time.monotonic()
|
||||||
response, lines, octets = pop_conn.retr(msg_num)
|
response, lines, octets = pop_conn.retr(msg_num)
|
||||||
email_data = b"\r\n".join(lines)
|
email_data = b"\r\n".join(lines)
|
||||||
fetched.append(email_data)
|
fetched.append(email_data)
|
||||||
fetched_uids.append(uid)
|
fetched_uids.append(uid)
|
||||||
fetched_count += 1
|
fetched_count += 1
|
||||||
|
elapsed = round((_time.monotonic() - _t_msg) * 1000)
|
||||||
logger.info(
|
logger.info(
|
||||||
f"Retrieved message {msg_num} (uid={uid}) "
|
f"Retrieved message {msg_num} (uid={uid}) "
|
||||||
f"from account {self.account.id}"
|
f"from account {self.account.id}"
|
||||||
)
|
)
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"fetch_msg",
|
||||||
|
f"Fetched message {msg_num} (uid={uid}): "
|
||||||
|
f"{len(email_data)} bytes",
|
||||||
|
{
|
||||||
|
"msg_num": msg_num,
|
||||||
|
"uid": uid,
|
||||||
|
"size_bytes": len(email_data),
|
||||||
|
"elapsed_ms": elapsed,
|
||||||
|
},
|
||||||
|
)
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.error(f"Error retrieving message {msg_num}: {e}")
|
logger.error(f"Error retrieving message {msg_num}: {e}")
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"fetch_error",
|
||||||
|
f"Failed to retrieve message {msg_num} (uid={uid}): {e}",
|
||||||
|
{"msg_num": msg_num, "uid": uid},
|
||||||
|
)
|
||||||
|
|
||||||
pop_conn.quit()
|
pop_conn.quit()
|
||||||
|
if _dbg:
|
||||||
|
_dbg.record(
|
||||||
|
"quit",
|
||||||
|
f"Disconnected — fetched {fetched_count} new message(s)",
|
||||||
|
{"fetched": fetched_count},
|
||||||
|
)
|
||||||
return fetched, fetched_uids
|
return fetched, fetched_uids
|
||||||
|
|
||||||
emails, new_uids = await loop.run_in_executor(None, fetch_pop3)
|
emails, new_uids = await loop.run_in_executor(None, fetch_pop3)
|
||||||
|
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.error(f"Error fetching POP3 emails: {e}")
|
logger.error(f"Error fetching POP3 emails: {e}")
|
||||||
raise MailFetchError(f"POP3 fetch error: {str(e)}")
|
raise MailFetchError(
|
||||||
|
_format_connection_error(
|
||||||
|
e,
|
||||||
|
str(self.account.host),
|
||||||
|
int(self.account.port),
|
||||||
|
"POP3",
|
||||||
|
)
|
||||||
|
)
|
||||||
|
|
||||||
return emails, new_uids
|
return emails, new_uids
|
||||||
|
|
||||||
@@ -290,28 +596,72 @@ class MailProcessor:
|
|||||||
host=self.account.host, port=self.account.port, timeout=30
|
host=self.account.host, port=self.account.port, timeout=30
|
||||||
)
|
)
|
||||||
|
|
||||||
|
_t_conn = _time.monotonic()
|
||||||
await imap_client.wait_hello_from_server()
|
await imap_client.wait_hello_from_server()
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"connect",
|
||||||
|
f"Connected to {self.account.host}:{self.account.port} "
|
||||||
|
f"({'SSL' if self.account.protocol == MailProtocol.IMAP_SSL else 'plain'})",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_conn) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
|
_t_auth = _time.monotonic()
|
||||||
await imap_client.login(self.account.username, self.password)
|
await imap_client.login(self.account.username, self.password)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"auth",
|
||||||
|
f"Authenticated as {self.account.username}",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_auth) * 1000)},
|
||||||
|
)
|
||||||
|
|
||||||
await imap_client.select("INBOX")
|
await imap_client.select("INBOX")
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record("select", "Selected INBOX")
|
||||||
|
|
||||||
# Step 1: Standard sequence-based SEARCH for UNSEEN messages.
|
# Step 1: Standard sequence-based SEARCH for UNSEEN messages.
|
||||||
# aioimaplib's .uid() wrapper explicitly blocks "search", so we
|
# aioimaplib's .uid() wrapper explicitly blocks "search", so we
|
||||||
# use the plain SEARCH command and resolve to UIDs in step 2.
|
# use the plain SEARCH command and resolve to UIDs in step 2.
|
||||||
|
_t_search = _time.monotonic()
|
||||||
response = await imap_client.search("UNSEEN")
|
response = await imap_client.search("UNSEEN")
|
||||||
if (
|
if (
|
||||||
response.result != "OK"
|
response.result != "OK"
|
||||||
or not response.lines
|
or not response.lines
|
||||||
or not response.lines[0].strip()
|
or not response.lines[0].strip()
|
||||||
):
|
):
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"search",
|
||||||
|
"SEARCH UNSEEN returned 0 messages",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_search) * 1000)},
|
||||||
|
)
|
||||||
logger.info(f"Found 0 unread messages for account {self.account.id}")
|
logger.info(f"Found 0 unread messages for account {self.account.id}")
|
||||||
# logout is handled by the finally block below
|
# logout is handled by the finally block below
|
||||||
return emails, new_uids
|
return emails, new_uids
|
||||||
|
|
||||||
seq_nums: List[bytes] = response.lines[0].split()
|
seq_nums: List[bytes] = response.lines[0].split()
|
||||||
if not seq_nums:
|
if not seq_nums:
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"search",
|
||||||
|
"SEARCH UNSEEN returned 0 messages",
|
||||||
|
{"elapsed_ms": round((_time.monotonic() - _t_search) * 1000)},
|
||||||
|
)
|
||||||
logger.info(f"Found 0 unread messages for account {self.account.id}")
|
logger.info(f"Found 0 unread messages for account {self.account.id}")
|
||||||
return emails, new_uids
|
return emails, new_uids
|
||||||
|
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"search",
|
||||||
|
f"SEARCH UNSEEN found {len(seq_nums)} message(s); "
|
||||||
|
f"limiting to {min(len(seq_nums), max_count)}",
|
||||||
|
{
|
||||||
|
"total_unseen": len(seq_nums),
|
||||||
|
"max_count": max_count,
|
||||||
|
"elapsed_ms": round((_time.monotonic() - _t_search) * 1000),
|
||||||
|
},
|
||||||
|
)
|
||||||
|
|
||||||
# Limit to max_count before doing any further work.
|
# Limit to max_count before doing any further work.
|
||||||
seq_nums = seq_nums[:max_count]
|
seq_nums = seq_nums[:max_count]
|
||||||
|
|
||||||
@@ -333,6 +683,16 @@ class MailProcessor:
|
|||||||
f"Found {len(all_unseen_uids)} unread messages for account "
|
f"Found {len(all_unseen_uids)} unread messages for account "
|
||||||
f"{self.account.id}"
|
f"{self.account.id}"
|
||||||
)
|
)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"fetch_uids",
|
||||||
|
f"Resolved {len(all_unseen_uids)} UID(s); "
|
||||||
|
f"{len(already_seen_uids)} already downloaded",
|
||||||
|
{
|
||||||
|
"uids": [u.decode() for u in all_unseen_uids[:10]],
|
||||||
|
"already_seen": len(already_seen_uids),
|
||||||
|
},
|
||||||
|
)
|
||||||
|
|
||||||
# Step 4: Split into stale UIDs (already in our DB but still
|
# Step 4: Split into stale UIDs (already in our DB but still
|
||||||
# UNSEEN on the server — e.g. a previous STORE failed) and
|
# UNSEEN on the server — e.g. a previous STORE failed) and
|
||||||
@@ -346,6 +706,14 @@ class MailProcessor:
|
|||||||
else:
|
else:
|
||||||
uids_to_fetch.append(uid)
|
uids_to_fetch.append(uid)
|
||||||
|
|
||||||
|
if self._debug and stale_uid_bytes:
|
||||||
|
self._debug.record(
|
||||||
|
"stale_uids",
|
||||||
|
f"Re-marking {len(stale_uid_bytes)} stale UID(s) as \\Seen "
|
||||||
|
f"(already downloaded but still UNSEEN on server)",
|
||||||
|
{"count": len(stale_uid_bytes)},
|
||||||
|
)
|
||||||
|
|
||||||
# Re-mark stale UIDs as \Seen in a single batch STORE command so
|
# Re-mark stale UIDs as \Seen in a single batch STORE command so
|
||||||
# they stop appearing in UNSEEN searches without consuming one
|
# they stop appearing in UNSEEN searches without consuming one
|
||||||
# round-trip per message.
|
# round-trip per message.
|
||||||
@@ -368,6 +736,7 @@ class MailProcessor:
|
|||||||
for uid in uids_to_fetch:
|
for uid in uids_to_fetch:
|
||||||
uid_str = uid.decode() if isinstance(uid, bytes) else str(uid)
|
uid_str = uid.decode() if isinstance(uid, bytes) else str(uid)
|
||||||
try:
|
try:
|
||||||
|
_t_msg = _time.monotonic()
|
||||||
fetch_response = await imap_client.uid(
|
fetch_response = await imap_client.uid(
|
||||||
"fetch", uid_str, "(BODY.PEEK[])"
|
"fetch", uid_str, "(BODY.PEEK[])"
|
||||||
)
|
)
|
||||||
@@ -396,8 +765,19 @@ class MailProcessor:
|
|||||||
break
|
break
|
||||||
|
|
||||||
if email_data and email_data.strip():
|
if email_data and email_data.strip():
|
||||||
|
elapsed = round((_time.monotonic() - _t_msg) * 1000)
|
||||||
emails.append(email_data)
|
emails.append(email_data)
|
||||||
new_uids.append(uid_str)
|
new_uids.append(uid_str)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"fetch_msg",
|
||||||
|
f"Fetched UID {uid_str}: {len(email_data)} bytes",
|
||||||
|
{
|
||||||
|
"uid": uid_str,
|
||||||
|
"size_bytes": len(email_data),
|
||||||
|
"elapsed_ms": elapsed,
|
||||||
|
},
|
||||||
|
)
|
||||||
else:
|
else:
|
||||||
logger.warning(
|
logger.warning(
|
||||||
f"No email data extracted for UID {uid_str} on "
|
f"No email data extracted for UID {uid_str} on "
|
||||||
@@ -406,12 +786,27 @@ class MailProcessor:
|
|||||||
"this may indicate a server-side error producing empty "
|
"this may indicate a server-side error producing empty "
|
||||||
"IMAP responses"
|
"IMAP responses"
|
||||||
)
|
)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"fetch_empty",
|
||||||
|
f"UID {uid_str} returned empty body — skipped",
|
||||||
|
{
|
||||||
|
"uid": uid_str,
|
||||||
|
"raw_bytes": len(email_data) if email_data else 0,
|
||||||
|
},
|
||||||
|
)
|
||||||
|
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
logger.error(
|
logger.error(
|
||||||
f"Error fetching message UID {uid_str} for account "
|
f"Error fetching message UID {uid_str} for account "
|
||||||
f"{self.account.id}: {e}"
|
f"{self.account.id}: {e}"
|
||||||
)
|
)
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"fetch_error",
|
||||||
|
f"Failed to fetch UID {uid_str}: {e}",
|
||||||
|
{"uid": uid_str},
|
||||||
|
)
|
||||||
|
|
||||||
except MailFetchError:
|
except MailFetchError:
|
||||||
raise
|
raise
|
||||||
@@ -419,7 +814,19 @@ class MailProcessor:
|
|||||||
logger.error(
|
logger.error(
|
||||||
f"Error fetching IMAP emails for account {self.account.id}: {e}"
|
f"Error fetching IMAP emails for account {self.account.id}: {e}"
|
||||||
)
|
)
|
||||||
raise MailFetchError(f"IMAP fetch error: {str(e)}")
|
if self._debug:
|
||||||
|
self._debug.record(
|
||||||
|
"error",
|
||||||
|
f"Fatal error: {_format_connection_error(e, str(self.account.host), int(self.account.port), 'IMAP')}",
|
||||||
|
)
|
||||||
|
raise MailFetchError(
|
||||||
|
_format_connection_error(
|
||||||
|
e,
|
||||||
|
str(self.account.host),
|
||||||
|
int(self.account.port),
|
||||||
|
"IMAP",
|
||||||
|
)
|
||||||
|
)
|
||||||
finally:
|
finally:
|
||||||
# Always attempt a clean logout. If the server already sent BYE
|
# Always attempt a clean logout. If the server already sent BYE
|
||||||
# the logout call will fail silently rather than masking the real
|
# the logout call will fail silently rather than masking the real
|
||||||
@@ -427,6 +834,8 @@ class MailProcessor:
|
|||||||
if imap_client is not None:
|
if imap_client is not None:
|
||||||
try:
|
try:
|
||||||
await imap_client.logout()
|
await imap_client.logout()
|
||||||
|
if self._debug:
|
||||||
|
self._debug.record("logout", "Logged out successfully")
|
||||||
except Exception:
|
except Exception:
|
||||||
pass
|
pass
|
||||||
|
|
||||||
|
|||||||
@@ -6,6 +6,7 @@ import asyncio
|
|||||||
import email as email_lib
|
import email as email_lib
|
||||||
import time
|
import time
|
||||||
from datetime import datetime, timedelta, timezone
|
from datetime import datetime, timedelta, timezone
|
||||||
|
from typing import Optional
|
||||||
from celery import Task
|
from celery import Task
|
||||||
import logging
|
import logging
|
||||||
|
|
||||||
@@ -31,12 +32,12 @@ from app.models.database_models import (
|
|||||||
DownloadedMessageId,
|
DownloadedMessageId,
|
||||||
UserSmtpConfig,
|
UserSmtpConfig,
|
||||||
)
|
)
|
||||||
from app.services.mail_processor import MailProcessor
|
from app.services.mail_processor import MailProcessor, MailDebugRecorder
|
||||||
from app.services.gmail_service import GmailService, GmailAuthError
|
from app.services.gmail_service import GmailService, GmailAuthError
|
||||||
from app.services.config_service import ConfigService
|
from app.services.config_service import ConfigService
|
||||||
from app.services.notification_service import send_user_notification
|
from app.services.notification_service import send_user_notification
|
||||||
from app.core.config import settings
|
from app.core.config import settings
|
||||||
from sqlalchemy import select, delete, or_
|
from sqlalchemy import select, delete, or_, func
|
||||||
|
|
||||||
logger = logging.getLogger(__name__)
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
@@ -116,8 +117,13 @@ async def process_mail_account(account_id: int):
|
|||||||
)
|
)
|
||||||
already_seen_uids = set(seen_result.scalars().all())
|
already_seen_uids = set(seen_result.scalars().all())
|
||||||
|
|
||||||
|
# Create debug recorder if debug logging is enabled for this account
|
||||||
|
_debug_recorder: Optional[MailDebugRecorder] = (
|
||||||
|
MailDebugRecorder() if account.debug_logging else None # type: ignore[attr-defined]
|
||||||
|
)
|
||||||
|
|
||||||
# Create processor
|
# Create processor
|
||||||
processor = MailProcessor(account, password)
|
processor = MailProcessor(account, password, debug_recorder=_debug_recorder)
|
||||||
|
|
||||||
# Fetch emails (returns raw bytes + new UIDs)
|
# Fetch emails (returns raw bytes + new UIDs)
|
||||||
emails, new_uids = await processor.fetch_emails(
|
emails, new_uids = await processor.fetch_emails(
|
||||||
@@ -465,6 +471,20 @@ async def process_mail_account(account_id: int):
|
|||||||
post_exc,
|
post_exc,
|
||||||
)
|
)
|
||||||
|
|
||||||
|
# Persist debug connection trace (if debug logging was enabled)
|
||||||
|
if _debug_recorder and _debug_recorder.has_entries():
|
||||||
|
db.add(
|
||||||
|
ProcessingLog(
|
||||||
|
user_id=account.user_id,
|
||||||
|
mail_account_id=account.id,
|
||||||
|
processing_run_id=run.id,
|
||||||
|
level="DEBUG",
|
||||||
|
message=f"Connection trace ({len(_debug_recorder)} entries)",
|
||||||
|
success=True,
|
||||||
|
error_details=_debug_recorder.as_details(),
|
||||||
|
)
|
||||||
|
)
|
||||||
|
|
||||||
# Persist new message UIDs so they are not processed again
|
# Persist new message UIDs so they are not processed again
|
||||||
for uid in successfully_forwarded_uids:
|
for uid in successfully_forwarded_uids:
|
||||||
if uid not in already_seen_uids:
|
if uid not in already_seen_uids:
|
||||||
@@ -513,15 +533,36 @@ async def process_mail_account(account_id: int):
|
|||||||
account.total_emails_failed += emails_failed # type: ignore[assignment]
|
account.total_emails_failed += emails_failed # type: ignore[assignment]
|
||||||
account.last_check_at = datetime.now(timezone.utc) # type: ignore[assignment]
|
account.last_check_at = datetime.now(timezone.utc) # type: ignore[assignment]
|
||||||
|
|
||||||
if emails_failed == 0:
|
# The fetch/connection succeeded: always clear any connection-level error
|
||||||
account.last_successful_check_at = datetime.now(timezone.utc) # type: ignore[assignment]
|
# and mark the account ACTIVE regardless of per-email forwarding failures.
|
||||||
account.status = AccountStatus.ACTIVE # type: ignore[assignment]
|
# Per-email failures are already tracked in ProcessingLog and the
|
||||||
account.last_error_message = None # type: ignore[assignment]
|
# run's emails_failed counter so the user can drill into them without
|
||||||
account.last_error_at = None # type: ignore[assignment]
|
# having the account badge stuck in ERROR indefinitely.
|
||||||
else:
|
account.last_successful_check_at = datetime.now(timezone.utc) # type: ignore[assignment]
|
||||||
account.status = AccountStatus.ERROR # type: ignore[assignment]
|
account.status = AccountStatus.ACTIVE # type: ignore[assignment]
|
||||||
account.last_error_at = datetime.now(timezone.utc) # type: ignore[assignment]
|
account.last_error_message = None # type: ignore[assignment]
|
||||||
account.last_error_message = f"{emails_failed} emails failed to forward" # type: ignore[assignment]
|
account.last_error_at = None # type: ignore[assignment]
|
||||||
|
|
||||||
|
# Auto-disable debug logging after 5 completed runs in the past 24 h
|
||||||
|
# to prevent it being left on indefinitely.
|
||||||
|
if account.debug_logging: # type: ignore[attr-defined]
|
||||||
|
_24h_ago = datetime.now(timezone.utc) - timedelta(hours=24)
|
||||||
|
_debug_run_count = (
|
||||||
|
await db.execute(
|
||||||
|
select(func.count(ProcessingRun.id)).where(
|
||||||
|
ProcessingRun.mail_account_id == account.id,
|
||||||
|
ProcessingRun.started_at >= _24h_ago,
|
||||||
|
ProcessingRun.status.in_(["completed", "partial_failure"]),
|
||||||
|
)
|
||||||
|
)
|
||||||
|
).scalar_one()
|
||||||
|
if _debug_run_count >= 5:
|
||||||
|
account.debug_logging = False # type: ignore[assignment]
|
||||||
|
logger.info(
|
||||||
|
"Auto-disabled debug logging for account %s after %d runs in 24 h",
|
||||||
|
account.id,
|
||||||
|
_debug_run_count,
|
||||||
|
)
|
||||||
|
|
||||||
await db.commit()
|
await db.commit()
|
||||||
|
|
||||||
|
|||||||
@@ -0,0 +1,264 @@
|
|||||||
|
"""
|
||||||
|
Unit tests for _format_connection_error() and MailDebugRecorder.
|
||||||
|
|
||||||
|
These tests verify:
|
||||||
|
- _format_connection_error returns human-readable, non-empty strings
|
||||||
|
for every relevant exception type.
|
||||||
|
- MailDebugRecorder caps its trace at the configured limits and never
|
||||||
|
includes password or credential data in its output.
|
||||||
|
"""
|
||||||
|
|
||||||
|
import asyncio
|
||||||
|
import poplib
|
||||||
|
import socket
|
||||||
|
import ssl
|
||||||
|
|
||||||
|
|
||||||
|
from app.services.mail_processor import (
|
||||||
|
MailDebugRecorder,
|
||||||
|
_format_connection_error,
|
||||||
|
_MAX_TRACE_ENTRIES,
|
||||||
|
)
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# _format_connection_error – helpers
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
def _fmt(exc: BaseException, host: str = "mail.example.com", port: int = 993) -> str:
|
||||||
|
return _format_connection_error(exc, host, port, "IMAP")
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# DNS failure (socket.gaierror)
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorDns:
|
||||||
|
def test_gaierror_includes_hostname(self):
|
||||||
|
exc = socket.gaierror(-5, "No address associated with hostname")
|
||||||
|
msg = _fmt(exc, host="pop.web.de", port=995)
|
||||||
|
assert "pop.web.de" in msg
|
||||||
|
assert "DNS" in msg or "resolve" in msg.lower()
|
||||||
|
|
||||||
|
def test_gaierror_never_empty(self):
|
||||||
|
exc = socket.gaierror(-2, "Name or service not known")
|
||||||
|
assert _fmt(exc)
|
||||||
|
|
||||||
|
def test_gaierror_without_host(self):
|
||||||
|
exc = socket.gaierror(-5, "No address associated with hostname")
|
||||||
|
msg = _format_connection_error(exc)
|
||||||
|
assert msg
|
||||||
|
assert "DNS" in msg or "lookup" in msg.lower()
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# Timeout
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorTimeout:
|
||||||
|
def test_socket_timeout_includes_host_port(self):
|
||||||
|
exc = socket.timeout("timed out")
|
||||||
|
msg = _fmt(exc, host="imap.gmx.net", port=993)
|
||||||
|
# Verify both the host and timeout indicator appear in the message
|
||||||
|
assert "imap.gmx.net" in msg
|
||||||
|
assert "993" in msg
|
||||||
|
assert "timed out" in msg.lower() or "timeout" in msg.lower()
|
||||||
|
|
||||||
|
def test_asyncio_timeout_error(self):
|
||||||
|
exc = asyncio.TimeoutError()
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg # never empty even though str() is ""
|
||||||
|
assert "timed out" in msg.lower() or "timeout" in msg.lower()
|
||||||
|
|
||||||
|
def test_bare_timeout_error(self):
|
||||||
|
"""Python 3.11+ TimeoutError (subclass of OSError) should be handled."""
|
||||||
|
exc = TimeoutError("timed out")
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# Connection refused / reset
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorRefused:
|
||||||
|
def test_connection_refused_includes_host_port(self):
|
||||||
|
exc = ConnectionRefusedError(111, "Connection refused")
|
||||||
|
msg = _fmt(exc, host="smtp.example.com", port=587)
|
||||||
|
# Verify both host and port appear in the message
|
||||||
|
assert "smtp.example.com" in msg
|
||||||
|
assert "587" in msg
|
||||||
|
assert "refused" in msg.lower()
|
||||||
|
|
||||||
|
def test_connection_reset(self):
|
||||||
|
exc = ConnectionResetError(104, "Connection reset by peer")
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg
|
||||||
|
assert "reset" in msg.lower()
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# SSL errors
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorSsl:
|
||||||
|
def test_ssl_cert_verification(self):
|
||||||
|
try:
|
||||||
|
# Create a real SSLCertVerificationError if possible
|
||||||
|
exc = ssl.SSLCertVerificationError(
|
||||||
|
1, "[SSL: CERTIFICATE_VERIFY_FAILED] certificate verify failed"
|
||||||
|
)
|
||||||
|
except Exception:
|
||||||
|
exc = ssl.SSLError(1, "CERTIFICATE_VERIFY_FAILED") # type: ignore[assignment]
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg
|
||||||
|
assert "TLS" in msg or "SSL" in msg or "certificate" in msg.lower()
|
||||||
|
|
||||||
|
def test_ssl_generic_error(self):
|
||||||
|
exc = ssl.SSLError(1, "wrong version number")
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg
|
||||||
|
assert "TLS" in msg or "SSL" in msg
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# POP3 protocol errors
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorPop3:
|
||||||
|
def test_auth_error_identifies_auth_failure(self):
|
||||||
|
exc = poplib.error_proto("-ERR authentication failed")
|
||||||
|
msg = _format_connection_error(exc, "pop.example.com", 995, "POP3")
|
||||||
|
# Verify both host and port appear in the message
|
||||||
|
assert "pop.example.com" in msg
|
||||||
|
assert "995" in msg
|
||||||
|
assert "Authentication" in msg or "authentication" in msg
|
||||||
|
|
||||||
|
def test_generic_pop3_error(self):
|
||||||
|
exc = poplib.error_proto("-ERR mailbox is locked")
|
||||||
|
msg = _format_connection_error(exc, "pop.example.com", 995, "POP3")
|
||||||
|
assert msg
|
||||||
|
assert "POP3" in msg
|
||||||
|
|
||||||
|
def test_empty_pop3_error(self):
|
||||||
|
"""Even a bare error_proto with no message must produce a non-empty string."""
|
||||||
|
exc = poplib.error_proto(b"")
|
||||||
|
msg = _format_connection_error(exc, "pop.example.com", 995, "POP3")
|
||||||
|
assert msg
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# Catch-all: empty-string exception
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestFormatConnectionErrorFallback:
|
||||||
|
def test_empty_string_exception(self):
|
||||||
|
"""An exception whose str() is empty must still produce a non-empty message."""
|
||||||
|
exc = asyncio.TimeoutError()
|
||||||
|
assert str(exc) == "" # confirm the premise
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert msg
|
||||||
|
assert len(msg) > 0
|
||||||
|
|
||||||
|
def test_generic_exception(self):
|
||||||
|
exc = RuntimeError("something went wrong")
|
||||||
|
msg = _fmt(exc)
|
||||||
|
assert "something went wrong" in msg or "RuntimeError" in msg
|
||||||
|
|
||||||
|
def test_no_host(self):
|
||||||
|
exc = RuntimeError("test")
|
||||||
|
msg = _format_connection_error(exc)
|
||||||
|
assert msg
|
||||||
|
|
||||||
|
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
# MailDebugRecorder
|
||||||
|
# ---------------------------------------------------------------------------
|
||||||
|
|
||||||
|
|
||||||
|
class TestMailDebugRecorder:
|
||||||
|
def test_record_entry_appears_in_trace(self):
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
rec.record("connect", "Connected to mail.example.com:993", {"elapsed_ms": 42})
|
||||||
|
details = rec.as_details()
|
||||||
|
assert len(details["trace"]) == 1
|
||||||
|
entry = details["trace"][0]
|
||||||
|
assert entry["phase"] == "connect"
|
||||||
|
assert entry["msg"] == "Connected to mail.example.com:993"
|
||||||
|
assert entry["data"]["elapsed_ms"] == 42
|
||||||
|
assert not details["truncated"]
|
||||||
|
|
||||||
|
def test_has_entries_false_when_empty(self):
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
assert not rec.has_entries()
|
||||||
|
|
||||||
|
def test_has_entries_true_after_record(self):
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
rec.record("auth", "Logged in")
|
||||||
|
assert rec.has_entries()
|
||||||
|
|
||||||
|
def test_size_cap_triggers_truncation(self):
|
||||||
|
"""Recording beyond _MAX_TRACE_BYTES silently truncates."""
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
# Each entry is ~100 chars; flood until truncated
|
||||||
|
long_msg = "x" * 1000
|
||||||
|
for i in range(200):
|
||||||
|
rec.record("flood", long_msg, {"i": i})
|
||||||
|
details = rec.as_details()
|
||||||
|
assert details["truncated"]
|
||||||
|
# After truncation, recording new entries is a no-op
|
||||||
|
prev_count = len(rec)
|
||||||
|
rec.record("after_truncate", "should be ignored")
|
||||||
|
assert len(rec) == prev_count
|
||||||
|
|
||||||
|
def test_entry_cap_triggers_truncation(self):
|
||||||
|
"""Recording more than _MAX_TRACE_ENTRIES entries truncates."""
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
for i in range(_MAX_TRACE_ENTRIES + 10):
|
||||||
|
rec.record("phase", f"entry {i}")
|
||||||
|
assert rec.as_details()["truncated"]
|
||||||
|
# Total entries should be MAX + 1 (the truncation sentinel)
|
||||||
|
assert len(rec.as_details()["trace"]) <= _MAX_TRACE_ENTRIES + 1
|
||||||
|
|
||||||
|
def test_no_password_in_trace_from_production_phases(self):
|
||||||
|
"""Production instrumentation records only usernames and counts, never passwords.
|
||||||
|
|
||||||
|
The recorder itself has no auto-redaction; the contract is that callers
|
||||||
|
(the instrumented IMAP/POP3 code) must never pass credential data.
|
||||||
|
This test verifies the expected production-phase entries contain no
|
||||||
|
password strings.
|
||||||
|
"""
|
||||||
|
password = "s3cr3tP@ssw0rd!"
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
# Simulate the entries that production code actually records
|
||||||
|
rec.record("auth", "Authenticated as user@example.com", {"elapsed_ms": 5})
|
||||||
|
rec.record("stat", "Mailbox has 3 messages", {"count": 3})
|
||||||
|
|
||||||
|
import json
|
||||||
|
|
||||||
|
serialised = json.dumps(rec.as_details())
|
||||||
|
# The password must not appear in any of these entries
|
||||||
|
assert password not in serialised
|
||||||
|
|
||||||
|
def test_timestamps_are_iso_format(self):
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
rec.record("connect", "ok")
|
||||||
|
ts = rec.as_details()["trace"][0]["ts"]
|
||||||
|
# Should be parseable as ISO 8601
|
||||||
|
from datetime import datetime
|
||||||
|
|
||||||
|
datetime.fromisoformat(ts) # raises if invalid
|
||||||
|
|
||||||
|
def test_multiple_phases_ordered(self):
|
||||||
|
rec = MailDebugRecorder()
|
||||||
|
for phase in ["connect", "auth", "select", "search", "fetch_msg", "logout"]:
|
||||||
|
rec.record(phase, f"{phase} done")
|
||||||
|
details = rec.as_details()
|
||||||
|
phases = [e["phase"] for e in details["trace"]]
|
||||||
|
assert phases == ["connect", "auth", "select", "search", "fetch_msg", "logout"]
|
||||||
@@ -81,6 +81,7 @@ def _make_account(**overrides) -> MagicMock:
|
|||||||
check_interval_minutes=5,
|
check_interval_minutes=5,
|
||||||
max_emails_per_check=50,
|
max_emails_per_check=50,
|
||||||
delete_after_forward=True,
|
delete_after_forward=True,
|
||||||
|
debug_logging=False,
|
||||||
provider_name="Gmail",
|
provider_name="Gmail",
|
||||||
auto_detected=False,
|
auto_detected=False,
|
||||||
total_emails_processed=100,
|
total_emails_processed=100,
|
||||||
|
|||||||
@@ -172,7 +172,7 @@ class TestTestPop3Connection:
|
|||||||
success, msg = await proc._test_pop3_connection()
|
success, msg = await proc._test_pop3_connection()
|
||||||
|
|
||||||
assert success is False
|
assert success is False
|
||||||
assert "Authentication failed" in msg
|
assert "Authentication rejected" in msg or "authentication" in msg.lower()
|
||||||
|
|
||||||
@patch("app.services.mail_processor.poplib")
|
@patch("app.services.mail_processor.poplib")
|
||||||
async def test_pop3_protocol_error(self, mock_poplib):
|
async def test_pop3_protocol_error(self, mock_poplib):
|
||||||
@@ -189,7 +189,7 @@ class TestTestPop3Connection:
|
|||||||
success, msg = await proc._test_pop3_connection()
|
success, msg = await proc._test_pop3_connection()
|
||||||
|
|
||||||
assert success is False
|
assert success is False
|
||||||
assert "POP3 protocol error" in msg
|
assert "POP3" in msg and "error" in msg.lower()
|
||||||
|
|
||||||
@patch("app.services.mail_processor.poplib")
|
@patch("app.services.mail_processor.poplib")
|
||||||
async def test_pop3_generic_exception(self, mock_poplib):
|
async def test_pop3_generic_exception(self, mock_poplib):
|
||||||
@@ -204,7 +204,7 @@ class TestTestPop3Connection:
|
|||||||
success, msg = await proc._test_pop3_connection()
|
success, msg = await proc._test_pop3_connection()
|
||||||
|
|
||||||
assert success is False
|
assert success is False
|
||||||
assert "Connection failed" in msg
|
assert msg # must be non-empty
|
||||||
|
|
||||||
|
|
||||||
# ---------------------------------------------------------------------------
|
# ---------------------------------------------------------------------------
|
||||||
@@ -280,7 +280,7 @@ class TestTestImapConnection:
|
|||||||
success, msg = await proc._test_imap_connection()
|
success, msg = await proc._test_imap_connection()
|
||||||
|
|
||||||
assert success is False
|
assert success is False
|
||||||
assert "Authentication failed" in msg
|
assert "Authentication" in msg or "rejected" in msg
|
||||||
|
|
||||||
@patch("app.services.mail_processor.aioimaplib")
|
@patch("app.services.mail_processor.aioimaplib")
|
||||||
async def test_imap_generic_exception(self, mock_aioimaplib):
|
async def test_imap_generic_exception(self, mock_aioimaplib):
|
||||||
@@ -292,7 +292,7 @@ class TestTestImapConnection:
|
|||||||
success, msg = await proc._test_imap_connection()
|
success, msg = await proc._test_imap_connection()
|
||||||
|
|
||||||
assert success is False
|
assert success is False
|
||||||
assert "IMAP connection failed" in msg
|
assert msg # must be non-empty
|
||||||
|
|
||||||
|
|
||||||
# ---------------------------------------------------------------------------
|
# ---------------------------------------------------------------------------
|
||||||
@@ -498,13 +498,18 @@ class TestFetchPop3Emails:
|
|||||||
|
|
||||||
@patch("app.services.mail_processor.poplib")
|
@patch("app.services.mail_processor.poplib")
|
||||||
async def test_connection_failure_raises_mail_fetch_error(self, mock_poplib):
|
async def test_connection_failure_raises_mail_fetch_error(self, mock_poplib):
|
||||||
"""Connection failure raises MailFetchError."""
|
"""Connection failure raises MailFetchError with non-empty message."""
|
||||||
|
import poplib as real_poplib
|
||||||
|
|
||||||
|
mock_poplib.error_proto = real_poplib.error_proto
|
||||||
mock_poplib.POP3_SSL.side_effect = OSError("connection refused")
|
mock_poplib.POP3_SSL.side_effect = OSError("connection refused")
|
||||||
|
|
||||||
account = _make_account(protocol="pop3_ssl")
|
account = _make_account(protocol="pop3_ssl")
|
||||||
proc = MailProcessor(account, "secret")
|
proc = MailProcessor(account, "secret")
|
||||||
with pytest.raises(MailFetchError, match="POP3 fetch error"):
|
with pytest.raises(MailFetchError) as exc_info:
|
||||||
await proc._fetch_pop3_emails(10, set())
|
await proc._fetch_pop3_emails(10, set())
|
||||||
|
# Message should be non-empty and describe the failure
|
||||||
|
assert str(exc_info.value)
|
||||||
|
|
||||||
@patch("app.services.mail_processor.poplib")
|
@patch("app.services.mail_processor.poplib")
|
||||||
async def test_empty_mailbox(self, mock_poplib):
|
async def test_empty_mailbox(self, mock_poplib):
|
||||||
|
|||||||
@@ -4,6 +4,25 @@ Comprehensive task breakdown for repository improvements and production readines
|
|||||||
|
|
||||||
## ✅ Recently Completed
|
## ✅ Recently Completed
|
||||||
|
|
||||||
|
- [x] **IMAP/POP3 diagnostics — Step 1: Friendly error messages**: Added
|
||||||
|
`_format_connection_error()` helper that converts raw OS/socket/SSL/POP3/IMAP
|
||||||
|
exceptions into human-readable sentences with host:port context. Applied at
|
||||||
|
every `raise MailFetchError`/`MailConnectionError` site. Fixes blank "IMAP
|
||||||
|
fetch error:" messages and cryptic DNS errno strings.
|
||||||
|
|
||||||
|
- [x] **IMAP/POP3 diagnostics — Step 2: Auto-clear stale error state**: Successful
|
||||||
|
fetches now always clear `last_error_message`/`last_error_at` and set
|
||||||
|
`status=ACTIVE`, even when some individual email forwards fail. Added
|
||||||
|
`POST /mail-accounts/{id}/clear-error` endpoint and "Clear" buttons on the
|
||||||
|
Accounts and Mailbox Activity pages.
|
||||||
|
|
||||||
|
- [x] **IMAP/POP3 diagnostics — Step 3: Per-account debug logging**: Added
|
||||||
|
`debug_logging` boolean column (migration `0002`), `MailDebugRecorder` class,
|
||||||
|
instrumented all connection phases (connect, auth, select, search, fetch UIDs,
|
||||||
|
per-message fetch, logout), persisted as `ProcessingLog[level=DEBUG]`.
|
||||||
|
Auto-disables after 5 runs in 24 h. Toggle in account edit form. Connection
|
||||||
|
trace viewer in Mailbox Activity logs page.
|
||||||
|
|
||||||
- [x] **Google OAuth consent screen legal compliance**: Added English Privacy Policy (`/privacy`) with Google API Limited Use Disclosure, Terms of Service (`/terms`), legal footer links on the home page (resolves Google's "homepage has no privacy policy link" verification rejection), login page, and register page (consent text). Cross-link from `/datenschutz` to `/privacy` added.
|
- [x] **Google OAuth consent screen legal compliance**: Added English Privacy Policy (`/privacy`) with Google API Limited Use Disclosure, Terms of Service (`/terms`), legal footer links on the home page (resolves Google's "homepage has no privacy policy link" verification rejection), login page, and register page (consent text). Cross-link from `/datenschutz` to `/privacy` added.
|
||||||
|
|
||||||
- [x] **Fix Pydantic V2 deprecation warnings**: Replaced `.dict()` with `.model_dump()` in `admin.py` and `notifications.py`. Fixed `RuntimeWarning: coroutine never awaited` for `db.add()` in test mocks (`test_tasks.py`, `test_config_service.py`).
|
- [x] **Fix Pydantic V2 deprecation warnings**: Replaced `.dict()` with `.model_dump()` in `admin.py` and `notifications.py`. Fixed `RuntimeWarning: coroutine never awaited` for `db.add()` in test mocks (`test_tasks.py`, `test_config_service.py`).
|
||||||
|
|||||||
@@ -4,7 +4,7 @@ import { AuthGuard } from '@/components/AuthGuard';
|
|||||||
import { DashboardLayout } from '@/components/DashboardLayout';
|
import { DashboardLayout } from '@/components/DashboardLayout';
|
||||||
import { useQuery, useMutation, useQueryClient } from '@tanstack/react-query';
|
import { useQuery, useMutation, useQueryClient } from '@tanstack/react-query';
|
||||||
import { mailAccountsApi, MailAccount } from '@/lib/api';
|
import { mailAccountsApi, MailAccount } from '@/lib/api';
|
||||||
import { Plus, Edit2, Trash2, CheckCircle, XCircle, AlertTriangle, Power, RefreshCw } from 'lucide-react';
|
import { Plus, Edit2, Trash2, CheckCircle, XCircle, AlertTriangle, Power, RefreshCw, RotateCcw } from 'lucide-react';
|
||||||
import { useState } from 'react';
|
import { useState } from 'react';
|
||||||
import Image from 'next/image';
|
import Image from 'next/image';
|
||||||
import { AddMailAccountModal } from '@/components/AddMailAccountModal';
|
import { AddMailAccountModal } from '@/components/AddMailAccountModal';
|
||||||
@@ -115,6 +115,13 @@ export default function AccountsPage() {
|
|||||||
},
|
},
|
||||||
});
|
});
|
||||||
|
|
||||||
|
const clearErrorMutation = useMutation({
|
||||||
|
mutationFn: mailAccountsApi.clearError,
|
||||||
|
onSuccess: () => {
|
||||||
|
queryClient.invalidateQueries({ queryKey: ['mail-accounts'] });
|
||||||
|
},
|
||||||
|
});
|
||||||
|
|
||||||
const handleEdit = (account: MailAccount) => {
|
const handleEdit = (account: MailAccount) => {
|
||||||
setEditingAccount(account);
|
setEditingAccount(account);
|
||||||
setIsModalOpen(true);
|
setIsModalOpen(true);
|
||||||
@@ -253,9 +260,20 @@ export default function AccountsPage() {
|
|||||||
|
|
||||||
{account.last_error_message && (
|
{account.last_error_message && (
|
||||||
<div className="mb-4 p-3 bg-red-50 border border-red-200 rounded-md">
|
<div className="mb-4 p-3 bg-red-50 border border-red-200 rounded-md">
|
||||||
<div className="flex items-start">
|
<div className="flex items-start justify-between gap-2">
|
||||||
<AlertTriangle className="h-4 w-4 text-red-500 mr-2 mt-0.5 flex-shrink-0" />
|
<div className="flex items-start min-w-0">
|
||||||
<p className="text-xs text-red-700">{account.last_error_message}</p>
|
<AlertTriangle className="h-4 w-4 text-red-500 mr-2 mt-0.5 flex-shrink-0" />
|
||||||
|
<p className="text-xs text-red-700">{account.last_error_message}</p>
|
||||||
|
</div>
|
||||||
|
<button
|
||||||
|
onClick={() => clearErrorMutation.mutate(account.id)}
|
||||||
|
disabled={clearErrorMutation.isPending}
|
||||||
|
title="Clear error status"
|
||||||
|
className="flex-shrink-0 flex items-center gap-1 px-2 py-1 text-xs font-medium text-red-600 bg-red-100 hover:bg-red-200 rounded transition-colors disabled:opacity-50"
|
||||||
|
>
|
||||||
|
<RotateCcw className="h-3 w-3" />
|
||||||
|
Clear
|
||||||
|
</button>
|
||||||
</div>
|
</div>
|
||||||
</div>
|
</div>
|
||||||
)}
|
)}
|
||||||
|
|||||||
@@ -2,7 +2,7 @@
|
|||||||
|
|
||||||
import { AuthGuard } from '@/components/AuthGuard';
|
import { AuthGuard } from '@/components/AuthGuard';
|
||||||
import { DashboardLayout } from '@/components/DashboardLayout';
|
import { DashboardLayout } from '@/components/DashboardLayout';
|
||||||
import { useQuery } from '@tanstack/react-query';
|
import { useQuery, useMutation, useQueryClient } from '@tanstack/react-query';
|
||||||
import { mailAccountsApi, MailAccount } from '@/lib/api';
|
import { mailAccountsApi, MailAccount } from '@/lib/api';
|
||||||
import { formatRelative } from '@/lib/date-utils';
|
import { formatRelative } from '@/lib/date-utils';
|
||||||
import Link from 'next/link';
|
import Link from 'next/link';
|
||||||
@@ -15,6 +15,7 @@ import {
|
|||||||
XCircle,
|
XCircle,
|
||||||
AlertTriangle,
|
AlertTriangle,
|
||||||
Inbox,
|
Inbox,
|
||||||
|
RotateCcw,
|
||||||
} from 'lucide-react';
|
} from 'lucide-react';
|
||||||
|
|
||||||
interface StatCardProps {
|
interface StatCardProps {
|
||||||
@@ -43,6 +44,14 @@ function StatCard({ title, value, icon: Icon, iconColor }: StatCardProps) {
|
|||||||
function AccountStatusRow({ account }: { account: MailAccount }) {
|
function AccountStatusRow({ account }: { account: MailAccount }) {
|
||||||
const hasError = !!account.last_error_message;
|
const hasError = !!account.last_error_message;
|
||||||
const lastChecked = account.last_check_at;
|
const lastChecked = account.last_check_at;
|
||||||
|
const queryClient = useQueryClient();
|
||||||
|
|
||||||
|
const clearErrorMutation = useMutation({
|
||||||
|
mutationFn: () => mailAccountsApi.clearError(account.id),
|
||||||
|
onSuccess: () => {
|
||||||
|
queryClient.invalidateQueries({ queryKey: ['mail-accounts'] });
|
||||||
|
},
|
||||||
|
});
|
||||||
|
|
||||||
return (
|
return (
|
||||||
<div className="px-5 py-4 border-b border-gray-100 last:border-b-0">
|
<div className="px-5 py-4 border-b border-gray-100 last:border-b-0">
|
||||||
@@ -84,7 +93,16 @@ function AccountStatusRow({ account }: { account: MailAccount }) {
|
|||||||
{hasError && (
|
{hasError && (
|
||||||
<div className="mt-2 flex items-start gap-1.5 p-2 bg-red-50 border border-red-200 rounded">
|
<div className="mt-2 flex items-start gap-1.5 p-2 bg-red-50 border border-red-200 rounded">
|
||||||
<AlertTriangle className="h-3.5 w-3.5 text-red-500 shrink-0 mt-0.5" />
|
<AlertTriangle className="h-3.5 w-3.5 text-red-500 shrink-0 mt-0.5" />
|
||||||
<p className="text-xs text-red-700 line-clamp-2">{account.last_error_message}</p>
|
<p className="text-xs text-red-700 line-clamp-2 flex-1">{account.last_error_message}</p>
|
||||||
|
<button
|
||||||
|
onClick={() => clearErrorMutation.mutate()}
|
||||||
|
disabled={clearErrorMutation.isPending}
|
||||||
|
title="Clear error status"
|
||||||
|
className="flex-shrink-0 flex items-center gap-0.5 px-1.5 py-0.5 text-xs text-red-600 bg-red-100 hover:bg-red-200 rounded transition-colors disabled:opacity-50"
|
||||||
|
>
|
||||||
|
<RotateCcw className="h-3 w-3" />
|
||||||
|
Clear
|
||||||
|
</button>
|
||||||
</div>
|
</div>
|
||||||
)}
|
)}
|
||||||
|
|
||||||
|
|||||||
@@ -3,7 +3,7 @@
|
|||||||
import { useState } from 'react';
|
import { useState } from 'react';
|
||||||
import { AuthGuard } from '@/components/AuthGuard';
|
import { AuthGuard } from '@/components/AuthGuard';
|
||||||
import { DashboardLayout } from '@/components/DashboardLayout';
|
import { DashboardLayout } from '@/components/DashboardLayout';
|
||||||
import { useQuery } from '@tanstack/react-query';
|
import { useQuery, useMutation, useQueryClient } from '@tanstack/react-query';
|
||||||
import { processingRunsApi, mailAccountsApi, MailAccount, ProcessingRun, ProcessingLog } from '@/lib/api';
|
import { processingRunsApi, mailAccountsApi, MailAccount, ProcessingRun, ProcessingLog } from '@/lib/api';
|
||||||
import { formatRelative, formatDate, formatDuration } from '@/lib/date-utils';
|
import { formatRelative, formatDate, formatDuration } from '@/lib/date-utils';
|
||||||
import {
|
import {
|
||||||
@@ -17,11 +17,14 @@ import {
|
|||||||
ChevronDown,
|
ChevronDown,
|
||||||
ChevronUp,
|
ChevronUp,
|
||||||
AlertTriangle,
|
AlertTriangle,
|
||||||
|
RotateCcw,
|
||||||
|
Bug,
|
||||||
} from 'lucide-react';
|
} from 'lucide-react';
|
||||||
|
|
||||||
function RunDetailRow({ run }: { run: ProcessingRun }) {
|
function RunDetailRow({ run }: { run: ProcessingRun }) {
|
||||||
const [expanded, setExpanded] = useState(false);
|
const [expanded, setExpanded] = useState(false);
|
||||||
const [logsPage, setLogsPage] = useState(1);
|
const [logsPage, setLogsPage] = useState(1);
|
||||||
|
const [traceExpanded, setTraceExpanded] = useState(false);
|
||||||
|
|
||||||
const { data: logsData, isLoading: logsLoading } = useQuery({
|
const { data: logsData, isLoading: logsLoading } = useQuery({
|
||||||
queryKey: ['run-logs', run.id, logsPage],
|
queryKey: ['run-logs', run.id, logsPage],
|
||||||
@@ -29,6 +32,10 @@ function RunDetailRow({ run }: { run: ProcessingRun }) {
|
|||||||
enabled: expanded,
|
enabled: expanded,
|
||||||
});
|
});
|
||||||
|
|
||||||
|
// Separate DEBUG-level connection trace entries from email-level logs
|
||||||
|
const debugLogs = (logsData?.items ?? []).filter((l: ProcessingLog) => l.level === 'DEBUG');
|
||||||
|
const emailLogs = (logsData?.items ?? []).filter((l: ProcessingLog) => l.level !== 'DEBUG');
|
||||||
|
|
||||||
return (
|
return (
|
||||||
<>
|
<>
|
||||||
<tr
|
<tr
|
||||||
@@ -62,11 +69,47 @@ function RunDetailRow({ run }: { run: ProcessingRun }) {
|
|||||||
{run.error_message}
|
{run.error_message}
|
||||||
</div>
|
</div>
|
||||||
)}
|
)}
|
||||||
|
|
||||||
|
{/* Connection trace (DEBUG-level logs) */}
|
||||||
|
{!logsLoading && debugLogs.length > 0 && (
|
||||||
|
<div className="mb-3">
|
||||||
|
<button
|
||||||
|
onClick={(e) => { e.stopPropagation(); setTraceExpanded((v) => !v); }}
|
||||||
|
className="flex items-center gap-1.5 text-xs font-medium text-purple-700 hover:text-purple-900 mb-1"
|
||||||
|
>
|
||||||
|
<Bug className="h-3.5 w-3.5" />
|
||||||
|
Connection trace
|
||||||
|
{traceExpanded ? <ChevronUp className="h-3 w-3" /> : <ChevronDown className="h-3 w-3" />}
|
||||||
|
</button>
|
||||||
|
{traceExpanded && debugLogs.map((log: ProcessingLog) => {
|
||||||
|
const trace = (log.error_details as { trace?: unknown[]; truncated?: boolean } | null)?.trace ?? [];
|
||||||
|
const truncated = (log.error_details as { trace?: unknown[]; truncated?: boolean } | null)?.truncated ?? false;
|
||||||
|
return (
|
||||||
|
<div key={log.id} className="bg-gray-900 text-gray-100 rounded p-3 text-xs font-mono overflow-x-auto max-h-80 overflow-y-auto">
|
||||||
|
{(trace as { ts: string; phase: string; msg: string; data?: Record<string, unknown> }[]).map((entry, i) => (
|
||||||
|
<div key={i} className="flex gap-2 mb-0.5">
|
||||||
|
<span className="text-gray-400 flex-shrink-0">{new Date(entry.ts).toISOString().slice(11, 23)}</span>
|
||||||
|
<span className={`flex-shrink-0 ${entry.phase === 'error' || entry.phase === 'fetch_error' ? 'text-red-400' : entry.phase === 'truncated' ? 'text-yellow-400' : 'text-green-400'}`}>[{entry.phase}]</span>
|
||||||
|
<span>{entry.msg}</span>
|
||||||
|
{entry.data && (
|
||||||
|
<span className="text-gray-500 ml-1">{JSON.stringify(entry.data)}</span>
|
||||||
|
)}
|
||||||
|
</div>
|
||||||
|
))}
|
||||||
|
{truncated && (
|
||||||
|
<div className="text-yellow-400 mt-1">⚠ Trace was truncated (size limit reached)</div>
|
||||||
|
)}
|
||||||
|
</div>
|
||||||
|
);
|
||||||
|
})}
|
||||||
|
</div>
|
||||||
|
)}
|
||||||
|
|
||||||
{logsLoading ? (
|
{logsLoading ? (
|
||||||
<div className="flex items-center gap-2 text-sm text-gray-500 py-1">
|
<div className="flex items-center gap-2 text-sm text-gray-500 py-1">
|
||||||
<RefreshCw className="h-4 w-4 animate-spin" /> Loading…
|
<RefreshCw className="h-4 w-4 animate-spin" /> Loading…
|
||||||
</div>
|
</div>
|
||||||
) : logsData && logsData.items.length > 0 ? (
|
) : emailLogs.length > 0 ? (
|
||||||
<>
|
<>
|
||||||
<table className="w-full text-xs">
|
<table className="w-full text-xs">
|
||||||
<thead>
|
<thead>
|
||||||
@@ -78,7 +121,7 @@ function RunDetailRow({ run }: { run: ProcessingRun }) {
|
|||||||
</tr>
|
</tr>
|
||||||
</thead>
|
</thead>
|
||||||
<tbody>
|
<tbody>
|
||||||
{logsData.items.map((log: ProcessingLog) => (
|
{emailLogs.map((log: ProcessingLog) => (
|
||||||
<tr key={log.id} className="border-t border-gray-100">
|
<tr key={log.id} className="border-t border-gray-100">
|
||||||
<td className="py-1 pr-4 text-gray-500 whitespace-nowrap">
|
<td className="py-1 pr-4 text-gray-500 whitespace-nowrap">
|
||||||
{formatDate(log.timestamp)}
|
{formatDate(log.timestamp)}
|
||||||
@@ -100,7 +143,7 @@ function RunDetailRow({ run }: { run: ProcessingRun }) {
|
|||||||
))}
|
))}
|
||||||
</tbody>
|
</tbody>
|
||||||
</table>
|
</table>
|
||||||
{logsData.pages > 1 && (
|
{logsData && logsData.pages > 1 && (
|
||||||
<div className="flex items-center gap-2 mt-2 text-xs text-gray-500">
|
<div className="flex items-center gap-2 mt-2 text-xs text-gray-500">
|
||||||
<button
|
<button
|
||||||
onClick={(e) => {
|
onClick={(e) => {
|
||||||
@@ -126,9 +169,9 @@ function RunDetailRow({ run }: { run: ProcessingRun }) {
|
|||||||
</div>
|
</div>
|
||||||
)}
|
)}
|
||||||
</>
|
</>
|
||||||
) : (
|
) : !logsLoading && debugLogs.length === 0 ? (
|
||||||
<p className="text-xs text-gray-400 py-1">No per-email logs for this run.</p>
|
<p className="text-xs text-gray-400 py-1">No per-email logs for this run.</p>
|
||||||
)}
|
) : null}
|
||||||
</td>
|
</td>
|
||||||
</tr>
|
</tr>
|
||||||
)}
|
)}
|
||||||
@@ -146,6 +189,14 @@ function MailboxCard({
|
|||||||
const [showHistory, setShowHistory] = useState(false);
|
const [showHistory, setShowHistory] = useState(false);
|
||||||
const hasError = !!account.last_error_message;
|
const hasError = !!account.last_error_message;
|
||||||
const lastChecked = account.last_check_at;
|
const lastChecked = account.last_check_at;
|
||||||
|
const queryClient = useQueryClient();
|
||||||
|
|
||||||
|
const clearErrorMutation = useMutation({
|
||||||
|
mutationFn: () => mailAccountsApi.clearError(account.id),
|
||||||
|
onSuccess: () => {
|
||||||
|
queryClient.invalidateQueries({ queryKey: ['mail-accounts'] });
|
||||||
|
},
|
||||||
|
});
|
||||||
|
|
||||||
return (
|
return (
|
||||||
<div className="bg-white rounded-lg border border-gray-200 shadow-sm overflow-hidden">
|
<div className="bg-white rounded-lg border border-gray-200 shadow-sm overflow-hidden">
|
||||||
@@ -186,7 +237,16 @@ function MailboxCard({
|
|||||||
{hasError && (
|
{hasError && (
|
||||||
<div className="mx-5 mb-3 p-2 bg-red-50 border border-red-200 rounded flex items-start gap-2">
|
<div className="mx-5 mb-3 p-2 bg-red-50 border border-red-200 rounded flex items-start gap-2">
|
||||||
<AlertTriangle className="h-4 w-4 text-red-500 shrink-0 mt-0.5" />
|
<AlertTriangle className="h-4 w-4 text-red-500 shrink-0 mt-0.5" />
|
||||||
<p className="text-xs text-red-700">{account.last_error_message}</p>
|
<p className="text-xs text-red-700 flex-1">{account.last_error_message}</p>
|
||||||
|
<button
|
||||||
|
onClick={() => clearErrorMutation.mutate()}
|
||||||
|
disabled={clearErrorMutation.isPending}
|
||||||
|
title="Clear error status"
|
||||||
|
className="flex-shrink-0 flex items-center gap-1 px-2 py-1 text-xs font-medium text-red-600 bg-red-100 hover:bg-red-200 rounded transition-colors disabled:opacity-50"
|
||||||
|
>
|
||||||
|
<RotateCcw className="h-3 w-3" />
|
||||||
|
Clear
|
||||||
|
</button>
|
||||||
</div>
|
</div>
|
||||||
)}
|
)}
|
||||||
|
|
||||||
|
|||||||
@@ -39,6 +39,7 @@ export function AddMailAccountModal({ account, onClose }: AddMailAccountModalPro
|
|||||||
check_interval_minutes: account?.check_interval_minutes || 5,
|
check_interval_minutes: account?.check_interval_minutes || 5,
|
||||||
max_emails_per_check: account?.max_emails_per_check || 50,
|
max_emails_per_check: account?.max_emails_per_check || 50,
|
||||||
delete_after_forward: account?.delete_after_forward ?? true,
|
delete_after_forward: account?.delete_after_forward ?? true,
|
||||||
|
debug_logging: account?.debug_logging ?? false,
|
||||||
provider_name: account?.provider_name ?? null,
|
provider_name: account?.provider_name ?? null,
|
||||||
});
|
});
|
||||||
|
|
||||||
@@ -188,6 +189,7 @@ export function AddMailAccountModal({ account, onClose }: AddMailAccountModalPro
|
|||||||
check_interval_minutes: formData.check_interval_minutes,
|
check_interval_minutes: formData.check_interval_minutes,
|
||||||
max_emails_per_check: formData.max_emails_per_check,
|
max_emails_per_check: formData.max_emails_per_check,
|
||||||
delete_after_forward: formData.delete_after_forward,
|
delete_after_forward: formData.delete_after_forward,
|
||||||
|
debug_logging: formData.debug_logging,
|
||||||
};
|
};
|
||||||
if (formData.password) {
|
if (formData.password) {
|
||||||
updateData.password = formData.password;
|
updateData.password = formData.password;
|
||||||
@@ -383,6 +385,20 @@ export function AddMailAccountModal({ account, onClose }: AddMailAccountModalPro
|
|||||||
Enabled
|
Enabled
|
||||||
</label>
|
</label>
|
||||||
</div>
|
</div>
|
||||||
|
<div className="flex items-center">
|
||||||
|
<input
|
||||||
|
type="checkbox"
|
||||||
|
name="debug_logging"
|
||||||
|
id="debug_logging"
|
||||||
|
checked={formData.debug_logging ?? false}
|
||||||
|
onChange={handleChange}
|
||||||
|
className="h-4 w-4 text-purple-600 focus:ring-purple-500 border-gray-300 rounded"
|
||||||
|
/>
|
||||||
|
<label htmlFor="debug_logging" className="ml-2 block text-sm text-gray-700">
|
||||||
|
Debug logging
|
||||||
|
<span className="ml-1 text-xs text-gray-400">(auto-disables after 5 runs)</span>
|
||||||
|
</label>
|
||||||
|
</div>
|
||||||
</div>
|
</div>
|
||||||
|
|
||||||
<div>
|
<div>
|
||||||
|
|||||||
@@ -66,6 +66,7 @@ export interface MailAccount {
|
|||||||
check_interval_minutes: number;
|
check_interval_minutes: number;
|
||||||
max_emails_per_check: number;
|
max_emails_per_check: number;
|
||||||
delete_after_forward: boolean;
|
delete_after_forward: boolean;
|
||||||
|
debug_logging: boolean;
|
||||||
status: string;
|
status: string;
|
||||||
provider_name?: string | null;
|
provider_name?: string | null;
|
||||||
auto_detected: boolean;
|
auto_detected: boolean;
|
||||||
@@ -95,6 +96,7 @@ export interface MailAccountCreate {
|
|||||||
check_interval_minutes?: number;
|
check_interval_minutes?: number;
|
||||||
max_emails_per_check?: number;
|
max_emails_per_check?: number;
|
||||||
delete_after_forward?: boolean;
|
delete_after_forward?: boolean;
|
||||||
|
debug_logging?: boolean;
|
||||||
provider_name?: string | null;
|
provider_name?: string | null;
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -114,6 +116,7 @@ export interface MailAccountUpdate {
|
|||||||
check_interval_minutes?: number;
|
check_interval_minutes?: number;
|
||||||
max_emails_per_check?: number;
|
max_emails_per_check?: number;
|
||||||
delete_after_forward?: boolean;
|
delete_after_forward?: boolean;
|
||||||
|
debug_logging?: boolean;
|
||||||
provider_name?: string | null;
|
provider_name?: string | null;
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -361,6 +364,11 @@ export const mailAccountsApi = {
|
|||||||
}>("/mail-accounts/auto-detect", { email_address: emailAddress });
|
}>("/mail-accounts/auto-detect", { email_address: emailAddress });
|
||||||
return response.data;
|
return response.data;
|
||||||
},
|
},
|
||||||
|
|
||||||
|
async clearError(id: number): Promise<MailAccount> {
|
||||||
|
const response = await api.post<MailAccount>(`/mail-accounts/${id}/clear-error`);
|
||||||
|
return response.data;
|
||||||
|
},
|
||||||
};
|
};
|
||||||
|
|
||||||
// ── Processing Runs API ─────────────────────────────────────────────────
|
// ── Processing Runs API ─────────────────────────────────────────────────
|
||||||
|
|||||||
Reference in New Issue
Block a user