From 50fd6b859fe82f7ba90934faed0a9b83ca10c090 Mon Sep 17 00:00:00 2001 From: Mix Date: Mon, 12 Oct 2026 15:56:13 +0300 Subject: [PATCH] panel-notifications: the notifier, its mail and the server's own DKIM key internal/notify applies the owner's rules. Each subject has a row of state, so a thing is said once and a restart says nothing again: - DNS of a sending domain: said after two hourly checks in a row found a record wrong, said to be over after two found it right. A lookup that did not answer moves nothing; a warning (no DMARC record) is not a subject. - TLS certificate: at 14 days and at 3, per certificate. - Queue: a message older than three days, once; once more when none is. - Level-2 limit: from the rejected rows of the send log, every five minutes; at most once a day per domain and application. Global users are told everything, domain users about their domains; one message per recipient. With the instance switch off nothing is checked and no state moves. A message that could not be handed to Postfix is tried again at the next check. Mail leaves by sendmail(1) as postmaster@, addresses after "--", no shell. For it to be believed the server's own name is signed like a sending domain: domain.Service keeps a key for it and a line in OpenDKIM's tables without a registry row, and non_smtpd_milters now names OpenDKIM. A sending domain of the same name shares its key with the server. dnscheck.ServerMail checks the name's DKIM and SPF records; postfix.QueueMessages reads postqueue -j for arrival times. The notifier is a sixth role of the panel process. Nothing in the panel shows or switches it yet. Checked on Windows: go vet clean; go test passes for notify, store, postfix, dnscheck, cmd, and domain apart from TestWriteLoadPrivateKeyRoundtrip, which fails there on file modes and always did. Not yet run in a container: whether the unprivileged panel may submit is for the e2e step. Co-Authored-By: Claude Opus 5.5 --- CHANGELOG.md | 16 +- build/postfix-config.sh | 8 +- cmd/panel/httpserver.go | 3 + cmd/panel/main.go | 4 +- cmd/panel/notifier.go | 42 +++ docs/plans/panel-notifications.md | 6 +- docs/roadmap.md | 2 +- internal/dnscheck/dnscheck.go | 52 ++++ internal/dnscheck/servermail_test.go | 82 ++++++ internal/domain/servermail_test.go | 109 +++++++ internal/domain/service.go | 78 ++++- internal/notify/mailer.go | 99 +++++++ internal/notify/notify.go | 415 +++++++++++++++++++++++++++ internal/notify/notify_test.go | 380 ++++++++++++++++++++++++ internal/notify/text.go | 131 +++++++++ internal/postfix/queuejson.go | 86 ++++++ internal/postfix/queuejson_test.go | 43 +++ 17 files changed, 1547 insertions(+), 9 deletions(-) create mode 100644 cmd/panel/notifier.go create mode 100644 internal/dnscheck/servermail_test.go create mode 100644 internal/domain/servermail_test.go create mode 100644 internal/notify/mailer.go create mode 100644 internal/notify/notify.go create mode 100644 internal/notify/notify_test.go create mode 100644 internal/notify/text.go create mode 100644 internal/postfix/queuejson.go create mode 100644 internal/postfix/queuejson_test.go diff --git a/CHANGELOG.md b/CHANGELOG.md index cfad559..f18d512 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -11,8 +11,20 @@ Format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/); version a user's own switch, `users.notify`, on for everyone; `notify_state`, what the panel has already written to its users about. The instance switch is a settings key, on unless turned off - ([plans/panel-notifications.md](docs/plans/panel-notifications.md)). Nothing - is sent yet. + ([plans/panel-notifications.md](docs/plans/panel-notifications.md)). +- **The panel writes to its users when something needs them.** Four things, + each said once: a sending domain's DKIM, SPF or DMARC record stops matching + (after two hourly checks in a row, and once more when it matches again); a + level-2 rate limit refuses mail (at most once a day per limit); the TLS + certificate is 14 days from expiry, and 3; a message has waited in the + queue for more than three days (and once more when none has). Global users + are told all of it, domain users about their own domains. Sent from + `postmaster@` by local submission, one message per + recipient; not rows of the Outbound log and counted against no limit. +- **The server's own name is signed.** The panel generates a DKIM key for + `SELFPOST_HOSTNAME` and OpenDKIM signs mail submitted locally as that name + (`non_smtpd_milters`), so that notifications arrive. The name is not a + sending domain: no application can send as it. ## [2.2.0] - 2026-10-12 diff --git a/build/postfix-config.sh b/build/postfix-config.sh index 0940e10..b92d627 100644 --- a/build/postfix-config.sh +++ b/build/postfix-config.sh @@ -224,11 +224,17 @@ postconf -e \ # if it is unreachable, defer rather than send unsigned). The journal-milter is # monitoring only and is fail-open (default_action=accept): its failure must # never block the relay. Per-milter settings use Postfix 3.0+ brace syntax. +# +# non_smtpd_milters is the chain for mail submitted locally with sendmail(1) - +# the panel's own notifications, sent as postmaster@ the hostname. OpenDKIM +# signs them with the key of the server's own name; the journal-milter is not +# on this chain, since they are not an application's mail. Bounces Postfix +# generates itself do not pass it (internal_mail_filter_classes is empty). postconf -e \ "milter_protocol=6" \ "milter_default_action=tempfail" \ "smtpd_milters={ unix:${OPENDKIM_SOCK}, default_action=tempfail }, { unix:${JOURNAL_SOCK}, default_action=accept }" \ - "non_smtpd_milters=" + "non_smtpd_milters={ unix:${OPENDKIM_SOCK}, default_action=tempfail }" # What Postfix tells a milter with MAIL FROM: its defaults plus the client's # address. The panel's milters judge every message by that address (an diff --git a/cmd/panel/httpserver.go b/cmd/panel/httpserver.go index 13e416f..b8dece1 100644 --- a/cmd/panel/httpserver.go +++ b/cmd/panel/httpserver.go @@ -37,6 +37,9 @@ func newMailStack(cfg config, st *store.Store) *mailStack { odk := domain.NewOpenDKIM(cfg.opendkimDir) apps := app.NewService(st, app.NewSASLDB(cfg.saslDBPath, cfg.saslRealm), pf) domains := domain.NewService(st, odk, apps, cfg.dkimSelectorDef) + // The panel's notifications are sent as postmaster@ the server's own name, + // and signed as it. + domains.SetServerName(cfg.hostname) inb := inbound.NewService(st, pf) dmarcSvc := dmarc.NewService(st, pf, cfg.hostname, cfg.dmarcEnabled) return &mailStack{ diff --git a/cmd/panel/main.go b/cmd/panel/main.go index 10b9166..37fa867 100644 --- a/cmd/panel/main.go +++ b/cmd/panel/main.go @@ -341,7 +341,8 @@ func run() error { } var wg sync.WaitGroup - errc := make(chan error, 5) + // Room for every role to report a failure without blocking: six at most. + errc := make(chan error, 6) roles := []struct { name string @@ -363,6 +364,7 @@ func run() error { runAutoRateLimitRecalc(ctx, cfg, st) return nil }}, + {"notifier", func(ctx context.Context) error { return runNotifier(ctx, cfg, st) }}, } if cfg.inboundEnabled { diff --git a/cmd/panel/notifier.go b/cmd/panel/notifier.go new file mode 100644 index 0000000..f816ed5 --- /dev/null +++ b/cmd/panel/notifier.go @@ -0,0 +1,42 @@ +package main + +import ( + "context" + + "github.com/mixeme/selfpost/internal/dnscheck" + "github.com/mixeme/selfpost/internal/health" + "github.com/mixeme/selfpost/internal/notify" + "github.com/mixeme/selfpost/internal/postfix" + "github.com/mixeme/selfpost/internal/store" +) + +// runNotifier writes to the panel's users when something needs them +// (architecture.md § Notifications), until ctx is cancelled. It reads what the +// pages read - a domain's published records against the key this server signs +// with, the certificate file, Postfix's queue - with a DNS checker of its own, +// so that its hourly look is never a page's cached one. +func runNotifier(ctx context.Context, cfg config, st *store.Store) error { + ms := newMailStack(cfg, st) + dns := dnscheck.New(cfg.dnsResolvers) + + n := notify.New(st, notify.Checks{ + Domain: func(d store.Domain) (dnscheck.Domain, error) { + rec, err := ms.Domains.DKIMRecord(d) + if err != nil { + return dnscheck.Domain{}, err + } + srv := dns.Server(cfg.hostname, true) + return dns.Domain(dnscheck.Query{ + Name: d.Name, + Selector: d.DKIMSelector, + ExpectedDKIM: rec.Value, + Hostname: srv.Hostname, + ServerIPs: srv.IPs, + DMARCReportEmail: d.DMARCRua, + }, true), nil + }, + Certificate: func() health.Certificate { return health.CheckCertificate(cfg.tlsCertFile) }, + Queue: postfix.QueueMessages, + }, notify.NewMailer(cfg.hostname), cfg.hostname) + return n.Run(ctx) +} diff --git a/docs/plans/panel-notifications.md b/docs/plans/panel-notifications.md index 368fe03..d2e70ad 100644 --- a/docs/plans/panel-notifications.md +++ b/docs/plans/panel-notifications.md @@ -109,9 +109,9 @@ to the owner before any code ([panel-redesign.md](panel-redesign.md) - [x] Mockups: Account checkbox, Settings switch and records, Health status card, help topic; accepted by the owner 2026-10-12 (`design:` commit) - [x] Migration and store: user flag, instance switch, event state -- [ ] Sending: local submission from `postmaster@`, message text -- [ ] Background checker: DNS, certificate, queue; the rules of *When a message is sent* -- [ ] Level-2 refusal event +- [x] Sending: local submission from `postmaster@`, message text (`sendmail` as the panel user; signed through `non_smtpd_milters` with a key of the server's own name; no link in the text - the panel does not know its own address) +- [x] Background checker: DNS, certificate, queue; the rules of *When a message is sent* +- [x] Level-2 refusal event (from the `rejected` rows of the send log, looked at every five minutes) - [ ] Panel: Account, Settings, Health check, help - [ ] guide.md, architecture.md, security.md, schema-migrations.md - [ ] `go vet`, `go test`, e2e: an event reaches a mailbox once and clears once diff --git a/docs/roadmap.md b/docs/roadmap.md index 97eadaf..11907ad 100644 --- a/docs/roadmap.md +++ b/docs/roadmap.md @@ -35,7 +35,7 @@ in `git log` and [CHANGELOG.md](../CHANGELOG.md). | template-data-typing | Typed structs for template data instead of `map[string]any` | candidate | — | — | | structured-logging | `log/slog` with levels and fields | candidate | — | — | | review-2026-08-followups | Remaining findings of the 2026-08-19 code review | candidate | — | — | -| panel-notifications | E-mail notifications about important events | in progress | 2/10 | [plans/panel-notifications.md](plans/panel-notifications.md) | +| panel-notifications | E-mail notifications about important events | in progress | 5/10 | [plans/panel-notifications.md](plans/panel-notifications.md) | | delivery-log-storage | Keep a message's `mail.log` lines with its send-log row | shipped `2.2.0` | 8/8 | [plans/delivery-log-storage.md](plans/delivery-log-storage.md) | | password-reset | Password reset by e-mail | candidate | — | — | | phone-desktop-mode | A phone browser in "desktop site" mode gets the phone navigation | candidate | — | — | diff --git a/internal/dnscheck/dnscheck.go b/internal/dnscheck/dnscheck.go index 5f1d99f..e9397a8 100644 --- a/internal/dnscheck/dnscheck.go +++ b/internal/dnscheck/dnscheck.go @@ -100,6 +100,7 @@ type Checker struct { servers map[string]cached[Server] domains map[string]cached[Domain] inbound map[string]cached[Result] + mail map[string]cached[Mail] } type cached[T any] struct { @@ -123,6 +124,7 @@ func newChecker(r resolver, timeout, srvTTL, domTTL time.Duration) *Checker { servers: make(map[string]cached[Server]), domains: make(map[string]cached[Domain]), inbound: make(map[string]cached[Result]), + mail: make(map[string]cached[Mail]), } } @@ -170,6 +172,56 @@ func (c *Checker) Domain(q Query, force bool) Domain { return d } +// Mail is the published-DNS state of the server's own name as a sender: the +// panel's notifications go out from postmaster@ the hostname, signed with a +// key of that name. +type Mail struct { + Name string + DKIM Result + SPF Result + Overall health.Status + CheckedAt time.Time +} + +// ServerMailSPF is the SPF record to publish for the server's own name: its +// address record is the one sender. +const ServerMailSPF = "v=spf1 a -all" + +// ServerMail checks the DKIM and SPF records of the server's own name. q is as +// for a domain, with Name the hostname. Cached like a domain; force skips the +// cache. +func (c *Checker) ServerMail(q Query, force bool) Mail { + key := "\x00mail\x00" + q.Name + if !force { + c.mu.Lock() + entry, ok := c.mail[key] + c.mu.Unlock() + if ok && time.Now().Before(entry.expires) { + return entry.value + } + } + + ctx, cancel := context.WithTimeout(context.Background(), c.timeout) + defer cancel() + m := Mail{Name: q.Name, CheckedAt: time.Now()} + var wg sync.WaitGroup + wg.Add(2) + go func() { defer wg.Done(); m.DKIM = c.checkDKIM(ctx, q) }() + go func() { defer wg.Done(); m.SPF = c.checkSPF(ctx, q) }() + wg.Wait() + // checkSPF words a missing record for a sending domain; for the server's + // own name the record to publish is a different one. + if m.SPF.Status == health.StatusError && len(m.SPF.Records) == 0 { + m.SPF.Detail = fmt.Sprintf("No SPF record is published for %s. Publish the TXT record %q - without it a receiver has nothing authorising this server to send as its own name.", q.Name, ServerMailSPF) + } + m.Overall = health.Worst(m.DKIM.Status, m.SPF.Status) + + c.mu.Lock() + c.mail[key] = cached[Mail]{value: m, expires: m.CheckedAt.Add(c.domainTTL)} + c.mu.Unlock() + return m +} + // Forget drops a domain's cached result, so the next page view re-checks it. // Used when a domain is removed or re-imported. func (c *Checker) Forget(domainName string) { diff --git a/internal/dnscheck/servermail_test.go b/internal/dnscheck/servermail_test.go new file mode 100644 index 0000000..234fd09 --- /dev/null +++ b/internal/dnscheck/servermail_test.go @@ -0,0 +1,82 @@ +package dnscheck + +import ( + "net" + "strings" + "testing" + + "github.com/mixeme/selfpost/internal/health" +) + +const serverDKIM = "v=DKIM1; k=rsa; p=MIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAserverkey" + +func serverMailQuery() Query { + return Query{ + Name: "mail.example.org", + Selector: "sp", + ExpectedDKIM: serverDKIM, + Hostname: "mail.example.org", + ServerIPs: []string{"203.0.113.25"}, + } +} + +// The server's own name passes with its key published and "v=spf1 a -all": +// the name's address record is this server. +func TestServerMailPublished(t *testing.T) { + f := &fakeResolver{ + txt: map[string][]string{ + "sp._domainkey.mail.example.org": {serverDKIM}, + "mail.example.org": {ServerMailSPF}, + }, + addr: map[string][]net.IPAddr{"mail.example.org": ipAddrs("203.0.113.25")}, + } + c := newTestChecker(f) + + m := c.ServerMail(serverMailQuery(), false) + if m.DKIM.Status != health.StatusOK || m.SPF.Status != health.StatusOK || m.Overall != health.StatusOK { + t.Fatalf("DKIM %s (%s), SPF %s (%s), overall %s", m.DKIM.Status, m.DKIM.Detail, m.SPF.Status, m.SPF.Detail, m.Overall) + } + + // Cached like a domain, and re-read when forced. + before := f.lookups + c.ServerMail(serverMailQuery(), false) + if f.lookups != before { + t.Errorf("a second reading looked DNS up again (%d lookups)", f.lookups-before) + } + c.ServerMail(serverMailQuery(), true) + if f.lookups == before { + t.Error("a forced reading used the cache") + } +} + +// With nothing published both records are errors, and the SPF advice names the +// record for a server's own name, not the one for a sending domain. +func TestServerMailMissing(t *testing.T) { + c := newTestChecker(&fakeResolver{}) + + m := c.ServerMail(serverMailQuery(), false) + if m.DKIM.Status != health.StatusError || m.SPF.Status != health.StatusError || m.Overall != health.StatusError { + t.Fatalf("DKIM %s, SPF %s, overall %s; want errors", m.DKIM.Status, m.SPF.Status, m.Overall) + } + if !strings.Contains(m.SPF.Detail, ServerMailSPF) || strings.Contains(m.SPF.Detail, "a:mail.example.org") { + t.Errorf("SPF advice: %s", m.SPF.Detail) + } +} + +// A sending domain of the same name does not share the cache entry. +func TestServerMailCacheIsItsOwn(t *testing.T) { + f := &fakeResolver{ + txt: map[string][]string{ + "sp._domainkey.mail.example.org": {serverDKIM}, + "mail.example.org": {ServerMailSPF}, + }, + addr: map[string][]net.IPAddr{"mail.example.org": ipAddrs("203.0.113.25")}, + } + c := newTestChecker(f) + c.Domain(serverMailQuery(), false) + before := f.lookups + c.ServerMail(serverMailQuery(), false) + if f.lookups == before { + t.Error("the server's mail check was answered from the domain's cache entry") + } +} diff --git a/internal/domain/servermail_test.go b/internal/domain/servermail_test.go new file mode 100644 index 0000000..6ffd315 --- /dev/null +++ b/internal/domain/servermail_test.go @@ -0,0 +1,109 @@ +package domain + +import ( + "os" + "strings" + "testing" +) + +func readTables(t *testing.T, odk *OpenDKIM) (keyTable, signingTable string) { + t.Helper() + kt, err := os.ReadFile(odk.keyTablePath) + if err != nil { + t.Fatalf("read KeyTable: %v", err) + } + st, err := os.ReadFile(odk.signingTablePath) + if err != nil { + t.Fatalf("read SigningTable: %v", err) + } + return string(kt), string(st) +} + +// The server's own name is signed like a sending domain - a key, a line in +// each table - without being one: no row in the registry, so no application +// can send as it. +func TestServerNameIsSignedWithoutBeingADomain(t *testing.T) { + svc, odk := newTestService(t, &fakeApps{}) + svc.SetServerName("mail.example.org") + + if _, err := svc.Add("example.com"); err != nil { + t.Fatalf("add domain: %v", err) + } + kt, st := readTables(t, odk) + for _, want := range []string{"mail.example.org mail.example.org:selfpost:", "example.com example.com:selfpost:"} { + if !strings.Contains(kt, want) { + t.Errorf("KeyTable lacks %q:\n%s", want, kt) + } + } + if !strings.Contains(st, "*@mail.example.org mail.example.org\n") { + t.Errorf("SigningTable does not sign the server's own name:\n%s", st) + } + domains, err := svc.List() + if err != nil || len(domains) != 1 { + t.Fatalf("registry holds %d domains, %v; want the one that was added", len(domains), err) + } + + mail, err := svc.ServerMail() + if err != nil { + t.Fatalf("ServerMail: %v", err) + } + if mail.Name != "mail.example.org" || mail.Selector != "selfpost" || + mail.Record.Name != "selfpost._domainkey.mail.example.org" || !strings.HasPrefix(mail.Record.Value, "v=DKIM1;") { + t.Errorf("server mail = %+v", mail) + } + // Asked again, it is the same key: the record published in DNS stays valid. + again, err := svc.ServerMail() + if err != nil || again.Record.Value != mail.Record.Value { + t.Errorf("the server's key changed between two readings (%v)", err) + } +} + +// When the hostname is itself a sending domain, there is one key and one line, +// the domain's; deleting the domain leaves the server's mail signed with it. +func TestServerNameThatIsAlsoADomain(t *testing.T) { + svc, odk := newTestService(t, &fakeApps{}) + svc.SetServerName("example.com") + + d, err := svc.Add("example.com") + if err != nil { + t.Fatalf("add domain: %v", err) + } + _, st := readTables(t, odk) + if strings.Count(st, "*@example.com ") != 1 { + t.Errorf("the name is in the SigningTable more than once:\n%s", st) + } + asDomain, err := svc.DKIMRecord(d) + if err != nil { + t.Fatal(err) + } + mail, err := svc.ServerMail() + if err != nil || mail.Record.Value != asDomain.Value { + t.Fatalf("the server's record is not the domain's (%v)", err) + } + + if err := svc.Delete(d.ID); err != nil { + t.Fatalf("delete domain: %v", err) + } + _, st = readTables(t, odk) + if !strings.Contains(st, "*@example.com example.com\n") { + t.Errorf("deleting the domain stopped the server's own mail being signed:\n%s", st) + } + after, err := svc.ServerMail() + if err != nil || after.Record.Value != asDomain.Value { + t.Errorf("deleting the domain changed the server's key (%v)", err) + } +} + +// Without a hostname nothing is added and nothing is signed for it. +func TestNoServerName(t *testing.T) { + svc, odk := newTestService(t, &fakeApps{}) + if _, err := svc.Add("example.com"); err != nil { + t.Fatal(err) + } + if _, st := readTables(t, odk); strings.Count(st, "\n") != 1 { + t.Errorf("SigningTable has more than the one domain:\n%s", st) + } + if _, err := svc.ServerMail(); err == nil { + t.Error("ServerMail without a hostname returned no error") + } +} diff --git a/internal/domain/service.go b/internal/domain/service.go index 87e69be..acc778e 100644 --- a/internal/domain/service.go +++ b/internal/domain/service.go @@ -38,6 +38,64 @@ type Service struct { odk *OpenDKIM apps Applications selector string + // serverName is the server's own hostname, which the panel's notifications + // are sent from and signed as (SetServerName). Empty: nothing is signed + // for it. + serverName string +} + +// SetServerName gives the service the server's own hostname. The panel sends +// its notifications from postmaster@ that name, and for a receiver to believe +// them the name is signed like a sending domain: it gets a DKIM key and a line +// in OpenDKIM's tables, without being a row of the registry - no application +// can send as it. The name comes from SELFPOST_HOSTNAME, which the entrypoint +// has validated; it is not user input. +func (s *Service) SetServerName(hostname string) { + s.serverName = hostname +} + +// ServerMail is how the server's own name is signed. +type ServerMail struct { + Name string + Selector string + Record DKIMRecord +} + +// ServerMail returns the name notifications are sent as, its DKIM selector and +// the record to publish for it, creating the key the first time. When the +// hostname is itself a sending domain, it is that domain's key and selector: +// one name has one key. +func (s *Service) ServerMail() (ServerMail, error) { + if s.serverName == "" { + return ServerMail{}, fmt.Errorf("server mail: no hostname") + } + selector, err := s.serverSelector() + if err != nil { + return ServerMail{}, err + } + if _, err := s.odk.EnsureKey(s.serverName, selector); err != nil { + return ServerMail{}, err + } + rec, err := s.odk.Record(s.serverName, selector) + if err != nil { + return ServerMail{}, err + } + return ServerMail{Name: s.serverName, Selector: selector, Record: rec}, nil +} + +// serverSelector is the selector the server's own name is signed with: that of +// the sending domain of the same name if there is one, the default otherwise. +func (s *Service) serverSelector() (string, error) { + domains, err := s.store.ListDomains() + if err != nil { + return "", err + } + for _, d := range domains { + if d.Name == s.serverName { + return d.DKIMSelector, nil + } + } + return s.selector, nil } // NewService builds the domain service. selectorDefault is the DKIM selector @@ -125,6 +183,12 @@ func (s *Service) Delete(id int64) error { if err := s.apps.Resync(); err != nil { return fmt.Errorf("rebuild sender map after deleting %s: %w", d.Name, err) } + // A sending domain named like the server shared its key with the server's + // own mail, which goes on being signed with it (resync above kept the name + // in the tables). + if d.Name == s.serverName { + return nil + } if err := s.odk.RemoveKey(d.Name); err != nil { // The domain is gone from the registry and tables; a leftover key // directory is harmless. Surface it so it is not silently ignored. @@ -172,9 +236,21 @@ func (s *Service) resync() error { if err != nil { return err } - signing := make([]SigningDomain, 0, len(domains)) + signing := make([]SigningDomain, 0, len(domains)+1) + registered := false for _, d := range domains { signing = append(signing, SigningDomain{Name: d.Name, Selector: d.DKIMSelector}) + if d.Name == s.serverName { + registered = true + } + } + // The server's own name, for the panel's notifications - unless it is a + // sending domain already and so in the tables above. + if s.serverName != "" && !registered { + if _, err := s.odk.EnsureKey(s.serverName, s.selector); err != nil { + return fmt.Errorf("dkim key for %s: %w", s.serverName, err) + } + signing = append(signing, SigningDomain{Name: s.serverName, Selector: s.selector}) } return s.odk.Rebuild(signing) } diff --git a/internal/notify/mailer.go b/internal/notify/mailer.go new file mode 100644 index 0000000..fb0508e --- /dev/null +++ b/internal/notify/mailer.go @@ -0,0 +1,99 @@ +package notify + +import ( + "bytes" + "context" + "crypto/rand" + "encoding/hex" + "fmt" + "mime" + "os/exec" + "strings" + "time" +) + +const ( + sendmailPath = "/usr/sbin/sendmail" + sendmailTimeout = 20 * time.Second +) + +// Mailer hands notifications to Postfix by local submission, as +// postmaster@. They are the panel's own mail: they pass no SASL +// login, are not rows of the send log and count against no rate limit. +// Postfix signs them through OpenDKIM with the key of the server's own name +// (non_smtpd_milters in build/postfix-config.sh, domain.Service.SetServerName). +type Mailer struct { + hostname string + // run submits a finished message; a field so tests can read it instead. + run func(from, to string, msg []byte) error +} + +// NewMailer returns a mailer for the server named hostname. +func NewMailer(hostname string) *Mailer { + return &Mailer{hostname: hostname, run: sendmail} +} + +// From is the address notifications are sent from. +func From(hostname string) string { return "postmaster@" + hostname } + +// Send submits one message to one recipient. +func (m *Mailer) Send(to, subject, body string) error { + // The address is a panel user's, validated when it was saved. It goes into + // a header and onto a command line all the same, so what cannot be part of + // an address is refused here as well (security.md). + if to == "" || strings.ContainsAny(to, " \t\r\n<>,;\"") || strings.HasPrefix(to, "-") || !strings.Contains(to, "@") { + return fmt.Errorf("not an address a notification can go to: %q", to) + } + from := From(m.hostname) + id, err := messageID(m.hostname) + if err != nil { + return err + } + + var b bytes.Buffer + fmt.Fprintf(&b, "From: SelfPost <%s>\r\n", from) + fmt.Fprintf(&b, "To: <%s>\r\n", to) + fmt.Fprintf(&b, "Subject: %s\r\n", mime.QEncoding.Encode("utf-8", oneLine(subject))) + fmt.Fprintf(&b, "Date: %s\r\n", time.Now().UTC().Format(time.RFC1123Z)) + fmt.Fprintf(&b, "Message-ID: %s\r\n", id) + // Tells a vacation responder and a ticket system that nobody wrote this. + b.WriteString("Auto-Submitted: auto-generated\r\n") + b.WriteString("MIME-Version: 1.0\r\n") + b.WriteString("Content-Type: text/plain; charset=utf-8\r\n") + b.WriteString("Content-Transfer-Encoding: 8bit\r\n") + b.WriteString("\r\n") + b.WriteString(strings.ReplaceAll(strings.ReplaceAll(body, "\r\n", "\n"), "\n", "\r\n")) + return m.run(from, to, b.Bytes()) +} + +// oneLine keeps a subject on its line whatever went into it. +func oneLine(s string) string { + return strings.Join(strings.Fields(s), " ") +} + +func messageID(hostname string) (string, error) { + var raw [12]byte + if _, err := rand.Read(raw[:]); err != nil { + return "", fmt.Errorf("message id: %w", err) + } + return fmt.Sprintf("<%s.%d@%s>", hex.EncodeToString(raw[:]), time.Now().Unix(), hostname), nil +} + +// sendmail submits msg through Postfix's sendmail command. The argument list is +// fixed apart from the two addresses, which follow "--" so that neither can be +// read as an option; nothing goes through a shell (security.md). -i keeps a +// line holding a single dot from ending the message. +func sendmail(from, to string, msg []byte) error { + ctx, cancel := context.WithTimeout(context.Background(), sendmailTimeout) + defer cancel() + cmd := exec.CommandContext(ctx, sendmailPath, "-i", "-f", from, "--", to) + cmd.Stdin = bytes.NewReader(msg) + out, err := cmd.CombinedOutput() + if ctx.Err() == context.DeadlineExceeded { + return fmt.Errorf("sendmail timed out after %s", sendmailTimeout) + } + if err != nil { + return fmt.Errorf("sendmail: %w: %s", err, strings.TrimSpace(string(out))) + } + return nil +} diff --git a/internal/notify/notify.go b/internal/notify/notify.go new file mode 100644 index 0000000..a04563b --- /dev/null +++ b/internal/notify/notify.go @@ -0,0 +1,415 @@ +// Package notify writes to the panel's users when something needs them +// (architecture.md § Notifications): a sending domain's DNS record stops +// matching, a level-2 rate limit refuses mail, the TLS certificate is about to +// expire, a message has waited in the queue for more than three days. +// +// Each subject has a row of state in the database, so a thing is said once and +// a restart says nothing again. The rules of when a message goes out are the +// owner's (docs/plans/panel-notifications.md § When a message is sent) and +// live in this file; what the messages say is in text.go, how they leave in +// mailer.go. +package notify + +import ( + "context" + "fmt" + "log" + "sort" + "strings" + "time" + + "github.com/mixeme/selfpost/internal/dnscheck" + "github.com/mixeme/selfpost/internal/health" + "github.com/mixeme/selfpost/internal/postfix" + "github.com/mixeme/selfpost/internal/store" +) + +const ( + // CheckInterval is how often DNS, the certificate and the queue are looked + // at. A var-free constant: the rules below count in checks. + CheckInterval = time.Hour + // LimitInterval is how often refused mail is looked for. A refusal is + // reported at once rather than on the hour: it is mail not being sent now. + LimitInterval = 5 * time.Minute + + // dnsChecks is how many checks in a row must agree before a DNS mismatch is + // reported, and before it is reported gone. One check is a resolver's bad + // minute; two, an hour apart, is a record that is wrong. + dnsChecks = 2 + + // QueueAge is how long a message waits before the queue is reported. Postfix + // keeps a message for five days by default, so two are left to act in. + QueueAge = 3 * 24 * time.Hour + + // The certificate is reported this many days before it expires, and again at + // the second number if it is still the same certificate. + certFirstDays = 14 + certLastDays = 3 + + // limitRepeat is the shortest time between two messages about the same + // level-2 limit. + limitRepeat = 24 * time.Hour + + phasePending = "pending" // seen wrong, not yet said + phaseOpen = "open" // said +) + +// Store is what the notifier needs of the database. *store.Store satisfies it. +type Store interface { + NotificationsEnabled() (bool, error) + NotifyRecipients(domainName string) ([]string, error) + GetNotifyState(key string) (store.NotifyState, bool, error) + SetNotifyState(st store.NotifyState) error + DeleteNotifyState(key string) error + ListNotifyStateKeys(prefix string) ([]string, error) + LimitRefusalsSince(since time.Time) ([]store.LimitRefusal, error) + ListDomains() ([]store.Domain, error) +} + +// Sender hands one message to the mail system. *Mailer does; tests collect. +type Sender interface { + Send(to, subject, body string) error +} + +// Checks are the readings the notifier acts on, as functions so that tests +// need neither DNS nor a certificate nor a queue. +type Checks struct { + // Domain is a fresh check of a sending domain's published records. + Domain func(d store.Domain) (dnscheck.Domain, error) + // Certificate is the state of the TLS certificate Postfix serves. + Certificate func() health.Certificate + // Queue lists the messages Postfix holds; an error says nothing about any. + Queue func() ([]postfix.QueuedMessage, error) +} + +// Notifier applies the rules. Create one with New and call Run. +type Notifier struct { + st Store + checks Checks + sender Sender + hostname string + now func() time.Time +} + +// New builds a notifier for the server named hostname. +func New(st Store, checks Checks, sender Sender, hostname string) *Notifier { + return &Notifier{st: st, checks: checks, sender: sender, hostname: hostname, now: func() time.Time { return time.Now().UTC() }} +} + +// Run checks on both cadences until ctx is cancelled. The first hourly check +// runs a few minutes after the start, not at it: a container that has just +// come up is still starting Postfix and may have no network yet. +func (n *Notifier) Run(ctx context.Context) error { + first := time.NewTimer(3 * time.Minute) + defer first.Stop() + hourly := time.NewTicker(CheckInterval) + defer hourly.Stop() + limits := time.NewTicker(LimitInterval) + defer limits.Stop() + for { + select { + case <-ctx.Done(): + return nil + case <-first.C: + n.Check() + case <-hourly.C: + n.Check() + case <-limits.C: + n.CheckLimits() + } + } +} + +// enabled reports whether anything is to be done at all. With the instance +// switch off nothing is checked and no state moves, so that what is wrong +// when it is turned on again is said then. +func (n *Notifier) enabled() bool { + on, err := n.st.NotificationsEnabled() + if err != nil { + log.Printf("notify: read the switch: %v", err) + return false + } + return on +} + +// Check is the hourly pass: DNS of every sending domain, the certificate, the +// queue. +func (n *Notifier) Check() { + if !n.enabled() { + return + } + n.checkDNS() + n.checkCertificate() + n.checkQueue() +} + +// send writes one message to every recipient of a subject, each in a message +// of their own - users are not shown each other's addresses. It reports +// whether the subject counts as said: nobody to tell is said, a message that +// could not be handed over to anyone is not, and is tried at the next check. +func (n *Notifier) send(domainName string, m message) bool { + to, err := n.st.NotifyRecipients(domainName) + if err != nil { + log.Printf("notify: recipients: %v", err) + return false + } + if len(to) == 0 { + return true + } + sent := 0 + for _, addr := range to { + if err := n.sender.Send(addr, m.subject, m.body); err != nil { + log.Printf("notify: send %q to %s: %v", m.subject, addr, err) + continue + } + sent++ + } + if sent > 0 { + log.Printf("notify: %q sent to %d of %d", m.subject, sent, len(to)) + } + return sent > 0 +} + +func (n *Notifier) save(st store.NotifyState) { + if err := n.st.SetNotifyState(st); err != nil { + log.Printf("notify: save state %s: %v", st.Key, err) + } +} + +func (n *Notifier) forget(key string) { + if err := n.st.DeleteNotifyState(key); err != nil { + log.Printf("notify: forget state %s: %v", key, err) + } +} + +// ---- DNS + +// dnsFault is what is wrong with a domain's records: the checks that failed, +// in the order the page shows them. +type dnsFault struct { + Record string // "DKIM", "SPF", "DMARC" + Detail string +} + +// dnsReading sorts a check into wrong, right, or nothing learned. A record +// that fails is wrong whatever the others say. A lookup that did not answer is +// nothing learned - unless another record is plainly wrong. A warning (no DMARC +// record, an SPF include this check does not follow) is advice the page gives +// and not a thing to write about. +func dnsReading(d dnscheck.Domain) (faults []dnsFault, known bool) { + known = true + for _, r := range []struct { + name string + res dnscheck.Result + }{{"DKIM", d.DKIM}, {"SPF", d.SPF}, {"DMARC", d.DMARC}} { + switch r.res.Status { + case health.StatusError: + faults = append(faults, dnsFault{Record: r.name, Detail: r.res.Detail}) + case health.StatusUnknown: + known = false + } + } + if len(faults) > 0 { + known = true + } + return faults, known +} + +func (n *Notifier) checkDNS() { + domains, err := n.st.ListDomains() + if err != nil { + log.Printf("notify: list domains: %v", err) + return + } + names := make(map[string]bool, len(domains)) + for _, d := range domains { + names[d.Name] = true + res, err := n.checks.Domain(d) + if err != nil { + log.Printf("notify: check %s: %v", d.Name, err) + continue + } + n.dnsStep(d.Name, res) + } + // A deleted domain has no records to be right or wrong. + keys, err := n.st.ListNotifyStateKeys("dns:") + if err != nil { + log.Printf("notify: list dns state: %v", err) + return + } + for _, key := range keys { + if !names[strings.TrimPrefix(key, "dns:")] { + n.forget(key) + } + } +} + +// dnsStep moves one domain's state by one check. +func (n *Notifier) dnsStep(name string, res dnscheck.Domain) { + faults, known := dnsReading(res) + if !known { + return + } + bad := len(faults) > 0 + key := "dns:" + name + st, have, err := n.st.GetNotifyState(key) + if err != nil { + log.Printf("notify: %v", err) + return + } + now := n.now() + + switch { + case !have && !bad: + // Nothing wrong and nothing said. + case !have && bad: + n.save(store.NotifyState{Key: key, Phase: phasePending, Count: 1, Since: now}) + case st.Phase == phasePending && !bad: + n.forget(key) // it was the resolver's bad minute + case st.Phase == phasePending && bad: + st.Count++ + if st.Count >= dnsChecks { + if !n.send(name, dnsProblem(n.hostname, name, faults, st.Since)) { + n.save(st) + return + } + st.Phase, st.Count, st.SentAt = phaseOpen, 0, now + } + n.save(st) + case st.Phase == phaseOpen && bad: + if st.Count != 0 { + st.Count = 0 // it went right for a check and wrong again: still the same trouble + n.save(st) + } + case st.Phase == phaseOpen && !bad: + st.Count++ + if st.Count >= dnsChecks { + if n.send(name, dnsCleared(n.hostname, name, st.Since)) { + n.forget(key) + return + } + } + n.save(st) + } +} + +// ---- certificate + +func (n *Notifier) checkCertificate() { + c := n.checks.Certificate() + if c.NotAfter.IsZero() { + return // no certificate configured, or one that cannot be read: Health says so + } + const key = "cert" + mark := c.NotAfter.UTC().Format(time.RFC3339) + st, have, err := n.st.GetNotifyState(key) + if err != nil { + log.Printf("notify: %v", err) + return + } + if have && st.Mark != mark { + // A different certificate: what was said about the old one is over. + n.forget(key) + have, st = false, store.NotifyState{} + } + + left := c.NotAfter.Sub(n.now()) + level := "" + switch { + case left <= certLastDays*24*time.Hour: + level = "last" + case left <= certFirstDays*24*time.Hour: + level = "first" + } + if level == "" || (have && (st.Phase == level || st.Phase == "last")) { + return + } + if !n.send("", certExpiring(n.hostname, c.NotAfter, left)) { + return + } + n.save(store.NotifyState{Key: key, Phase: level, Mark: mark, Since: n.now(), SentAt: n.now()}) +} + +// ---- queue + +func (n *Notifier) checkQueue() { + msgs, err := n.checks.Queue() + if err != nil { + log.Printf("notify: read the queue: %v", err) + return // no listing is no information + } + now := n.now() + var old []postfix.QueuedMessage + for _, m := range msgs { + if now.Sub(m.Arrival) > QueueAge { + old = append(old, m) + } + } + sort.Slice(old, func(i, j int) bool { return old[i].Arrival.Before(old[j].Arrival) }) + + const key = "queue" + st, have, err := n.st.GetNotifyState(key) + if err != nil { + log.Printf("notify: %v", err) + return + } + switch { + case len(old) > 0 && !have: + if n.send("", queueStuck(n.hostname, old, now)) { + n.save(store.NotifyState{Key: key, Phase: phaseOpen, Since: now, SentAt: now}) + } + case len(old) == 0 && have: + if n.send("", queueCleared(n.hostname, st.Since)) { + n.forget(key) + } + } +} + +// ---- level-2 limits + +// CheckLimits looks for mail refused under a level-2 rate limit and reports +// each limit that refused, at most once in limitRepeat. +func (n *Notifier) CheckLimits() { + if !n.enabled() { + return + } + now := n.now() + refusals, err := n.st.LimitRefusalsSince(now.Add(-limitRepeat)) + if err != nil { + log.Printf("notify: %v", err) + return + } + for _, r := range refusals { + if r.Domain == "" { + continue + } + key := fmt.Sprintf("limit:%s:%s", r.Domain, r.AppLogin) + st, have, err := n.st.GetNotifyState(key) + if err != nil { + log.Printf("notify: %v", err) + continue + } + // Told within the day: the refusals counted now are the ones it was + // told about, or more of the same. Told longer ago: everything in the + // window is new since then. + if have && now.Sub(st.SentAt) < limitRepeat { + continue + } + if n.send(r.Domain, limitRefused(n.hostname, r)) { + n.save(store.NotifyState{Key: key, Phase: phaseOpen, Since: r.First, SentAt: now}) + } + } + + // A limit nobody has hit for two days is not a subject any more. + keys, err := n.st.ListNotifyStateKeys("limit:") + if err != nil { + log.Printf("notify: list limit state: %v", err) + return + } + for _, key := range keys { + st, have, err := n.st.GetNotifyState(key) + if err == nil && have && now.Sub(st.SentAt) > 2*limitRepeat { + n.forget(key) + } + } +} diff --git a/internal/notify/notify_test.go b/internal/notify/notify_test.go new file mode 100644 index 0000000..72ddb82 --- /dev/null +++ b/internal/notify/notify_test.go @@ -0,0 +1,380 @@ +package notify + +import ( + "errors" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/mixeme/selfpost/internal/dnscheck" + "github.com/mixeme/selfpost/internal/health" + "github.com/mixeme/selfpost/internal/postfix" + "github.com/mixeme/selfpost/internal/store" +) + +// outbox collects what would have been handed to Postfix. +type outbox struct { + sent []string // "to|subject" + body []string + fail bool +} + +func (o *outbox) Send(to, subject, body string) error { + if o.fail { + return errors.New("sendmail: queue file write error") + } + o.sent = append(o.sent, to+"|"+subject) + o.body = append(o.body, body) + return nil +} + +func (o *outbox) take() []string { + s := o.sent + o.sent, o.body = nil, nil + return s +} + +// bench is a notifier over a real database with a clock and readings the test +// sets: one global user, one user of example.com, one user of another domain. +type bench struct { + n *Notifier + st *store.Store + out *outbox + now time.Time + dns map[string]dnscheck.Domain + cert health.Certificate + q []postfix.QueuedMessage + qErr error +} + +func newBench(t *testing.T) *bench { + t.Helper() + st, err := store.Open(filepath.Join(t.TempDir(), "test.db")) + if err != nil { + t.Fatalf("open store: %v", err) + } + t.Cleanup(func() { _ = st.Close() }) + + b := &bench{st: st, out: &outbox{}, now: time.Date(2026, 10, 12, 12, 0, 0, 0, time.UTC), dns: map[string]dnscheck.Domain{}} + mine, err := st.AddDomain("example.com", "sp") + if err != nil { + t.Fatal(err) + } + other, err := st.AddDomain("other.example", "sp") + if err != nil { + t.Fatal(err) + } + for _, u := range []struct { + name string + role store.Role + reach store.Reach + }{ + {"root", store.RoleGlobal, store.Reach{}}, + {"mine", store.RoleDomain, store.Reach{DomainIDs: []int64{mine.ID}}}, + {"theirs", store.RoleDomain, store.Reach{DomainIDs: []int64{other.ID}}}, + } { + id, err := st.CreateUser(u.name, "hash", u.role, u.reach) + if err != nil { + t.Fatal(err) + } + if err := st.UpdateUser(id, u.name, "hash", u.name+"@example.org"); err != nil { + t.Fatal(err) + } + } + + b.n = New(st, Checks{ + Domain: func(d store.Domain) (dnscheck.Domain, error) { + res, ok := b.dns[d.Name] + if !ok { + return good(), nil + } + return res, nil + }, + Certificate: func() health.Certificate { return b.cert }, + Queue: func() ([]postfix.QueuedMessage, error) { return b.q, b.qErr }, + }, b.out, "mail.example.org") + b.n.now = func() time.Time { return b.now } + return b +} + +// hour runs the hourly check and moves the clock on by an hour. +func (b *bench) hour() []string { + b.n.Check() + b.now = b.now.Add(time.Hour) + return b.out.take() +} + +func good() dnscheck.Domain { + ok := dnscheck.Result{Status: health.StatusOK} + return dnscheck.Domain{DKIM: ok, SPF: ok, DMARC: ok} +} + +func badDKIM() dnscheck.Domain { + d := good() + d.DKIM = dnscheck.Result{Status: health.StatusError, Detail: "A TXT record exists but its public key is not the one this server signs with."} + return d +} + +func want(t *testing.T, what string, got []string, wanted ...string) { + t.Helper() + if strings.Join(got, "\n") != strings.Join(wanted, "\n") { + t.Errorf("%s: sent\n %s\nwant\n %s", what, strings.Join(got, "\n "), strings.Join(wanted, "\n ")) + } +} + +// A DNS mismatch is said once, after two checks in a row found it, to the +// global users and the domain's own; it is said to be over once, after two +// checks in a row found the records right. +func TestDNSMismatchIsSaidOnceAndClearedOnce(t *testing.T) { + b := newBench(t) + b.dns["example.com"] = badDKIM() + + want(t, "first bad check", b.hour()) + problem := "[SelfPost] example.com: DKIM no longer matches" + want(t, "second bad check", b.hour(), "mine@example.org|"+problem, "root@example.org|"+problem) + want(t, "third bad check", b.hour()) + + b.dns["example.com"] = good() + want(t, "first good check", b.hour()) + // One good check does not end it: wrong again is the same trouble, not a new one. + b.dns["example.com"] = badDKIM() + want(t, "wrong again", b.hour()) + b.dns["example.com"] = good() + want(t, "good once more", b.hour()) + cleared := "[SelfPost] example.com: DNS records match again" + want(t, "second good check in a row", b.hour(), "mine@example.org|"+cleared, "root@example.org|"+cleared) + want(t, "after it cleared", b.hour()) + + if _, have, _ := b.st.GetNotifyState("dns:example.com"); have { + t.Error("state left behind after the trouble was over") + } +} + +// One bad check followed by a good one was the resolver, and nothing is said. +// A lookup that did not answer says nothing either way; a warning is advice +// the page gives, not a thing to write about. +func TestDNSNoiseIsNotSaid(t *testing.T) { + b := newBench(t) + + b.dns["example.com"] = badDKIM() + want(t, "one bad check", b.hour()) + b.dns["example.com"] = good() + want(t, "then good", b.hour()) + b.dns["example.com"] = badDKIM() + want(t, "bad again, counted from one", b.hour()) + + unknown := good() + unknown.SPF = dnscheck.Result{Status: health.StatusUnknown, Detail: "Could not look up the SPF record."} + b.dns["example.com"] = unknown + want(t, "resolver did not answer", b.hour()) + if st, have, _ := b.st.GetNotifyState("dns:example.com"); !have || st.Count != 1 { + t.Errorf("an unanswered lookup moved the state: %+v, %v", st, have) + } + + warn := good() + warn.DMARC = dnscheck.Result{Status: health.StatusWarn, Detail: "No DMARC record."} + b.dns["other.example"] = warn + want(t, "a warning", b.hour()) + want(t, "a warning, twice", b.hour()) +} + +// The instance switch stops everything, state included; a domain that is +// deleted takes its state with it; a message that could not be handed over is +// tried again at the next check. +func TestDNSSwitchDeletionAndRetry(t *testing.T) { + b := newBench(t) + b.dns["example.com"] = badDKIM() + + if err := b.st.SetNotificationsEnabled(false); err != nil { + t.Fatal(err) + } + want(t, "switched off", b.hour()) + want(t, "switched off", b.hour()) + if _, have, _ := b.st.GetNotifyState("dns:example.com"); have { + t.Fatal("state moved while notifications were off") + } + if err := b.st.SetNotificationsEnabled(true); err != nil { + t.Fatal(err) + } + + want(t, "on again, first check", b.hour()) + b.out.fail = true + want(t, "second check, mail system down", b.hour()) + b.out.fail = false + if got := b.hour(); len(got) != 2 { + t.Errorf("after the mail system came back: %v, want the two messages", got) + } + + domains, _ := b.st.ListDomains() + for _, d := range domains { + if d.Name == "example.com" { + if err := b.st.DeleteDomain(d.ID); err != nil { + t.Fatal(err) + } + } + } + want(t, "domain deleted", b.hour()) + if _, have, _ := b.st.GetNotifyState("dns:example.com"); have { + t.Error("a deleted domain kept its state") + } +} + +// The certificate is said at 14 days and again at 3 if it is still the same +// one, to global users only; a new certificate starts over. +func TestCertificateIsSaidTwice(t *testing.T) { + b := newBench(t) + expiry := b.now.Add(20 * 24 * time.Hour) + b.cert = health.Certificate{NotAfter: expiry} + want(t, "20 days left", b.hour()) + + b.now = expiry.Add(-14 * 24 * time.Hour) + want(t, "14 days left", b.hour(), "root@example.org|[SelfPost] TLS certificate of mail.example.org expires in 14 days") + want(t, "an hour later", b.hour()) + b.now = expiry.Add(-8 * 24 * time.Hour) + want(t, "8 days left", b.hour()) + + b.now = expiry.Add(-3 * 24 * time.Hour) + want(t, "3 days left", b.hour(), "root@example.org|[SelfPost] TLS certificate of mail.example.org expires in 3 days") + b.now = expiry.Add(time.Hour) + want(t, "expired, already said", b.hour()) + + // Renewed: nothing to say, and the next expiry is a new subject. + renewed := b.now.Add(90 * 24 * time.Hour) + b.cert = health.Certificate{NotAfter: renewed} + want(t, "renewed", b.hour()) + b.now = renewed.Add(-2 * 24 * time.Hour) + want(t, "the new one, first seen with 2 days left", b.hour(), "root@example.org|[SelfPost] TLS certificate of mail.example.org expires in 2 days") + + // No certificate configured: Health says so, mail does not. + b.cert = health.Certificate{Status: health.StatusUnknown} + want(t, "no certificate", b.hour()) +} + +// A message older than three days is said once, and its going once; a queue +// that cannot be listed says nothing. +func TestQueueIsSaidOnceAndClearedOnce(t *testing.T) { + b := newBench(t) + b.q = []postfix.QueuedMessage{ + {ID: "FRESH001", Queue: "deferred", Sender: "app@example.com", Arrival: b.now.Add(-2 * 24 * time.Hour)}, + } + want(t, "two days old", b.hour()) + + b.q = append(b.q, postfix.QueuedMessage{ID: "OLD00001", Queue: "deferred", Sender: "app@example.com", Arrival: b.now.Add(-4 * 24 * time.Hour)}) + b.n.Check() + if len(b.out.sent) != 1 || b.out.sent[0] != "root@example.org|[SelfPost] A message has been in the queue of mail.example.org for more than 3 days" { + t.Fatalf("four days old: %v", b.out.sent) + } + if body := b.out.body[0]; !strings.Contains(body, "OLD00001") || strings.Contains(body, "FRESH001") { + t.Errorf("the message names the wrong mail:\n%s", body) + } + b.out.take() + want(t, "still there", b.hour()) + + b.qErr = errors.New("postqueue: Permission denied") + b.q = nil + want(t, "queue cannot be listed", b.hour()) + b.qErr = nil + want(t, "gone", b.hour(), "root@example.org|[SelfPost] The queue of mail.example.org holds nothing older than 3 days") + want(t, "after", b.hour()) +} + +// A limit that refuses mail is said to the domain's users, at most once a day. +func TestLimitRefusalIsSaidOnceADay(t *testing.T) { + b := newBench(t) + b.now = time.Now().UTC() // refusals are dated by the store's clock + refuse := func() { + t.Helper() + if err := b.st.InsertRejected(store.SendLogEntry{Domain: "example.com", AppLogin: "app1", From: "a@example.com"}); err != nil { + t.Fatal(err) + } + } + + b.n.CheckLimits() + want(t, "nothing refused", b.out.take()) + + refuse() + b.n.CheckLimits() + subject := "[SelfPost] example.com: a rate limit is refusing mail" + want(t, "first refusal", b.out.take(), "mine@example.org|"+subject, "root@example.org|"+subject) + + refuse() + b.now = b.now.Add(2 * time.Hour) + b.n.CheckLimits() + want(t, "more of it two hours later", b.out.take()) + + // A day after it was said, mail is still being refused: said again. The + // refusals are dated by the store's clock, so it is the telling that is + // moved back, not the clock forward. + st, have, err := b.st.GetNotifyState("limit:example.com:app1") + if err != nil || !have { + t.Fatalf("no state for the limit: %v, %v", have, err) + } + b.now = time.Now().UTC() + st.SentAt = b.now.Add(-25 * time.Hour) + if err := b.st.SetNotifyState(st); err != nil { + t.Fatal(err) + } + b.n.CheckLimits() + want(t, "a day later, still refusing", b.out.take(), "mine@example.org|"+subject, "root@example.org|"+subject) + if body := limitRefused("mail.example.org", store.LimitRefusal{Domain: "example.com", AppLogin: "app1", Count: 3, First: b.now}).body; !strings.Contains(body, "3 messages from the application app1 of example.com") { + t.Errorf("the message does not say who was refused how much:\n%s", body) + } + + // Nobody has hit the limit for two days: it is not a subject any more. + st.SentAt = b.now.Add(-49 * time.Hour) + if err := b.st.SetNotifyState(st); err != nil { + t.Fatal(err) + } + if _, err := b.st.LimitRefusalsSince(b.now); err != nil { + t.Fatal(err) + } + b.now = b.now.Add(25 * time.Hour) // past the window the refusals lie in + b.n.CheckLimits() + want(t, "long quiet", b.out.take()) + if _, have, _ := b.st.GetNotifyState("limit:example.com:app1"); have { + t.Error("a limit nobody hits kept its state") + } +} + +func TestMailerComposesAndRefuses(t *testing.T) { + var from, to string + var msg []byte + m := NewMailer("mail.example.org") + m.run = func(f, t string, b []byte) error { from, to, msg = f, t, b; return nil } + + if err := m.Send("root@example.org", "[SelfPost] example.com:\r\nBcc: x@evil.example", "line one\n.\nline three\n"); err != nil { + t.Fatalf("Send: %v", err) + } + if from != "postmaster@mail.example.org" || to != "root@example.org" { + t.Errorf("envelope %s -> %s", from, to) + } + text := string(msg) + head, body, ok := strings.Cut(text, "\r\n\r\n") + if !ok { + t.Fatalf("no header/body break:\n%s", text) + } + for _, h := range []string{ + "From: SelfPost ", + "To: ", + "Subject: [SelfPost] example.com: Bcc: x@evil.example", + "Auto-Submitted: auto-generated", + "Content-Type: text/plain; charset=utf-8", + } { + if !strings.Contains(head, h+"\r\n") && !strings.HasSuffix(head, h) { + t.Errorf("header %q missing from:\n%s", h, head) + } + } + if strings.Count(head, "\r\n")+1 != 9 { + t.Errorf("a subject broke out of its line; headers:\n%s", head) + } + if body != "line one\r\n.\r\nline three\r\n" { + t.Errorf("body = %q", body) + } + + for _, bad := range []string{"", "no-at-sign", "-oQ/tmp@example.org", "a@example.org\nBcc: b@example.org", "a b@example.org", ""} { + if err := m.Send(bad, "s", "b"); err == nil { + t.Errorf("address %q was accepted", bad) + } + } +} diff --git a/internal/notify/text.go b/internal/notify/text.go new file mode 100644 index 0000000..390cb99 --- /dev/null +++ b/internal/notify/text.go @@ -0,0 +1,131 @@ +package notify + +import ( + "fmt" + "strings" + "time" + + "github.com/mixeme/selfpost/internal/postfix" + "github.com/mixeme/selfpost/internal/store" +) + +// message is one notification: a subject line and a plain-text body. +// +// The texts name the page of the panel to open rather than link to it: the +// panel does not know its own address - it sits behind the operator's reverse +// proxy - and a link built from a guess would be a wrong link in a message +// people are asked to trust. +type message struct { + subject string + body string +} + +// maxListed is how many messages of the queue a notification names. The rest +// are counted: the page shows them all. +const maxListed = 10 + +func compose(hostname, subject string, paragraphs ...string) message { + paragraphs = append(paragraphs, + fmt.Sprintf("Sent by the SelfPost panel on %s. You receive this because notifications are on in your Account there; turn them off on the same page.", hostname)) + return message{ + subject: "[SelfPost] " + subject, + body: strings.Join(paragraphs, "\n\n") + "\n", + } +} + +func stamp(t time.Time) string { return t.UTC().Format("2006-01-02 15:04 UTC") } + +// days words a duration in whole days, the unit these messages count in. +func days(d time.Duration) string { + n := int(d.Hours() / 24) + if n == 1 { + return "1 day" + } + return fmt.Sprintf("%d days", n) +} + +func dnsProblem(hostname, domain string, faults []dnsFault, since time.Time) message { + names := make([]string, len(faults)) + lines := make([]string, len(faults)) + for i, f := range faults { + names[i] = f.Record + lines[i] = f.Record + ": " + f.Detail + } + return compose(hostname, + fmt.Sprintf("%s: %s no longer matches", domain, strings.Join(names, ", ")), + fmt.Sprintf("The DNS records of %s do not match what this server sends with. Two checks an hour apart found the same, the first at %s.", domain, stamp(since)), + strings.Join(lines, "\n\n"), + fmt.Sprintf("Until the records are right, receivers may refuse mail from %s or file it as spam. The records to publish are in the panel under Outbound > Domains > %s.", domain, domain), + "One more message follows when the records match again.", + ) +} + +func dnsCleared(hostname, domain string, since time.Time) message { + return compose(hostname, + fmt.Sprintf("%s: DNS records match again", domain), + fmt.Sprintf("The DNS records of %s match what this server sends with again; two checks an hour apart agree. They had not since %s.", domain, stamp(since)), + ) +} + +func certExpiring(hostname string, notAfter time.Time, left time.Duration) message { + subject := fmt.Sprintf("TLS certificate of %s expires in %s", hostname, days(left)) + first := fmt.Sprintf("The TLS certificate this server presents on its submission ports expires on %s, in %s.", stamp(notAfter), days(left)) + if left <= 0 { + subject = fmt.Sprintf("TLS certificate of %s has expired", hostname) + first = fmt.Sprintf("The TLS certificate this server presents on its submission ports expired on %s.", stamp(notAfter)) + } + return compose(hostname, subject, + first, + "Once it has expired, applications that verify the certificate can no longer submit mail. Renewal normally happens on the host, at the reverse proxy the certificate comes from; check that it still runs. The panel shows the certificate under Server > Health.", + ) +} + +func queueStuck(hostname string, old []postfix.QueuedMessage, now time.Time) message { + var b strings.Builder + for i, m := range old { + if i == maxListed { + fmt.Fprintf(&b, "... and %d more\n", len(old)-maxListed) + break + } + sender := m.Sender + if sender == "" { + sender = "(bounce)" + } + fmt.Fprintf(&b, "%s from %s waiting %s, since %s\n", m.ID, sender, days(now.Sub(m.Arrival)), stamp(m.Arrival)) + } + what := "A message has" + if len(old) > 1 { + what = fmt.Sprintf("%d messages have", len(old)) + } + return compose(hostname, + fmt.Sprintf("%s been in the queue of %s for more than %s", what, hostname, days(QueueAge)), + fmt.Sprintf("%s waited in the mail queue for more than %s. Postfix goes on retrying and returns a message to its sender when the queue lifetime runs out.", what, days(QueueAge)), + strings.TrimRight(b.String(), "\n"), + "The reason the receiving server gives is in the panel: Outbound > Queue lists what is held, and the message's page in Outbound > Log shows what Postfix logged about it.", + "One more message follows when nothing that old is left in the queue.", + ) +} + +func queueCleared(hostname string, since time.Time) message { + return compose(hostname, + fmt.Sprintf("The queue of %s holds nothing older than %s", hostname, days(QueueAge)), + fmt.Sprintf("No message in the mail queue is older than %s any more: what was waiting since the notification of %s was delivered, or returned to its sender.", days(QueueAge), stamp(since)), + ) +} + +func limitRefused(hostname string, r store.LimitRefusal) message { + who := "the domain " + r.Domain + if r.AppLogin != "" { + who = fmt.Sprintf("the application %s of %s", r.AppLogin, r.Domain) + } + count := "1 message" + if r.Count != 1 { + count = fmt.Sprintf("%d messages", r.Count) + } + return compose(hostname, + fmt.Sprintf("%s: a rate limit is refusing mail", r.Domain), + fmt.Sprintf("In the last 24 hours this server refused %s from %s under a level-2 rate limit, the first at %s. Refused mail is not queued: the application has to send it again.", count, who, stamp(r.First)), + fmt.Sprintf("If the volume is expected, raise the limit in the panel: Outbound > Domains > %s, on the domain or on the application. If it is not, the application is sending more than it should.", r.Domain), + "This limit is reported at most once a day.", + ) +} diff --git a/internal/postfix/queuejson.go b/internal/postfix/queuejson.go new file mode 100644 index 0000000..c5e3bf5 --- /dev/null +++ b/internal/postfix/queuejson.go @@ -0,0 +1,86 @@ +package postfix + +import ( + "bufio" + "context" + "encoding/json" + "fmt" + "os/exec" + "strings" + "time" +) + +// QueuedMessage is one message Postfix is holding, as `postqueue -j` reports +// it: where it is, and since when. +type QueuedMessage struct { + ID string + Queue string // "deferred", "active", "hold", "incoming", "maildrop" + Sender string + Arrival time.Time +} + +// readQueueJSON runs `postqueue -j`. It is a var so tests can answer without a +// running Postfix, the way readRetryConf is. +var readQueueJSON = postqueueJSON + +func postqueueJSON() ([]byte, error) { + ctx, cancel := context.WithTimeout(context.Background(), postqueueTimeout) + defer cancel() + // A fixed flag and no user input, never through a shell (security.md). + cmd := exec.CommandContext(ctx, "postqueue", "-j") + out := &limitWriter{remaining: maxQueueOutput} + errOut := &limitWriter{remaining: 4096} + cmd.Stdout = out + cmd.Stderr = errOut + err := cmd.Run() + if ctx.Err() == context.DeadlineExceeded { + return nil, fmt.Errorf("postqueue -j timed out after %s", postqueueTimeout) + } + if err != nil { + return nil, fmt.Errorf("postqueue -j: %w: %s", err, strings.TrimSpace(errOut.buf.String())) + } + // A listing cut at the size limit is still a list of whole lines up to the + // cut; the last, broken one is dropped by the parser. + return out.buf.Bytes(), nil +} + +// QueueMessages returns the messages Postfix holds with the time each arrived, +// for the notification about mail that has waited too long. An error means the +// queue could not be listed and says nothing about any message. +func QueueMessages() ([]QueuedMessage, error) { + out, err := readQueueJSON() + if err != nil { + return nil, err + } + return parseQueueJSON(out), nil +} + +// parseQueueJSON reads `postqueue -j` output: one JSON object per line. A line +// that is not one - the tail of a listing cut at its size limit - is skipped. +func parseQueueJSON(out []byte) []QueuedMessage { + var msgs []QueuedMessage + sc := bufio.NewScanner(strings.NewReader(string(out))) + sc.Buffer(make([]byte, 0, 64*1024), 1<<20) + for sc.Scan() { + line := strings.TrimSpace(sc.Text()) + if line == "" { + continue + } + var e struct { + QueueName string `json:"queue_name"` + QueueID string `json:"queue_id"` + ArrivalTime int64 `json:"arrival_time"` + Sender string `json:"sender"` + } + if err := json.Unmarshal([]byte(line), &e); err != nil || e.QueueID == "" || e.ArrivalTime <= 0 { + continue + } + msgs = append(msgs, QueuedMessage{ + ID: e.QueueID, + Queue: e.QueueName, + Sender: e.Sender, + Arrival: time.Unix(e.ArrivalTime, 0).UTC(), + }) + } + return msgs +} diff --git a/internal/postfix/queuejson_test.go b/internal/postfix/queuejson_test.go new file mode 100644 index 0000000..f8e0448 --- /dev/null +++ b/internal/postfix/queuejson_test.go @@ -0,0 +1,43 @@ +package postfix + +import ( + "errors" + "testing" + "time" +) + +func TestParseQueueJSON(t *testing.T) { + out := []byte(`{"queue_name": "deferred", "queue_id": "41E862C00D9E", "arrival_time": 1791000000, "message_size": 446, "forced_expire": false, "sender": "app@example.com", "recipients": [{"address": "a@example.net", "delay_reason": "connect to mx.example.net[203.0.113.9]:25: Connection timed out"}]} +{"queue_name": "active", "queue_id": "5F00AA12", "arrival_time": 1791250000, "message_size": 900, "sender": "", "recipients": [{"address": "b@example.net"}]} + +not json at all +{"queue_name": "deferred", "queue_id": "", "arrival_time": 1791250000} +{"queue_name": "deferred", "queue_id": "6C00BB34", "arrival_time": 17912`) + + got := parseQueueJSON(out) + if len(got) != 2 { + t.Fatalf("parsed %d messages, want 2: %+v", len(got), got) + } + if got[0].ID != "41E862C00D9E" || got[0].Queue != "deferred" || got[0].Sender != "app@example.com" || + !got[0].Arrival.Equal(time.Unix(1791000000, 0)) { + t.Errorf("first message = %+v", got[0]) + } + if got[1].ID != "5F00AA12" || got[1].Queue != "active" { + t.Errorf("second message = %+v", got[1]) + } + if len(parseQueueJSON(nil)) != 0 { + t.Error("an empty queue is not empty") + } +} + +// A queue that cannot be listed is an error, not an empty queue: the caller +// must not conclude that nothing is waiting. +func TestQueueMessagesReportsAFailedListing(t *testing.T) { + old := readQueueJSON + t.Cleanup(func() { readQueueJSON = old }) + readQueueJSON = func() ([]byte, error) { return nil, errors.New("postqueue: Permission denied") } + + if msgs, err := QueueMessages(); err == nil { + t.Fatalf("no error for a failed listing (got %v)", msgs) + } +}