mixandClaude Opus 5.5
af130e268a
Technical review (Opus) and security review (Fable) of 5be109b..5154bba;
reports in the session's scratchpad. Nothing above low from security; one
bug and three risks from the technical review. Migration 0009 is not
deployed, so it was extended.
- Bug: two refusals of one second swapped their NOQUEUE lines (each line
went to the newest lineless row). AttachRefusalLine now matches the
client address too (send_log.client_ip, written by the journal milter -
Postfix's line names the client and the sender, never the login: the
sasl_username part of the pattern never matched and could be fed by HELO,
security F1/F2), takes the nearest row in time and the oldest of equals,
and a line already on a row goes on no other (security F6).
- Waiting lines and recoveries lived only in memory while the saved offset
moved past them: a stop within 30 s lost them. The tracker now never saves
an offset past the oldest waiting item in its file (tracker.hold,
refusalLines.oldest) - for a recovery, the client= line that names its
login - so they are read again; the "once" guards make that harmless.
- A recovered row whose login the tailer did not see was nobody's: its
domain_id falls back to the envelope domain's.
- The fingerprint's file identity is the inode alone: the device number can
change across a host reboot and make the same log look rotated.
- A refused row carries its queue id; UpdateStatus's "newest row" now skips
refused rows, so a later message with that id does not flip it to sent.
- The alive mark: its age is read first and kept from then on, so asking
supervisord for 30 s cannot make it stale; the entrypoint removes it with
the sockets - a container restart is not the check's downtime, and a mark
from before would have counted the whole outage as "≈".
- Security F3: the sender check prints no ";" of the client's in the From:
text of its reply, and the tailer reads the envelope after the first ";"
- Postfix's own text.
- A refused row with a queue id and no stored lines says so (it was told the
mail.log text of 2.2.0); the fact's em dash is the house hyphen.
- Docs: architecture (client address, no login), guide § Health (warns on
either count), help topics log and sender-check (design 1ca87f2).
- e2e: refusals_show_postfixs_line wants the refusal's own sender in the
line; refusal_recovered_from_the_log waits past the tailer's 30 s and
checks that a refusal the panel wrote got no recovered twin.
Not changed, written down: review 9 (mail.log.1 read to its end at that
moment; postlogd may still write to it until the reload), 10 (a log under
512 bytes has no fingerprint, so places fall back to time briefly after a
rotation), 6 (a 451 at MAIL FROM of another milter reads the same - the
client and sender must match too now), security F5/F12 (info). Review 12:
the refused and closed-by-the-panel variants of out-message were shown to
the owner as pictures of the real templates, not drawn in out-message.html:
the guard ties every drawn screen to a page of the engine, and a variant
has the page's outline.
Evidence on the test server for this tree: go vet clean, go test ./... 23
packages ok, make e2e exit 0 (refusal_recovered_from_the_log 70 s).
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
220 lines
13 KiB
Go
220 lines
13 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-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, "", "")
|
|
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, "", "").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"}, "shop.example.org", "alerts")
|
|
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)
|
|
pageHas(t, "Outbound log", out,
|
|
`<option value="shop.example.org" selected>shop.example.org</option>`, `<option value="alerts" selected>alerts</option>`,
|
|
`hx-get="/outbound/log/fragment?app=alerts&domain=shop.example.org&p=3"`,
|
|
`href="/outbound/log/7?app=alerts&domain=shop.example.org&p=3"`,
|
|
`Page 3 of 5 · <a href="/outbound/log?app=alerts&domain=shop.example.org&p=2">← Newer</a>`,
|
|
`<a href="/outbound/log?app=alerts&domain=shop.example.org&p=4">Older →</a>`,
|
|
)
|
|
if got := LogHref("", "", 1); got != "/outbound/log" {
|
|
t.Errorf("the first unfiltered page is %q", got)
|
|
}
|
|
if got := LogHref("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, "", "")
|
|
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, "", "").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>`}, "", "")
|
|
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, `<script>alert(1)</script>`)
|
|
}
|
|
|
|
// ---- 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=<noc@example.org>`,
|
|
)
|
|
}
|
|
|
|
// 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&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)
|
|
}
|
|
}
|