No database change (schema version 6005).
What was actually happening
Postfix's error means the message body and the terminating dot were fully transmitted, and it was waiting for hMailServer's 250 — which never came. So the stall was never in reception; it was in the accept/save work that runs after end-of-data and before the reply.
Two things combine to produce it
- For a trusted incoming relay — exactly what a Proxmox/Postfix front end is — hMailServer defers its whole spam battery to after end-of-data. For a direct or authenticated sender those same tests run earlier, during MAIL FROM/RCPT TO, on the connection thread. That is why this only ever happened to relayed mail, and why it never reproduced on a simple test server.
- That work runs on a bounded pool (15 threads by default) and holds the thread that sends the 250. SpamAssassin's wait had no overall ceiling: the connection's idle timeout is re-armed on every byte received, so a scanner that stalls, or dribbles, holds the thread indefinitely.
Reproduced deliberately, against a SpamAssassin endpoint that accepts connections and never answers:
The fixes
- SpamAssassin's wait is now bounded. It was an untimed wait released only by an idle timer that any trickle of data re-arms. It now has a hard ceiling (SAMaxTimeout + 30 s) after which the message is accepted without a SpamAssassin verdict — the same outcome as when spamd is simply down. This also required sharing the completion flag properly with the connection, since the old code held a reference to the waiting function's stack.
- Message acceptance is bounded overall. A new FinalizationTimeout (default 240 s, comfortably inside Postfix's 600 s data-done timeout; 0 disables it) makes the server answer 451 4.3.1 and let the sender retry, rather than leaving it waiting for a reply that will not arrive. The check runs on the accepting thread itself and only before anything is saved, so it cannot duplicate mail — a watchdog replying from outside would race the 250 and deliver the message twice.
- The silence is now instrumented. Acceptance is timed per stage, and each spam test is timed individually. A slow stage is reported at APPLICATION level rather than only under debug logging, so the log now says:
- Spam test: SpamTestSpamAssassin, Score: 0, Time: 120031 ms
- SMTPConnection - accept: done spam-protection in 120047 ms (session 5).
- Where previously there was nothing at all between 354 and the reply. If acceptance waited on a saturated queue, that is logged too, with the wait in milliseconds.
If you are affected, upgrading is enough to convert silent stalls into either a completed delivery or a clean 451 retry. If you want to know why your server is slow, enable debug logging and the per-stage timings will name the scanner, DNS lookup or event script responsible.
Known related issues, not fixed here
The audit that found this also found other unbounded waits on the same and adjacent paths, deliberately left for a follow-up rather than rushed into this release: synchronous DNS lookups in the spam tests have no application-level timeout, the database connection pool has no acquisition deadline, event scripts have no execution limit, and on the delivery side the ClamAV read/write timeout is currently ineffective. None of these is the reported fault, and each needs its own fix and its own test.
Also in this release
- The README has been rewritten around what the server does and what it is built on. Per-version change history now lives here on the Releases page, where it belongs.
- The regression suite gains coverage for clients that vanish mid-operation (aborted DATA, truncated BDAT, IMAP APPEND literals cut short, POP3 disconnects during RETR) — the class of defect that produced the two blockers found during 6.2.15.
- A new installer smoke test installs each release on a clean throwaway machine and verifies the service registers, starts and listens, so the installer is no longer validated only by the fact that it compiles.
