selfpost/internal/web/handlers/handlers_monitor.go

package handlers

import (
	"errors"
	"fmt"
	"io/fs"
	"net/http"
	"net/url"
	"slices"
	"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/view"
)

// 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 Outbound log over the send log: server-side
// filters by domain/application and pagination (architecture.md § Persistence).
// The table and the count under it are the polled region, rendered by the same
// template for the page and for HandleDeliveriesRows, so the initial page and
// its HTMX-polled refreshes never diverge.
func (h *Handlers) HandleDeliveries(w http.ResponseWriter, r *http.Request) {
	page, err := h.outLogPage(r)
	if err != nil {
		logf("panel: send log: %v", err)
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	h.view.Render(w, http.StatusOK, "out-log", page)
}

// HandleDeliveriesRows serves the HTMX polling fragment for the log
// (architecture.md § Panel HTTP surface: fragment endpoints return HTML, not
// JSON): the table, and the foot under it for the page to swap in.
func (h *Handlers) HandleDeliveriesRows(w http.ResponseWriter, r *http.Request) {
	page, err := h.outLogPage(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, "out_log_rows", page.Fragment())
}

// 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
	}
	allowed, err := h.assignedDomains(p)
	if err != nil {
		http.Error(w, "internal error", http.StatusInternalServerError)
		return
	}
	if !p.IsGlobal() && !domainIDSet(allowed)[row.DomainID] {
		http.NotFound(w, r)
		return
	}
	row.Subject = mailhdr.DecodeSubject(row.Subject)
	logLines, logNote := h.deliveryLog(row)

	in := view.MessageInput{
		ID: row.ID, QueueID: row.QueueID, Domain: row.Domain, App: row.AppLogin,
		From: row.From, To: row.To, Subject: row.Subject, Status: row.Status,
		Reason: row.Reason, HeaderFrom: row.HeaderFrom, Recovered: row.Recovered,
		Accepted: row.CreatedAt, Reported: row.UpdatedAt,
		// Where the row came from, so the way back returns to the page and filters
		// the operator was looking at rather than the top of an unfiltered log.
		BackHref: deliveriesBackURL(r),
	}
	// The names link to their pages when there is a page to go to: a domain
	// that was deleted since, or an application of another domain, is text.
	for _, d := range allowed {
		if d.ID != row.DomainID {
			continue
		}
		in.DomainHref = view.DomainHref(d.ID)
		if a, err := h.store.GetApplicationByLogin(row.AppLogin); err == nil && a.DomainID == d.ID {
			in.AppHref = view.DomainHref(d.ID) + "/applications/" + strconv.FormatInt(a.ID, 10)
		}
		break
	}
	page := view.NewOutMessage(h.shellMeta(r), in).
		WithHistory(deliveryEvents(row, h.cfg.RetryPolicy, h.sendsAs(row))).
		// The mail.log lines for this message, and — when there are none — the
		// reason, which is a normal outcome rather than a failure.
		WithDeliveryLog(logLines, logNote)
	h.view.Render(w, http.StatusOK, "out-message", page)
}

// sendsAs says what the row's application may send as, in the words of a
// refusal: any address of its domain, or the addresses of its list. Empty when
// the login is no application's any more, or is now another domain's.
func (h *Handlers) sendsAs(row store.SendLogRow) view.Text {
	a, err := h.store.GetApplicationByLogin(row.AppLogin)
	if err != nil || a.DomainID != row.DomainID {
		return nil
	}
	if a.AddressMode == store.AddressModeList {
		return view.Plain("the addresses of its list")
	}
	d, err := h.store.GetDomain(a.DomainID)
	if err != nil {
		return nil
	}
	return view.Rich("any address of ", view.Mono(d.Name))
}

