postfix: a truncated postqueue -p listing is no listing for the sweep (audit H3)

QueueIDs parsed Queue()'s text, which caps postqueue -p at 4 MiB and appends a note, and returned the ids before the cut with no error: the reconcile sweep then closed every queued row past the cut as bounced while Postfix still held the mail. listQueue() now returns the text and whether it was cut; QueueIDs refuses a cut listing with an error (reconcile already treats an error as no information), the way postqueueJSON does for the notifier. Queue() keeps showing the cut listing with its note. postqueueP is a var so tests run a fake postqueue (the test binary as a helper process): 5 MiB -> QueueIDs errors, Queue ends with the note; 1000 bytes -> ids read. CHANGELOG [Unreleased], audit plan line ticked, roadmap 8/61. Evidence: go test ./internal/postfix ok (Windows); the server run of the stage follows before the push. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-10-14 14:13:34 +03:00
parent 9efc9c7005
commit dfe10f6c27
5 changed files with 119 additions and 18 deletions
@@ -5,6 +5,17 @@ Format follows [Keep a Changelog](https://keepachangelog.com/en/1.1.0/); version

 ## [Unreleased]

+### Fixed
+
+- **A queue too large to list no longer closes its own messages.** The
+  reconcile sweep asks `postqueue -p` which messages Postfix still holds and
+  closes every `queued` row that is not among them. The listing is capped at
+  4 MiB, and the ids past the cap were read as gone: during a large deferred
+  backlog - the outage the sweep exists for - mail Postfix still held was
+  marked `bounced`. A listing over the cap now tells the sweep nothing, as it
+  already did for the notification about mail waiting too long; the Mail
+  queue page still shows the cut listing with its note (audit 2026-10-12, H3).
+
 ## [2.4.2] - 2026-10-14

 Release hygiene: stage 0 of the 2026-10-12 audit. Nothing the panel or the
@@ -593,7 +593,7 @@ has already run is never edited — the next file is added; the published

 ### Stage 1 — mail that is shown wrong (H3, H2, M12, M13) → `2.5.0`

- [ ] **`QueueIDs` on a truncated listing returns an error**, as `postqueueJSON`
+- [x] **`QueueIDs` on a truncated listing returns an error**, as `postqueueJSON`
   does; `reconcile` already treats an error as no information. Test: a 5 MiB
   fake `postqueue -p`. — **Opus**
 - [ ] **Reconcile only closes `queued` rows** (`AND status = 'queued'` in the
@@ -42,7 +42,7 @@ in `git log` and [CHANGELOG.md](../CHANGELOG.md).
 | from-header-binding | Hold a message's `From:` header against the application that sends it | shipped `2.4.0` | 9/9 | [plans/from-header-binding.md](plans/from-header-binding.md) |
 | panel-redesign | Panel redesign (accepted mockups, design contract) | shipped `2.0.0` | 27/27 | [plans/panel-redesign.md](plans/panel-redesign.md) |
 | schema-squash | Squash SQLite migrations into a 2.x baseline | built in panel-redesign (stage 1) | — | [plans/panel-redesign.md](plans/panel-redesign.md) |
-| audit-2026-10-12 | Follow-ups of the 2026-10-12 full-tree code audit, seven stages | in progress (stage 0 shipped `2.4.2`; next stages 1+2 → `2.5.0`) | 7/61 | [audit-2026-10-12.md](audit-2026-10-12.md) |
+| audit-2026-10-12 | Follow-ups of the 2026-10-12 full-tree code audit, seven stages | in progress (stage 0 shipped `2.4.2`; next stages 1+2 → `2.5.0`) | 8/61 | [audit-2026-10-12.md](audit-2026-10-12.md) |

 **Recommended order** (not binding; owner, 2026-10-09: feature order follows
 development convenience): **panel-redesign** shipped as `2.0.0` (2026-10-11) and
@@ -41,28 +41,43 @@ func (l *limitWriter) Write(p []byte) (int, error) {
 	return len(p), nil
 }

-// Queue returns Postfix's own human-readable mail-queue listing
-// (architecture.md § Panel HTTP surface): active, deferred and held messages,
-// exactly as an administrator would see via the CLI. The command takes a
-// single fixed flag and no user input, so it never goes through a shell
-// (security.md). The panel is responsible for escaping the output before
-// display (security.md); this function returns it as-is.
-func Queue() (string, error) {
+// postqueueP builds the `postqueue -p` command. It is a var so tests can put
+// a fake postqueue in its place, the way readQueueJSON is.
+var postqueueP = func(ctx context.Context) *exec.Cmd {
+	// A single fixed flag and no user input, never through a shell (security.md).
+	return exec.CommandContext(ctx, "postqueue", "-p")
+}
+
+// listQueue runs `postqueue -p` and keeps at most maxQueueOutput bytes of it;
+// truncated says whether there was more.
+func listQueue() (text string, truncated bool, err error) {
 	ctx, cancel := context.WithTimeout(context.Background(), postqueueTimeout)
 	defer cancel()
-	cmd := exec.CommandContext(ctx, "postqueue", "-p")
+	cmd := postqueueP(ctx)
 	out := &limitWriter{remaining: maxQueueOutput}
 	cmd.Stdout = out
 	cmd.Stderr = out
-	err := cmd.Run()
+	err = cmd.Run()
 	if ctx.Err() == context.DeadlineExceeded {
-		return "", fmt.Errorf("postqueue -p timed out after %s", postqueueTimeout)
+		return "", false, fmt.Errorf("postqueue -p timed out after %s", postqueueTimeout)
 	}
 	if err != nil {
-		return "", fmt.Errorf("postqueue -p: %w: %s", err, strings.TrimSpace(out.buf.String()))
+		return "", false, fmt.Errorf("postqueue -p: %w: %s", err, strings.TrimSpace(out.buf.String()))
 	}
-	text := out.buf.String()
-	if out.truncated {
+	return out.buf.String(), out.truncated, nil
+}
+
+// Queue returns Postfix's own human-readable mail-queue listing
+// (architecture.md § Panel HTTP surface): active, deferred and held messages,
+// exactly as an administrator would see via the CLI. The panel is responsible
+// for escaping the output before display (security.md); this function returns
+// it as-is. A listing over the size cap is shown cut, with a note saying so.
+func Queue() (string, error) {
+	text, truncated, err := listQueue()
+	if err != nil {
+		return "", err
+	}
+	if truncated {
 		text += fmt.Sprintf("\n[listing truncated at %d bytes]\n", maxQueueOutput)
 	}
 	return text, nil
@@ -77,12 +92,17 @@ func Queue() (string, error) {
 //
 // An error means the queue could not be listed and therefore says nothing about
 // any message; the caller must treat it as "no information", never as an empty
-// queue.
+// queue. A listing cut at the size cap is such an error: the messages past the
+// cut are still in the queue, and a backlog that large is the outage the sweep
+// exists for (audit 2026-10-12, H3). QueueMessages treats its cap the same way.
 func QueueIDs() (map[string]struct{}, error) {
-	out, err := Queue()
+	out, truncated, err := listQueue()
 	if err != nil {
 		return nil, err
 	}
+	if truncated {
+		return nil, fmt.Errorf("postqueue -p: listing is larger than %d bytes", maxQueueOutput)
+	}
 	return parseQueueIDs(out), nil
 }

@@ -1,6 +1,76 @@
 package postfix

-import "testing"
+import (
+	"bufio"
+	"context"
+	"fmt"
+	"os"
+	"os/exec"
+	"strings"
+	"testing"
+)
+
+// TestFakePostqueue is not a test: it is the fake `postqueue -p` the tests
+// below run in place of the real one, writing SP_FAKE_POSTQUEUE_BYTES bytes of
+// queue entries.
+func TestFakePostqueue(t *testing.T) {
+	if os.Getenv("SP_FAKE_POSTQUEUE") != "1" {
+		t.Skip("helper process")
+	}
+	var size int
+	fmt.Sscan(os.Getenv("SP_FAKE_POSTQUEUE_BYTES"), &size)
+	out := bufio.NewWriter(os.Stdout)
+	fmt.Fprintln(out, "-Queue ID-  --Size-- ----Arrival Time---- -Sender/Recipient-------")
+	for n, i := 0, 0; n < size; i++ {
+		entry := fmt.Sprintf("%010X      446 Fri Aug  8 10:13:31  app@example.com\n%41s rcpt@example.net\n\n", i, "")
+		out.WriteString(entry)
+		n += len(entry)
+	}
+	out.Flush()
+	os.Exit(0)
+}
+
+// fakePostqueue puts a postqueue that lists about size bytes of entries in
+// place of the real one for the rest of the test.
+func fakePostqueue(t *testing.T, size int) {
+	t.Helper()
+	old := postqueueP
+	postqueueP = func(ctx context.Context) *exec.Cmd {
+		cmd := exec.CommandContext(ctx, os.Args[0], "-test.run=^TestFakePostqueue$")
+		cmd.Env = append(os.Environ(), "SP_FAKE_POSTQUEUE=1", fmt.Sprintf("SP_FAKE_POSTQUEUE_BYTES=%d", size))
+		return cmd
+	}
+	t.Cleanup(func() { postqueueP = old })
+}
+
+// A listing over the cap is no listing for the reconcile sweep: the messages
+// past the cut are still queued, and taking the first 4 MiB of ids for the
+// whole queue closed every row past it as bounced (audit 2026-10-12, H3).
+// The queue page still shows the cut listing, with the note.
+func TestQueueIDsRefusesATruncatedListing(t *testing.T) {
+	fakePostqueue(t, 5<<20)
+	if ids, err := QueueIDs(); err == nil {
+		t.Fatalf("QueueIDs on a 5 MiB listing = %d ids and no error, want an error", len(ids))
+	}
+	text, err := Queue()
+	if err != nil {
+		t.Fatalf("Queue on a 5 MiB listing: %v", err)
+	}
+	if !strings.HasSuffix(text, fmt.Sprintf("[listing truncated at %d bytes]\n", maxQueueOutput)) {
+		t.Fatalf("Queue on a 5 MiB listing does not end with the truncation note: ...%q", text[len(text)-80:])
+	}
+}
+
+func TestQueueIDsReadsAListingUnderTheCap(t *testing.T) {
+	fakePostqueue(t, 1000)
+	ids, err := QueueIDs()
+	if err != nil {
+		t.Fatal(err)
+	}
+	if _, ok := ids["0000000000"]; !ok || len(ids) < 5 {
+		t.Fatalf("QueueIDs on a small listing = %v", ids)
+	}
+}

 // The reconcile sweep decides whether a message is still Postfix's problem, so
 // the parser must pick queue ids out of a real listing and nothing else out of