mailgoserver/internal/relay/queue_test.go

package relay

import (
	"io"
	"net"
	"os"
	"strconv"
	"testing"
	"time"

	"github.com/emersion/go-smtp"

	"mailgoserver/internal/db"
	"mailgoserver/internal/toolbox"
)

// testDB opens a fresh temp-file sqlite DB with the full schema applied — same
// pattern smtpserver's newTestBackend uses (db.Open runs schema.go's CREATE TABLE
// statements, including esrv_relay_queue).
func testDB(t *testing.T) *db.DB {
	t.Helper()
	f, err := os.CreateTemp("", "relay-queue-test-*.db")
	if err != nil {
		t.Fatal(err)
	}
	f.Close()
	t.Cleanup(func() { os.Remove(f.Name()) })

	database, err := db.Open(f.Name())
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(func() { database.Close() })
	return database
}

// fixedMXLookup resolves any domain to 127.0.0.1 — combined with Relay.port
// (overriding the real MX port 25), this points deliverToDomain at a local
// stand-in MTA regardless of what domain is being "relayed" to.
func fixedMXLookup(domain string) ([]*net.MX, error) {
	return []*net.MX{{Host: "127.0.0.1.", Pref: 10}}, nil
}

// failingMXLookup simulates every MX lookup failing (e.g. an unreachable/nonexistent
// domain) — deliverToDomain fails immediately, no connection ever attempted.
func failingMXLookup(domain string) ([]*net.MX, error) {
	return nil, &net.DNSError{Err: "no such host", Name: domain, IsNotFound: true}
}

func TestProcessQueueOnceDeliversSuccessfully(t *testing.T) {
	cert, caPool := genTestCert(t)
	port, received, _ := startTestMTA(t, cert)
	database := testDB(t)

	r := &Relay{
		DB: database, Hostname: "sender.example.com", Timeout: 5 * time.Second,
		Logger: toolbox.GetLogger("relay_test"), port: port, rootCAs: caPool, mxLookup: fixedMXLookup,
	}

	logID, err := database.InsertEmailLog(db.EmailLog{MailFrom: "from@example.com", ToAddress: "to@dest.example", Status: "queued"})
	if err != nil {
		t.Fatal(err)
	}
	if err := database.InsertEmailRecipientLog(db.EmailRecipientLog{EmailLogID: logID, Recipient: "to@dest.example", RecipientType: "to", Status: "queued"}); err != nil {
		t.Fatal(err)
	}
	if err := r.EnqueueForDelivery(logID, "from@example.com", []string{"to@dest.example"}, []string{"to"}, "Subject: hi\r\n\r\nbody"); err != nil {
		t.Fatal(err)
	}

	r.ProcessQueueOnce(5, 10)

	select {
	case <-received:
	case <-time.After(2 * time.Second):
		t.Fatal("expected the test MTA to receive the queued message")
	}

	recipients, err := database.ListRecipientLogsForEmail(logID)
	if err != nil {
		t.Fatal(err)
	}
	if len(recipients) != 1 || recipients[0].Status != "success" {
		t.Fatalf("expected recipient status success, got %+v", recipients)
	}

	pending, err := database.CountPendingRelayQueueItemsForEmailLog(logID)
	if err != nil {
		t.Fatal(err)
	}
	if pending != 0 {
		t.Fatalf("expected the queue row to be gone after delivery, got %d pending", pending)
	}

	log, err := database.GetEmailLogByID(logID)
	if err != nil {
		t.Fatal(err)
	}
	if log.Status != "relayed" {
		t.Errorf("expected email_log status 'relayed', got %q", log.Status)
	}
}

func TestProcessQueueOnceReschedulesOnFailure(t *testing.T) {
	database := testDB(t)
	r := &Relay{
		DB: database, Hostname: "sender.example.com", Timeout: 5 * time.Second,
		Logger: toolbox.GetLogger("relay_test"), mxLookup: failingMXLookup,
	}

	logID, err := database.InsertEmailLog(db.EmailLog{MailFrom: "from@example.com", ToAddress: "to@dest.example", Status: "queued"})
	if err != nil {
		t.Fatal(err)
	}
	if err := database.InsertEmailRecipientLog(db.EmailRecipientLog{EmailLogID: logID, Recipient: "to@dest.example", RecipientType: "to", Status: "queued"}); err != nil {
		t.Fatal(err)
	}
	if err := r.EnqueueForDelivery(logID, "from@example.com", []string{"to@dest.example"}, []string{"to"}, "Subject: hi\r\n\r\nbody"); err != nil {
		t.Fatal(err)
	}

	r.ProcessQueueOnce(5, 10)

	pending, err := database.CountPendingRelayQueueItemsForEmailLog(logID)
	if err != nil {
		t.Fatal(err)
	}
	if pending != 1 {
		t.Fatalf("expected the queue row to still exist (rescheduled, not exhausted), got %d", pending)
	}
	recipients, err := database.ListRecipientLogsForEmail(logID)
	if err != nil {
		t.Fatal(err)
	}
	if recipients[0].Status != "queued" {
		t.Errorf("expected recipient to remain 'queued' pending retry, got %q", recipients[0].Status)
	}
}

