Judge mailu's deferred queue by this side's faults, not one dead recipient
mesh/merge-gate head 60495376551d merged into trunk 50861c74f8b4 — fail: builds mailu, sent nowhere; no bus step; 1 wait(s) for a person; a manifest the ch…
mesh/repo-check head 60495376551d merged into trunk 50861c74f8b4 — fail: its merge-check.sh failed: files asking for a setting without saying whether it is…
mesh/delivery superseded: a newer head of the same pull request

A message to a far host that is down stays deferred for up to five days,
and mailu's unhealthy now pages the operator, so one dead recipient would
page for days. Overdue deferred mail is unhealthy only when a lookup failed
here (a name-service failure, as in issue 687) or when it reaches three or
more domains; one or two far domains are said in the answer, not alarmed.
This commit is contained in:
jochen
2026-10-14 15:19:08 +02:00
parent bf3e801f67
commit 6049537655
3 changed files with 110 additions and 27 deletions
+68 -15
View File
@@ -3,9 +3,12 @@
// inbound mail was refused with 450 and outbound mail sat in the deferred queue for days. The parts'
// checks judge parts; this judges the flow, from inside the postfix container, the way postfix sees it:
//
// 1. postfix runs (`postfix status`, the check the image itself ships, which this one replaces);
// 2. no message waits in the deferred queue longer than the bound (`postqueue -j`): a message that
// cannot be delivered for that long is mail that does not flow, whatever the reason;
// 1. postfix runs (`postfix status`, standing in for the image's own check, `! /usr/libexec/postfix/master
// -t`, which this one replaces);
// 2. the deferred queue (`postqueue -j`) shows no fault of this side: a recipient deferred longer than the
// bound because a lookup failed here, or overdue mail to three or more domains. One or two far domains
// that do not answer are theirs, and can stay deferred for days: said, never unhealthy, so one dead
// recipient does not page the operator for days;
// 3. a public mail host's name resolves through the resolver postfix is given: a resolver that
// SERVFAILs refuses inbound mail before anything reaches the queue.
//
@@ -34,6 +37,23 @@ const RESOLVE = [
" sys.exit(type(e).__name__ + ': ' + str(e))",
].join("\n");
/** Overdue mail to this many recipient domains or more is our side's fault, not one far server's. */
export const SPREAD_DOMAINS = 3;
/**
* What postfix writes when its own lookups fail, as on 2026-10-14 (issue 687): "Host or domain name not
* found. Name service error for name=gmail.com type=MX: Host not found, try again", or "Temporary lookup
* failure". A far server that is down reads otherwise ("Connection timed out", "Connection refused").
*/
export const LOCAL_LOOKUP_FAILURE =
/Name service error|Temporary lookup failure|Host or domain name not found.*try again/is;
/** The domain of an address, lower-cased; "(no recipient)" when there is none. */
function domainOf(address?: string): string {
const at = address?.lastIndexOf("@") ?? -1;
return address && at >= 0 ? address.slice(at + 1).toLowerCase() : "(no recipient)";
}
/** Runs a command in a container: its stdout, or a rejection carrying stderr. */
export type Exec = (container: string, command: string[]) => Promise<string>;
@@ -42,7 +62,14 @@ export interface HealthAnswer {
state: "healthy" | "unhealthy";
healthy: boolean;
why: string;
queue?: { messages: number; deferred: number; overdue: number; oldestDeferredSeconds?: number };
queue?: {
messages: number;
deferred: number;
overdue: number;
oldestDeferredSeconds?: number;
overdueDomains?: string[];
nameServiceFailures?: number;
};
}
/** One message as `postqueue -j` prints it, one JSON object a line (postfix 3.1 and later). */
@@ -109,6 +136,7 @@ export async function mailFlows(
}
let summary: HealthAnswer["queue"];
const notes: string[] = [];
if (queue.status === "rejected") {
faults.push(`postfix's queue in ${container} could not be read: ${said(queue.reason)}.`);
} else {
@@ -126,20 +154,42 @@ export async function mailFlows(
(o, q) => (typeof q.arrival_time === "number" && (o === undefined || q.arrival_time < o) ? q.arrival_time : o),
undefined,
);
// Each overdue recipient, oldest message first: what our side is judged by, not one far host.
const late = overdue.flatMap((q) =>
(q.recipients?.length ? q.recipients : [{}]).map((r) => ({
to: r.address,
domain: domainOf(r.address),
reason: r.delay_reason?.trim() || "postfix gave no reason",
waited: now - (q.arrival_time ?? now),
})),
);
const lookups = late.filter((r) => LOCAL_LOOKUP_FAILURE.test(r.reason));
const domains = [...new Set(late.map((r) => r.domain))];
summary = {
messages: queued.length,
deferred: deferred.length,
overdue: overdue.length,
...(oldest !== undefined ? { oldestDeferredSeconds: Math.max(0, Math.floor(now - oldest)) } : {}),
...(domains.length > 0 ? { overdueDomains: domains } : {}),
...(lookups.length > 0 ? { nameServiceFailures: lookups.length } : {}),
};
if (overdue.length > 0) {
const first = overdue[0];
const reason = first.recipients?.find((r) => r.delay_reason)?.delay_reason?.trim();
const to = first.recipients?.[0]?.address;
const one = (r: (typeof late)[number]) =>
`the oldest, ${age(r.waited)} old${r.to ? ` to ${r.to}` : ""}, waits because: ${r.reason}`;
const bound = age(boundSeconds);
if (lookups.length > 0) {
faults.push(
`${overdue.length} of ${deferred.length} deferred messages have waited longer than ${age(boundSeconds)}; ` +
`the oldest, ${age(now - (first.arrival_time ?? now))} old${to ? ` to ${to}` : ""}, ` +
`waits because: ${reason || "postfix gave no reason"}.`,
`${lookups.length} deferred ${lookups.length === 1 ? "recipient has" : "recipients have"} waited longer ` +
`than ${bound} on a name-service failure, which is this server's resolver; ${one(lookups[0])}.`,
);
} else if (domains.length >= SPREAD_DOMAINS) {
faults.push(
`${overdue.length} of ${deferred.length} deferred messages have waited longer than ${bound}, to ` +
`${domains.length} domains (${domains.join(", ")}): more than one far server's fault; ${one(late[0])}.`,
);
} else if (late.length > 0) {
notes.push(
`${overdue.length} deferred ${overdue.length === 1 ? "message has" : "messages have"} waited longer than ` +
`${bound}, only to ${domains.join(" and ")}, which reads as the far side's: ${one(late[0])}.`,
);
}
}
@@ -149,11 +199,14 @@ export async function mailFlows(
}
if (faults.length > 0) {
return { state: "unhealthy", healthy: false, why: `Mail does not flow. ${faults.join(" ")}`, queue: summary };
const why = [`Mail does not flow.`, ...faults, ...notes].join(" ");
return { state: "unhealthy", healthy: false, why, queue: summary };
}
const waiting = summary && summary.deferred > 0
? ` ${summary.deferred} deferred, the oldest ${age(summary.oldestDeferredSeconds ?? 0)} old, within ${age(boundSeconds)}.`
: " The deferred queue is empty.";
const waiting = !summary || summary.deferred === 0
? " The deferred queue is empty."
: notes.length > 0
? ` ${notes.join(" ")}`
: ` ${summary.deferred} deferred, the oldest ${age(summary.oldestDeferredSeconds ?? 0)} old, within ${age(boundSeconds)}.`;
return {
state: "healthy",
healthy: true,
+36 -7
View File
@@ -28,14 +28,14 @@ function failed(stderr: string): Error {
return Object.assign(new Error("Command failed: docker exec"), { stderr });
}
function deferred(id: string, ageSeconds: number, reason: string): string {
function deferred(id: string, ageSeconds: number, reason: string, to = "friend@example.com"): string {
return JSON.stringify({
queue_name: "deferred",
queue_id: id,
arrival_time: NOW - ageSeconds,
message_size: 1234,
sender: "someone@example.org",
recipients: [{ address: "friend@example.com", delay_reason: reason }],
recipients: [{ address: to, delay_reason: reason }],
});
}
@@ -49,8 +49,8 @@ test("an empty queue is healthy, and says so", async () => {
assert.equal(c.asked.length, 3, "postfix, its queue and a lookup were each asked");
});
test("a deferred message older than the bound is unhealthy, with counts, its age and its reason", async () => {
const reason = "Host or domain name not found. Name service error for name=example.com type=MX: Host not found, try again";
test("a recipient overdue on a name-service failure is unhealthy, with counts, its age and its reason", async () => {
const reason = "Host or domain name not found. Name service error for name=gmail.com type=MX: Host not found, try again";
const queue = [
deferred("AAA111", 3 * 86400 + 2 * 3600, reason),
deferred("BBB222", 5 * 60, "connect to mx.example.net[192.0.2.1]:25: Connection timed out"),
@@ -60,10 +60,39 @@ test("a deferred message older than the bound is unhealthy, with counts, its age
assert.equal(a.state, "unhealthy");
assert.equal(a.healthy, false);
assert.match(a.why, /^Mail does not flow\./);
assert.match(a.why, /1 of 2 deferred messages have waited longer than 30 minutes/);
assert.match(a.why, /1 deferred recipient has waited longer than 30 minutes on a name-service failure/);
assert.match(a.why, /3 days 2 hours old to friend@example\.com/);
assert.ok(a.why.includes(reason), "the first reason is said");
assert.deepEqual(a.queue, { messages: 3, deferred: 2, overdue: 1, oldestDeferredSeconds: 3 * 86400 + 2 * 3600 });
assert.ok(a.why.includes(reason), "the reason is said");
assert.deepEqual(a.queue, {
messages: 3, deferred: 2, overdue: 1, oldestDeferredSeconds: 3 * 86400 + 2 * 3600,
overdueDomains: ["example.com"], nameServiceFailures: 1,
});
});
test("one dead far domain overdue is healthy, and said", async () => {
const queue = [
deferred("AAA111", 2 * 86400, "connect to mx.dead.example[192.0.2.9]:25: Connection timed out", "a@dead.example"),
deferred("BBB222", 3600, "connect to mx.dead.example[192.0.2.9]:25: Connection timed out", "b@dead.example"),
].join("\n");
const a = await mailFlows(container({ queue }).exec, "mailu-smtp", NOW);
assert.equal(a.state, "healthy");
assert.equal(a.healthy, true);
assert.match(a.why, /2 deferred messages have waited longer than 30 minutes, only to dead\.example, which reads as the far side's/);
assert.match(a.why, /2 days old to a@dead\.example, waits because: connect to mx\.dead\.example/);
assert.deepEqual(a.queue?.overdueDomains, ["dead.example"]);
});
test("overdue mail to three domains is unhealthy, whatever the reason", async () => {
const timedOut = "connect to mx[192.0.2.1]:25: Connection timed out";
const queue = [
deferred("AAA111", 7200, timedOut, "a@one.example"),
deferred("BBB222", 3600, timedOut, "b@two.example"),
deferred("CCC333", 3600, timedOut, "c@three.example"),
].join("\n");
const a = await mailFlows(container({ queue }).exec, "mailu-smtp", NOW);
assert.equal(a.state, "unhealthy");
assert.match(a.why, /3 of 3 deferred messages have waited longer than 30 minutes, to 3 domains \(one\.example, two\.example, three\.example\)/);
assert.match(a.why, /the oldest, 2 hours old to a@one\.example/);
});
test("a deferred message younger than the bound is healthy, and is said", async () => {
+6 -5
View File
@@ -4,7 +4,7 @@
import { registerModuleTools, type ToolDefinition } from "@novox/mesh-sdk/tools";
import { MailuClient } from "../client.js";
import { dockerExec, mailFlows, DEFERRED_BOUND_SECONDS, PUBLIC_NAME } from "../health.js";
import { dockerExec, mailFlows, DEFERRED_BOUND_SECONDS, PUBLIC_NAME, SPREAD_DOMAINS } from "../health.js";
/**
* Whether mail flows (novox/hq ADR 0240, issue 690): the tool the node-engine asks as the smtp container's
@@ -16,10 +16,11 @@ export function getHealthTool(env: NodeJS.ProcessEnv): ToolDefinition {
return {
name: "mailu_health",
description:
`Whether mail flows through mailu, asked inside ${container}: postfix runs, no message has waited in ` +
`its deferred queue longer than ${DEFERRED_BOUND_SECONDS / 60} minutes, and ${PUBLIC_NAME} resolves ` +
"through the resolver postfix uses. Unhealthy with counts, the oldest message's age and its first reason " +
"(novox/hq ADR 0240, issue 690).",
`Whether mail flows through mailu, asked inside ${container}: postfix runs; no recipient has waited ` +
`deferred longer than ${DEFERRED_BOUND_SECONDS / 60} minutes on a name-service failure here, and overdue ` +
`deferred mail does not reach ${SPREAD_DOMAINS} or more domains (one or two far domains are said, not ` +
`unhealthy); and ${PUBLIC_NAME} resolves through the resolver postfix uses. Says counts, domains, the ` +
"oldest message's age and its reason (novox/hq ADR 0240, issue 690).",
input: {},
run: async () => mailFlows(dockerExec(), container),
};