Files
PaperClipAI/server/src/__tests__/error-handler.test.ts
T
e482f0f632 fix(server): shed only retryable object-journal reads under load (#19176)
Client polling can exhaust the shared object journal queue and reject log persistence. Bound ordinary object-log and trace reads, keep persistence and internal verification queued, and return retryable 503 responses when reads are busy. Leave feedback exports unsent until every log page is available.

Validation: 72 latest-master affected tests and 10 workflow tests pass locally, with the workflow fixture passing strict TypeScript checks. The preceding broader run passed 280 server tests with two opt-in S3 skips. All applicable checks on d0a937768d are green (56 success, three skipped); exact-head Apex review is 5/5 with no unresolved findings. Background persistence still has no fixed queue bound during a prolonged storage outage.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
Co-Authored-By: Paperclip <noreply@paperclip.ing>
2026-11-06 13:47:25 -08:00

418 lines
15 KiB
TypeScript

import type { NextFunction, Request, Response } from "express";
import { beforeEach, describe, expect, it, vi } from "vitest";
import { HttpError } from "../errors.js";
import { errorHandler } from "../middleware/error-handler.js";
import { mcpDiscoveryHttpFailure, retainMcpConnectionFailure } from "../services/mcp-connection-failure.js";
import { ObjectJournalBusyError } from "../services/object-byte-journal.js";
const recordResponsibleUserDenialOnActiveRunMock = vi.hoisted(() => vi.fn());
const captureExceptionMock = vi.hoisted(() => vi.fn());
const telemetryMocks = vi.hoisted(() => ({
client: {},
trackErrorHandlerCrash: vi.fn(),
}));
vi.mock("../services/responsible-user-denial-run-outcomes.js", () => ({
recordResponsibleUserDenialOnActiveRun:
recordResponsibleUserDenialOnActiveRunMock,
}));
vi.mock("../sentry.js", () => ({ captureException: captureExceptionMock }));
vi.mock("../telemetry.js", () => ({
getTelemetryClient: () => telemetryMocks.client,
}));
vi.mock("@paperclipai/shared/telemetry", () => ({
trackErrorHandlerCrash: telemetryMocks.trackErrorHandlerCrash,
}));
function makeReq(): Request {
return {
method: "GET",
originalUrl: "/api/test",
body: { a: 1 },
params: { id: "123" },
query: { q: "x" },
} as unknown as Request;
}
function makeRes(): Response {
const res = {
status: vi.fn(),
json: vi.fn(),
} as unknown as Response;
(res.status as unknown as ReturnType<typeof vi.fn>).mockReturnValue(res);
return res;
}
describe("errorHandler", () => {
beforeEach(() => {
recordResponsibleUserDenialOnActiveRunMock.mockReset();
recordResponsibleUserDenialOnActiveRunMock.mockResolvedValue(null);
captureExceptionMock.mockReset();
telemetryMocks.trackErrorHandlerCrash.mockReset();
});
it("passes only authenticated run identity to Sentry for a run-related server error", () => {
const req = makeReq();
req.actor = { type: "agent", runId: "run", companyId: "company", agentId: "agent" };
const error = new Error("run request failed");
errorHandler(error, req, makeRes(), vi.fn());
expect(captureExceptionMock).toHaveBeenCalledWith(error, { runId: "run", companyId: "company", agentId: "agent" });
expect(JSON.stringify(captureExceptionMock.mock.calls)).not.toContain('"a":1');
});
it("attaches the original Error to res.err for 500s", () => {
const req = makeReq();
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new Error("boom");
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(500);
expect(res.json).toHaveBeenCalledWith({ error: "Internal server error" });
expect(res.err).toBe(err);
expect(res.__errorContext?.error?.message).toBe("boom");
});
it("ends aborted client requests without reporting a crash", () => {
// A closed tab or dropped network surfaces as `Error: aborted` with
// ECONNRESET; there is no server fault and nobody left to answer.
const req = makeReq();
const res = { ...makeRes(), end: vi.fn(), headersSent: false } as any;
(res.status as ReturnType<typeof vi.fn>).mockReturnValue(res);
const next = vi.fn() as unknown as NextFunction;
const err = Object.assign(new Error("aborted"), { code: "ECONNRESET" });
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(499);
expect(res.end).toHaveBeenCalled();
expect(res.json).not.toHaveBeenCalled();
expect(captureExceptionMock).not.toHaveBeenCalled();
expect(telemetryMocks.trackErrorHandlerCrash).not.toHaveBeenCalled();
});
function endedPoolQueryError() {
// Drizzle wraps the driver error; postgres.js uses CONNECTION_ENDED for a
// query issued after this process called `sql.end()`.
const driverError = Object.assign(new Error("write CONNECTION_ENDED db.example:5432"), {
code: "CONNECTION_ENDED",
});
return new Error('Failed query: select "id" from "issues"', { cause: driverError });
}
it("answers 503 without reporting a query that outlived the database shutdown", () => {
const req = { ...makeReq(), app: { locals: { paperclipDatabaseClosing: true } } } as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
errorHandler(endedPoolQueryError(), req, res, next);
expect(res.status).toHaveBeenCalledWith(503);
expect(res.json).toHaveBeenCalledWith({ error: "Server is shutting down" });
expect(res.err).toBeUndefined();
expect(captureExceptionMock).not.toHaveBeenCalled();
expect(telemetryMocks.trackErrorHandlerCrash).not.toHaveBeenCalled();
});
it("answers a shed object-storage read with a retryable 503 without reporting it", () => {
const res = { ...makeRes(), set: vi.fn() } as any;
const next = vi.fn() as unknown as NextFunction;
errorHandler(new ObjectJournalBusyError(), makeReq(), res, next);
expect(res.set).toHaveBeenCalledWith("Retry-After", "2");
expect(res.status).toHaveBeenCalledWith(503);
expect(res.json).toHaveBeenCalledWith({
error: "Object storage is busy; retry shortly",
code: "object_journal_io_busy",
});
expect(res.err).toBeUndefined();
expect(captureExceptionMock).not.toHaveBeenCalled();
expect(telemetryMocks.trackErrorHandlerCrash).not.toHaveBeenCalled();
});
it("only ends the response when headers were already sent during database shutdown", () => {
const req = { ...makeReq(), app: { locals: { paperclipDatabaseClosing: true } } } as unknown as Request;
const res = { ...makeRes(), end: vi.fn(), headersSent: true } as any;
const next = vi.fn() as unknown as NextFunction;
errorHandler(endedPoolQueryError(), req, res, next);
expect(res.status).not.toHaveBeenCalled();
expect(res.end).toHaveBeenCalled();
expect(captureExceptionMock).not.toHaveBeenCalled();
});
it("still reports an ended-pool query error outside database shutdown", () => {
const req = { ...makeReq(), app: { locals: {} } } as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = endedPoolQueryError();
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(500);
expect(captureExceptionMock).toHaveBeenCalledWith(err);
});
it("still reports other connection failures during database shutdown", () => {
const req = { ...makeReq(), app: { locals: { paperclipDatabaseClosing: true } } } as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new Error("Failed query", {
cause: Object.assign(new Error("write CONNECTION_CLOSED"), { code: "CONNECTION_CLOSED" }),
});
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(500);
expect(captureExceptionMock).toHaveBeenCalledWith(err);
});
it("exposes raw 500 messages for trusted Cloud tenant imports", () => {
const req = {
...makeReq(),
method: "POST",
originalUrl: "/api/companies/import",
actor: {
type: "board",
userId: "cloud-user",
source: "cloud_tenant",
},
} as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new Error("portable file references missing upload id");
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(500);
expect(res.json).toHaveBeenCalledWith({
error: "Internal server error",
message: "portable file references missing upload id",
});
expect(res.err).toBe(err);
});
it("attaches HttpError instances for 500 responses", () => {
const req = makeReq();
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new HttpError(500, "db exploded");
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(500);
expect(res.json).toHaveBeenCalledWith({ error: "db exploded" });
expect(res.err).toBe(err);
expect(res.__errorContext?.error?.message).toBe("db exploded");
});
it("keeps HTTP failures and existing telemetry for proven external MCP outages while skipping Sentry", () => {
const req = makeReq();
const res = makeRes() as any;
const original = mcpDiscoveryHttpFailure(new Response(null, { status: 503 }), "Remote app returned HTTP 503");
const err = retainMcpConnectionFailure(original, new HttpError(502, original.message));
errorHandler(err, req, res, vi.fn());
expect(res.status).toHaveBeenCalledWith(502);
expect(res.json).toHaveBeenCalledWith({ error: original.message });
expect(res.err).toBe(err);
expect(res.__errorContext.error.message).toBe(original.message);
expect(telemetryMocks.trackErrorHandlerCrash).toHaveBeenCalledOnce();
expect(captureExceptionMock).not.toHaveBeenCalled();
});
it("reports copied connection markers and unrelated database failures", () => {
for (const err of [
Object.assign(new HttpError(502, "Remote app returned HTTP 503", { status: 503 }), {
connectionFailure: { schemaVersion: 1, provider: "mcp_http", operation: "discover_tools", reason: "remote_unavailable" },
}),
new HttpError(500, "database unavailable"),
]) {
errorHandler(err, makeReq(), makeRes(), vi.fn());
}
expect(captureExceptionMock).toHaveBeenCalledTimes(2);
expect(telemetryMocks.trackErrorHandlerCrash).toHaveBeenCalledTimes(2);
});
it.each([
{ name: "chat setup", method: "POST", path: "/api/chat-endpoints/endpoint-1/setup", body: { credentials: { botToken: "setup-error-token-canary" } } },
{ name: "observability API keys", method: "PUT", path: "/api/companies/company/observability", body: { credentials: { mode: "replace", apiKey: "setup-error-token-canary" } } },
{ name: "arbitrary OTLP headers", method: "PUT", path: "/api/companies/company/observability", body: { credentials: { mode: "replace", headers: [{ name: "x-custom", value: "setup-error-token-canary" }] } } },
])("sanitizes $name errors before logs and crash reporting", ({ method, path, body }) => {
const req = {
...makeReq(),
method,
originalUrl: path,
body,
} as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new Error("provider echoed setup-error-token-canary");
err.name = "SecretName-setup-error-token-canary";
errorHandler(err, req, res, next);
expect(res.err).not.toBe(err);
expect(res.err).toMatchObject({
name: "Error",
message: "Secret-sensitive request failed",
});
expect(res.__errorContext.error).toEqual({
name: "Error",
message: "Secret-sensitive request failed",
});
expect(captureExceptionMock).toHaveBeenCalledWith(res.err);
expect(JSON.stringify(captureExceptionMock.mock.calls)).not.toContain(
"setup-error-token-canary",
);
expect(telemetryMocks.trackErrorHandlerCrash).toHaveBeenCalledWith(
telemetryMocks.client,
{ errorCode: "Error" },
);
expect(
JSON.stringify(telemetryMocks.trackErrorHandlerCrash.mock.calls),
).not.toContain("setup-error-token-canary");
});
it("keeps actionable setup validation details while removing submitted credentials", () => {
const req = {
...makeReq(),
method: "POST",
originalUrl: "/api/chat-endpoints/endpoint-1/setup",
body: { credentials: { botToken: "invalid-token-canary" } },
} as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const err = new HttpError(
422,
"Missing required Slack scopes for invalid-token-canary",
{
code: "chat_provider_permissions_missing",
credentials: { botToken: "invalid-token-canary" },
explanation: "Provider rejected invalid-token-canary",
requiredScopes: ["chat:write", "reactions:write"],
},
);
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(422);
expect(res.json).toHaveBeenCalledWith({
error: "Missing required Slack scopes for [REDACTED]",
code: "chat_provider_permissions_missing",
details: {
code: "chat_provider_permissions_missing",
credentials: "[REDACTED]",
explanation: "Provider rejected [REDACTED]",
requiredScopes: ["chat:write", "reactions:write"],
},
});
});
it("returns 400 for Zod validation errors from another module instance", () => {
const req = makeReq();
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const issue = {
code: "invalid_type",
expected: "string",
received: "undefined",
path: ["provider"],
message: "Required",
};
const err = Object.assign(new Error("Validation failed"), {
name: "ZodError",
issues: [issue],
errors: [issue],
});
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(400);
expect(res.json).toHaveBeenCalledWith({
error: "Validation error",
details: [issue],
});
expect(res.err).toBeUndefined();
expect(res.__errorContext).toBeUndefined();
});
it("removes submitted credentials from setup Zod issue prose", () => {
const req = {
...makeReq(),
method: "POST",
originalUrl: "/api/chat-endpoints/endpoint-1/setup",
body: { credentials: { botToken: "zod-token-canary" } },
} as unknown as Request;
const res = makeRes() as any;
const next = vi.fn() as unknown as NextFunction;
const issue = {
code: "custom",
path: ["credentials", "botToken"],
message: "Rejected zod-token-canary",
};
const err = Object.assign(new Error("Validation failed"), {
name: "ZodError",
issues: [issue],
errors: [issue],
});
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(400);
expect(res.json).toHaveBeenCalledWith({
error: "Validation error",
details: [
{
code: "custom",
path: ["credentials", "botToken"],
message: "Rejected [REDACTED]",
},
],
});
});
it("records responsible-user denial codes on the active agent run", () => {
const db = { marker: "db" };
const req = {
...makeReq(),
app: { locals: { paperclipDb: db } },
actor: {
type: "agent",
agentId: "agent-1",
companyId: "company-1",
runId: "run-1",
source: "agent_jwt",
},
} as unknown as Request;
const res = makeRes();
const next = vi.fn() as unknown as NextFunction;
const err = new HttpError(403, "Responsible user is not authorized", {
code: "RESPONSIBLE_USER_UNAUTHORIZED",
});
errorHandler(err, req, res, next);
expect(res.status).toHaveBeenCalledWith(403);
expect(res.json).toHaveBeenCalledWith({
error: "Responsible user is not authorized",
code: "RESPONSIBLE_USER_UNAUTHORIZED",
details: { code: "RESPONSIBLE_USER_UNAUTHORIZED" },
});
expect(recordResponsibleUserDenialOnActiveRunMock).toHaveBeenCalledWith(
db,
{
runId: "run-1",
agentId: "agent-1",
companyId: "company-1",
code: "RESPONSIBLE_USER_UNAUTHORIZED",
},
);
});
});