Files
HealthLog/src/lib/logging/__tests__/signal.test.ts
T
Marc-André Bombeck 2210f823d6 feat(logging): give failed runs and caught failures their own error lines
A wide event carries one action and the last annotation wins, so a hop
that failed before the next provider answered, one failed account among
six, or a caught error the code carried on past was either a meta key on
someone else's info line or nothing at all. `emitSignal` writes one extra
line under a stable action and level, joined to the surrounding event by
request and trace id; `logCaught` / `caughtAs` are its warn-level shape
for a catch that degrades on purpose.

Every failed pg-boss run now writes `job.run.failed` at error with the
queue and how many runs of it in a row have failed, counted from pg-boss's
own rows (`readConsecutiveRunFailures`). `reportJobRun` takes a fan-out
pass's whole candidate list: an all-failed run is `job.run.failed`, a
partial one `job.run.partial` at warn, and the run reports `all_failed` in
its facts so a completed night with nothing done still counts toward the
streak. The repeated-failure alert keys on that one action and number.

Retention is per queue now. `failureReaderRetention` refuses a queue
retention under 96 hours (the 72-hour reader window plus a day), and a
guard refuses any `deleteAfterSeconds` that is neither that helper nor a
literal at or above the floor.

A refusal the request was meant to get (any error carrying a 4xx status)
is recorded at warn instead of error. Expired-token 401s were most of the
error lines and hid the real failures between them.
2026-10-08 09:05:54 +02:00

102 lines
3.5 KiB
TypeScript

/**
* v1.42 — the logging pieces the error-log discipline rests on.
*
* - `emitSignal` writes its own line with a stable action and level, joined
* to the surrounding event by request and trace id, and leaves that event
* alone.
* - `setError` keeps `error` for real failures and records a refusal the
* request was meant to get (any 4xx) at `warn`. Expired-token 401s made up
* most of the error lines and hid the real ones.
*/
import { beforeEach, describe, expect, it, vi } from "vitest";
const emitted: Array<Record<string, unknown>> = [];
vi.mock("../transports", () => ({
emitIfSampled: (event: Record<string, unknown>) => emitted.push(event),
}));
import { WideEventBuilder } from "../event-builder";
import { eventStorage } from "../context";
import { emitSignal, logCaught } from "../signal";
beforeEach(() => {
emitted.length = 0;
});
describe("emitSignal", () => {
it("writes one line with its own action and level, joined to the parent by id", () => {
const parent = new WideEventBuilder("http");
parent.setAction({ name: "insights.generate" });
eventStorage.run(parent, () =>
emitSignal({
action: "ai.chain.link_failed",
level: "error",
meta: { provider: "admin-openai", status: 500 },
}),
);
expect(emitted).toHaveLength(1);
const line = emitted[0] as {
action: { name: string };
level: string;
request_id: string;
trace_id: string;
meta: Record<string, unknown>;
};
expect(line.action.name).toBe("ai.chain.link_failed");
expect(line.level).toBe("error");
expect(line.request_id).toBe(parent.getRequestId());
expect(line.trace_id).toBe(parent.getTraceId());
expect(line.meta).toMatchObject({ provider: "admin-openai", status: 500 });
// The parent keeps its own action and level.
expect(parent.toJSON().action?.name).toBe("insights.generate");
expect(parent.getLevel()).toBe("info");
});
it("logCaught carries the error's type and a bounded, redacted message at warn", () => {
logCaught(
"jobs.enqueue.failed",
new Error(`boom Bearer sk-abcdefghijklmnopqrstuvwxyz ${"x".repeat(500)}`),
{ queue: "insight-pregenerate" },
);
const line = emitted[0] as { level: string; meta: Record<string, string> };
expect(line.level).toBe("warn");
expect(line.meta.error_type).toBe("Error");
expect(line.meta.error_message.length).toBeLessThanOrEqual(240);
expect(line.meta.error_message).not.toContain("sk-abcdefghijklmnop");
});
it("never throws, even when emitting fails", () => {
expect(() =>
emitSignal({
action: "x.y.z",
level: "warn",
meta: {
get bad(): never {
throw new Error("getter");
},
},
}),
).not.toThrow();
});
});
describe("setError level", () => {
it("records a 4xx refusal at warn", () => {
const evt = new WideEventBuilder("http");
evt.setError(
Object.assign(new Error("Token expired"), { statusCode: 401 }),
);
expect(evt.getLevel()).toBe("warn");
expect(evt.toJSON().error?.message).toBe("Token expired");
});
it("keeps a real failure at error", () => {
const evt = new WideEventBuilder("http");
evt.setError(new Error("database unreachable"));
expect(evt.getLevel()).toBe("error");
const five = new WideEventBuilder("http");
five.setError(Object.assign(new Error("bad gateway"), { statusCode: 502 }));
expect(five.getLevel()).toBe("error");
});
});