// 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.
//
// sendsAs is what the row's application may send as, for the step of a message
// refused for its From: line; empty when the application is gone.
func deliveryEvents(row store.SendLogRow, policy postfix.RetryPolicy, sendsAs view.Text) []view.Step {
	// step states what happened and when; outcome is ok, warn, error or "" for a
	// step that reports nothing either way, and a zero time is a step that has
	// not happened yet.
	step := func(at time.Time, outcome, title, detail string) view.Step {
		return view.Step{
			Time:   view.StepTime(at),
			Strong: title,
			Text:   view.Plain(" — " + detail),
			Level:  view.StepLevel(outcome, !at.IsZero()),
		}
	}

	// 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 {
		switch row.Reason {
		case store.ReasonFrom, store.ReasonSender:
			// The one step that names things: which line, whose, and what that
			// application may write instead.
			field := "From: "
			if row.Reason == store.ReasonSender {
				field = "Sender: "
			}
			text := view.Rich(" — ", view.Code(field+row.HeaderFrom), " is not an address of application ", view.Mono(row.AppLogin))
			if len(sendsAs) > 0 {
				text = append(append(text, view.Inline{Text: ", which sends as "}), sendsAs...)
			}
			text = append(text, view.Rich(". The application was told ", view.Code("550 5.7.1"), " and will not try again.")...)
			s := step(row.CreatedAt, "error", "Refused before queueing", "")
			s.Text = text
			return []view.Step{s}
		case store.ReasonClient:
			return []view.Step{step(row.CreatedAt, "error", "Refused before queueing",
				"The application accepts mail only from its listed client addresses, and this message came from another. It was never queued, so there is no queue id and Postfix never attempted delivery.")}
		}
		return []view.Step{step(row.CreatedAt, "error", "Refused before queueing",
			"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 := []view.Step{step(row.CreatedAt, "", "Accepted and queued",
		"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, step(time.Time{}, "", "Waiting for a delivery report",
			"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, step(row.UpdatedAt, "ok", "Delivered",
			"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:
		// And the wait that follows, as an open dot: the next attempt is
		// Postfix's, at a time the panel does not know.
		return append(events, step(row.UpdatedAt, "warn", "Deferred, will be retried",
			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())),
			view.Step{Time: view.StepTime(time.Time{}), Level: view.StepLevel("", false),
				Text: view.Plain(fmt.Sprintf("Still in the queue; the next attempt is Postfix's own, and after %s it is bounced.", policy.QueueLifetime()))})
	case store.StatusBounced:
		if row.Reason == store.ReasonReconcile {
			// Neither the receiving server nor Postfix said so: the panel
			// closed the row (audit 2026-10-12, stage 2b).
			return append(events, step(row.UpdatedAt, "error", "Closed by the panel",
				"Postfix no longer held the message and mail.log never said what became of it - the log rotated away while the panel was down, or could not be read. The panel closed it as a failure rather than show a delivery it cannot evidence."))
		}
		return append(events, step(row.UpdatedAt, "error", "Bounced",
			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, step(row.UpdatedAt, "", "Status reported",
			"The last state Postfix reported for this recipient."))
	}
}

// deliveryLogMargin is added to the queue lifetime when asking which stored
// lines are a row's: Postfix expires a message on a queue run after the
// lifetime has passed, not at the second it does, and logs the bounce after
// that.
const deliveryLogMargin = 24 * time.Hour

// deliveryLog returns the mail.log lines Postfix wrote about one message, each
// split into the time and the text the page shows it in. They come from the
// database, where the log tailer keeps them for as long as the row lives
// (architecture.md § Log tailer). A row with none stored is searched for in
// the current mail.log, as every row was before 2.2.0: that is what shows a
// message accepted before the lines were kept.
//
// 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 it predates the stored lines and the log has rotated — so none of
// them is an error on the page. Only lines that cannot be read at all are
// reported as a fault, and that one is logged for the operator as well.
func (h *Handlers) deliveryLog(row store.SendLogRow) ([]view.LogLine, string) {
	if row.QueueID == "" {
		if row.RefusalLine != "" {
			return logLines([]string{row.RefusalLine}), ""
		}
		if row.Status == store.StatusRejected {
			return nil, "Postfix's line about this refusal is not stored: the message was refused before version 2.5.1, or the line was never read."
		}
		return nil, "This message never reached the queue, so Postfix wrote no delivery lines for it."
	}
	stored, err := h.store.SendLogLines(row, h.cfg.RetryPolicy.LongestLifetime()+deliveryLogMargin, deliveryLogLines)
	if err != nil {
		logf("panel: delivery log %s: %v", row.QueueID, err)
		return nil, "Could not read the stored delivery log."
	}
	lines := make([]string, len(stored))
	for i, l := range stored {
		lines[i] = l.Line
	}
	// A refused message's id was freed at once and may be another's by now:
	// what was not stored with the row is not looked for in the log.
	if len(lines) == 0 && row.Status != store.StatusRejected {
		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 && row.Status == store.StatusRejected {
		return nil, "Postfix's lines about this refusal are not stored: the message was refused before version 2.5.1, or the lines were never read."
	}
	if len(lines) == 0 {
		return nil, "Nothing is stored for this queue id and nothing is in the current mail log. Lines are kept with the row since version 2.2.0; a message accepted before that had them only in mail.log, which has since rotated."
	}
	return logLines(lines), ""
}

// logLines are lines of mail.log as the delivery log box shows them.
func logLines(lines []string) []view.LogLine {
	out := make([]view.LogLine, len(lines))
	for i, line := range lines {
		// A line whose head is not a timestamp the log format recognises keeps its
		// whole text and no time: nothing is dropped from what the log says.
		stamp, rest := logtail.SplitTimestamp(line)
		out[i] = view.LogLine{Time: stamp, Text: rest, Level: view.LogLineLevel(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", "status", "from", "to", "p"} {
		if v := q.Get(k); v != "" {
			back.Set(k, v)
		}
	}
	if len(back) == 0 {
		return "/outbound/log"
	}
	return "/outbound/log?" + back.Encode()
}

// outLogPage reads the domain/app filters and page number off the query
// string, queries the store, and fills the log page (filter choices 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) outLogPage(r *http.Request) (*view.OutLog, 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))
	domainIDs := make([]int64, 0, len(assigned))
	for _, d := range assigned {
		domainNames = append(domainNames, d.Name)
		domainIDs = append(domainIDs, d.ID)
	}

	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"),
		Status:   outLogStatus(q.Get("status")),
		// A global administrator reads the whole journal, including rows left
		// behind by a domain that has since been deleted; anyone else the rows
		// of the domains assigned to them, by id - not those an earlier domain
		// of the same name left (audit 2026-10-12, L12).
		DomainIDs:  domainIDs,
		AllDomains: p.IsGlobal(),
	}
	if !p.IsGlobal() {
		if filter.Domain != "" && !allowedNames[filter.Domain] {
			filter.Domain = ""
		}
		if filter.AppLogin != "" && !loginSet[filter.AppLogin] {
			filter.AppLogin = ""
		}
	}
	form := view.OutLogFilter{Domain: filter.Domain, App: filter.AppLogin, Status: filter.Status}
	// The days, as on the Inbound log: from the first's midnight to the end of
	// the last, in the container's zone; a day that does not parse is no
	// narrowing.
	if t, err := time.Parse(logDay, q.Get("from")); err == nil {
		form.From, filter.Since = t.Format(logDay), t
	}
	if t, err := time.Parse(logDay, q.Get("to")); err == nil {
		form.To, filter.Until = t.Format(logDay), t
	}

	total, err := h.store.CountSendLog(filter)
	if err != nil {
		return nil, err
	}
	lastPage := 1
	if total > 0 {
		lastPage = int((total + sendLogPageSize - 1) / sendLogPageSize)
	}
	// A page past the end is the last one, as on the Inbound log: a link
	// kept while the log was pruned, or a number typed, shows rows, not an
	// empty table under "Page 9 of 2" (audit 2026-10-12, L10).
	page := min(parsePage(q.Get("p")), lastPage)
	rows, err := h.store.QuerySendLog(filter, sendLogPageSize, (page-1)*sendLogPageSize)
	if err != nil {
		return nil, err
	}
	out := view.NewOutLog(h.shellMeta(r), h.sendLogRetentionDays(), p.IsGlobal(), domainNames, logins, form)
	table := make([]view.OutLogRow, len(rows))
	for i, row := range rows {
		table[i] = view.OutLogRow{
			Time: view.FormatLogTime(row.CreatedAt), From: row.From, To: row.To,
			Subject: mailhdr.DecodeSubject(row.Subject), Status: view.SendLogTag(row.Status, row.Reason),
			Href: out.DetailHref(row.ID, page),
		}
	}
	return out.WithRows(table, page, lastPage), nil
}

// outLogStatus is the status filter of the Outbound log: one of the statuses
// a row has, or none.
func outLogStatus(v string) string {
	if slices.Contains(view.OutLogStatuses, v) {
		return v
	}
	return ""
}

// parsePage clamps the "p" query parameter to a valid page number, defaulting
// to 1 for anything missing or malformed rather than rejecting the request.
//
// A number too large for an int is past every last page, and is taken as
// that: strconv returns it as the largest int with ErrRange (Go 1.26,
// strconv.ParseInt: "the maximum magnitude integer of the appropriate
// bitSize and sign"), and the caller clamps it to the last page.
func parsePage(v string) int {
	n, err := strconv.Atoi(v)
	if errors.Is(err, strconv.ErrRange) && n > 0 {
		return n
	}
	if err != nil || n < 1 {
		return 1
	}
	return n
}

// HandleMailQueue renders the Outbound 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
	}
	policy := h.cfg.RetryPolicy
	h.view.Render(w, http.StatusOK, "out-queue", h.outQueuePage(r).
		WithRetryPolicy(policy.FirstRetry(), policy.BackoffCap(), policy.QueueLifetime(), 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
	}
	h.view.RenderFragment(w, http.StatusOK, "out_queue_body", h.outQueuePage(r))
}

// outQueuePage reads the queue and gives it to the view; the page and its
// fragment draw the same box from it.
func (h *Handlers) outQueuePage(r *http.Request) *view.OutQueue {
	out, errText := readQueue()
	return view.NewOutQueue(h.shellMeta(r), out, 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
	}
	h.view.Render(w, http.StatusOK, "system-log", h.systemLogPage(r))
}

// 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
	}
	h.view.RenderFragment(w, http.StatusOK, "system_log_body", h.systemLogPage(r))
}

// systemLogPage reads the tail of mail.log and splits each line into the time
// and the text the page shows it in, as the delivery log of one message does. A
// line whose head is not a timestamp the log format recognises keeps its whole
// text and no time: nothing is dropped from what the log says.
func (h *Handlers) systemLogPage(r *http.Request) *view.SystemLog {
	raw, errText := h.readLogTail()
	lines := make([]view.LogLine, len(raw))
	for i, line := range raw {
		stamp, rest := logtail.SplitTimestamp(line)
		lines[i] = view.LogLine{Time: stamp, Text: rest, Level: view.LogLineLevel(rest)}
	}
	return view.NewSystemLog(h.shellMeta(r), lines, 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, ""
}