diff --git a/modules/mailu/health.ts b/modules/mailu/health.ts new file mode 100644 index 00000000..ff6126ff --- /dev/null +++ b/modules/mailu/health.ts @@ -0,0 +1,216 @@ +// 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; + +/** 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 { + 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( + (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, + }; +} diff --git a/modules/mailu/module.json b/modules/mailu/module.json index e7cae034..b4cc6b2c 100644 --- a/modules/mailu/module.json +++ b/modules/mailu/module.json @@ -56,6 +56,19 @@ "api-token": "${dir:state}/api-token.secret" } }, + "tools": [ + "mailu_list_users", + "mailu_create_user", + "mailu_change_password", + "mailu_delete_user", + "mailu_list_aliases", + "mailu_create_alias", + "mailu_delete_alias", + "mailu_list_domains", + "mailu_read_mail", + "mailu_search_mail", + "mailu_health" + ], "emits": [ "user.created", "user.deleted", @@ -443,7 +456,12 @@ "name": "mailu-smtp", "image": "ghcr.io/mailu/postfix@sha256:e2e49f39e53b80eac9e7a2f18d9df11edeb4914fd62dbba89b3155e8e034f62e", "health": { - "kind": "runtime" + "kind": "tool", + "tool": "mailu_health", + "interval": "60s", + "timeout": "30s", + "looks": 3, + "grace": "120s" }, "network": "mailu", "env-file": [ @@ -642,6 +660,7 @@ "MESH_MAILU_URL": "http://127.0.0.1:${port:8080}/api/v1", "MESH_MAILU_API_KEY_FILE": "${dir:state}/api-token.secret", "MESH_MAILU_IMAP_CONTAINER": "mailu-imap", + "MESH_MAILU_SMTP_CONTAINER": "mailu-smtp", "MESH_MAILU_CONFIG_FILE": "${dir:mesh-state}/config.json", "MESH_RECEIVES": "${dir:grants}/mesh.json" } diff --git a/modules/mailu/test/mail-flows.test.ts b/modules/mailu/test/mail-flows.test.ts new file mode 100644 index 00000000..ddea9791 --- /dev/null +++ b/modules/mailu/test/mail-flows.test.ts @@ -0,0 +1,140 @@ +// Whether mail flows (novox/hq issue 690): the health tool is unhealthy, in words, when a message waits in +// postfix's deferred queue longer than the bound, when postfix does not run, when a public name does not +// resolve, and when the container cannot be reached — and healthy otherwise. Run against the compiled +// module, the way the runtime loads it. + +import { test } from "node:test"; +import assert from "node:assert/strict"; + +import { mailFlows, DEFERRED_BOUND_SECONDS } from "../dist/health.js"; + +const NOW = 1_800_000_000; + +type Answers = { status?: string | Error; queue?: string | Error; resolve?: string | Error }; + +/** A container that answers each command as told; an Error is a failed exec, with its stderr. */ +function container(a: Answers) { + const asked: string[][] = []; + const exec = async (_name: string, command: string[]) => { + asked.push(command); + const answer = command[0] === "postfix" ? a.status ?? "" : command[0] === "postqueue" ? a.queue ?? "" : a.resolve ?? ""; + if (answer instanceof Error) throw answer; + return answer; + }; + return { exec, asked }; +} + +function failed(stderr: string): Error { + return Object.assign(new Error("Command failed: docker exec"), { stderr }); +} + +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: to, delay_reason: reason }], + }); +} + +test("an empty queue is healthy, and says so", async () => { + const c = container({ queue: "" }); + const a = await mailFlows(c.exec, "mailu-smtp", NOW); + assert.equal(a.state, "healthy"); + assert.equal(a.healthy, true); + assert.match(a.why, /deferred queue is empty/); + assert.deepEqual(a.queue, { messages: 0, deferred: 0, overdue: 0 }); + assert.equal(c.asked.length, 3, "postfix, its queue and a lookup were each asked"); +}); + +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"), + JSON.stringify({ queue_name: "active", queue_id: "CCC333", arrival_time: NOW - 10, recipients: [] }), + ].join("\n"); + const a = await mailFlows(container({ queue }).exec, "mailu-smtp", NOW); + assert.equal(a.state, "unhealthy"); + assert.equal(a.healthy, false); + assert.match(a.why, /^Mail does not flow\./); + 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 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 () => { + const queue = deferred("BBB222", DEFERRED_BOUND_SECONDS - 60, "connect to mx.example.net: Connection timed out"); + const a = await mailFlows(container({ queue }).exec, "mailu-smtp", NOW); + assert.equal(a.state, "healthy"); + assert.equal(a.healthy, true); + assert.match(a.why, /1 deferred, the oldest 29 minutes old, within 30 minutes/); +}); + +test("a container that cannot be reached is unhealthy, and says what docker said", async () => { + const gone = failed("Error response from daemon: No such container: mailu-smtp\n"); + const a = await mailFlows(container({ status: gone, queue: gone, resolve: gone }).exec, "mailu-smtp", NOW); + assert.equal(a.state, "unhealthy"); + assert.equal(a.healthy, false); + assert.match(a.why, /postfix in mailu-smtp does not run: Error response from daemon: No such container: mailu-smtp\./); + assert.match(a.why, /postfix's queue in mailu-smtp could not be read: Error response from daemon: No such container/); + assert.equal(a.queue, undefined); +}); + +test("a name that does not resolve is unhealthy, though the queue is empty", async () => { + const a = await mailFlows( + container({ queue: "", resolve: failed("gaierror: [Errno -3] Try again\n") }).exec, + "mailu-smtp", + NOW, + ); + assert.equal(a.state, "unhealthy"); + assert.match(a.why, /mailu-smtp cannot resolve gmail-smtp-in\.l\.google\.com through its resolver: gaierror: \[Errno -3\] Try again\./); +}); + +test("a container that does not answer in time is said so", async () => { + const hung = Object.assign(new Error("Command failed"), { killed: true, signal: "SIGTERM" }); + const a = await mailFlows(container({ queue: hung }).exec, "mailu-smtp", NOW); + assert.equal(a.state, "unhealthy"); + assert.match(a.why, /postfix's queue in mailu-smtp could not be read: it did not answer in time\./); +}); + +test("the health tool is served without the admin API, on the smtp container it is told", async () => { + const { collectTools } = await import("@novox/mesh-sdk/tools"); + await import("../dist/tools/index.js"); + const mailu = collectTools({ MESH_MAILU_SMTP_CONTAINER: "mailu-smtp" }).find((m) => m.module === "mailu"); + const names = (mailu?.tools ?? []).map((t) => t.name); + assert.deepEqual(names, ["mailu_health"]); + assert.match(mailu!.tools[0].description, /inside mailu-smtp/); +}); diff --git a/modules/mailu/tools/index.ts b/modules/mailu/tools/index.ts index c1ab925b..6b8442e9 100644 --- a/modules/mailu/tools/index.ts +++ b/modules/mailu/tools/index.ts @@ -4,6 +4,27 @@ import { registerModuleTools, type ToolDefinition } from "@novox/mesh-sdk/tools"; import { MailuClient } from "../client.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 + * check. It needs no admin API, only the postfix container, so it is served even when the API is not + * configured — a check that vanished with the API would say unhealthy for the wrong reason. + */ +export function getHealthTool(env: NodeJS.ProcessEnv): ToolDefinition { + const container = env.MESH_MAILU_SMTP_CONTAINER || "mailu-smtp"; + return { + name: "mailu_health", + description: + `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), + }; +} export function getMailuTools(mailu: MailuClient): ToolDefinition[] { return [ @@ -143,12 +164,14 @@ export function getMailuTools(mailu: MailuClient): ToolDefinition[] { ]; } -// The tools exist only when the admin API is configured; without it, mailu contributes none rather -// than failing the whole runtime. +// The admin tools exist only when the admin API is configured; without it, mailu contributes only its +// health tool rather than failing the whole runtime. registerModuleTools("mailu", (env) => { + let tools: ToolDefinition[] = []; try { - return getMailuTools(MailuClient.fromEnv(env)); + tools = getMailuTools(MailuClient.fromEnv(env)); } catch { - return []; + tools = []; } + return [...tools, getHealthTool(env)]; }); diff --git a/modules/mailu/tsconfig.json b/modules/mailu/tsconfig.json index 36778592..a55a92ee 100644 --- a/modules/mailu/tsconfig.json +++ b/modules/mailu/tsconfig.json @@ -8,5 +8,5 @@ "skipLibCheck": true, "noEmit": true }, - "include": ["client.ts", "index.ts", "tools/index.ts"] + "include": ["client.ts", "health.ts", "index.ts", "tools/index.ts"] }