// TestProcessQueueOnceExhaustsRetriesAndBounces short-circuits retrySchedule so the
// test doesn't wait real hours — after every scheduled attempt fails, the queue row
// should be dropped, the recipient marked failed, and a bounce delivered back to the
// original sender's own inbox (via SendBounce's relay-out path, using the same
// always-fails mxLookup — proving the bounce attempt doesn't crash even when it too
// can't be delivered, matching real MTA behavior of just logging the failed bounce).
func TestProcessQueueOnceExhaustsRetriesAndBounces(t *testing.T) {
	orig := retrySchedule
	retrySchedule = []time.Duration{0, 0}
	t.Cleanup(func() { retrySchedule = orig })

	database := testDB(t)
	r := &Relay{
		DB: database, Hostname: "sender.example.com", Timeout: 5 * time.Second,
		Logger: toolbox.GetLogger("relay_test"), mxLookup: failingMXLookup,
	}

	logID, err := database.InsertEmailLog(db.EmailLog{MailFrom: "from@example.com", ToAddress: "to@dest.example", Status: "queued"})
	if err != nil {
		t.Fatal(err)
	}
	if err := database.InsertEmailRecipientLog(db.EmailRecipientLog{EmailLogID: logID, Recipient: "to@dest.example", RecipientType: "to", Status: "queued"}); err != nil {
		t.Fatal(err)
	}
	if err := r.EnqueueForDelivery(logID, "from@example.com", []string{"to@dest.example"}, []string{"to"}, "Subject: hi\r\n\r\nbody"); err != nil {
		t.Fatal(err)
	}

	// One tick per scheduled retry, plus one for the initial attempt — each due
	// immediately since the schedule above is all-zero backoff.
	for i := 0; i <= len(retrySchedule); i++ {
		r.ProcessQueueOnce(5, 10)
	}

	pending, err := database.CountPendingRelayQueueItemsForEmailLog(logID)
	if err != nil {
		t.Fatal(err)
	}
	if pending != 0 {
		t.Fatalf("expected the queue row to be gone once retries are exhausted, got %d pending", pending)
	}
	recipients, err := database.ListRecipientLogsForEmail(logID)
	if err != nil {
		t.Fatal(err)
	}
	if recipients[0].Status != "failed" {
		t.Errorf("expected recipient status 'failed' after exhausting retries, got %q", recipients[0].Status)
	}

	log, err := database.GetEmailLogByID(logID)
	if err != nil {
		t.Fatal(err)
	}
	if log.Status != "failed" {
		t.Errorf("expected email_log status 'failed', got %q", log.Status)
	}
}

// rejectingBackend is a stand-in "receiving MTA" that rejects every RCPT with a fixed
// SMTP status/message — used to prove a permanent (5xx) rejection bounces on the first
// attempt instead of working through retrySchedule.
type rejectingBackend struct{ code int }

func (b *rejectingBackend) NewSession(*smtp.Conn) (smtp.Session, error) {
	return &rejectingSession{code: b.code}, nil
}

type rejectingSession struct{ code int }

func (s *rejectingSession) Mail(from string, opts *smtp.MailOptions) error { return nil }
func (s *rejectingSession) Rcpt(to string, opts *smtp.RcptOptions) error {
	return &smtp.SMTPError{Code: s.code, EnhancedCode: smtp.NoEnhancedCode, Message: "poor reputation"}
}
func (s *rejectingSession) Data(r io.Reader) error { _, err := io.ReadAll(r); return err }
func (s *rejectingSession) Reset()                 {}
func (s *rejectingSession) Logout() error          { return nil }

func TestProcessQueueOnceBouncesImmediatelyOnPermanentRejection(t *testing.T) {
	database := testDB(t)
	s := smtp.NewServer(&rejectingBackend{code: 554})
	s.Domain = "mx.example.com"
	s.AllowInsecureAuth = true
	l, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		t.Fatal(err)
	}
	t.Cleanup(func() { s.Close() })
	go s.Serve(l)
	_, portStr, _ := net.SplitHostPort(l.Addr().String())
	port, err := strconv.Atoi(portStr)
	if err != nil {
		t.Fatal(err)
	}

	r := &Relay{
		DB: database, Hostname: "sender.example.com", Timeout: 5 * time.Second,
		Logger: toolbox.GetLogger("relay_test"), port: port, mxLookup: fixedMXLookup,
	}

	logID, err := database.InsertEmailLog(db.EmailLog{MailFrom: "from@example.com", ToAddress: "to@dest.example", Status: "queued"})
	if err != nil {
		t.Fatal(err)
	}
	if err := database.InsertEmailRecipientLog(db.EmailRecipientLog{EmailLogID: logID, Recipient: "to@dest.example", RecipientType: "to", Status: "queued"}); err != nil {
		t.Fatal(err)
	}
	if err := r.EnqueueForDelivery(logID, "from@example.com", []string{"to@dest.example"}, []string{"to"}, "Subject: hi\r\n\r\nbody"); err != nil {
		t.Fatal(err)
	}

	// One tick. If this were misclassified as a transient failure it would still be
	// pending (rescheduled per retrySchedule), not gone.
	r.ProcessQueueOnce(5, 10)

	pending, err := database.CountPendingRelayQueueItemsForEmailLog(logID)
	if err != nil {
		t.Fatal(err)
	}
	if pending != 0 {
		t.Fatalf("expected the queue row to be gone after a single permanent (5xx) rejection, got %d pending", pending)
	}
	recipients, err := database.ListRecipientLogsForEmail(logID)
	if err != nil {
		t.Fatal(err)
	}
	if recipients[0].Status != "failed" {
		t.Errorf("expected recipient status 'failed' immediately on a 554, got %q", recipients[0].Status)
	}
	if recipients[0].ErrorMessage == "" {
		t.Error("expected the recipient log to carry the server's rejection reason")
	}
}