mirror of
https://github.com/MBombeck/HealthLog.git
synced 2026-11-10 05:12:14 +00:00
fix(jobs): report the measurements bloat as whole percent, and keep finished runs finished
The nightly measurements check reported its bloat factor, a ratio such as 1.3, as a job fact. A fact is a non-negative whole number, so the outcome validation refused it on every run, after the vacuum and the reindex had already done their work, and the run failed. It now reports bloat_percent (130), and the duration goes through the same rounding. A malformed fact no longer fails a run whose work is done: runJob drops it from the result and emits job.outcome.fact_invalid at error level with the queue and the key, where failing would have made pg-boss retry finished work. A failed outcome is unchanged. wholeFact and percentFact are the intended way to report a measured value or a ratio, and a guard reads every outcome producer and refuses a fact that is a division or names a ratio unless it is rounded on purpose. The other producers were checked: their numeric facts are counts and integer millisecond durations. Refs #1271
This commit is contained in:
1 parent
67135b2ce8
commit
2ed863f877
7 files changed
+357
-34
No files matched your search
@@ -165,8 +165,9 @@ singleton key with the run you start, so the two never overlap. The admin
|
||||
card keeps showing only the runs you started.
|
||||
|
||||
The check also measures how far the table file has grown past what its live
|
||||
rows need (`maintenance_bloat_factor` on the wide event, `bloat_factor` in the
|
||||
job result). Past 3 it adds a warning to the event: a vacuum makes the space
|
||||
rows need (`maintenance_bloat_factor` on the wide event, as a factor such as
|
||||
1.3; `bloat_percent` in the job result, as whole percent such as 130, because a
|
||||
job fact is a whole number). Past 3 it adds a warning to the event: a vacuum makes the space
|
||||
reusable but does not shrink the file, and only `VACUUM FULL` does (see
|
||||
below).
|
||||
|
||||
|
||||
@@ -0,0 +1,134 @@
|
||||
/**
|
||||
* A job fact is a non-negative whole number, a stable code or a boolean
|
||||
* (`src/lib/jobs/job-outcome.ts`). A producer that hands a ratio, an average
|
||||
* or a quotient over as a number passes the type checker and fails the
|
||||
* outcome's validation at run time: the nightly measurements check reported
|
||||
* its bloat factor (1.3) that way and failed every run (#1271).
|
||||
*
|
||||
* This reads every module that reports a job outcome and refuses a fact whose
|
||||
* value is a division, or names a ratio-shaped quantity (a name ending in
|
||||
* factor, ratio, average, mean, share, fraction or percent), unless it goes through
|
||||
* `wholeFact`/`percentFact` or an explicit `Math.round`/`floor`/`ceil`/`trunc`.
|
||||
* A text-level check: it sees the expression written at the fact, not what a
|
||||
* variable it names was computed from. The runtime half is `runJob`, which
|
||||
* drops and signals an invalid fact instead of failing finished work.
|
||||
*/
|
||||
import ts from "typescript";
|
||||
import { join } from "node:path";
|
||||
import { describe, expect, it } from "vitest";
|
||||
|
||||
import { JOB_FACT_ALLOWLIST } from "@/lib/jobs/job-outcome";
|
||||
|
||||
import { readSourceText, walkSourceFiles } from "./helpers/source-files";
|
||||
import { parse } from "./helpers/source-metrics";
|
||||
|
||||
const SRC = join(process.cwd(), "src");
|
||||
/** The last word of a camelCase or snake_case name: what the value IS. */
|
||||
const RATIO_NOUN = /^(factor|ratio|average|avg|mean|share|fraction|percent)$/;
|
||||
function namesRatio(name: string): boolean {
|
||||
const words = name
|
||||
.replace(/([a-z0-9])([A-Z])/g, "$1_$2")
|
||||
.toLowerCase()
|
||||
.split("_")
|
||||
.filter(Boolean);
|
||||
return RATIO_NOUN.test(words[words.length - 1] ?? "");
|
||||
}
|
||||
const ROUNDING_CALL =
|
||||
/^(wholeFact|percentFact|Math\.(round|floor|ceil|trunc))$/;
|
||||
|
||||
function roundedByCall(node: ts.Node): boolean {
|
||||
for (let n: ts.Node | undefined = node; n; n = n.parent) {
|
||||
if (ts.isCallExpression(n) && ROUNDING_CALL.test(n.expression.getText())) {
|
||||
return true;
|
||||
}
|
||||
if (ts.isPropertyAssignment(n)) return false;
|
||||
}
|
||||
return false;
|
||||
}
|
||||
|
||||
function suspicious(initializer: ts.Expression): boolean {
|
||||
let found = false;
|
||||
const visit = (node: ts.Node): void => {
|
||||
if (found) return;
|
||||
const divides =
|
||||
ts.isBinaryExpression(node) &&
|
||||
node.operatorToken.kind === ts.SyntaxKind.SlashToken;
|
||||
const ratioName =
|
||||
(ts.isIdentifier(node) || ts.isPrivateIdentifier(node)) &&
|
||||
namesRatio(node.text);
|
||||
if ((divides || ratioName) && !roundedByCall(node)) {
|
||||
found = true;
|
||||
return;
|
||||
}
|
||||
ts.forEachChild(node, visit);
|
||||
};
|
||||
visit(initializer);
|
||||
return found;
|
||||
}
|
||||
|
||||
/** `file:line key` for every allowlisted fact whose value looks fractional. */
|
||||
function offenders(rel: string, text: string): string[] {
|
||||
if (!text.includes("jobDone(") && !text.includes("jobFailed(")) return [];
|
||||
const source = parse(rel, text);
|
||||
const out: string[] = [];
|
||||
const visit = (node: ts.Node): void => {
|
||||
if (
|
||||
ts.isPropertyAssignment(node) &&
|
||||
(ts.isIdentifier(node.name) || ts.isStringLiteral(node.name)) &&
|
||||
JOB_FACT_ALLOWLIST.has(node.name.text) &&
|
||||
suspicious(node.initializer)
|
||||
) {
|
||||
const { line } = source.getLineAndCharacterOfPosition(node.getStart());
|
||||
out.push(`${rel}:${line + 1} ${node.name.text}`);
|
||||
}
|
||||
ts.forEachChild(node, visit);
|
||||
};
|
||||
visit(source);
|
||||
return out;
|
||||
}
|
||||
|
||||
describe("job facts are whole numbers at the source", () => {
|
||||
const files = walkSourceFiles(SRC, { floor: 1500 }).filter(
|
||||
(rel) =>
|
||||
!rel.startsWith("generated/") &&
|
||||
!rel.includes("__tests__") &&
|
||||
!rel.endsWith(".test.ts"),
|
||||
);
|
||||
|
||||
it("reads the producers it claims to check", () => {
|
||||
const producers = files.filter((rel) =>
|
||||
readSourceText(join(SRC, rel)).includes("jobDone("),
|
||||
);
|
||||
expect(producers.length).toBeGreaterThan(40);
|
||||
});
|
||||
|
||||
it("finds no fact that carries a ratio or a quotient as it stands", () => {
|
||||
const found = files.flatMap((rel) =>
|
||||
offenders(rel, readSourceText(join(SRC, rel))),
|
||||
);
|
||||
expect(found).toEqual([]);
|
||||
});
|
||||
|
||||
it("catches the shape it guards against, and lets the rounded one through", () => {
|
||||
const old = [
|
||||
"const facts = {",
|
||||
" dead_rows: health.deadRows,",
|
||||
" bloat_percent: health.bloatFactor ?? 0,",
|
||||
" duration_ms: elapsed / 1000,",
|
||||
"};",
|
||||
"return jobDone(facts);",
|
||||
].join("\n");
|
||||
expect(offenders("x.ts", old)).toEqual([
|
||||
"x.ts:3 bloat_percent",
|
||||
"x.ts:4 duration_ms",
|
||||
]);
|
||||
const fixed = [
|
||||
"const facts = {",
|
||||
" bloat_percent: percentFact(health.bloatFactor),",
|
||||
" duration_ms: Math.round(elapsed / 1000),",
|
||||
"};",
|
||||
"return jobDone(facts);",
|
||||
].join("\n");
|
||||
expect(offenders("x.ts", fixed)).toEqual([]);
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,89 @@
|
||||
/**
|
||||
* #1271: the nightly measurements check failed every run, because it reported
|
||||
* its bloat factor (heap size over what the live rows need, a ratio such as
|
||||
* 1.3) as a job fact, and a fact is a non-negative whole number. The factor
|
||||
* now rides as whole percent.
|
||||
*
|
||||
* The handler runs for real against a stand-in connection that answers the
|
||||
* table-statistics read with a heap 1.3 times what its rows need; its outcome
|
||||
* goes through the strict serializer, which refused the old fact.
|
||||
*/
|
||||
import { describe, expect, it, vi } from "vitest";
|
||||
import type { Job } from "pg-boss";
|
||||
|
||||
vi.mock("pg", () => ({
|
||||
Client: class {
|
||||
on() {}
|
||||
async connect() {}
|
||||
async end() {}
|
||||
async query(sql: string) {
|
||||
if (sql.includes("pg_stat_user_tables")) {
|
||||
// 1,000 rows of 72 bytes plus 28 of overhead at fill factor 0.85
|
||||
// need about 117,647 bytes; the heap holds 1.3 times that.
|
||||
return {
|
||||
rows: [{ live: "1000", dead: "40", heap: "152941", width: "72" }],
|
||||
};
|
||||
}
|
||||
if (sql.includes("pg_total_relation_size")) {
|
||||
return { rows: [{ table: "300000", indexes: "100000" }] };
|
||||
}
|
||||
return { rows: [] };
|
||||
}
|
||||
},
|
||||
}));
|
||||
vi.mock("@/lib/db", () => ({ sessionOptionsDisabled: () => true }));
|
||||
vi.mock("@/lib/jobs/job-lock", () => ({
|
||||
withJobLock: async (_queue: string, run: () => Promise<unknown>) => ({
|
||||
ran: true,
|
||||
result: await run(),
|
||||
}),
|
||||
}));
|
||||
vi.mock("@/lib/jobs/job-run-report", () => ({ reportJobRun: () => {} }));
|
||||
|
||||
import {
|
||||
jobDone,
|
||||
percentFact,
|
||||
serializeJobOutcome,
|
||||
wholeFact,
|
||||
} from "../job-outcome";
|
||||
import {
|
||||
handleMeasurementMaintenance,
|
||||
type MeasurementMaintenancePayload,
|
||||
} from "../measurement-maintenance";
|
||||
|
||||
describe("the measurement maintenance outcome", () => {
|
||||
it("serialises with a realistic, fractional bloat factor", async () => {
|
||||
const outcome = await handleMeasurementMaintenance([
|
||||
{ id: "run-1", data: {} } as Job<MeasurementMaintenancePayload>,
|
||||
]);
|
||||
expect(outcome.ok).toBe(true);
|
||||
const serialized = serializeJobOutcome(outcome);
|
||||
expect(serialized.ok).toBe(true);
|
||||
expect(serialized.did).toMatchObject({
|
||||
dead_rows: 40,
|
||||
bloat_percent: 130,
|
||||
});
|
||||
expect(serialized.did).not.toHaveProperty("bloat_factor");
|
||||
});
|
||||
});
|
||||
|
||||
describe("the fact helpers", () => {
|
||||
it("round a measured value to a whole, non-negative fact", () => {
|
||||
expect(wholeFact(12.5)).toBe(13);
|
||||
expect(wholeFact(-4)).toBe(0);
|
||||
expect(wholeFact(Number.NaN)).toBe(0);
|
||||
expect(wholeFact(null)).toBe(0);
|
||||
});
|
||||
|
||||
it("turn a ratio into whole percent", () => {
|
||||
expect(percentFact(1.3)).toBe(130);
|
||||
expect(percentFact(0.004)).toBe(0);
|
||||
expect(percentFact(undefined)).toBe(0);
|
||||
});
|
||||
|
||||
it("leave the strict serializer refusing what the helpers exist to prevent", () => {
|
||||
expect(() => serializeJobOutcome(jobDone({ dead_rows: 1.3 }))).toThrow(
|
||||
/non-negative safe integer/,
|
||||
);
|
||||
});
|
||||
});
|
||||
@@ -87,17 +87,53 @@ describe("runJob", () => {
|
||||
expect(reportWorkerError).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
it("refuses to persist credentials or unbounded facts on success", async () => {
|
||||
it("refuses to persist credentials on success, without failing the finished run", async () => {
|
||||
const wrapped = runJob("google-health-sync", async () =>
|
||||
jobDone({
|
||||
refresh_token: "private-token",
|
||||
processed: 2,
|
||||
} as unknown as Record<string, string>),
|
||||
);
|
||||
|
||||
await expect(wrapped(noJobs)).rejects.toThrow(/fact key is not allowed/i);
|
||||
// The run's work is done: the result keeps what the contract allows and
|
||||
// drops the rest, and the drop is an error-level signal naming the key.
|
||||
await expect(wrapped(noJobs)).resolves.toEqual({
|
||||
ok: true,
|
||||
did: { processed: 2 },
|
||||
});
|
||||
expect(emitSignal).toHaveBeenCalledWith(
|
||||
expect.objectContaining({
|
||||
action: "job.outcome.fact_invalid",
|
||||
level: "error",
|
||||
meta: { queue: "google-health-sync", key: "refresh_token" },
|
||||
}),
|
||||
);
|
||||
expect(JSON.stringify(emitSignal.mock.calls)).not.toContain(
|
||||
"private-token",
|
||||
);
|
||||
expect(reportWorkerError).not.toHaveBeenCalled();
|
||||
});
|
||||
|
||||
it("does not fail a finished run over a fact that is not a whole number (#1271)", async () => {
|
||||
// The nightly measurements check reported its bloat factor, a ratio such
|
||||
// as 1.3, as a fact. The validation refused it after the VACUUM had run,
|
||||
// so every run failed and pg-boss retried finished work.
|
||||
const wrapped = runJob("measurement-maintenance", async () =>
|
||||
jobDone({ processed: 3, duration_ms: 12.5, dead_rows: 40 }),
|
||||
);
|
||||
|
||||
await expect(wrapped(noJobs)).resolves.toEqual({
|
||||
ok: true,
|
||||
did: { processed: 3, dead_rows: 40 },
|
||||
});
|
||||
expect(emitSignal).toHaveBeenCalledWith(
|
||||
expect.objectContaining({
|
||||
action: "job.outcome.fact_invalid",
|
||||
meta: { queue: "measurement-maintenance", key: "duration_ms" },
|
||||
}),
|
||||
);
|
||||
});
|
||||
|
||||
it("rethrows a failed outcome so pg-boss records a failed job", async () => {
|
||||
const cause = new Error("statement timeout");
|
||||
const wrapped = runJob("push-attempt-cleanup", async () =>
|
||||
|
||||
+66
-25
@@ -57,8 +57,9 @@ export const JOB_FACT_ALLOWLIST: ReadonlySet<string> = new Set([
|
||||
"assessments_warmed",
|
||||
"auto_resolved",
|
||||
"backed",
|
||||
// The nightly measurements check: heap size over what the live rows need.
|
||||
"bloat_factor",
|
||||
// The nightly measurements check: heap size over what the live rows need,
|
||||
// in percent (130 is a heap 1.3 times the size its live rows need).
|
||||
"bloat_percent",
|
||||
"buckets_collapsed",
|
||||
"buckets_recomputed",
|
||||
"budget_blocked",
|
||||
@@ -367,46 +368,86 @@ function assertStableCode(value: string, label: string): void {
|
||||
}
|
||||
}
|
||||
|
||||
function validateFacts(facts: JobFacts): JobFacts {
|
||||
/**
|
||||
* A measured quantity as a fact: a duration or an amount computed in floating
|
||||
* point, rounded on purpose. A fact is a non-negative whole number, and a
|
||||
* value that is not one fails the outcome's validation.
|
||||
*/
|
||||
export function wholeFact(value: number | null | undefined): number {
|
||||
if (value == null || !Number.isFinite(value)) return 0;
|
||||
return Math.max(0, Math.round(value));
|
||||
}
|
||||
|
||||
/**
|
||||
* A ratio as a fact, in whole percent: 1.3 is 130. A ratio is not a whole
|
||||
* number, so it cannot be a fact as it stands; this is the one way to report
|
||||
* one. Absent or unmeasurable is 0.
|
||||
*/
|
||||
export function percentFact(ratio: number | null | undefined): number {
|
||||
if (ratio == null || !Number.isFinite(ratio)) return 0;
|
||||
return wholeFact(ratio * 100);
|
||||
}
|
||||
|
||||
/** Why one fact is refused, or null when it is a valid fact. */
|
||||
function invalidFact(key: string, value: unknown): string | null {
|
||||
if (!JOB_FACT_ALLOWLIST.has(key))
|
||||
return `job fact key is not allowed: ${key}`;
|
||||
if (typeof value === "number") {
|
||||
return Number.isSafeInteger(value) && value >= 0
|
||||
? null
|
||||
: `job fact ${key} must be a non-negative safe integer`;
|
||||
}
|
||||
if (typeof value === "string") {
|
||||
return STABLE_CODE_PATTERN.test(value)
|
||||
? null
|
||||
: `job fact ${key} must be a stable lowercase code`;
|
||||
}
|
||||
return typeof value === "boolean"
|
||||
? null
|
||||
: `job fact ${key} must be a bounded scalar`;
|
||||
}
|
||||
|
||||
/**
|
||||
* Called for each fact the serializer drops instead of throwing over it. A
|
||||
* caller that passes it has already done the run's work: refusing the whole
|
||||
* outcome over one malformed fact would fail completed work, and pg-boss
|
||||
* would retry it.
|
||||
*/
|
||||
export type InvalidFactHandler = (key: string, reason: string) => void;
|
||||
|
||||
function validateFacts(
|
||||
facts: JobFacts,
|
||||
onInvalidFact?: InvalidFactHandler,
|
||||
): JobFacts {
|
||||
const entries = Object.entries(facts);
|
||||
|
||||
if (entries.length > MAX_JOB_FACTS) {
|
||||
throw new RangeError(`job outcome exceeds ${MAX_JOB_FACTS} facts`);
|
||||
}
|
||||
|
||||
const kept: Array<[string, JobFact]> = [];
|
||||
for (const [key, value] of entries) {
|
||||
if (!JOB_FACT_ALLOWLIST.has(key)) {
|
||||
throw new TypeError(`job fact key is not allowed: ${key}`);
|
||||
}
|
||||
|
||||
if (typeof value === "number") {
|
||||
if (!Number.isSafeInteger(value) || value < 0) {
|
||||
throw new TypeError(
|
||||
`job fact ${key} must be a non-negative safe integer`,
|
||||
);
|
||||
}
|
||||
const reason = invalidFact(key, value);
|
||||
if (reason === null) {
|
||||
kept.push([key, value]);
|
||||
continue;
|
||||
}
|
||||
|
||||
if (typeof value === "string") {
|
||||
assertStableCode(value, `job fact ${key}`);
|
||||
continue;
|
||||
}
|
||||
|
||||
if (typeof value !== "boolean") {
|
||||
throw new TypeError(`job fact ${key} must be a bounded scalar`);
|
||||
}
|
||||
if (!onInvalidFact) throw new TypeError(reason);
|
||||
onInvalidFact(key, reason);
|
||||
}
|
||||
|
||||
return Object.freeze(Object.fromEntries(entries)) as JobFacts;
|
||||
return Object.freeze(Object.fromEntries(kept)) as JobFacts;
|
||||
}
|
||||
|
||||
/**
|
||||
* Produce the only representation suitable for persistence or structured
|
||||
* logging. The raw `cause` deliberately remains in-process for retry handling.
|
||||
*/
|
||||
export function serializeJobOutcome(outcome: JobOutcome): SerializedJobOutcome {
|
||||
const did = validateFacts(outcome.did ?? {});
|
||||
export function serializeJobOutcome(
|
||||
outcome: JobOutcome,
|
||||
options: { onInvalidFact?: InvalidFactHandler } = {},
|
||||
): SerializedJobOutcome {
|
||||
const did = validateFacts(outcome.did ?? {}, options.onInvalidFact);
|
||||
const serialized: SerializedJobOutcome = outcome.ok
|
||||
? { ok: true, did }
|
||||
: (() => {
|
||||
|
||||
@@ -61,7 +61,13 @@ import type { Job } from "pg-boss";
|
||||
import { sessionOptionsDisabled } from "@/lib/db";
|
||||
|
||||
import { withJobLock } from "@/lib/jobs/job-lock";
|
||||
import { jobDone, jobFailed, type JobOutcome } from "@/lib/jobs/job-outcome";
|
||||
import {
|
||||
jobDone,
|
||||
jobFailed,
|
||||
percentFact,
|
||||
wholeFact,
|
||||
type JobOutcome,
|
||||
} from "@/lib/jobs/job-outcome";
|
||||
import { reportJobRun, type JobRunCandidate } from "@/lib/jobs/job-run-report";
|
||||
import { withBackgroundEvent } from "@/lib/logging/background";
|
||||
import { logCaught } from "@/lib/logging/signal";
|
||||
@@ -640,10 +646,12 @@ export async function handleMeasurementMaintenance(
|
||||
outcome: result.outcome,
|
||||
processed: result.steps.filter((s) => s.ok).length,
|
||||
failed: result.steps.filter((s) => !s.ok).length,
|
||||
duration_ms: Date.now() - startedAt,
|
||||
duration_ms: wholeFact(Date.now() - startedAt),
|
||||
dead_rows: health.deadRows,
|
||||
// Zero before the table has statistics to measure against.
|
||||
bloat_factor: health.bloatFactor ?? 0,
|
||||
// In whole percent: a fact is a whole number and the factor a ratio
|
||||
// (1.3). Reported as the ratio itself it failed every run's outcome
|
||||
// validation (#1271). Zero before the table has statistics.
|
||||
bloat_percent: percentFact(health.bloatFactor),
|
||||
};
|
||||
if (result.outcome === "failed") {
|
||||
const firstError = result.steps.find((s) => !s.ok);
|
||||
|
||||
+15
-1
@@ -116,7 +116,21 @@ export function runJob<J>(
|
||||
await signalRunFailed(queue, "handler_threw", error);
|
||||
throw error;
|
||||
}
|
||||
if (outcome.ok) return serializeJobOutcome(outcome);
|
||||
// The work is done by now. A fact that breaks the contract is a
|
||||
// programming error in the handler, reported at error level and dropped
|
||||
// from the result; failing the run over it would retry work that already
|
||||
// succeeded (a nightly VACUUM, a full sweep).
|
||||
if (outcome.ok) {
|
||||
return serializeJobOutcome(outcome, {
|
||||
onInvalidFact: (key, reason) =>
|
||||
emitSignal({
|
||||
action: "job.outcome.fact_invalid",
|
||||
level: "error",
|
||||
meta: { queue, key },
|
||||
error: new TypeError(reason),
|
||||
}),
|
||||
});
|
||||
}
|
||||
|
||||
const failure = new JobFailure(queue, outcome.reason, outcome.cause);
|
||||
const causeMessage =
|
||||
|
||||
Reference in new issue
Block a user