selfpost/internal/web/handlers/handlers_monitor.go

package handlers

import (
	"errors"
	"fmt"
	"io/fs"
	"net/http"
	"net/url"
	"sort"
	"strconv"
	"time"

	"github.com/mixeme/selfpost/internal/logtail"
	"github.com/mixeme/selfpost/internal/mailhdr"
	"github.com/mixeme/selfpost/internal/postfix"
	"github.com/mixeme/selfpost/internal/store"
	"github.com/mixeme/selfpost/internal/web/auth"
)

// sendLogPageSize bounds each send-log page (product.md's monitoring screens
// call for pagination); logTailLines bounds how much of mail.log the log view
// shows per refresh, and deliveryLogLines how many of one message's own lines
// its page shows.
const (
	sendLogPageSize  = 50
	logTailLines     = 200
	deliveryLogLines = 200
)

// HandleDeliveries renders the Deliveries page over the send log: server-side
// filters by domain/application and pagination (architecture.md §
// Persistence). The row table itself is the "deliveries_rows" fragment, shared
// verbatim with HandleDeliveriesRows so the initial page and its HTMX-polled
// refreshes never diverge.
func (h *Handlers) HandleDeliveries(w http.ResponseWriter, r *http.Request) {
	data, err := h.sendLogData(r)
	if err != nil {
		logf("panel: send log: %v", err)
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	data["Title"] = "SelfPost — deliveries"
	for k, v := range h.pageBase(r) {
		data[k] = v
	}
	data["Active"] = "deliveries"
	h.view.Render(w, http.StatusOK, "deliveries", data)
}

// HandleDeliveriesRows serves the HTMX polling fragment for the delivery table
// (architecture.md § Panel HTTP surface: fragment endpoints return HTML, not
// JSON).
func (h *Handlers) HandleDeliveriesRows(w http.ResponseWriter, r *http.Request) {
	data, err := h.sendLogData(r)
	if err != nil {
		logf("panel: send log rows: %v", err)
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	h.view.RenderFragment(w, http.StatusOK, "deliveries_rows", data)
}

// HandleDelivery renders one send-log row in full. The log itself carries only
// what identifies a message at a glance — when, who to and from, what about,
// how it ended — and every remaining field (domain, application, queue id, when
// the status was last reported) lives here, one page per row, so widening the
// journal never costs the table a column.
//
// The page answers the question the log raises rather than restating it: what
// the journal recorded, in what order it happened, and what Postfix itself
// wrote about the message. So it is three blocks — the message's own facts and
// its history side by side, and the mail.log lines for its queue id under both.
// The queue id used to be printed here as something to go and search the system
// log for by hand; the search is done for the operator instead.
func (h *Handlers) HandleDelivery(w http.ResponseWriter, r *http.Request) {
	id, err := strconv.ParseInt(r.PathValue("id"), 10, 64)
	if err != nil || id <= 0 {
		http.NotFound(w, r)
		return
	}
	row, err := h.store.GetSendLog(id)
	if err != nil {
		// A row pruned on the retention window is gone, not broken.
		if errors.Is(err, store.ErrSendLogNotFound) {
			http.NotFound(w, r)
			return
		}
		logf("panel: delivery %d: %v", id, err)
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	p, ok := h.principal(r)
	if !ok {
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	if !p.IsGlobal() {
		allowed, err := h.assignedDomains(p)
		if err != nil {
			http.Error(w, "internal error", http.StatusInternalServerError)
			return
		}
		if !domainNameSet(allowed)[row.Domain] {
			http.NotFound(w, r)
			return
		}
	}
	row.Subject = mailhdr.DecodeSubject(row.Subject)
	logRows, logNote := h.deliveryLog(row)
	h.view.Render(w, http.StatusOK, "delivery", map[string]any{
		"Title":                "SelfPost — delivery",
		"User":                 auth.CurrentUser(r),
		"Active":               "deliveries",
		"IsGlobal":             p.IsGlobal(),
		"SendLogRetentionDays": h.sendLogRetentionDays(),
		"Row":                  row,
		// The status in the panel's own badge vocabulary, so the headline reads
		// the same way as every other health signal in the panel.
		"Level":  deliveryLevel(row.Status),
		"Events": deliveryEvents(row, h.cfg.RetryPolicy),
		// The mail.log lines for this message, and — when there are none — the
		// reason, which is a normal outcome rather than a failure.
		"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),
	})
}

// deliveryLevel maps a send-log status onto the ok/warn/error/unknown badge
// vocabulary the status page and the DNS checks already use (see .st in
// panel.css), so a colour means the same thing on every page: delivered is the
// good outcome, deferred is not settled yet, and the two refusals are failures.
// A queued row is "unknown" rather than "warn" — nothing has gone wrong, it is
// simply that nothing has been reported.
func deliveryLevel(status string) string {
	switch status {
	case store.StatusSent:
		return "ok"
	case store.StatusDeferred:
		return "warn"
	case store.StatusBounced, store.StatusRejected:
		return "error"
	default:
		return "unknown"
	}
}

// sendLogRow is a row of the send log as the table draws it: the stored row
// plus the badge level its status maps onto. The level is carried rather than
// derived in the template because deliveryLevel is the one place that decides
// what a status means — the delivery page already reads it, and a second
// mapping written in the template or the stylesheet would be free to drift
// from it.
type sendLogRow struct {
	store.SendLogRow
	Level string // ok / warn / error / unknown, as deliveryLevel returns
}

// deliveryEvent is one step of a message's history, as the timeline on the
// delivery page draws it. At is zero for the step that has not happened yet —
// the delivery report a queued message is still waiting for.
type deliveryEvent struct {
	At     time.Time
	Level  string // ok / warn / error / unknown, as deliveryLevel returns
	Status string // the send-log status value this step reached
	Title  string
	Detail string
}

// deliveryEvents turns a row's two timestamps into the history the page shows.
// The journal keeps no event table — a row is created when the message is
// accepted and updated once when Postfix reports the attempt — so the two
// timestamps *are* the history, and stating them as steps is what makes a row
// whose created_at and updated_at differ by six hours legible as "queued for
// six hours, then delivered" rather than as two dates in a list of fields.
// policy supplies the human intervals for deferred and bounced copy, the same
// strings the Mail queue card prints, so the two cannot drift.
func deliveryEvents(row store.SendLogRow, policy postfix.RetryPolicy) []deliveryEvent {
	// A rejected message has no second step, and its first one is not an
	// acceptance: the journal-milter refused it, so Postfix never queued it.
	if row.Status == store.StatusRejected {
		return []deliveryEvent{{
			At:     row.CreatedAt,
			Level:  "error",
			Status: store.StatusRejected,
			Title:  "Refused before queueing",
			Detail: "The journal-milter refused the message under a rate limit. It was never queued, so there is no queue id and Postfix never attempted delivery.",
		}}
	}

	events := []deliveryEvent{{
		At:     row.CreatedAt,
		Level:  "unknown",
		Status: store.StatusQueued,
		Title:  "Accepted and queued",
		Detail: "Postfix accepted the message over an authenticated submission and the journal-milter recorded it. Delivery to the recipient had not been attempted yet.",
	}}

	switch row.Status {
	case store.StatusQueued:
		// The step that has not happened. Drawn as an open dot with no time.
		return append(events, deliveryEvent{
			Level:  "unknown",
			Status: store.StatusQueued,
			Title:  "Waiting for a delivery report",
			Detail: "Postfix has not reported an attempt for this recipient yet. The Mail queue page shows what it is still holding.",
		})
	case store.StatusSent:
		return append(events, deliveryEvent{
			At:     row.UpdatedAt,
			Level:  "ok",
			Status: store.StatusSent,
			Title:  "Delivered",
			Detail: "The receiving server accepted the message. That is as far as this server can see — what the recipient's mailbox then did with it is not reported back.",
		})
	case store.StatusDeferred:
		return append(events, deliveryEvent{
			At:     row.UpdatedAt,
			Level:  "warn",
			Status: store.StatusDeferred,
			Title:  "Deferred, will be retried",
			Detail: fmt.Sprintf("The receiving server could not take the message yet. Postfix retries: first after %s, then with increasing gaps up to %s, for up to %s. There is no fixed attempt count — a deferred message stays in the queue until it is delivered or that lifetime runs out.",
				policy.FirstRetry(), policy.BackoffCap(), policy.QueueLifetime()),
		})
	case store.StatusBounced:
		return append(events, deliveryEvent{
			At:     row.UpdatedAt,
			Level:  "error",
			Status: store.StatusBounced,
			Title:  "Bounced",
			Detail: fmt.Sprintf("Delivery failed for good: the receiving server refused the message permanently, or Postfix gave up after %s in the queue. The reason is in the delivery log below.",
				policy.QueueLifetime()),
		})
	default:
		// A status the log-tailer learns to write before this switch does.
		return append(events, deliveryEvent{
			At:     row.UpdatedAt,
			Level:  deliveryLevel(row.Status),
			Status: row.Status,
			Title:  "Status reported",
			Detail: "The last state Postfix reported for this recipient.",
		})
	}
}

// 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 (h *Handlers) 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."
	}
	lines, err := logtail.QueueLines(h.cfg.MailLogPath, row.QueueID, deliveryLogLines)
	if err != nil && !errors.Is(err, fs.ErrNotExist) {
		logf("panel: delivery log %s: %v", row.QueueID, err)
		return nil, "Could not read the mail log."
	}
	if len(lines) == 0 {
		days := h.sendLogRetentionDays()
		return nil, fmt.Sprintf("Nothing for this queue id in the current mail log. Its lines have most likely been rotated away (send-log rows are kept for %d days).", days)
	}
	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
// from. Only the log's own parameters are carried over, and each is re-encoded
// by url.Values, so nothing a visitor appends to the link can travel back into
// the page as markup or as a different destination.
func deliveriesBackURL(r *http.Request) string {
	q := r.URL.Query()
	back := url.Values{}
	for _, k := range []string{"domain", "app", "p"} {
		if v := q.Get(k); v != "" {
			back.Set(k, v)
		}
	}
	if len(back) == 0 {
		return "/deliveries"
	}
	return "/deliveries?" + back.Encode()
}

// sendLogData reads the domain/app filters and page number off the query
// string, queries the store, and assembles everything the template needs
// (filter dropdown options plus the current selection, rows, and pagination).
//
// The invariant this function owes the journal: a principal who is not global
// only ever reads rows for the domains assigned to them. That scope is stated
// to the store as SendLogFilter.Domains and holds for every number of
// assignments, including none — a domain administrator whose last domain was
// deleted gets an empty log, not the whole one. The query parameters are
// filters *within* that scope and can only narrow it: both are checked against
// the assigned domains and their applications before the query runs, because a
// dropdown that offers only permitted values is a courtesy to the browser, not
// a check on the request.
func (h *Handlers) sendLogData(r *http.Request) (map[string]any, error) {
	p, ok := h.principal(r)
	if !ok {
		return nil, errors.New("no principal")
	}
	q := r.URL.Query()

	assigned, err := h.assignedDomains(p)
	if err != nil {
		return nil, err
	}
	allowedNames := domainNameSet(assigned)

	domainNames := make([]string, 0, len(assigned))
	for _, d := range assigned {
		domainNames = append(domainNames, d.Name)
	}

	loginSet := make(map[string]bool)
	for _, d := range assigned {
		apps, err := h.store.ListApplicationsByDomain(d.ID)
		if err != nil {
			return nil, err
		}
		for _, a := range apps {
			loginSet[a.Login] = true
		}
	}
	logins := make([]string, 0, len(loginSet))
	for login := range loginSet {
		logins = append(logins, login)
	}
	sort.Strings(logins)

	filter := store.SendLogFilter{
		Domain:   q.Get("domain"),
		AppLogin: q.Get("app"),
		// A global administrator reads the whole journal, including rows left
		// behind by a domain that has since been deleted.
		Domains:    domainNames,
		AllDomains: p.IsGlobal(),
	}
	if !p.IsGlobal() {
		if filter.Domain != "" && !allowedNames[filter.Domain] {
			filter.Domain = ""
		}
		if filter.AppLogin != "" && !loginSet[filter.AppLogin] {
			filter.AppLogin = ""
		}
	}

	page := parsePage(q.Get("p"))

	total, err := h.store.CountSendLog(filter)
	if err != nil {
		return nil, err
	}
	rows, err := h.store.QuerySendLog(filter, sendLogPageSize, (page-1)*sendLogPageSize)
	if err != nil {
		return nil, err
	}
	view := make([]sendLogRow, len(rows))
	for i := range rows {
		rows[i].Subject = mailhdr.DecodeSubject(rows[i].Subject)
		view[i] = sendLogRow{SendLogRow: rows[i], Level: deliveryLevel(rows[i].Status)}
	}

	lastPage := 1
	if total > 0 {
		lastPage = int((total + sendLogPageSize - 1) / sendLogPageSize)
	}
	return map[string]any{
		"Rows":                 view,
		"FilterDomains":        domainNames,
		"FilterApps":           logins,
		"FilterDomain":         filter.Domain,
		"FilterApp":            filter.AppLogin,
		"Page":                 page,
		"PrevPage":             page - 1,
		"NextPage":             page + 1,
		"LastPage":             lastPage,
		"HasPrev":              page > 1,
		"HasNext":              page < lastPage,
		"SendLogRetentionDays": h.sendLogRetentionDays(),
	}, nil
}

// parsePage clamps the "p" query parameter to a valid page number, defaulting
// to 1 for anything missing or malformed rather than rejecting the request.
func parsePage(v string) int {
	n, err := strconv.Atoi(v)
	if err != nil || n < 1 {
		return 1
	}
	return n
}

// HandleMailQueue renders the Mail queue page (architecture.md § Panel HTTP
// surface).
func (h *Handlers) HandleMailQueue(w http.ResponseWriter, r *http.Request) {
	if _, ok := h.requireGlobal(w, r); !ok {
		return
	}
	out, errText := readQueue()
	policy := h.cfg.RetryPolicy
	h.view.Render(w, http.StatusOK, "mail_queue", map[string]any{
		"Title":             "SelfPost — mail queue",
		"User":              auth.CurrentUser(r),
		"Active":            "mail_queue",
		"IsGlobal":          true,
		"Output":            out,
		"Error":             errText,
		"FirstRetry":        policy.FirstRetry(),
		"BackoffCap":        policy.BackoffCap(),
		"QueueLifetime":     policy.QueueLifetime(),
		"RetryFromDefaults": policy.FromDefaults,
	})
}

// HandleMailQueueBody serves the HTMX polling fragment for the queue view.
func (h *Handlers) HandleMailQueueBody(w http.ResponseWriter, r *http.Request) {
	if _, ok := h.requireGlobal(w, r); !ok {
		return
	}
	out, errText := readQueue()
	h.view.RenderFragment(w, http.StatusOK, "mail_queue_body", map[string]any{
		"Output": out,
		"Error":  errText,
	})
}

// readQueue runs postqueue -p, returning a friendly message instead of the
// error itself: a transient postqueue failure should degrade the monitoring
// view, not surface internals to the panel.
func readQueue() (string, string) {
	out, err := postfix.Queue()
	if err != nil {
		logf("panel: postqueue -p: %v", err)
		return "", "Could not read the mail queue."
	}
	return out, ""
}

// HandleSystemLog renders the System log page over mail.log (architecture.md §
// Panel HTTP surface).
func (h *Handlers) HandleSystemLog(w http.ResponseWriter, r *http.Request) {
	if _, ok := h.requireGlobal(w, r); !ok {
		return
	}
	lines, errText := h.readLogTail()
	h.view.Render(w, http.StatusOK, "system_log", map[string]any{
		"Title":    "SelfPost — system log",
		"User":     auth.CurrentUser(r),
		"Active":   "system_log",
		"IsGlobal": true,
		"Lines":    lines,
		"Error":    errText,
	})
}

// HandleSystemLogBody serves the HTMX polling fragment for the log-tail view.
func (h *Handlers) HandleSystemLogBody(w http.ResponseWriter, r *http.Request) {
	if _, ok := h.requireGlobal(w, r); !ok {
		return
	}
	lines, errText := h.readLogTail()
	h.view.RenderFragment(w, http.StatusOK, "system_log_body", map[string]any{
		"Lines": lines,
		"Error": errText,
	})
}

func (h *Handlers) readLogTail() ([]string, string) {
	lines, err := logtail.TailLines(h.cfg.MailLogPath, logTailLines)
	if err != nil {
		if errors.Is(err, fs.ErrNotExist) {
			// Rotation renamed the file away; Postfix recreates it on reload
			// (within about a second), so this is a normal, brief gap rather
			// than a failure worth alarming the operator about.
			return nil, ""
		}
		logf("panel: tail %s: %v", h.cfg.MailLogPath, err)
		return nil, "Could not read the mail log."
	}
	return lines, ""
}