Skip to content

Commit

Permalink
include full smtp response in dsn on errors
Browse files Browse the repository at this point in the history 
we now keep track of the full smtp error responses, potentially multi-line. and
we include it in a dsn in the first free-form human-readable text.

it can have multiple lines in practice, e.g. when a destination mail server
tries to be helpful in explaining what the problem is.
  • Loading branch information
@mjl-
mjl- committed Feb 14, 2024
1 parent 39bfa43 commit 50c1396
Show file tree
Hide file tree
Showing 5 changed files with 116 additions and 100 deletions.
32 changes: 17 additions & 15 deletions queue/direct.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -89,14 +89,14 @@ var (
)

// todo: rename function, perhaps put some of the params in a delivery struct so we don't pass all the params all the time?
func fail(ctx context.Context, qlog mlog.Log, m Msg, backoff time.Duration, permanent bool, remoteMTA dsn.NameIP, secodeOpt, errmsg string) {
func fail(ctx context.Context, qlog mlog.Log, m Msg, backoff time.Duration, permanent bool, remoteMTA dsn.NameIP, secodeOpt, errmsg string, moreLines []string) {
// todo future: when we implement relaying, we should be able to send DSNs to non-local users. and possibly specify a null mailfrom. ../rfc/5321:1503
// todo future: when we implement relaying, and a dsn cannot be delivered, and requiretls was active, we cannot drop the message. instead deliver to local postmaster? though ../rfc/8689:383 may intend to say the dsn should be delivered without requiretls?
// todo future: when we implement smtp dsn extension, parameter RET=FULL must be disregarded for messages with REQUIRETLS. ../rfc/8689:379

if permanent || m.MaxAttempts == 0 && m.Attempts >= 8 || m.MaxAttempts > 0 && m.Attempts >= m.MaxAttempts {
qlog.Errorx("permanent failure delivering from queue", errors.New(errmsg))
deliverDSNFailure(ctx, qlog, m, remoteMTA, secodeOpt, errmsg)
deliverDSNFailure(ctx, qlog, m, remoteMTA, secodeOpt, errmsg, moreLines)

if err := queueDelete(context.Background(), m.ID); err != nil {
qlog.Errorx("deleting message from queue after permanent failure", err)
Expand All @@ -116,7 +116,7 @@ func fail(ctx context.Context, qlog mlog.Log, m Msg, backoff time.Duration, perm
qlog.Errorx("temporary failure delivering from queue, sending delayed dsn", errors.New(errmsg), slog.Duration("backoff", backoff))

retryUntil := m.LastAttempt.Add((4 + 8 + 16) * time.Hour)
deliverDSNDelay(ctx, qlog, m, remoteMTA, secodeOpt, errmsg, retryUntil)
deliverDSNDelay(ctx, qlog, m, remoteMTA, secodeOpt, errmsg, moreLines, retryUntil)
} else {
qlog.Errorx("temporary failure delivering from queue", errors.New(errmsg), slog.Duration("backoff", backoff), slog.Time("nextattempt", m.NextAttempt))
}
Expand Down Expand Up @@ -168,7 +168,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
recipientDomainResult.Summary.TotalFailureSessionCount++
}

fail(ctx, qlog, m, backoff, permanent, dsn.NameIP{}, "", err.Error())
fail(ctx, qlog, m, backoff, permanent, dsn.NameIP{}, "", err.Error(), nil)
return
}

Expand All @@ -188,7 +188,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
} else {
qlog.Infox("mtasts lookup temporary error, aborting delivery attempt", err, slog.Any("domain", origNextHop))
recipientDomainResult.Summary.TotalFailureSessionCount++
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", err.Error())
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", err.Error(), nil)
return
}
}
Expand All @@ -206,6 +206,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
// ../rfc/3974:268.
var remoteMTA dsn.NameIP
var secodeOpt, errmsg string
var moreLines []string // For additional SMTP response lines, included in DSN.
permanent = false
nmissingRequireTLS := 0
// todo: should make distinction between host permanently not accepting the message, and the message not being deliverable permanently. e.g. a mx host may have a size limit, or not accept 8bitmime, while another host in the list does accept the message. same for smtputf8, ../rfc/6531:555
Expand All @@ -230,6 +231,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
metricTLSRequiredNoIgnored.WithLabelValues("mtastsmx").Inc()
} else {
errmsg = fmt.Sprintf("mx host %s does not match enforced mta-sts policy with hosts %s", h.Domain, strings.Join(policyHosts, ","))
moreLines = nil
qlog.Error("mx host does not match mta-sts policy in mode enforce, skipping", slog.Any("host", h.Domain), slog.Any("policyhosts", policyHosts))
recipientDomainResult.Summary.TotalFailureSessionCount++
continue
Expand Down Expand Up @@ -269,7 +271,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale

var badTLS, ok bool
var hostResult tlsrpt.Result
permanent, tlsDANE, badTLS, secodeOpt, remoteIP, errmsg, hostResult, ok = deliverHost(nqlog, resolver, dialer, ourHostname, transportName, h, enforceMTASTS, haveMX, origNextHopAuthentic, origNextHop, expandedNextHopAuthentic, expandedNextHop, &m, tlsMode, tlsPKIX, &recipientDomainResult)
permanent, tlsDANE, badTLS, secodeOpt, remoteIP, errmsg, moreLines, hostResult, ok = deliverHost(nqlog, resolver, dialer, ourHostname, transportName, h, enforceMTASTS, haveMX, origNextHopAuthentic, origNextHop, expandedNextHopAuthentic, expandedNextHop, &m, tlsMode, tlsPKIX, &recipientDomainResult)

var zerotype tlsrpt.PolicyType
if hostResult.Policy.Type != zerotype {
Expand All @@ -296,7 +298,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
slog.Bool("enforcemtasts", enforceMTASTS),
slog.Bool("tlsdane", tlsDANE),
slog.Any("requiretls", m.RequireTLS))
permanent, _, _, secodeOpt, remoteIP, errmsg, _, ok = deliverHost(nqlog, resolver, dialer, ourHostname, transportName, h, enforceMTASTS, haveMX, origNextHopAuthentic, origNextHop, expandedNextHopAuthentic, expandedNextHop, &m, smtpclient.TLSSkip, false, &tlsrpt.Result{})
permanent, _, _, secodeOpt, remoteIP, errmsg, moreLines, _, ok = deliverHost(nqlog, resolver, dialer, ourHostname, transportName, h, enforceMTASTS, haveMX, origNextHopAuthentic, origNextHop, expandedNextHopAuthentic, expandedNextHop, &m, smtpclient.TLSSkip, false, &tlsrpt.Result{})
}

