Files
selfpost/internal/web/view/outbound_log_test.go
T
mixandClaude Opus 5.5 2b8e0c086d
test / test (push) Canceled after 0s
audit 4: a deleted domain says so, the Outbound log filters by status and day
L17: past DeleteDomain both rebuilds run, their errors joined under
domain.ErrDeletedIncomplete; the key is removed only when OpenDKIM's tables
were rebuilt (they may still name it otherwise); the domain list says the
domain is deleted and that Reload configuration finishes it, not "internal
error". Tests in domain (the tables failing, the sender map failing) and
handlers.

The Outbound log's status and day filters (owner, 2026-10-13; the mockup
first, 80e3979): view.OutLogFilter carried by the poll, the pages, the rows'
links and the message's way back; SendLogFilter.Status, Since, Until (whole
UTC days, as the Inbound log's); rejected is the three refusals together; a
status not in the list is no narrowing. Tests: the filters through the
handler, the poll and the way back; the day boundaries in store.

The plan's milter-socket step is ticked: done in 2.5.2 (98e09fe).

Tested on the test server: go vet + go test of 25 packages, make e2e (all
pass, 642 s) on this tree.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-15 11:34:24 +03:00

229 lines
14 KiB
Go

package view
import (
"strings"
"testing"
"time"
)
// ---- The log
// The log is the whole of what the journal holds about the viewer's mail: the
// filters offer what the viewer reaches, the head says how long rows live and
// where to change it, and every row leads to its own page.
func TestOutLogShowsTheRowsAndTheirFilters(t *testing.T) {
out := renderSignedIn(t, "out-log", outLogFixture())
pageHas(t, "Outbound log", out,
`<h1 class="title is-3">Outbound log</h1>`,
`Rows older than 30 days are deleted — change that in <a href="/server/settings">Settings</a>.`,
`<form class="sp-end" method="get" action="/outbound/log">`,
`<select name="domain" aria-label="Domain"><option value="" selected>All domains</option><option value="example.org">example.org</option>`,
`<select name="app" aria-label="Application"><option value="" selected>All applications</option>`,
`<th>Time, UTC</th>`, `09-21 14:01:52`,
`shop@<wbr>shop.example.org`, `m.keller@<wbr>gmx.de`, `title="[FIRING] disk usage above 90 % on db-2"`,
`<span class="tag is-success is-light">sent</span>`, `<span class="tag is-warning is-light">deferred</span>`,
`<span class="tag is-danger is-light">bounced</span>`, `<span class="tag is-danger is-light">rate-limited</span>`, `<span class="tag is-danger is-light">wrong From</span>`,
`href="/outbound/log/184220">Details</a>`,
`Page 1 of 412`, `<a href="/outbound/log?p=2">Older →</a>`, `New rows appear on their own`,
)
pageLacks(t, "Outbound log", out, `← Newer`)
// Without the global role there is nowhere to change the retention.
p := NewOutLog(Meta{User: "ops", HasOutbound: true}, 7, false, []string{"example.org"}, nil, OutLogFilter{})
out = renderSignedIn(t, "out-log", p.WithRows(nil, 1, 1))
pageHas(t, "Outbound log", out, `Rows older than 7 days are deleted.`)
pageLacks(t, "Outbound log", out, `/server/settings`)
pageLacks(t, "Outbound log", renderSignedIn(t, "out-log", NewOutLog(Meta{User: "ops", HasOutbound: true}, 1, false, nil, nil, OutLogFilter{}).WithRows(nil, 1, 1)),
`older than 1 days`)
}
// The filter in force is the one selected, and the poll, the paging and the
// links of the rows all carry it — and say nothing for a filter that is not set.
func TestOutLogCarriesItsFilters(t *testing.T) {
p := NewOutLog(admin(), 30, true, []string{"example.org", "shop.example.org"}, []string{"alerts"}, OutLogFilter{Domain: "shop.example.org", App: "alerts", Status: "rejected", From: "2026-09-14", To: "2026-09-21"})
p.WithRows([]OutLogRow{{Time: "09-21 14:01:52", From: "a@example.org", To: "b@example.org", Subject: "Hi",
Status: Tag{Status: "sent"}, Href: p.DetailHref(7, 3)}}, 3, 5)
out := renderSignedIn(t, "out-log", p)
// The keys in order (url.Values.Encode sorts them), the page among them.
q := func(page string) string {
return `app=alerts&amp;domain=shop.example.org&amp;from=2026-09-14&amp;p=` + page + `&amp;status=rejected&amp;to=2026-09-21`
}
pageHas(t, "Outbound log", out,
`<option value="shop.example.org" selected>shop.example.org</option>`, `<option value="alerts" selected>alerts</option>`,
`<option value="rejected" selected>rejected</option>`, `<option value="queued">queued</option>`,
`name="from" value="2026-09-14"`, `name="to" value="2026-09-21"`,
`hx-get="/outbound/log/fragment?`+q("3")+`"`,
`href="/outbound/log/7?`+q("3")+`"`,
`Page 3 of 5 · <a href="/outbound/log?`+q("2")+`">← Newer</a>`,
`<a href="/outbound/log?`+q("4")+`">Older →</a>`,
)
// The status list is the statuses of a row, rejected the three refusals
// together; a reason is not a status (owner, 2026-10-13).
pageLacks(t, "Outbound log", out, `<option value="rate-limited"`)
if got := LogHref(OutLogFilter{}, 1); got != "/outbound/log" {
t.Errorf("the first unfiltered page is %q", got)
}
if got := LogHref(OutLogFilter{Domain: "a b&c"}, 2); got != "/outbound/log?domain=a+b%26c&p=2" {
t.Errorf("a filter is not encoded: %q", got)
}
}
// The last page has nothing older, and a page with no rows says so and still
// polls: a log that is empty now is the one that fills while the page is open.
func TestOutLogLastPageAndEmptyPage(t *testing.T) {
p := NewOutLog(admin(), 30, true, nil, nil, OutLogFilter{})
out := renderSignedIn(t, "out-log", p.WithRows([]OutLogRow{{Subject: "x", Status: Tag{Status: "sent"}, Href: "/outbound/log/1"}}, 2, 2))
pageHas(t, "Outbound log", out, `Page 2 of 2`, `← Newer</a>`)
pageLacks(t, "Outbound log", out, `Older →`)
out = renderSignedIn(t, "out-log", NewOutLog(admin(), 30, true, nil, nil, OutLogFilter{}).WithRows(nil, 1, 1))
pageHas(t, "Outbound log", out, `No messages logged yet.`, `id="out-log-rows"`, `data-poll`, `id="out-log-foot"`, `New rows appear on their own`)
pageLacks(t, "Outbound log", out, `<table`, `Page 1`)
}
// The fragment is the table and, marked to be swapped in by its id, the foot;
// the page's own foot carries the id and no mark.
func TestOutLogFragmentMarksOnlyTheFoot(t *testing.T) {
page := renderSignedIn(t, "out-log", outLogFixture())
frag := renderFragment(t, "out_log_rows", outLogFixture().Fragment())
pageHas(t, "fragment", frag, `<div class="table-container" id="out-log-rows" data-poll`, `<div class="sp-box-foot" id="out-log-foot" hx-swap-oob="true">`)
pageLacks(t, "fragment", frag, `<form`, `<select`, `sp-head`)
pageLacks(t, "page", page, `hx-swap-oob`)
pageHas(t, "page", page, `<div class="sp-box-foot" id="out-log-foot">`)
if strings.Count(frag, `<table`) != 1 {
t.Errorf("the fragment holds %d tables", strings.Count(frag, `<table`))
}
}
func TestOutLogEscapesWhatSendersWrote(t *testing.T) {
p := NewOutLog(admin(), 30, true, []string{`<b>d</b>`}, []string{`"><i>`}, OutLogFilter{})
p.WithRows([]OutLogRow{{Time: "t", From: `"><img src=x>@a`, To: `<u>@b`, Subject: `<script>alert(1)</script>`,
Status: Tag{Status: `<i>`}, Href: "/outbound/log/1"}}, 1, 1)
out := renderSignedIn(t, "out-log", p)
pageLacks(t, "Outbound log", out, `<script>alert`, `<img src=x>`, `<b>d</b>`, `<u>@b`, `<i>`)
pageHas(t, "Outbound log", out, `&lt;script&gt;alert(1)&lt;/script&gt;`)
}
// ---- One message
func TestOutMessageShowsWhatTheJournalRecorded(t *testing.T) {
out := renderSignedIn(t, "out-message", outMessageFixture())
pageHas(t, "Message", out,
`<h1 class="title is-4">[FIRING] disk usage above 90 % on db-2</h1>`,
`<a href="/outbound/log">Outbound log</a> /`,
`<p class="sp-route"><span>alerts@example.org</span><i class="ti ti-arrow-right sp-muted"></i><span>noc@example.org</span><span class="tag is-warning is-light">deferred</span></p>`,
`<a href="/outbound/domains/1">example.org</a>`, `<dd class="sp-mono"><a href="/outbound/domains/1/applications/2">alerts</a></dd>`,
`2026-09-21 13:58:07 UTC`, `2026-09-21 13:58:09 UTC`, `<dd class="sp-mono">4XcB7k2Jm9z1</dd>`, `<dd class="sp-mono">184220</dd>`,
`<li><time>2026-09-21 13:58:07 UTC</time><strong>Accepted and queued</strong>`,
`<li class="sp-warn"><time>2026-09-21 13:58:09 UTC</time><strong>Deferred, will be retried</strong>`,
`<li class="sp-pending"><time>not yet</time>`,
`Lines from <code>mail.log</code> with this queue id`, `<pre class="sp-log">`, `<span class="sp-d">13:58:07</span> postfix/smtpd[2114]`,
`<span class="sp-w">postfix/smtp[2123]: 4XcB7k2Jm9z1: to=&lt;noc@example.org&gt;`,
)
}
// A message without a subject is named for it, and a row with nothing to show
// for a field shows a dash. A refused row has no queue id and says so; one
// from before the reason was recorded is plainly "rejected".
func TestOutMessageWithoutSubjectOrRecipient(t *testing.T) {
at := time.Date(2026, 9, 21, 13, 58, 7, 0, time.UTC)
p := NewOutMessage(admin(), MessageInput{ID: 9, Domain: "gone.example", App: "old", Status: "rejected", Accepted: at, Reported: at,
BackHref: "/outbound/log?domain=gone.example&p=2"}).
WithDeliveryLog(nil, "This message never reached the queue, so Postfix wrote no delivery lines for it.")
out := renderSignedIn(t, "out-message", p)
pageHas(t, "Message", out, `<h1 class="title is-4">(no subject)</h1>`, `<span>—</span><i class="ti ti-arrow-right sp-muted"></i><span>—</span>`,
`<span class="tag is-light">rejected</span>`, `href="/outbound/log?domain=gone.example&amp;p=2"`,
`<dd>gone.example</dd>`, `<dd class="sp-mono">old</dd>`, `<dt>Refused</dt>`,
`<dd>none - refused at <span class="sp-mono">MAIL FROM</span>, before one is given</dd>`,
`The line from <code>mail.log</code> for this refusal`, `never reached the queue`)
pageLacks(t, "Message", out, `<pre`, `<a href="/outbound/domains/`, `Status reported`, `From: line`)
}
// A row refused for its From: line says so in its tag, shows what the line
// said, and its History links to the topic that explains the rule. The
// message had a queue id - cleanup gives one before the headers are judged -
// and its box shows Postfix's lines by it, the refusal red.
func TestOutMessageRefusedForItsFromLine(t *testing.T) {
at := time.Date(2026, 9, 21, 13, 40, 55, 0, time.UTC)
p := NewOutMessage(admin(), MessageInput{ID: 184231, QueueID: "7BCAF3C75DA0", Domain: "shop.example.org", App: "shop",
From: "shop@shop.example.org", To: "k.berg@web.de", Subject: "A message from the director",
Status: "rejected", Reason: "from", HeaderFrom: "director@example.org", Accepted: at, Reported: at}).
WithDeliveryLog([]LogLine{{Time: "13:40:55", Text: "postfix/cleanup[2120]: 7BCAF3C75DA0: milter-reject: END-OF-MESSAGE from unknown[198.51.100.7]: 5.7.1 From: director@example.org - not an address this application sends as",
Level: LogLineLevel("postfix/cleanup[2120]: 7BCAF3C75DA0: milter-reject: END-OF-MESSAGE from unknown[198.51.100.7]: 5.7.1 From: director@example.org - not an address this application sends as")}}, "")
out := renderSignedIn(t, "out-message", p)
pageHas(t, "Message", out, `<span class="tag is-danger is-light">wrong From</span>`,
`<dt>From: line</dt><dd class="sp-mono sp-small">director@example.org</dd>`, `<dt>Refused</dt>`,
`<span class="sp-mono">7BCAF3C75DA0</span> - given, the message was not queued`, `href="/help#sender-check"`,
`Lines from <code>mail.log</code> with this queue id`, `<span class="sp-e">postfix/cleanup[2120]: 7BCAF3C75DA0: milter-reject`)
}
// A refused row the log tailer wrote from mail.log says so.
func TestOutMessageRecoveredFromTheLog(t *testing.T) {
at := time.Date(2026, 9, 21, 13, 40, 55, 0, time.UTC)
p := NewOutMessage(admin(), MessageInput{ID: 184232, QueueID: "E543D3C75DA0", Domain: "shop.example.org", App: "shop",
From: "shop@shop.example.org", To: "k.berg@web.de", Status: "rejected", Reason: "from", HeaderFrom: "director@example.org",
Recovered: true, Accepted: at, Reported: at}).WithDeliveryLog(nil, "")
out := renderSignedIn(t, "out-message", p)
pageHas(t, "Message", out, `<dt>Written</dt>`, `after a restart: the panel stopped before it wrote the refusal`)
}
func TestSendLogTag(t *testing.T) {
for _, c := range []struct {
status, reason string
want Tag
}{
{"sent", "", Tag{Status: "sent"}},
{"rejected", "", Tag{Status: "rejected"}},
{"rejected", "limit", Tag{Status: "rate-limited"}},
{"rejected", "from", Tag{Status: "reject", Label: "wrong From"}},
{"rejected", "client", Tag{Status: "reject", Label: "wrong client"}},
} {
if got := SendLogTag(c.status, c.reason); got != c.want {
t.Errorf("SendLogTag(%q, %q) = %+v, want %+v", c.status, c.reason, got, c.want)
}
}
}
func TestOutMessageEscapesWhatSendersWrote(t *testing.T) {
at := time.Now()
p := NewOutMessage(admin(), MessageInput{ID: 1, QueueID: `"><i>`, Domain: `<b>d</b>`, App: `<u>a</u>`, From: `<s>f</s>`, To: `"><img src=x>`,
Subject: `<script>alert(1)</script>`, Status: "sent", Accepted: at, Reported: at, BackHref: "/outbound/log"}).
WithHistory([]Step{{Time: "t", Strong: `<b>s</b>`, Text: Plain(`<i>x</i>`)}}).
WithDeliveryLog([]LogLine{{Time: `<u>`, Text: `<script>y</script>`}}, "")
out := renderSignedIn(t, "out-message", p)
pageLacks(t, "Message", out, `<script>alert`, `<script>y`, `<b>d</b>`, `<u>a</u>`, `<s>f</s>`, `<img src=x>`, `<b>s</b>`, `<i>x</i>`, `<u>`)
}
func TestStepLevelAndLogLineLevel(t *testing.T) {
for _, c := range []struct {
outcome string
happened bool
want string
}{
{"ok", true, ""}, {"", true, ""}, {"warn", true, LevelWarn}, {"error", true, LevelFail},
{"", false, LevelPending}, {"error", false, LevelPending},
} {
if got := StepLevel(c.outcome, c.happened); got != c.want {
t.Errorf("StepLevel(%q, %v) = %q, want %q", c.outcome, c.happened, got, c.want)
}
}
for text, want := range map[string]string{
"postfix/smtp[1]: Q1: to=<a@b>, status=sent (250 OK)": "",
"postfix/smtp[1]: Q1: to=<a@b>, status=deferred (try later)": "warn",
"postfix/smtp[1]: Q1: to=<a@b>, status=bounced (no such user)": "error",
"postfix/qmgr[1]: Q1: status=expired, returned to sender": "error",
"postfix/smtp[1]: warning: TLS library problem": "warn",
"opendkim[1]: Q1: DKIM-Signature field added": "",
"postfix/cleanup[1]: Q1: milter-reject: END-OF-MESSAGE from unknown[10.77.0.1]: 5.7.1 From: x - no": "error",
"postfix/smtpd[1]: NOQUEUE: milter-reject: MAIL from unknown[10.77.0.1]: 451 4.7.1 Service unavailable": "warn",
"postfix/smtpd[1]: NOQUEUE: reject: RCPT from unknown[2001:db8::1]: 554 5.7.1 <a@b>: Relay access denied": "error",
} {
if got := LogLineLevel(text); got != want {
t.Errorf("LogLineLevel(%q) = %q, want %q", text, got, want)
}
}
if got := StepTime(time.Time{}); got != "not yet" {
t.Errorf("a step that has not happened is at %q", got)
}
}