novox/hq 04-ISSUES/024. A run stalled for thirty-five minutes and said nothing. The cause was a link systemd was still configuring, three layers down inside a `docker load` blocked on a socket — and every one of those layers knew what it was waiting for. None of them said so. Three decisions, each doing work. **Every external command is logged, at the three places that run one.** Ninety-seven call sites reach a hypervisor or a container runtime through three wrappers, so instrumenting the wrappers covers all of them and nothing has to remember to log. **A command still running says so while it runs.** A line before and a line after tells you nothing until the after arrives, which is exactly the case that matters. Anything outstanding past fifteen seconds reports itself with how long it has been going. It is reported as still running, not as stuck — which it is is not knowable from there, and a log that calls a slow step a hang teaches people to ignore it. **It goes to a file, written synchronously.** Node block-buffers stdout when redirected and a test runner buffers it again, so a console log can sit minutes behind. `appendFileSync` cannot lag. Two things this found in itself while being written, both the same shape as what it exists to catch: A question that answers no is not a fault. Half the lab's commands are questions — does this network exist, is the agent up yet — and they fail constantly while a scenario comes up. Logging those as faults filled a healthy run with ✗, which is how you end up ignoring ✗ when one is real. They are recorded quietly now, and still recorded. And `around` skipped its own wrapper when a step's level was below the configured one — taking the failure line and the heartbeat with it. The two things worth having at a low level were the two that vanished at exactly the level somebody would use. The gate belongs in `write`. Also unsilences the four call sites that passed a callback throwing everything away, including the one the stall sat in, and tees `raise`'s progress into the file whether or not a caller asked to see it — the end-to-end test passed no callback, so the one run that mattered reported not a single step.
283 lines
10 KiB
TypeScript
283 lines
10 KiB
TypeScript
/**
|
|
* A thin wrapper over the incus CLI. Thin on purpose: the lab's value is in the scenario
|
|
* model, not in re-describing a hypervisor.
|
|
*
|
|
* Everything here goes through incus's own channel and never over IP. A scenario is a
|
|
* closed address space — two scenarios raised from one declaration hold the same
|
|
* addresses and must never meet — so the workstation has no route into either, and
|
|
* reaching a machine by address would make concurrency impossible in the worst way:
|
|
* not with an error, but with one scenario's traffic arriving in another.
|
|
*
|
|
* See novox/hq 02-DECISIONS/0032-a-scenario-is-an-isolated-address-space.md
|
|
*/
|
|
|
|
import { spawn } from "node:child_process";
|
|
|
|
import { around, log, shorten } from "../log.ts";
|
|
|
|
/**
|
|
* How to invoke incus. Overridable because the socket is group-owned and a session that
|
|
* predates the group grant cannot reach it — which is a real thing that happens on the
|
|
* machine that just installed it.
|
|
*/
|
|
const INCUS = (process.env["MESH_LAB_INCUS"] ?? "incus").split(" ").filter(Boolean);
|
|
|
|
export interface IncusResult {
|
|
stdout: string;
|
|
stderr: string;
|
|
}
|
|
|
|
export class IncusError extends Error {
|
|
readonly args: string[];
|
|
readonly stderr: string;
|
|
readonly exitCode: number | null;
|
|
|
|
constructor(args: string[], stderr: string, exitCode: number | null) {
|
|
const detail = stderr.trim() || (exitCode === null ? "timed out" : `exit ${exitCode}`);
|
|
super(`incus ${args.join(" ")} failed: ${detail}`);
|
|
this.name = "IncusError";
|
|
this.args = args;
|
|
this.stderr = stderr;
|
|
this.exitCode = exitCode;
|
|
}
|
|
}
|
|
|
|
/**
|
|
* Runs incus with **stdin closed**, which is not incidental.
|
|
*
|
|
* Several incus subcommands accept a YAML definition on stdin and, given a descriptor
|
|
* that is not a terminal, wait for one. Under a shell that never happens because stdin is
|
|
* a TTY; under a spawned process it hangs until the timeout kills it — and the timeout
|
|
* kill produces an empty stderr, so the failure arrives with no explanation at all.
|
|
*
|
|
* Found exactly that way: the first raise reported "failed: (no output)" on a command
|
|
* that worked perfectly when typed.
|
|
*/
|
|
export async function incus(args: string[], timeoutMs = 60_000): Promise<IncusResult> {
|
|
// **Every command through here is recorded** (novox/hq 04-ISSUES/024). This is one of three
|
|
// places the lab runs an external program, and ninety-odd call sites reach a hypervisor through
|
|
// it — so logging here covers all of them and none of them has to remember to.
|
|
return invoke(args, timeoutMs, false);
|
|
}
|
|
|
|
/**
|
|
* `expectedToFail` is not about this command; it is about the caller.
|
|
*
|
|
* `incus` rejects and the caller is expected to care. `incusOk` and `succeeds` turn a failure into
|
|
* an answer — *does this network exist*, *is the agent up yet* — and those are asked constantly
|
|
* while a scenario comes up. Recording them as faults fills a healthy run with ✗.
|
|
*/
|
|
function invoke(args: string[], timeoutMs: number, expectedToFail: boolean): Promise<IncusResult> {
|
|
return around(`incus ${shorten(args)}`, () => run(args, timeoutMs), {
|
|
heartbeatMs: 15_000,
|
|
expectedToFail,
|
|
});
|
|
}
|
|
|
|
function run(args: string[], timeoutMs: number): Promise<IncusResult> {
|
|
const [command, ...prefix] = INCUS;
|
|
if (!command) throw new Error("MESH_LAB_INCUS is empty");
|
|
|
|
return new Promise((resolve, reject) => {
|
|
const child = spawn(command, [...prefix, ...args], {
|
|
stdio: ["ignore", "pipe", "pipe"],
|
|
});
|
|
|
|
let stdout = "";
|
|
let stderr = "";
|
|
let timedOut = false;
|
|
|
|
const timer = setTimeout(() => {
|
|
timedOut = true;
|
|
child.kill("SIGKILL");
|
|
}, timeoutMs);
|
|
|
|
child.stdout.on("data", (chunk) => (stdout += chunk));
|
|
child.stderr.on("data", (chunk) => (stderr += chunk));
|
|
|
|
child.on("error", (err) => {
|
|
clearTimeout(timer);
|
|
reject(new IncusError(args, err.message, null));
|
|
});
|
|
|
|
child.on("close", (code) => {
|
|
clearTimeout(timer);
|
|
if (timedOut) {
|
|
// Said explicitly. A SIGKILL leaves an empty stderr, so without this the failure arrives
|
|
// with no explanation at all — which is how the first raise reported "(no output)".
|
|
log.info(`incus ${shorten(args)} was killed after ${timeoutMs}ms`);
|
|
reject(new IncusError(args, `timed out after ${timeoutMs}ms`, null));
|
|
} else if (code === 0) {
|
|
if (stdout.trim()) log.trace(` stdout: ${shorten([stdout.trim()], 400)}`);
|
|
resolve({ stdout, stderr });
|
|
} else {
|
|
log.debug(` exit ${code}: ${shorten([stderr.trim() || "(nothing on stderr)"], 400)}`);
|
|
reject(new IncusError(args, stderr, code));
|
|
}
|
|
});
|
|
});
|
|
}
|
|
|
|
/**
|
|
* Like `incus`, but a failure is an answer rather than an exception. Returns the command's
|
|
* output, or `null` if it failed.
|
|
*
|
|
* **Never truthiness-test this.** Plenty of incus commands succeed with no output at all —
|
|
* `exec … true`, `network delete`, `start` — so an empty string means *worked and said
|
|
* nothing*, and `if (await incusOk(...))` reads that as failure. Use `succeeds()` when the
|
|
* question is whether it worked, and `!== null` when the output matters.
|
|
*
|
|
* This is the mesh's own recurring fault in miniature: absence and success made
|
|
* indistinguishable. It cost a raise that reported a machine unreachable while `incus exec`
|
|
* on that machine worked perfectly.
|
|
*/
|
|
export async function incusOk(args: string[], timeoutMs = 60_000): Promise<string | null> {
|
|
try {
|
|
return (await invoke(args, timeoutMs, true)).stdout;
|
|
} catch {
|
|
return null;
|
|
}
|
|
}
|
|
|
|
/**
|
|
* Ask incus what exists, where answering "none" without having looked would be a lie.
|
|
*
|
|
* The comment on `incusOk` above warns that absence and success must not be made
|
|
* indistinguishable. Three of its callers then wrote `?? "[]"` and did exactly that, and it cost
|
|
* a session: `mesh-lab list` reported *no scenario instances standing* while two were standing,
|
|
* because this shell had no permission to reach the daemon. The lab was not wrong about the
|
|
* instances — it had never managed to ask.
|
|
*
|
|
* So anything enumerating what exists comes through here and throws. `incusOk` remains right for
|
|
* questions where failure genuinely means no, like `instanceExists`.
|
|
*/
|
|
async function enumerate(args: string[], timeoutMs = 30_000): Promise<string> {
|
|
return (await incus(args, timeoutMs)).stdout;
|
|
}
|
|
|
|
/** Did the command work? For commands whose output is not the point. */
|
|
export async function succeeds(args: string[], timeoutMs = 60_000): Promise<boolean> {
|
|
return (await incusOk(args, timeoutMs)) !== null;
|
|
}
|
|
|
|
export async function isReachable(): Promise<boolean> {
|
|
return succeeds(["info"], 15_000);
|
|
}
|
|
|
|
/** Storage drivers the daemon offers. It only advertises those whose tooling it found. */
|
|
export async function supportedDrivers(): Promise<string[]> {
|
|
const info = (await incusOk(["info"], 15_000)) ?? "";
|
|
const block = info.split("storage_supported_drivers:")[1] ?? "";
|
|
return [...block.matchAll(/-\s+name:\s*(\w+)/g)].map((m) => m[1] ?? "");
|
|
}
|
|
|
|
export interface Pool {
|
|
name: string;
|
|
driver: string;
|
|
}
|
|
|
|
export async function pools(): Promise<Pool[]> {
|
|
const csv = (await incusOk(["storage", "list", "--format", "csv"])) ?? "";
|
|
return csv
|
|
.split("\n")
|
|
.filter(Boolean)
|
|
.map((line) => {
|
|
const [name = "", driver = ""] = line.split(",");
|
|
return { name, driver };
|
|
});
|
|
}
|
|
|
|
export async function networkExists(name: string): Promise<boolean> {
|
|
return succeeds(["network", "show", name], 15_000);
|
|
}
|
|
|
|
export async function instanceExists(name: string): Promise<boolean> {
|
|
return succeeds(["config", "show", name], 15_000);
|
|
}
|
|
|
|
export interface TaggedInstance {
|
|
name: string;
|
|
status: string;
|
|
instanceId: string;
|
|
machine: string;
|
|
}
|
|
|
|
/**
|
|
* Instances this lab owns, identified by the config keys set when they were created —
|
|
* never by parsing their names.
|
|
*
|
|
* Names were parsed at first, splitting on the last dash to separate machine from
|
|
* instance. That works until a machine is called something like `home-server`, at which
|
|
* point the instance id absorbs half the machine name and `destroy` silently finds
|
|
* nothing. Metadata is what the instance actually knows about itself.
|
|
*/
|
|
export async function taggedInstances(): Promise<TaggedInstance[]> {
|
|
const json = (await enumerate(["list", "--format", "json"])).trim() || "[]";
|
|
let parsed: unknown;
|
|
try {
|
|
parsed = JSON.parse(json);
|
|
} catch {
|
|
throw new IncusError(["list", "--format", "json"],
|
|
`incus answered something that is not JSON: ${json.slice(0, 200)}`, null);
|
|
}
|
|
if (!Array.isArray(parsed)) {
|
|
throw new IncusError(["list", "--format", "json"],
|
|
"incus answered JSON that is not a list of instances", null);
|
|
}
|
|
|
|
const tagged: TaggedInstance[] = [];
|
|
for (const entry of parsed) {
|
|
const item = entry as { name?: string; status?: string; config?: Record<string, string> };
|
|
const instanceId = item.config?.["user.mesh-lab.instance"];
|
|
const machine = item.config?.["user.mesh-lab.machine"];
|
|
if (!instanceId || !machine || !item.name) continue;
|
|
tagged.push({ name: item.name, status: item.status ?? "", instanceId, machine });
|
|
}
|
|
return tagged;
|
|
}
|
|
|
|
export interface TaggedNetwork {
|
|
name: string;
|
|
instanceId: string;
|
|
segment: string;
|
|
/** Absent on a link raised before segment shape was recorded. */
|
|
kind?: "public" | "private";
|
|
cidr: string[];
|
|
mtu?: number;
|
|
}
|
|
|
|
export async function taggedNetworks(): Promise<TaggedNetwork[]> {
|
|
const args = ["network", "list", "--format", "json"];
|
|
const json = (await enumerate(args)).trim() || "[]";
|
|
let parsed: unknown;
|
|
try {
|
|
parsed = JSON.parse(json);
|
|
} catch {
|
|
throw new IncusError(args, `incus answered something that is not JSON: ${json.slice(0, 200)}`, null);
|
|
}
|
|
if (!Array.isArray(parsed)) {
|
|
throw new IncusError(args, "incus answered JSON that is not a list of networks", null);
|
|
}
|
|
|
|
const tagged: TaggedNetwork[] = [];
|
|
for (const entry of parsed) {
|
|
const item = entry as { name?: string; config?: Record<string, string> };
|
|
const instanceId = item.config?.["user.mesh-lab.instance"];
|
|
const segment = item.config?.["user.mesh-lab.segment"];
|
|
if (!instanceId || !segment || !item.name) continue;
|
|
const kind = item.config?.["user.mesh-lab.kind"];
|
|
const cidr = item.config?.["user.mesh-lab.cidr"];
|
|
tagged.push({
|
|
name: item.name,
|
|
instanceId,
|
|
segment,
|
|
...(kind === "public" || kind === "private" ? { kind } : {}),
|
|
cidr: cidr ? cidr.split(",").filter(Boolean) : [],
|
|
...(Number.isFinite(Number(item.config?.["user.mesh-lab.mtu"]))
|
|
? { mtu: Number(item.config?.["user.mesh-lab.mtu"]) }
|
|
: {}),
|
|
});
|
|
}
|
|
return tagged;
|
|
}
|