if ok {
Expand Down Expand Up @@ -332,7 +334,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
permanent = true
}

fail(ctx, qlog, m, backoff, permanent, remoteMTA, secodeOpt, errmsg)
fail(ctx, qlog, m, backoff, permanent, remoteMTA, secodeOpt, errmsg, moreLines)
return
}

Expand All @@ -352,7 +354,7 @@ func deliverDirect(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
// The returned hostResult holds TLSRPT reporting results for the connection
// attempt. Its policy type can be the zero value, indicating there was no finding
// (e.g. internal error).
func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer, ourHostname dns.Domain, transportName string, host dns.IPDomain, enforceMTASTS, haveMX, origNextHopAuthentic bool, origNextHop dns.Domain, expandedNextHopAuthentic bool, expandedNextHop dns.Domain, m *Msg, tlsMode smtpclient.TLSMode, tlsPKIX bool, recipientDomainResult *tlsrpt.Result) (permanent, tlsDANE, badTLS bool, secodeOpt string, remoteIP net.IP, errmsg string, hostResult tlsrpt.Result, ok bool) {
func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer, ourHostname dns.Domain, transportName string, host dns.IPDomain, enforceMTASTS, haveMX, origNextHopAuthentic bool, origNextHop dns.Domain, expandedNextHopAuthentic bool, expandedNextHop dns.Domain, m *Msg, tlsMode smtpclient.TLSMode, tlsPKIX bool, recipientDomainResult *tlsrpt.Result) (permanent, tlsDANE, badTLS bool, secodeOpt string, remoteIP net.IP, errmsg string, moreLines []string, hostResult tlsrpt.Result, ok bool) {
// About attempting delivery to multiple addresses of a host: ../rfc/5321:3898

tlsRequiredNo := m.RequireTLS != nil && !*m.RequireTLS
Expand Down Expand Up @@ -386,7 +388,7 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer,
// Open message to deliver.
f, err := os.Open(m.MessagePath())
if err != nil {
return false, false, false, "", nil, fmt.Sprintf("open message file: %s", err), hostResult, false
return false, false, false, "", nil, fmt.Sprintf("open message file: %s", err), nil, hostResult, false
}
msgr := store.FileMsgReader(m.MsgPrefix, f)
defer func() {
Expand Down Expand Up @@ -517,7 +519,7 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer,
log.Info("verified tls is required, but destination has no usable dane records and no mta-sts policy, canceling delivery attempt to host")
metricRequireTLSUnsupported.WithLabelValues("nopolicy").Inc()
// Resond with proper enhanced status code. ../rfc/8689:301
return false, tlsDANE, false, smtp.SePol7MissingReqTLS, remoteIP, "missing required tls verification mechanism", hostResult, false
return false, tlsDANE, false, smtp.SePol7MissingReqTLS, remoteIP, "missing required tls verification mechanism", nil, hostResult, false
}

// Dial the remote host given the IPs if no error yet.
Expand Down Expand Up @@ -545,7 +547,7 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer,
metricConnection.WithLabelValues(result).Inc()
if err != nil {
log.Debugx("connecting to remote smtp", err, slog.Any("host", host))
return false, tlsDANE, false, "", remoteIP, fmt.Sprintf("dialing smtp server: %v", err), hostResult, false
return false, tlsDANE, false, "", remoteIP, fmt.Sprintf("dialing smtp server: %v", err), nil, hostResult, false
}

var mailFrom string
Expand Down Expand Up @@ -636,7 +638,7 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer,
deliveryResult = "error"
}
if err == nil {
return false, tlsDANE, false, "", remoteIP, "", hostResult, true
return false, tlsDANE, false, "", remoteIP, "", nil, hostResult, true
} else if cerr, ok := err.(smtpclient.Error); ok {
// If we are being rejected due to policy reasons on the first
// attempt and remote has both IPv4 and IPv6, we'll give it
Expand All @@ -652,9 +654,9 @@ func deliverHost(log mlog.Log, resolver dns.Resolver, dialer smtpclient.Dialer,
secode = smtp.SePol7MissingReqTLS
metricRequireTLSUnsupported.WithLabelValues("norequiretls").Inc()
}
return permanent, tlsDANE, errors.Is(cerr, smtpclient.ErrTLS), secode, remoteIP, cerr.Error(), hostResult, false
return permanent, tlsDANE, errors.Is(cerr, smtpclient.ErrTLS), secode, remoteIP, cerr.Error(), cerr.MoreLines, hostResult, false
} else {
return false, tlsDANE, errors.Is(cerr, smtpclient.ErrTLS), "", remoteIP, err.Error(), hostResult, false
return false, tlsDANE, errors.Is(cerr, smtpclient.ErrTLS), "", remoteIP, err.Error(), nil, hostResult, false
}
}

