mirror of
https://github.com/snapotter-hq/SnapOtter.git
synced 2026-08-03 07:46:42 +02:00
fix(telemetry): sharpen Sentry signal for v2.1.0 residual defects (#498)
Follow-ups to the v2.1.0 Sentry telemetry overhaul, found by reviewing live release:2.1.0 events: - error_code tag was empty because reportError read only the top-level err.code; add extractErrorCode() to walk the cause chain (pg SQLSTATE, node E-code, else first short code). - InputValidationError from a tool's processV2 in the worker was logged as error_class=bug; classify it as expected for any source. Worker-side ZodError stays a bug (schema drift). - AI dispatcher timeouts rejected with a bare Error, which the sanitizer scrubbed to a message-less "Error: Error"; reject with an operational SafeError (code "timeout") at both timeout sites. Each fix written failing-test-first; affected and adjacent unit suites green plus full CI (integration + e2e).
This commit is contained in:
@@ -13,6 +13,7 @@
|
||||
*/
|
||||
import {
|
||||
connectivityClass,
|
||||
extractErrorCode,
|
||||
isClientAbort,
|
||||
isSafeMessageError,
|
||||
isToolInputError,
|
||||
@@ -38,6 +39,10 @@ export interface ReportContext {
|
||||
export function classifyError(err: unknown, source?: ReportContext["source"]): ErrorClass {
|
||||
if (isToolInputError(err)) return "expected";
|
||||
const e = err as { name?: string; message?: string; code?: string } | null;
|
||||
// InputValidationError (apps/api/src/modality/contract.ts) is a 400 the user
|
||||
// caused with a bad file/args. Tools throw it from processV2 inside the worker
|
||||
// (e.g. sprite-sheet), so it is expected wherever it surfaces, not only http.
|
||||
if (e?.name === "InputValidationError") return "expected";
|
||||
if (e && typeof e.message === "string" && /^(Canceled$|Timed out after )/.test(e.message)) {
|
||||
return "expected";
|
||||
}
|
||||
@@ -48,9 +53,9 @@ export function classifyError(err: unknown, source?: ReportContext["source"]): E
|
||||
// worker-side parse failure is our bug.
|
||||
if (source === "http" || source === undefined) {
|
||||
if (isClientAbort(err)) return "expected";
|
||||
// ZodError = settings validation; InputValidationError = upload validation
|
||||
// (apps/api/src/modality/contract.ts). Both are user-input problems.
|
||||
if (e?.name === "ZodError" || e?.name === "InputValidationError") return "expected";
|
||||
// ZodError = settings validation. Settings are validated at the boundary, so
|
||||
// a worker-side ZodError is schema drift (our bug); only expected on http.
|
||||
if (e?.name === "ZodError") return "expected";
|
||||
}
|
||||
if (isSafeMessageError(err)) return err.kind === "bug" ? "bug" : "operational";
|
||||
if (connectivityClass(err)) return "operational";
|
||||
@@ -106,7 +111,7 @@ export async function reportError(err: unknown, ctx: ReportContext): Promise<voi
|
||||
scope.setLevel(cls === "operational" ? "warning" : "error");
|
||||
scope.setTag("source", ctx.source);
|
||||
scope.setTag("error_class", cls);
|
||||
const code = (err as { code?: string } | null)?.code;
|
||||
const code = extractErrorCode(err);
|
||||
if (code) scope.setTag("error_code", code);
|
||||
if (ctx.toolId) scope.setTag("tool_id", ctx.toolId);
|
||||
if (ctx.pool) scope.setTag("pool", ctx.pool);
|
||||
|
||||
@@ -429,7 +429,9 @@ export class PythonDispatcher {
|
||||
if (this.child && !this.child.killed) {
|
||||
this.child.kill("SIGTERM");
|
||||
}
|
||||
rejectPromise(new Error("Python script timed out"));
|
||||
rejectPromise(
|
||||
new SafeError("Python script timed out", { kind: "operational", code: "timeout" }),
|
||||
);
|
||||
}, timeout);
|
||||
|
||||
const wrappedResolve = (result: { stdout: string; stderr: string }) => {
|
||||
@@ -557,7 +559,9 @@ export class PythonDispatcher {
|
||||
}
|
||||
|
||||
if (timedOut) {
|
||||
rejectPromise(new Error("Python script timed out"));
|
||||
rejectPromise(
|
||||
new SafeError("Python script timed out", { kind: "operational", code: "timeout" }),
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
|
||||
@@ -102,6 +102,30 @@ export function rebuildErrorValue(err: unknown): string | null {
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* The most specific, non-sensitive error code in the cause chain, for the
|
||||
* Sentry `error_code` tag. Prefers a pg SQLSTATE, then a node E-code, else the
|
||||
* first short string code found (e.g. a SafeError's authored code). Returns
|
||||
* null when none is present. reportError used to read only the top-level
|
||||
* `.code`, but pg/undici bury the real code under a drizzle/wrapper Error whose
|
||||
* own `.code` is undefined, so the tag was always empty on those events.
|
||||
*/
|
||||
export function extractErrorCode(err: unknown): string | null {
|
||||
try {
|
||||
let fallback: string | null = null;
|
||||
for (const l of chain(err)) {
|
||||
const code = l.code;
|
||||
if (typeof code !== "string" || code.length === 0 || code.length > 40) continue;
|
||||
if (SQLSTATE.test(code) && !NODE_CODE.test(code)) return code;
|
||||
if (NODE_CODE.test(code)) return code;
|
||||
if (fallback === null) fallback = code;
|
||||
}
|
||||
return fallback;
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
export type ConnectivityClass = "pg-unavailable" | "redis-unavailable" | "net-unavailable";
|
||||
|
||||
/** Infra-connectivity classification used for fingerprinting + throttling. */
|
||||
|
||||
@@ -271,6 +271,30 @@ describe("bridge - runPythonWithProgress (per-request fallback)", () => {
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("rejects a per-request timeout as an operational SafeError with a 'timeout' code", async () => {
|
||||
// A timeout is environmental (huge input / slow box), not our bug. Sentry
|
||||
// must see it as an operational SafeError, not a message-less "Error: Error".
|
||||
vi.useFakeTimers();
|
||||
const mock = createMockProcess();
|
||||
vi.mocked(spawn).mockReturnValue(mock.process);
|
||||
|
||||
const promise = runPythonWithProgress("slow.py", [], { timeout: 1000 });
|
||||
const settled = promise.catch((e: unknown) => e); // attach before firing the timer
|
||||
vi.advanceTimersByTime(1500);
|
||||
mock.emitEvent("close", null, "SIGTERM");
|
||||
|
||||
const err = (await settled) as Error & {
|
||||
isSafeMessage?: unknown;
|
||||
kind?: string;
|
||||
code?: string;
|
||||
};
|
||||
expect(err.message).toBe("Python script timed out");
|
||||
expect(err.isSafeMessage).toBe(true);
|
||||
expect(err.kind).toBe("operational");
|
||||
expect(err.code).toBe("timeout");
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("invokes onProgress callback for JSON progress lines on stderr", async () => {
|
||||
const mock = createMockProcess();
|
||||
vi.mocked(spawn).mockReturnValue(mock.process);
|
||||
@@ -1390,6 +1414,36 @@ describe("bridge - dispatcher stdin JSON-RPC protocol", () => {
|
||||
expect(result.stdout).toBe('{"success": true}');
|
||||
});
|
||||
|
||||
it("rejects a dispatcher-path timeout as an operational SafeError (NODE-26 regression)", async () => {
|
||||
// NODE-26: the dispatcher request() timeout rejected with a bare
|
||||
// new Error("Python script timed out"), which the Sentry sanitizer scrubbed
|
||||
// to a message-less "Error: Error" bug. It must be an operational SafeError.
|
||||
vi.useFakeTimers();
|
||||
const mock = createMockProcess();
|
||||
vi.mocked(spawn).mockReturnValue(mock.process);
|
||||
|
||||
const initPromise = initDispatcher();
|
||||
mock.stderr.emit("data", Buffer.from('{"ready": true, "gpu": false}\n'));
|
||||
await vi.advanceTimersByTimeAsync(60); // init() polls childReady every 50ms
|
||||
await initPromise;
|
||||
|
||||
const promise = runPythonWithProgress("slow.py", [], { timeout: 1000 });
|
||||
const settled = promise.catch((e: unknown) => e); // attach before firing the timer
|
||||
await vi.advanceTimersByTimeAsync(0); // flush the request's stdin write
|
||||
await vi.advanceTimersByTimeAsync(1100); // fire the dispatcher request timeout
|
||||
|
||||
const err = (await settled) as Error & {
|
||||
isSafeMessage?: unknown;
|
||||
kind?: string;
|
||||
code?: string;
|
||||
};
|
||||
expect(err.message).toBe("Python script timed out");
|
||||
expect(err.isSafeMessage).toBe(true);
|
||||
expect(err.kind).toBe("operational");
|
||||
expect(err.code).toBe("timeout");
|
||||
vi.useRealTimers();
|
||||
});
|
||||
|
||||
it("strips .py extension from script name in dispatcher request", async () => {
|
||||
const mock = await setupReadyDispatcher();
|
||||
|
||||
|
||||
@@ -46,6 +46,21 @@ describe("capture path", () => {
|
||||
expect(h.scope.setTag).toHaveBeenCalledWith("pool", "image");
|
||||
});
|
||||
|
||||
it("tags error_code from a code nested in the cause chain, not just the top level", async () => {
|
||||
// pg/undici bury the real code under a drizzle/wrapper Error whose own
|
||||
// .code is undefined; reading only the top level left error_code empty.
|
||||
const pg = Object.assign(new Error("password authentication failed"), {
|
||||
code: "28P01",
|
||||
severity: "FATAL",
|
||||
});
|
||||
const wrapped = Object.assign(new Error("Failed query: select 1"), { cause: pg });
|
||||
|
||||
await reportError(wrapped, { source: "worker", pool: "docs" });
|
||||
|
||||
expect(h.captureException).toHaveBeenCalledTimes(1);
|
||||
expect(h.scope.setTag).toHaveBeenCalledWith("error_code", "28P01");
|
||||
});
|
||||
|
||||
it("captures once per distinct signature; operational repeats are throttled", async () => {
|
||||
const full = Object.assign(new Error("disk full"), { code: "ENOSPC" });
|
||||
await reportError(full, { source: "worker", pool: "image" });
|
||||
|
||||
@@ -50,6 +50,17 @@ describe("classifyError", () => {
|
||||
expect(classifyError(reset, "worker")).toBe("operational");
|
||||
expect(classifyError(reset, "http")).toBe("expected");
|
||||
});
|
||||
it("InputValidationError is a user 400 wherever it surfaces, not only on http", () => {
|
||||
// Tools throw InputValidationError from processV2 in the worker (e.g.
|
||||
// sprite-sheet "Provide at least two images"); it must not be logged as a bug.
|
||||
const e = Object.assign(new Error("Provide at least two images"), {
|
||||
name: "InputValidationError",
|
||||
});
|
||||
expect(classifyError(e, "worker")).toBe("expected");
|
||||
expect(classifyError(e, "cron")).toBe("expected");
|
||||
expect(classifyError(e, "http")).toBe("expected");
|
||||
expect(classifyError(e)).toBe("expected");
|
||||
});
|
||||
});
|
||||
|
||||
describe("throttle", () => {
|
||||
|
||||
@@ -1,4 +1,10 @@
|
||||
import { connectivityClass, isClientAbort, rebuildErrorValue, SafeError } from "@snapotter/shared";
|
||||
import {
|
||||
connectivityClass,
|
||||
extractErrorCode,
|
||||
isClientAbort,
|
||||
rebuildErrorValue,
|
||||
SafeError,
|
||||
} from "@snapotter/shared";
|
||||
import { describe, expect, it } from "vitest";
|
||||
|
||||
const sysErr = (code: string, syscall?: string) =>
|
||||
@@ -79,6 +85,45 @@ describe("rebuildErrorValue", () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("extractErrorCode", () => {
|
||||
it("finds a pg SQLSTATE through a drizzle-style cause chain", () => {
|
||||
const pg = Object.assign(new Error("password authentication failed"), {
|
||||
code: "28P01",
|
||||
severity: "FATAL",
|
||||
});
|
||||
const wrapped = Object.assign(new Error("Failed query: select 1"), { cause: pg });
|
||||
expect(extractErrorCode(wrapped)).toBe("28P01");
|
||||
});
|
||||
it("finds a node syscall code nested in the chain", () => {
|
||||
const net = Object.assign(new Error("getaddrinfo ENOTFOUND db"), { code: "ENOTFOUND" });
|
||||
const wrapped = Object.assign(new Error("connect failed"), { cause: net });
|
||||
expect(extractErrorCode(wrapped)).toBe("ENOTFOUND");
|
||||
});
|
||||
it("prefers a pg SQLSTATE over an earlier non-standard code", () => {
|
||||
const pg = Object.assign(new Error("deadlock detected"), { code: "40P01" });
|
||||
const wrapped = Object.assign(new Error("wrap"), { code: "generic", cause: pg });
|
||||
expect(extractErrorCode(wrapped)).toBe("40P01");
|
||||
});
|
||||
it("falls back to a SafeError's authored code when no pg/node code is present", () => {
|
||||
const err = new SafeError("Python script timed out", { kind: "operational", code: "timeout" });
|
||||
expect(extractErrorCode(err)).toBe("timeout");
|
||||
});
|
||||
it("returns null when no code exists anywhere in the chain", () => {
|
||||
expect(extractErrorCode(new Error("plain boom"))).toBeNull();
|
||||
expect(extractErrorCode("string")).toBeNull();
|
||||
expect(extractErrorCode(null)).toBeNull();
|
||||
});
|
||||
it("returns null when a cause getter throws (hostile)", () => {
|
||||
const hostile = new Error("boom");
|
||||
Object.defineProperty(hostile, "cause", {
|
||||
get() {
|
||||
throw new Error("gotcha");
|
||||
},
|
||||
});
|
||||
expect(extractErrorCode(hostile)).toBeNull();
|
||||
});
|
||||
});
|
||||
|
||||
describe("connectivityClass", () => {
|
||||
it("classifies pg-unavailable via SQLSTATE 08/57P and drizzle wrapping", () => {
|
||||
const pg = Object.assign(new Error("terminating connection"), { code: "57P01" });
|
||||
|
||||
Reference in New Issue
Block a user