FabledSteward/steward/core/outbox.py

"""Every email Steward sends goes out through here (#5506).

An email is a row in email_outbox until the mail server accepts it (System
156 ruling, "Every email goes through a queue on the record"). The sender,
send_due, runs every SENDER_TICK_S. Each tick it:
- claims what is due;
- sends the batch over one connection;
- settles each row on what the server said.

How a row settles:
- **accepted:** sent.
- **refused outright** (a 5xx reply, e.g. "no such mailbox"): failed at once,
  with the server's reason. Retrying would only repeat the refusal.
- **temporary** (no connection, a timeout, a 4xx reply): tried again after
  BACKOFF_S, and once more at the hour. If the server still hasn't taken it
  by then, it is failed with the last error.
- **a test** (retry=False): settles on its first answer either way.

Nothing is kept in memory. A row left behind by a restart is still pending
(or held, or claimed by a run that died), and the next tick picks it up.
"""
from __future__ import annotations

import asyncio
import logging
import smtplib
from datetime import datetime, timedelta, timezone
from email.message import EmailMessage
from typing import TYPE_CHECKING

from sqlalchemy import or_, select, update

from steward.models.outbox import EmailOutbox

if TYPE_CHECKING:
    from quart import Quart
    from steward.core.mail import Recipient

logger = logging.getLogger(__name__)

SENDER_TICK_S = 15
# Waits after the 1st, 2nd, … temporary failure; every later wait is the last.
BACKOFF_S = (30, 60, 120, 300, 600, 900)
# An email the server hasn't accepted this long after its first attempt is
# failed (operator ruling: "retry fails at an hour").
GIVE_UP_S = 3600
# A claim older than this belongs to a run that died mid-send: back to pending.
STALE_CLAIM_S = 300
BATCH = 50


def backoff(attempts: int) -> int:
    """Seconds to wait after the `attempts`-th failed try."""
    return BACKOFF_S[min(max(attempts, 1), len(BACKOFF_S)) - 1]


def classify(exc: BaseException) -> str:
    """"permanent" when the mail server refused it (5xx), or the message
    can't be sent as written; "temporary" when trying later may work: no
    connection, a timeout, a dropped line, or a 4xx "try again"."""
    if isinstance(exc, smtplib.SMTPRecipientsRefused):
        codes = [code for code, _ in exc.recipients.values()]
        return "permanent" if codes and all(500 <= c < 600 for c in codes) else "temporary"
    if isinstance(exc, smtplib.SMTPResponseException):
        return "permanent" if 500 <= exc.smtp_code < 600 else "temporary"
    if isinstance(exc, smtplib.SMTPNotSupportedError):
        return "permanent"            # e.g. STARTTLS asked of a server without it
    if isinstance(exc, (OSError, TimeoutError)):
        return "temporary"            # SMTPServerDisconnected, refused, unreachable, TLS
    return "permanent"                # a message we couldn't build: trying again repeats it


def reason(exc: BaseException) -> str:
    """What went wrong, as the server said it where it said anything."""
    def said(code, msg) -> str:
        text = msg.decode(errors="replace") if isinstance(msg, bytes) else str(msg)
        return f"{code} {' '.join(text.split())}"
    if isinstance(exc, smtplib.SMTPRecipientsRefused):
        return "; ".join(f"{to}: {said(c, m)}" for to, (c, m) in exc.recipients.items())
    if isinstance(exc, smtplib.SMTPResponseException):
        return said(exc.smtp_code, exc.smtp_error)
    if isinstance(exc, TimeoutError):
        return "The mail server didn't answer in time"
    if isinstance(exc, ConnectionRefusedError):
        return "The mail server refused the connection"
    if isinstance(exc, smtplib.SMTPServerDisconnected):
        return f"The mail server closed the connection{': ' + str(exc) if str(exc) else ''}"
    return str(exc) or type(exc).__name__


def enqueue(db, *, kind: str, to: "Recipient | str", subject: str | None = None,
            text: str | None = None, html: str | None = None,
            send_after: datetime | None = None, retry: bool = True,
            now: datetime | None = None) -> EmailOutbox:
    """Add one email to the queue in `db`'s transaction (the caller commits).
    `send_after` holds it until then (an alert burst, #5507); otherwise it is
    due at once. `to` is a mail.Recipient, or a bare address read in UTC."""
    now = now or datetime.now(timezone.utc)
    address, tz, show_utc = (to, "UTC", False) if isinstance(to, str) else \
        (to.address, getattr(to.tz, "key", None) or "UTC", to.show_utc)
    row = EmailOutbox(kind=kind, recipient=address, tz=tz, show_utc=show_utc,
                      subject=subject, text=text, html=html, retry=retry, created_at=now,
                      state="held" if send_after else "pending", send_after=send_after,
                      next_attempt_at=send_after or now)
    db.add(row)
    return row


