mix/selfpost
1
0
Fork 0
Code Issues Pull Requests Actions 3 Packages Projects Releases Wiki Activity

feat(panel): lay a delivery's log lines out as a table

Browse Source 
The lines came out as one block of preformatted text, which is what the
system log page does with a tail of mail.log — right there, where the
lines are unrelated to each other and the block is the log itself. Here
they are one message's six or seven lines, and what is read off them is
the pace: the second between the connection and the banner, the ten
between DATA and the reply. Run together, every line began with a
different-width stamp and none of those numbers lined up.

So they are two columns now, when and what, the same shape the send log
itself has. logtail.SplitTimestamp takes the stamp off the head of a
line: postlogd's format, which is what this server writes, and syslog's
traditional one for a deployment that routes the log through syslogd
instead. The stamp loses its microseconds and its offset — five decimal
places are the widest part of the column and the least worth reading —
but is not converted, so the page shows the log's own wall clock rather
than a claim about which zone it was in.

A line whose head is not a stamp either parser recognises keeps its whole
text in the second column and leaves the first empty. The format is the
log's, not ours; a line we cannot split is a line we must not drop, and
the test says so.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
mixeme
2026-08-08 10:22:29 +03:00
parent cf7587754f
commit 43841790d4
7 changed files with 187 additions and 21 deletions
Download Patch File Download Diff File Expand all files Collapse all files
internal/logtail/logtail.go
+31
View File
@@ -280,6 +280,37 @@ func isQueueIDByte(b byte) bool {
return b >= '0' && b <= '9' || b >= 'A' && b <= 'Z' || b >= 'a' && b <= 'z'
}
// Timestamps at the head of a mail.log line. The first is what Postfix's own
// postlogd writes, which is what this server runs (maillog_file in
// build/postfix-config.sh) — RFC 3339 down to microseconds and with an offset.
// The second is syslog's traditional format, for a deployment that routes the
// log through syslogd instead; it carries no year and no zone, which is why it
// is not the one being matched first.
var (
isoStampRe = regexp.MustCompile(`^(\d{4}-\d{2}-\d{2})T(\d{2}:\d{2}:\d{2})(?:\.\d+)?(?:Z|[+-]\d{2}:?\d{2})?\s`)
syslogStampRe = regexp.MustCompile(`^([A-Z][a-z]{2}\s+\d{1,2} \d{2}:\d{2}:\d{2})\s`)
)
// SplitTimestamp separates the timestamp at the head of a mail.log line from
// the rest of it, so a page can put the two in their own columns. The stamp
// comes back without its fractional seconds and zone offset — five decimal
// places of microsecond are the widest part of the column and the least worth
// reading — but is otherwise the log's own wall clock, not converted: what is
// on the page is what is in the file.
//
// A line whose head is not a timestamp this recognises comes back whole, as
// rest, with an empty stamp. Nothing is ever dropped: the point of showing the
// log is that it says what it says.
func SplitTimestamp(line string) (stamp, rest string) {
if m := isoStampRe.FindStringSubmatch(line); m != nil {
return m[1] + " " + m[2], strings.TrimSpace(line[len(m[0]):])
}
if m := syslogStampRe.FindStringSubmatch(line); m != nil {
return m[1], strings.TrimSpace(line[len(m[0]):])
}
return "", line
}
// follow tails path line by line, calling handle for each complete line, until
// ctx is cancelled. Where it starts is tr's decision (a persisted offset, the
// start of a file that changed while the panel was down, or end-of-file on a
internal/logtail/logtail_test.go
+61
View File
@@ -454,3 +454,64 @@ func TestQueueLinesReadsABoundedTail(t *testing.T) {
t.Errorf("got %d lines, want only the one inside the budget:\n%s", len(lines), strings.Join(lines, "\n"))
}
}
// The delivery page shows a message's lines as a table of when and what, so the
// timestamp has to come off the head of the line — in either of the two formats
// a mail log arrives in — and nothing may be lost doing it.
func TestSplitTimestamp(t *testing.T) {
cases := []struct {
name string
line string
stamp, rest string
}{
{
name: "postlogd, which is what this server writes",
line: "2026-08-03T05:15:52.219218+00:00 mail postfix/smtp[26]: 4A1B2C3D: to=<a@example.net>, status=sent (250 OK)",
stamp: "2026-08-03 05:15:52",
rest: "mail postfix/smtp[26]: 4A1B2C3D: to=<a@example.net>, status=sent (250 OK)",
},
{
name: "no fractional seconds, zone as Z",
line: "2026-08-03T05:15:52Z mail postfix/qmgr[10]: 4A1B2C3D: removed",
stamp: "2026-08-03 05:15:52",
rest: "mail postfix/qmgr[10]: 4A1B2C3D: removed",
},
{
name: "no zone at all",
line: "2026-08-03T05:15:52 mail opendkim[30]: 4A1B2C3D: DKIM-Signature field added",
stamp: "2026-08-03 05:15:52",
rest: "mail opendkim[30]: 4A1B2C3D: DKIM-Signature field added",
},
{
name: "syslog's traditional format, padded day",
line: "Aug 3 05:15:52 mail postfix/smtpd[20]: 4A1B2C3D: client=app.example.ru[203.0.113.4]",
stamp: "Aug 3 05:15:52",
rest: "mail postfix/smtpd[20]: 4A1B2C3D: client=app.example.ru[203.0.113.4]",
},
{
name: "unrecognised head keeps the whole line",
line: "mail postfix/smtp[26]: 4A1B2C3D: to=<a@example.net>, status=sent (250 OK)",
stamp: "",
rest: "mail postfix/smtp[26]: 4A1B2C3D: to=<a@example.net>, status=sent (250 OK)",
},
{
// A date-like run that is not the head of the line is not a stamp.
name: "date inside the text is left alone",
line: "mail postfix/smtp[26]: ABC: 220 mx.example.net ready at 2026-08-03T05:15:52+00:00",
stamp: "",
rest: "mail postfix/smtp[26]: ABC: 220 mx.example.net ready at 2026-08-03T05:15:52+00:00",
},
}
for _, c := range cases {
t.Run(c.name, func(t *testing.T) {
stamp, rest := SplitTimestamp(c.line)
if stamp != c.stamp || rest != c.rest {
t.Errorf("SplitTimestamp(%q) = (%q, %q), want (%q, %q)", c.line, stamp, rest, c.stamp, c.rest)
}
// Whatever the split, the line's own text survives it whole.
if !strings.Contains(c.line, rest) {
t.Errorf("the text column is not part of the line it came from: %q", rest)
}
})
}
}
internal/web/handlers_monitor.go
+26 -11
View File
@@ -85,7 +85,7 @@ func (s *Server) handleDelivery(w http.ResponseWriter, r *http.Request) {
return
}
row.Subject = mailhdr.DecodeSubject(row.Subject)
lines, logNote := s.deliveryLog(row)
logRows, logNote := s.deliveryLog(row)
s.render(w, http.StatusOK, "delivery", map[string]any{
"Title": "SelfPost — delivery",
"User": currentUser(r),
@@ -97,8 +97,8 @@ func (s *Server) handleDelivery(w http.ResponseWriter, r *http.Request) {
"Events": deliveryEvents(row),
// The mail.log lines for this message, and — when there are none — the
// reason, which is a normal outcome rather than a failure.
"LogLines": lines,
"LogNote": logNote,
"LogRows": logRows,
"LogNote": logNote,
// Where the row came from, so "Back" returns to the page and filters
// the operator was looking at rather than the top of an unfiltered log.
"BackURL": deliveriesBackURL(r),
@@ -207,13 +207,23 @@ func deliveryEvents(row store.SendLogRow) []deliveryEvent {
}
}
// deliveryLog reads the mail.log lines Postfix wrote about one message. The
// second return value is what to say when there are none: every reason for an
// empty result here is an ordinary one — the message never reached the queue,
// or its lines have aged out of the log — so none of them is an error on the
// page. Only a log that cannot be read at all is reported as a fault, and that
// one is logged for the operator as well.
func (s *Server) deliveryLog(row store.SendLogRow) ([]string, string) {
// deliveryLogRow is one mail.log line split for the table on the delivery
// page: when it was written, and what it says. Time is empty for a line whose
// head is not a timestamp the log format recognises — the line still shows, in
// full, under Message.
type deliveryLogRow struct {
Time string
Text string
}
// deliveryLog reads the mail.log lines Postfix wrote about one message and
// splits each into the two columns the page shows it in. The second return
// value is what to say when there are none: every reason for an empty result
// here is an ordinary one — the message never reached the queue, or its lines
// have aged out of the log — so none of them is an error on the page. Only a
// log that cannot be read at all is reported as a fault, and that one is
// logged for the operator as well.
func (s *Server) deliveryLog(row store.SendLogRow) ([]deliveryLogRow, string) {
if row.QueueID == "" {
return nil, "This message never reached the queue, so Postfix wrote no delivery lines for it."
}
@@ -228,7 +238,12 @@ func (s *Server) deliveryLog(row store.SendLogRow) ([]string, string) {
// left to show is the normal end state, not a fault.
return nil, "Nothing for this queue id in the current mail log. Its lines have most likely been rotated away."
}
return lines, ""
out := make([]deliveryLogRow, len(lines))
for i, line := range lines {
stamp, rest := logtail.SplitTimestamp(line)
out[i] = deliveryLogRow{Time: stamp, Text: rest}
}
return out, ""
}
// deliveriesBackURL rebuilds the delivery-log URL a detail page was opened
internal/web/handlers_monitor_test.go
+28 -6
View File
@@ -143,24 +143,46 @@ func TestDeliveryPageMarksAQueuedMessageAsStillWaiting(t *testing.T) {
// The queue id used to be printed as something to go and search the system log
// for by hand; the page does that search now, and shows only this message's
// lines.
// lines — as a table of when and what, so the seconds between the connection
// and the reply line up down one edge.
func TestDeliveryPageShowsThisMessagesLogLines(t *testing.T) {
s, row := serverWithDelivery(t)
s.cfg.MailLogPath = writeMailLog(t,
"host postfix/smtpd[20]: 4A1B2C3D: client=mail.example.com[203.0.113.4]",
"host postfix/qmgr[10]: 99999999: from=<other@example.ru>, size=500, nrcpt=1 (queue active)",
"host postfix/smtp[26]: 4A1B2C3D: to=<public@example.ru>, dsn=2.0.0, status=sent (250 OK)",
"2026-08-03T05:15:52.219218+00:00 host postfix/smtpd[20]: 4A1B2C3D: client=mail.example.com[203.0.113.4]",
"2026-08-03T05:15:52.300000+00:00 host postfix/qmgr[10]: 99999999: from=<other@example.ru>, size=500, nrcpt=1 (queue active)",
"2026-08-03T05:16:03.884210+00:00 host postfix/smtp[26]: 4A1B2C3D: to=<public@example.ru>, dsn=2.0.0, status=sent (250 OK)",
)
out := getBody(t, s.handleDelivery, "/deliveries/"+itoa(row.ID))
if !strings.Contains(out, "client=mail.example.com") || !strings.Contains(out, "status=sent (250 OK)") {
t.Errorf("delivery page does not show this message's log lines:\n%s", out)
for _, want := range []string{
"<th>Time</th>", "<th>Message</th>",
// The stamp is split off into its own cell, without the microseconds
// and the offset that make it the widest thing on the line.
`<td class="time muted">2026-08-03 05:15:52</td>`,
`<td class="time muted">2026-08-03 05:16:03</td>`,
"client=mail.example.com", "status=sent (250 OK)",
} {
if !strings.Contains(out, want) {
t.Errorf("delivery log table is missing %q:\n%s", want, out)
}
}
if strings.Contains(out, "99999999") {
t.Errorf("delivery page shows another message's log line:\n%s", out)
}
}
// A line whose head is not a timestamp still has to show in full; the format is
// the log's, not ours, and a line we cannot split is a line we must not drop.
func TestDeliveryPageKeepsAnUnstampedLogLineWhole(t *testing.T) {
s, row := serverWithDelivery(t)
s.cfg.MailLogPath = writeMailLog(t, "host postfix/smtp[26]: 4A1B2C3D: to=<public@example.ru>, status=sent (250 OK)")
out := getBody(t, s.handleDelivery, "/deliveries/"+itoa(row.ID))
if !strings.Contains(out, "host postfix/smtp[26]: 4A1B2C3D: to=&lt;public@example.ru&gt;, status=sent (250 OK)") {
t.Errorf("an unstamped log line did not survive the split into columns:\n%s", out)
}
}
// Rows outlive mail.log, and a message the milter refused never reached the
// queue at all. Neither is a fault, so neither may render as an error.
func TestDeliveryPageExplainsAnEmptyDeliveryLog(t *testing.T) {
internal/web/static/panel.css
+16
View File
@@ -468,6 +468,22 @@ h1.subject { overflow-wrap: anywhere; }
.event-time { margin: 0; font-size: 0.75rem; color: #6b7280; }
.event-title { display: flex; flex-wrap: wrap; align-items: center; gap: 0.4rem; margin: 0.15rem 0 0; font-weight: 600; }
.event-detail { margin: 0.2rem 0 0; font-size: 0.9rem; }
/* A message's own mail.log lines, as a table of when and what. The time column
is sized to its content — width:1% is as narrow as the automatic layout will
take a column, which with the nowrap on td.time settles on exactly the stamp
— so everything left over goes to the text, which is the column that needs
it. */
table.log { margin-top: 1rem; }
table.log th:first-child, table.log td.time { width: 1%; }
/* The log's own text: monospace, because it is full of addresses, response
codes and identifiers that are compared character by character rather than
read as words. pre-wrap keeps the spacing a server's reply was written with
while still letting a long line wrap inside the cell instead of widening it
(the th/td rule above allows the break). */
table.log td.log-text {
font-family: ui-monospace, SFMono-Regular, Menlo, monospace;
font-size: 0.8rem; white-space: pre-wrap;
}
/* Compact outlined button: same affordance as the filled one but quiet enough
that several can sit together without shouting — the Copy buttons beside a
value, the controls of a table row or of an application block. Sign out
internal/web/templates/delivery.html
+19 -3
View File
@@ -98,9 +98,25 @@
message's queue id are shown; the whole log is on the
<a href="/system-log">System log</a> page.</p>
{{if .LogLines}}
<span class="code">{{range .LogLines}}{{.}}
{{end}}</span>
{{if .LogRows}}
{{/* Two columns, the way the send log itself is a table: the times down one
edge are what the message's pace is read off — the seconds between the
connection and the reply — and lining them up is what makes that
readable. A line whose head was not a timestamp keeps its whole text in
the second column and leaves the first empty. */}}
<table class="log">
<thead>
<tr><th>Time</th><th>Message</th></tr>
</thead>
<tbody>
{{range .LogRows}}
<tr>
<td class="time muted">{{if .Time}}{{.Time}}{{else}}—{{end}}</td>
<td class="log-text">{{.Text}}</td>
</tr>
{{end}}
</tbody>
</table>
{{else}}
<p class="muted">{{.LogNote}}</p>
{{end}}