Files
mesh-catalog/modules/mailu/health.ts
T

217 lines
9.5 KiB
TypeScript

// Whether mail flows through mailu, as the node-engine asks it every interval (novox/hq ADR 0240, kind
// `tool`; issue 690). Every container read healthy on 2026-10-14 while postfix could not resolve a name:
// 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`, 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.
//
// The answer is the health answer every health tool gives (mesh-sdk go/health): `state`, `healthy` beside
// it for an older reader, and `why` in words — counts, the oldest message's age and its first reason —
// never a bare false.
import { execFile } from "node:child_process";
import { promisify } from "node:util";
const run = promisify(execFile);
/** How long a message may wait in the deferred queue before mail is said not to flow. */
export const DEFERRED_BOUND_SECONDS = 30 * 60;
/** The public name resolved through postfix's resolver: gmail's mail exchanger, which mail needs. */
export const PUBLIC_NAME = "gmail-smtp-in.l.google.com";
// The lookup postfix's own would make, through the resolver the container is given; a failure is said on one
// line ("gaierror: [Errno -3] Try again" is what a SERVFAIL reads as), never as a traceback.
const RESOLVE = [
"import socket, sys",
"try:",
` socket.getaddrinfo(${JSON.stringify(PUBLIC_NAME)}, 25)`,
"except Exception as e:",
" 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>;
/** The health answer (mesh-sdk go/health): healthy, or unhealthy with why. */
export interface HealthAnswer {
state: "healthy" | "unhealthy";
healthy: boolean;
why: string;
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). */
interface Queued {
queue_name?: string;
queue_id?: string;
arrival_time?: number;
recipients?: Array<{ address?: string; delay_reason?: string }>;
}
/** docker exec, bounded: a hung container is an answer too. */
export function dockerExec(timeoutMs = 10_000): Exec {
return async (container, command) =>
(await run("docker", ["exec", container, ...command], { timeout: timeoutMs })).stdout;
}
/** What a failed exec said, on one line: its stderr when it has one, else its message. */
function said(e: unknown): string {
const err = e as { stderr?: string; message?: string; killed?: boolean; signal?: string };
if (err?.killed || err?.signal === "SIGTERM") return "it did not answer in time";
const text = (err?.stderr ?? "").trim() || (err?.message ?? String(e)).trim();
return text.split("\n").map((l) => l.trim()).filter(Boolean)[0] ?? "it failed and said nothing";
}
/** An age in words: "2 days 3 hours", "45 minutes". */
export function age(seconds: number): string {
const s = Math.max(0, Math.floor(seconds));
const d = Math.floor(s / 86400), h = Math.floor((s % 86400) / 3600), m = Math.floor((s % 3600) / 60);
const unit = (n: number, w: string) => `${n} ${w}${n === 1 ? "" : "s"}`;
if (d > 0) return h > 0 ? `${unit(d, "day")} ${unit(h, "hour")}` : unit(d, "day");
if (h > 0) return m > 0 ? `${unit(h, "hour")} ${unit(m, "minute")}` : unit(h, "hour");
return unit(m, "minute");
}
function parseQueue(output: string): Queued[] {
const queued: Queued[] = [];
for (const line of output.split("\n")) {
const text = line.trim();
if (!text.startsWith("{")) continue; // "Mail queue is empty" and the like
queued.push(JSON.parse(text) as Queued);
}
return queued;
}
/**
* Judge whether mail flows. `now` is in seconds since the epoch. Every part is asked even when one
* fails, so the answer says everything that is wrong at once.
*/
export async function mailFlows(
exec: Exec,
container: string,
now: number = Date.now() / 1000,
boundSeconds: number = DEFERRED_BOUND_SECONDS,
): Promise<HealthAnswer> {
const faults: string[] = [];
const [status, queue, resolve] = await Promise.allSettled([
exec(container, ["postfix", "status"]),
exec(container, ["postqueue", "-j"]),
exec(container, ["python3", "-c", RESOLVE]),
]);
if (status.status === "rejected") {
faults.push(`postfix in ${container} does not run: ${said(status.reason)}.`);
}
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 {
let queued: Queued[] = [];
try {
queued = parseQueue(queue.value);
} catch (e) {
faults.push(`postfix's queue in ${container} printed a line that is not JSON: ${said(e)}.`);
}
const deferred = queued.filter((q) => q.queue_name === "deferred");
const overdue = deferred
.filter((q) => typeof q.arrival_time === "number" && now - q.arrival_time > boundSeconds)
.sort((a, b) => (a.arrival_time ?? 0) - (b.arrival_time ?? 0));
const oldest = deferred.reduce<number | undefined>(
(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 } : {}),
};
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(
`${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])}.`,
);
}
}
if (resolve.status === "rejected") {
faults.push(`${container} cannot resolve ${PUBLIC_NAME} through its resolver: ${said(resolve.reason)}.`);
}
if (faults.length > 0) {
const why = [`Mail does not flow.`, ...faults, ...notes].join(" ");
return { state: "unhealthy", healthy: false, why, queue: summary };
}
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,
why: `Mail flows: postfix runs, ${PUBLIC_NAME} resolves.${waiting}`,
queue: summary,
};
}