def settle(row: EmailOutbox, outcome: BaseException | None, now: datetime) -> None:
    """Record one attempt's outcome on `row`: None is the server's acceptance."""
    row.attempts += 1
    row.first_attempt_at = row.first_attempt_at or now
    row.claimed_at = None
    if outcome is None:
        row.state, row.sent_at, row.last_error, row.next_attempt_at = "sent", now, None, None
        return
    row.last_error = reason(outcome)
    deadline = row.first_attempt_at + timedelta(seconds=GIVE_UP_S)
    if classify(outcome) == "permanent" or not row.retry or now >= deadline:
        row.state, row.next_attempt_at = "failed", None
        if now >= deadline and classify(outcome) == "temporary" and row.retry:
            row.last_error += " (gave up after an hour of retries)"
        return
    # Retry; the last try lands at the hour, not after it.
    row.state = "pending"
    row.next_attempt_at = min(now + timedelta(seconds=backoff(row.attempts)), deadline)


def deliver_sync(cfg: dict, messages: list[EmailMessage]) -> list[BaseException | None]:
    """Send each message over one connection; per message, None when the
    server accepted it, else what went wrong. A failure to connect, or a
    line dropped mid-batch, is every unsent message's outcome."""
    from steward.core.notifications import smtp_open
    outcomes: list[BaseException | None] = []
    try:
        with smtp_open(cfg) as smtp:
            for msg in messages:
                try:
                    smtp.send_message(msg)
                    outcomes.append(None)
                except smtplib.SMTPServerDisconnected as exc:
                    outcomes.append(exc)
                    break
                except Exception as exc:
                    outcomes.append(exc)
    except Exception as exc:
        outcomes += [exc] * (len(messages) - len(outcomes))
    return outcomes + [smtplib.SMTPServerDisconnected("connection lost")] * (len(messages) - len(outcomes))


async def write_held(app: "Quart", row: EmailOutbox) -> None:
    """Fill in a row queued without its words: an alert burst, written when
    its window closes (#5507). Raises when it can't be written."""
    raise ValueError(f"no words to send for a {row.kind} email")


async def attempt(app: "Quart", ids: list[str], now: datetime | None = None) -> dict[str, str]:
    """Try to send the claimed rows `ids` once, and settle each. The words
    are written and kept first, so a retry sends the same email; no session
    is held while the mail server is talked to. Returns {id: state after}."""
    from steward.core.mail import message
    if not ids:
        return {}
    cfg = app.config.get("SMTP", {})
    outcomes: dict[str, BaseException | None] = {}
    sendable: list[tuple[str, EmailMessage]] = []
    async with app.db_sessionmaker() as db:
        for row in (await db.execute(select(EmailOutbox).where(EmailOutbox.id.in_(ids)))).scalars():
            if not cfg.get("host"):
                outcomes[row.id] = smtplib.SMTPNotSupportedError(
                    "No mail server is set (Settings → Notifications)")
                continue
            try:
                if row.subject is None:
                    await write_held(app, row)
                sendable.append((row.id, message(cfg, row.recipient, row.subject, row.text, row.html)))
            except Exception as exc:
                logger.exception("email %s: could not be written", row.id)
                outcomes[row.id] = exc
        await db.commit()
    if sendable:
        sent = await asyncio.get_running_loop().run_in_executor(
            None, deliver_sync, cfg, [m for _, m in sendable])
        outcomes.update({rid: out for (rid, _), out in zip(sendable, sent)})
    now = now or datetime.now(timezone.utc)
    async with app.db_sessionmaker() as db:
        async with db.begin():
            rows = list((await db.execute(
                select(EmailOutbox).where(EmailOutbox.id.in_(ids)))).scalars())
            for row in rows:
                settle(row, outcomes.get(row.id, RuntimeError("not tried")), now)
                if row.state == "failed":
                    logger.warning("email %s to %s failed: %s", row.kind, row.recipient, row.last_error)
            await after_settle(db, rows)
        return {row.id: row.state for row in rows}


async def after_settle(db, rows: list[EmailOutbox]) -> None:
    """What else follows from these rows' new states, in the same
    transaction: an alert event's email outcome (#5507)."""


async def claim_due(app: "Quart", now: datetime, limit: int = BATCH) -> list[str]:
    """Mark what is due as being sent, and return its ids: pending rows whose
    time has come, held rows whose window has closed, and rows a dead run
    had claimed. SKIP LOCKED, so two senders never claim one row."""
    stale = now - timedelta(seconds=STALE_CLAIM_S)
    async with app.db_sessionmaker() as db:
        async with db.begin():
            await db.execute(update(EmailOutbox)
                             .where(EmailOutbox.state == "sending", EmailOutbox.claimed_at < stale)
                             .values(state="pending", claimed_at=None, next_attempt_at=now))
            ids = list((await db.execute(
                select(EmailOutbox.id)
                .where(or_(EmailOutbox.state == "pending", EmailOutbox.state == "held"),
                       EmailOutbox.next_attempt_at <= now)
                .order_by(EmailOutbox.next_attempt_at)
                .limit(limit)
                .with_for_update(skip_locked=True))).scalars())
            if ids:
                await db.execute(update(EmailOutbox).where(EmailOutbox.id.in_(ids))
                                 .values(state="sending", claimed_at=now))
    return ids


async def send_due(app: "Quart") -> None:
    """The sender's tick: claim what is due and try it once."""
    now = datetime.now(timezone.utc)
    ids = await claim_due(app, now)
    if ids:
        states = await attempt(app, ids, now)
        logger.info("email outbox: %d tried, %d sent", len(states),
                    sum(1 for s in states.values() if s == "sent"))