Expand Down
9 changes: 5 additions & 4 deletions queue/dsn.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import (
"fmt"
"log/slog"
"os"
"strings"
"time"

"github.com/prometheus/client_golang/prometheus"
Expand All @@ -29,7 +30,7 @@ var (
)
)

func deliverDSNFailure(ctx context.Context, log mlog.Log, m Msg, remoteMTA dsn.NameIP, secodeOpt, errmsg string) {
func deliverDSNFailure(ctx context.Context, log mlog.Log, m Msg, remoteMTA dsn.NameIP, secodeOpt, errmsg string, moreLines []string) {
const subject = "mail delivery failed"
message := fmt.Sprintf(`
Delivery has failed permanently for your email to:
Expand All @@ -41,12 +42,12 @@ No further deliveries will be attempted.
Error during the last delivery attempt:
%s
`, m.Recipient().XString(m.SMTPUTF8), errmsg)
`, m.Recipient().XString(m.SMTPUTF8), strings.Join(append([]string{errmsg}, moreLines...), "\n\t"))

deliverDSN(ctx, log, m, remoteMTA, secodeOpt, errmsg, true, nil, subject, message)
}

func deliverDSNDelay(ctx context.Context, log mlog.Log, m Msg, remoteMTA dsn.NameIP, secodeOpt, errmsg string, retryUntil time.Time) {
func deliverDSNDelay(ctx context.Context, log mlog.Log, m Msg, remoteMTA dsn.NameIP, secodeOpt, errmsg string, moreLines []string, retryUntil time.Time) {
// Should not happen, but doesn't hurt to prevent sending delayed delivery
// notifications for DMARC reports. We don't want to waste postmaster attention.
if m.IsDMARCReport {
Expand All @@ -65,7 +66,7 @@ If these attempts all fail, you will receive a notice.
Error during the last delivery attempt:
%s
`, m.Recipient().XString(false), errmsg)
`, m.Recipient().XString(false), strings.Join(append([]string{errmsg}, moreLines...), "\n\t"))

deliverDSN(ctx, log, m, remoteMTA, secodeOpt, errmsg, false, &retryUntil, subject, message)
}
Expand Down
6 changes: 3 additions & 3 deletions queue/queue.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -581,7 +581,7 @@ func deliver(log mlog.Log, resolver dns.Resolver, m Msg) {
transport, ok = mox.Conf.Static.Transports[m.Transport]
if !ok {
var remoteMTA dsn.NameIP // Zero value, will not be included in DSN. ../rfc/3464:1027
fail(ctx, qlog, m, backoff, false, remoteMTA, "", fmt.Sprintf("cannot find transport %q", m.Transport))
fail(ctx, qlog, m, backoff, false, remoteMTA, "", fmt.Sprintf("cannot find transport %q", m.Transport), nil)
return
}
transportName = m.Transport
Expand Down Expand Up @@ -692,10 +692,10 @@ func deliver(log mlog.Log, resolver dns.Resolver, m Msg) {
if transport.Socks != nil {
socksdialer, err := proxy.SOCKS5("tcp", transport.Socks.Address, nil, &net.Dialer{})
if err != nil {
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", fmt.Sprintf("socks dialer: %v", err))
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", fmt.Sprintf("socks dialer: %v", err), nil)
return
} else if d, ok := socksdialer.(smtpclient.Dialer); !ok {
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", "socks dialer is not a contextdialer")
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", "socks dialer is not a contextdialer", nil)
return
} else {
dialer = d
Expand Down
10 changes: 5 additions & 5 deletions queue/submit.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,7 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
requireTLS := m.RequireTLS != nil && *m.RequireTLS
if requireTLS && (tlsMode != smtpclient.TLSRequiredStartTLS && tlsMode != smtpclient.TLSImmediate || !tlsPKIX) {
errmsg = fmt.Sprintf("transport %s: message requires verified tls but transport does not verify tls", transportName)
fail(ctx, qlog, m, backoff, true, dsn.NameIP{}, smtp.SePol7MissingReqTLS, errmsg)
fail(ctx, qlog, m, backoff, true, dsn.NameIP{}, smtp.SePol7MissingReqTLS, errmsg, nil)
return
}

Expand Down Expand Up @@ -115,7 +115,7 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
}
qlog.Errorx("dialing for submission", err, slog.String("remote", addr))
errmsg = fmt.Sprintf("transport %s: dialing %s for submission: %v", transportName, addr, err)
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", errmsg)
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", errmsg, nil)
return
}
dialcancel()
Expand Down Expand Up @@ -171,7 +171,7 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
qlog.Errorx("establishing smtp session for submission", err, slog.String("remote", addr))
errmsg = fmt.Sprintf("transport %s: establishing smtp session with %s for submission: %v", transportName, addr, err)
secodeOpt = smtperr.Secode
fail(ctx, qlog, m, backoff, false, remoteMTA, secodeOpt, errmsg)
fail(ctx, qlog, m, backoff, false, remoteMTA, secodeOpt, errmsg, smtperr.MoreLines)
return
}
defer func() {
Expand All @@ -196,7 +196,7 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
if err != nil {
qlog.Errorx("opening message for delivery", err, slog.String("remote", addr), slog.String("path", p))
errmsg = fmt.Sprintf("transport %s: opening message file for submission: %v", transportName, err)
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", errmsg)
fail(ctx, qlog, m, backoff, false, dsn.NameIP{}, "", errmsg, nil)
return
}
msgr = store.FileMsgReader(m.MsgPrefix, f)
Expand Down Expand Up @@ -239,7 +239,7 @@ func deliverSubmit(qlog mlog.Log, resolver dns.Resolver, dialer smtpclient.Diale
permanent = smtperr.Permanent
secodeOpt = smtperr.Secode
errmsg = fmt.Sprintf("transport %s: submitting email to %s: %v", transportName, addr, err)
fail(ctx, qlog, m, backoff, permanent, remoteMTA, secodeOpt, errmsg)
fail(ctx, qlog, m, backoff, permanent, remoteMTA, secodeOpt, errmsg, smtperr.MoreLines)
return
}
qlog.Info("delivered from queue with transport")
Expand Down
Loading

0 comments on commit 50c1396

Please sign in to comment.