in integration test, don't read database index files but use imap idle to get notified of message delivery, and make integration & quickstart tests faster by making first-time sender delay configurable, and using a 1s timeout instead of the default 15s

we could make more types of delays configurable. the current approach isn't
great, as it results in an a default value of "0s" in the config file, while
the actual default is 15s (which is documented just above, but still).

config/config.go

@@ -100,11 +100,14 @@ type Listener struct {
 	SMTPMaxMessageSize int64 `sconf:"optional" sconf-doc:"Maximum size in bytes accepted incoming and outgoing messages. Default is 100MB."`
 	SMTP               struct {
 		Enabled         bool
-		Port            int          `sconf:"optional" sconf-doc:"Default 25."`
+		Port            int      `sconf:"optional" sconf-doc:"Default 25."`
-		NoSTARTTLS      bool         `sconf:"optional" sconf-doc:"Do not offer STARTTLS to secure the connection. Not recommended."`
+		NoSTARTTLS      bool     `sconf:"optional" sconf-doc:"Do not offer STARTTLS to secure the connection. Not recommended."`
-		RequireSTARTTLS bool         `sconf:"optional" sconf-doc:"Do not accept incoming messages if STARTTLS is not active. Can be used in combination with a strict MTA-STS policy. A remote SMTP server may not support TLS and may not be able to deliver messages."`
+		RequireSTARTTLS bool     `sconf:"optional" sconf-doc:"Do not accept incoming messages if STARTTLS is not active. Can be used in combination with a strict MTA-STS policy. A remote SMTP server may not support TLS and may not be able to deliver messages."`
-		DNSBLs          []string     `sconf:"optional" sconf-doc:"Addresses of DNS block lists for incoming messages. Block lists are only consulted for connections/messages without enough reputation to make an accept/reject decision. This prevents sending IPs of all communications to the block list provider. If any of the listed DNSBLs contains a requested IP address, the message is rejected as spam. The DNSBLs are checked for healthiness before use, at most once per 4 hours. Example DNSBLs: sbl.spamhaus.org, bl.spamcop.net"`
+		DNSBLs          []string `sconf:"optional" sconf-doc:"Addresses of DNS block lists for incoming messages. Block lists are only consulted for connections/messages without enough reputation to make an accept/reject decision. This prevents sending IPs of all communications to the block list provider. If any of the listed DNSBLs contains a requested IP address, the message is rejected as spam. The DNSBLs are checked for healthiness before use, at most once per 4 hours. Example DNSBLs: sbl.spamhaus.org, bl.spamcop.net"`
-		DNSBLZones      []dns.Domain `sconf:"-"`
+
+		FirstTimeSenderDelay *time.Duration `sconf:"optional" sconf-doc:"Delay before accepting a message from a first-time sender for the destination account. Default: 15s."`
+
+		DNSBLZones []dns.Domain `sconf:"-"`
 	} `sconf:"optional"`
 	Submission struct {
 		Enabled           bool

config/doc.go

@@ -170,6 +170,10 @@ describe-static" and "mox config describe-domains":
 				DNSBLs:
 					-
 
+				# Delay before accepting a message from a first-time sender for the destination
+				# account. Default: 15s. (optional)
+				FirstTimeSenderDelay: 0s
+
 			# SMTP for submitting email, e.g. by email applications. Starts out in plain text,
 			# can be upgraded to TLS with the STARTTLS command. Prefer using Submissions which
 			# is always a TLS connection. (optional)

integration_test.go

@@ -6,9 +6,7 @@ package main
 
 import (
 	"context"
-	"errors"
 	"fmt"
-	"log"
 	"net"
 	"os"
 	"path/filepath"
@@ -16,11 +14,8 @@ import (
 	"testing"
 	"time"
 
-	bolt "go.etcd.io/bbolt"
-
-	"github.com/mjl-/bstore"
-
 	"github.com/mjl-/mox/dns"
+	"github.com/mjl-/mox/imapclient"
 	"github.com/mjl-/mox/mlog"
 	"github.com/mjl-/mox/mox-"
 	"github.com/mjl-/mox/sasl"
@@ -78,56 +73,46 @@ func TestDeliver(t *testing.T) {
 	err := start(mtastsdbRefresher, skipForkExec)
 	tcheck(t, err, "starting mox")
 
-	// todo: we should probably hook store.Comm to get updates.
+	// Single update from IMAP IDLE.
-	latestMsgID := func(username string) int64 {
+	type idleResponse struct {
-		// We open the account index database created by mox for the test user. And we keep looking for the email we sent.
+		untagged imapclient.Untagged
-		dbpath := fmt.Sprintf("testdata/integration/data/accounts/%s/index.db", username)
+		err      error
-		db, err := bstore.Open(ctxbg, dbpath, &bstore.Options{Timeout: 3 * time.Second}, store.DBTypes...)
-		if err != nil && errors.Is(err, bolt.ErrTimeout) {
-			log.Printf("db open timeout (normal delay for new sender with account and db file kept open)")
-			return 0
-		}
-		tcheck(t, err, "open test account database")
-		defer db.Close()
-
-		q := bstore.QueryDB[store.Mailbox](ctxbg, db)
-		q.FilterNonzero(store.Mailbox{Name: "Inbox"})
-		inbox, err := q.Get()
-		if err != nil {
-			log.Printf("inbox for finding latest message id: %v", err)
-			return 0
-		}
-
-		qm := bstore.QueryDB[store.Message](ctxbg, db)
-		qm.FilterNonzero(store.Message{MailboxID: inbox.ID})
-		qm.SortDesc("ID")
-		qm.Limit(1)
-		m, err := qm.Get()
-		if err != nil {
-			log.Printf("finding latest message id: %v", err)
-			return 0
-		}
-		return m.ID
 	}
 
-	waitForMsg := func(prevMsgID int64, username string) int64 {
+	deliver := func(username, desthost, mailfrom, password, rcptto, imapuser string) {
 		t.Helper()
 
-		for i := 0; i < 10; i++ {
+		// Make IMAP connection, we'll wait for a delivery notification with IDLE.
-			msgID := latestMsgID(username)
+		imapconn, err := net.Dial("tcp", "moxmail1.mox1.example:143")
-			if msgID > prevMsgID {
+		tcheck(t, err, "dial imap server")
-				return msgID
+		defer imapconn.Close()
+		client, err := imapclient.New(imapconn, false)
+		tcheck(t, err, "new imapclient")
+		_, _, err = client.Login(imapuser, "pass1234")
+		tcheck(t, err, "imap client login")
+		_, _, err = client.Select("inbox")
+		tcheck(t, err, "imap select inbox")
+
+		err = client.Commandf("", "idle")
+		tcheck(t, err, "imap idle command")
+
+		_, _, _, err = client.ReadContinuation()
+		tcheck(t, err, "read imap continuation")
+
+		idle := make(chan idleResponse)
+		go func() {
+			for {
+				untagged, err := client.ReadUntagged()
+				idle <- idleResponse{untagged, err}
+				if err != nil {
+					return
+				}
 			}
-			time.Sleep(500 * time.Millisecond)
+		}()
-		}
+		defer func() {
-		t.Fatalf("timeout waiting for message")
+			err := client.Writelinef("done")
-		return 0 // not reached
+			tcheck(t, err, "aborting idle")
-	}
+		}()
-
-	deliver := func(username, desthost, mailfrom, password, rcptto string) {
-		t.Helper()
-
-		prevMsgID := latestMsgID(username)
 
 		conn, err := net.Dial("tcp", desthost+":587")
 		tcheck(t, err, "dial submission")
@@ -143,14 +128,28 @@ This is the message.
 		auth := []sasl.Client{sasl.NewClientPlain(mailfrom, password)}
 		c, err := smtpclient.New(mox.Context, mlog.New("test"), conn, smtpclient.TLSOpportunistic, mox.Conf.Static.HostnameDomain, dns.Domain{ASCII: desthost}, auth)
 		tcheck(t, err, "smtp hello")
+		t0 := time.Now()
 		err = c.Deliver(mox.Context, mailfrom, rcptto, int64(len(msg)), strings.NewReader(msg), false, false)
 		tcheck(t, err, "deliver with smtp")
 		err = c.Close()
 		tcheck(t, err, "close smtpclient")
 
-		waitForMsg(prevMsgID, username)
+		// Wait for notification of delivery.
+		select {
+		case resp := <-idle:
+			tcheck(t, resp.err, "idle notification")
+			_, ok := resp.untagged.(imapclient.UntaggedExists)
+			if !ok {
+				t.Fatalf("got idle %#v, expected untagged exists", resp.untagged)
+			}
+			if d := time.Since(t0); d < 1*time.Second {
+				t.Fatalf("delivery took %v, bt should have taken at least 1 second, the first-time sender delay", d)
+			}
+		case <-time.After(5 * time.Second):
+			t.Fatalf("timeout after 5s waiting for IMAP IDLE notification of new message, should take about 1 second")
+		}
 	}
 
-	deliver("moxtest1", "moxmail1.mox1.example", "moxtest1@mox1.example", "pass1234", "root@postfix.example")
+	deliver("moxtest1", "moxmail1.mox1.example", "moxtest1@mox1.example", "pass1234", "root@postfix.example", "moxtest1@mox1.example")
-	deliver("moxtest3", "moxmail2.mox2.example", "moxtest2@mox2.example", "pass1234", "moxtest3@mox3.example")
+	deliver("moxtest3", "moxmail2.mox2.example", "moxtest2@mox2.example", "pass1234", "moxtest3@mox3.example", "moxtest3@mox3.example")
 }

quickstart_test.go

@@ -132,12 +132,12 @@ This is the message.
 		tcheck(t, err, "imap idle")
 	}
 
-	xlog.Print("submitting email to moxacmepebble, waiting for imap notification at moxmail2, takes time because first-time sender")
+	xlog.Print("submitting email to moxacmepebble, waiting for imap notification at moxmail2")
 	t0 := time.Now()
 	deliver("moxacmepebble.mox1.example", "moxtest1@mox1.example", "accountpass1234", "moxtest2@mox2.example", "moxmail2.mox2.example", "moxtest2@mox2.example", "accountpass4321")
 	xlog.Print("success", mlog.Field("duration", time.Since(t0)))
 
-	xlog.Print("submitting email to moxmail2, waiting for imap notification at moxacmepebble, takes time because first-time sender")
+	xlog.Print("submitting email to moxmail2, waiting for imap notification at moxacmepebble")
 	t0 = time.Now()
 	deliver("moxmail2.mox2.example", "moxtest2@mox2.example", "accountpass4321", "moxtest1@mox1.example", "moxacmepebble.mox1.example", "moxtest1@mox1.example", "accountpass1234")
 	xlog.Print("success", mlog.Field("duration", time.Since(t0)))

smtpserver/fuzz_test.go

@@ -100,7 +100,7 @@ func FuzzServer(f *testing.F) {
 			const submission = false
 			err := serverConn.SetDeadline(time.Now().Add(time.Second))
 			flog(err, "set server deadline")
-			serve("test", cid, dns.Domain{ASCII: "mox.example"}, nil, serverConn, resolver, submission, false, 100<<10, false, false, nil)
+			serve("test", cid, dns.Domain{ASCII: "mox.example"}, nil, serverConn, resolver, submission, false, 100<<10, false, false, nil, 0)
 			cid++
 		}
 

smtpserver/server.go

@@ -100,10 +100,10 @@ func limitersInit() {
 
 var (
 	// Delays for bad/suspicious behaviour. Zero during tests.
-	badClientDelay                    = time.Second      // Before reads and after 1-byte writes for probably spammers.
+	badClientDelay              = time.Second      // Before reads and after 1-byte writes for probably spammers.
-	authFailDelay                     = time.Second      // Response to authentication failure.
+	authFailDelay               = time.Second      // Response to authentication failure.
-	reputationlessSenderDeliveryDelay = 15 * time.Second // Before accepting message from first-time sender.
+	unknownRecipientsDelay      = 5 * time.Second  // Response when all recipients are unknown.
-	unknownRecipientsDelay            = 5 * time.Second  // Response when all recipients are unknown.
+	firstTimeSenderDelayDefault = 15 * time.Second // Before accepting message from first-time sender.
 )
 
 type codes struct {
@@ -166,6 +166,13 @@ var (
 
 var jitterRand = mox.NewRand()
 
+func durationDefault(delay *time.Duration, def time.Duration) time.Duration {
+	if delay == nil {
+		return def
+	}
+	return *delay
+}
+
 // Listen initializes network listeners for incoming SMTP connection.
 // The listeners are stored for a later call to Serve.
 func Listen() {
@@ -187,7 +194,8 @@ func Listen() {
 			}
 			port := config.Port(listener.SMTP.Port, 25)
 			for _, ip := range listener.IPs {
-				listen1("smtp", name, ip, port, hostname, tlsConfig, false, false, maxMsgSize, false, listener.SMTP.RequireSTARTTLS, listener.SMTP.DNSBLZones)
+				firstTimeSenderDelay := durationDefault(listener.SMTP.FirstTimeSenderDelay, firstTimeSenderDelayDefault)
+				listen1("smtp", name, ip, port, hostname, tlsConfig, false, false, maxMsgSize, false, listener.SMTP.RequireSTARTTLS, listener.SMTP.DNSBLZones, firstTimeSenderDelay)
 			}
 		}
 		if listener.Submission.Enabled {
@@ -197,7 +205,7 @@ func Listen() {
 			}
 			port := config.Port(listener.Submission.Port, 587)
 			for _, ip := range listener.IPs {
-				listen1("submission", name, ip, port, hostname, tlsConfig, true, false, maxMsgSize, !listener.Submission.NoRequireSTARTTLS, !listener.Submission.NoRequireSTARTTLS, nil)
+				listen1("submission", name, ip, port, hostname, tlsConfig, true, false, maxMsgSize, !listener.Submission.NoRequireSTARTTLS, !listener.Submission.NoRequireSTARTTLS, nil, 0)
 			}
 		}
 
@@ -208,7 +216,7 @@ func Listen() {
 			}
 			port := config.Port(listener.Submissions.Port, 465)
 			for _, ip := range listener.IPs {
-				listen1("submissions", name, ip, port, hostname, tlsConfig, true, true, maxMsgSize, true, true, nil)
+				listen1("submissions", name, ip, port, hostname, tlsConfig, true, true, maxMsgSize, true, true, nil, 0)
 			}
 		}
 	}
@@ -216,7 +224,7 @@ func Listen() {
 
 var servers []func()
 
-func listen1(protocol, name, ip string, port int, hostname dns.Domain, tlsConfig *tls.Config, submission, xtls bool, maxMessageSize int64, requireTLSForAuth, requireTLSForDelivery bool, dnsBLs []dns.Domain) {
+func listen1(protocol, name, ip string, port int, hostname dns.Domain, tlsConfig *tls.Config, submission, xtls bool, maxMessageSize int64, requireTLSForAuth, requireTLSForDelivery bool, dnsBLs []dns.Domain, firstTimeSenderDelay time.Duration) {
 	addr := net.JoinHostPort(ip, fmt.Sprintf("%d", port))
 	if os.Getuid() == 0 {
 		xlog.Print("listening for smtp", mlog.Field("listener", name), mlog.Field("address", addr), mlog.Field("protocol", protocol))
@@ -238,7 +246,7 @@ func listen1(protocol, name, ip string, port int, hostname dns.Domain, tlsConfig
 				continue
 			}
 			resolver := dns.StrictResolver{} // By leaving Pkg empty, it'll be set by each package that uses the resolver, e.g. spf/dkim/dmarc.
-			go serve(name, mox.Cid(), hostname, tlsConfig, conn, resolver, submission, xtls, maxMessageSize, requireTLSForAuth, requireTLSForDelivery, dnsBLs)
+			go serve(name, mox.Cid(), hostname, tlsConfig, conn, resolver, submission, xtls, maxMessageSize, requireTLSForAuth, requireTLSForDelivery, dnsBLs, firstTimeSenderDelay)
 		}
 	}
 
@@ -283,6 +291,7 @@ type conn struct {
 	cmdStart              time.Time // Start of current command.
 	ncmds                 int       // Number of commands processed. Used to abort connection when first incoming command is unknown/invalid.
 	dnsBLs                []dns.Domain
+	firstTimeSenderDelay  time.Duration
 
 	// If non-zero, taken into account during Read and Write. Set while processing DATA
 	// command, we don't want the entire delivery to take too long.
@@ -509,7 +518,7 @@ func (c *conn) writelinef(format string, args ...any) {
 
 var cleanClose struct{} // Sentinel value for panic/recover indicating clean close of connection.
 
-func serve(listenerName string, cid int64, hostname dns.Domain, tlsConfig *tls.Config, nc net.Conn, resolver dns.Resolver, submission, tls bool, maxMessageSize int64, requireTLSForAuth, requireTLSForDelivery bool, dnsBLs []dns.Domain) {
+func serve(listenerName string, cid int64, hostname dns.Domain, tlsConfig *tls.Config, nc net.Conn, resolver dns.Resolver, submission, tls bool, maxMessageSize int64, requireTLSForAuth, requireTLSForDelivery bool, dnsBLs []dns.Domain, firstTimeSenderDelay time.Duration) {
 	var localIP, remoteIP net.IP
 	if a, ok := nc.LocalAddr().(*net.TCPAddr); ok {
 		localIP = a.IP
@@ -540,6 +549,7 @@ func serve(listenerName string, cid int64, hostname dns.Domain, tlsConfig *tls.C
 		requireTLSForAuth:     requireTLSForAuth,
 		requireTLSForDelivery: requireTLSForDelivery,
 		dnsBLs:                dnsBLs,
+		firstTimeSenderDelay:  firstTimeSenderDelay,
 	}
 	c.log = xlog.MoreFields(func() []mlog.Pair {
 		now := time.Now()
@@ -2454,9 +2464,9 @@ func (c *conn) deliver(ctx context.Context, recvHdrFor func(string) string, msgW
 		// If not dmarc or tls report (Seen set above), and this is a first-time sender,
 		// wait before actually delivering. If this turns out to be a spammer, we've kept
 		// one of their connections busy.
-		if !m.Flags.Seen && a.reason == reasonNoBadSignals && reputationlessSenderDeliveryDelay > 0 {
+		if !m.Flags.Seen && a.reason == reasonNoBadSignals && c.firstTimeSenderDelay > 0 {
-			log.Debug("delaying before delivering from sender without reputation", mlog.Field("delay", reputationlessSenderDeliveryDelay))
+			log.Debug("delaying before delivering from sender without reputation", mlog.Field("delay", c.firstTimeSenderDelay))
-			mox.Sleep(mox.Context, reputationlessSenderDeliveryDelay)
+			mox.Sleep(mox.Context, c.firstTimeSenderDelay)
 		}
 
 		// Gather the message-id before we deliver and the file may be consumed.

smtpserver/server_test.go

@@ -45,7 +45,6 @@ var ctxbg = context.Background()
 func init() {
 	// Don't make tests slow.
 	badClientDelay = 0
-	reputationlessSenderDeliveryDelay = 0
 	authFailDelay = 0
 	unknownRecipientsDelay = 0
 }
@@ -133,7 +132,7 @@ func (ts *testserver) run(fn func(helloErr error, client *smtpclient.Client)) {
 		tlsConfig := &tls.Config{
 			Certificates: []tls.Certificate{fakeCert(ts.t)},
 		}
-		serve("test", ts.cid-2, dns.Domain{ASCII: "mox.example"}, tlsConfig, serverConn, ts.resolver, ts.submission, false, 100<<20, false, false, ts.dnsbls)
+		serve("test", ts.cid-2, dns.Domain{ASCII: "mox.example"}, tlsConfig, serverConn, ts.resolver, ts.submission, false, 100<<20, false, false, ts.dnsbls, 0)
 		close(serverdone)
 	}()
 
@@ -914,7 +913,7 @@ func TestNonSMTP(t *testing.T) {
 		tlsConfig := &tls.Config{
 			Certificates: []tls.Certificate{fakeCert(ts.t)},
 		}
-		serve("test", ts.cid-2, dns.Domain{ASCII: "mox.example"}, tlsConfig, serverConn, ts.resolver, ts.submission, false, 100<<20, false, false, ts.dnsbls)
+		serve("test", ts.cid-2, dns.Domain{ASCII: "mox.example"}, tlsConfig, serverConn, ts.resolver, ts.submission, false, 100<<20, false, false, ts.dnsbls, 0)
 		close(serverdone)
 	}()
 

testdata/integration/config/mox.conf

@@ -15,9 +15,13 @@ Listeners:
 		SMTP:
 			Enabled: true
 			NoSTARTTLS: true
+			FirstTimeSenderDelay: 1s
 		Submission:
 			Enabled: true
 			NoRequireSTARTTLS: true
+		IMAP:
+			Enabled: true
+			NoRequireSTARTTLS: true
 	mox2:
 		IPs:
 			- 172.28.2.10
@@ -59,6 +63,7 @@ Listeners:
 					KeyFile: ../tls/moxmail3-key.pem
 		SMTP:
 			Enabled: true
+			FirstTimeSenderDelay: 1s
 		Submission:
 			Enabled: true
 			NoRequireSTARTTLS: true

testdata/quickstart/moxacmepebble.sh

@@ -9,7 +9,7 @@ mkdir /tmp/mox
 cd /tmp/mox
 mox quickstart moxtest1@mox1.example "$MOX_UID" > output.txt
 
-sed -i -e '/- 172.28.1.10/d' -e 's/- 0.0.0.0/- 172.28.1.10/' -e '/- ::/d' -e 's/letsencrypt:/pebble:/g' -e 's/: letsencrypt/: pebble/g' -e 's,DirectoryURL: https://acme-v02.api.letsencrypt.org/directory,DirectoryURL: https://acmepebble.example:14000/dir,' config/mox.conf
+sed -i -e '/- 172.28.1.10/d' -e 's/- 0.0.0.0/- 172.28.1.10/' -e '/- ::/d' -e 's/letsencrypt:/pebble:/g' -e 's/: letsencrypt/: pebble/g' -e 's,DirectoryURL: https://acme-v02.api.letsencrypt.org/directory,DirectoryURL: https://acmepebble.example:14000/dir,' -e 's/SMTP:$/SMTP:\n\t\t\tFirstTimeSenderDelay: 1s/' config/mox.conf
 cat <<EOF >>config/mox.conf
 
 TLS:

testdata/quickstart/moxmail2.sh

@@ -9,7 +9,7 @@ mkdir /tmp/mox
 cd /tmp/mox
 mox quickstart moxtest2@mox2.example "$MOX_UID" > output.txt
 
-sed -i -e '/- 172.28.1.20/d' -e 's/- 0.0.0.0/- 172.28.1.20/' -e '/- ::/d' -e 's,ACME: .*$,KeyCerts:\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/moxmail2.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/moxmail2-key.pem\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/mox2-autoconfig.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/mox2-autoconfig-key.pem\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/mox2-mtasts.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/mox2-mtasts-key.pem\n,' config/mox.conf
+sed -i -e '/- 172.28.1.20/d' -e 's/- 0.0.0.0/- 172.28.1.20/' -e '/- ::/d' -e 's,ACME: .*$,KeyCerts:\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/moxmail2.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/moxmail2-key.pem\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/mox2-autoconfig.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/mox2-autoconfig-key.pem\n\t\t\t\t-\n\t\t\t\t\tCertFile: /quickstart/tls/mox2-mtasts.pem\n\t\t\t\t\tKeyFile: /quickstart/tls/mox2-mtasts-key.pem\n,' -e 's/SMTP:$/SMTP:\n\t\t\tFirstTimeSenderDelay: 1s/' config/mox.conf
 cat <<EOF >>config/mox.conf
 
 TLS: