mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-22 00:30:19 +02:00
## Thinking Path > - Paperclip manages AI agents and the services they use for work. > - An agent can wait for a workspace service to become ready. > - Each readiness probe has a time limit. > - A final probe can expire and hide an earlier HTTP failure. > - This pull request keeps that observed failure in the reported error. > - Operators can then see why the service was not ready. ## Linked Issues or Issue Description Refs #11525. Related: #11494. **What happened?** A deadline-limited final readiness probe replaced an observed HTTP 503 with an abort message. **Expected behavior** Keep an earlier service failure when only the readiness deadline aborts the last probe. Report normal connection failures and probe timeouts as before. **Steps to reproduce** Return HTTP 503 from the first probe. Leave one millisecond in the readiness budget. Abort the last probe. The reported error must still contain HTTP 503. ## What Changed - Track whether a readiness probe observed a service failure. - Preserve that observation when the final probe expires at the readiness deadline. - Add a deterministic regression with an injected clock. - Keep probe scheduling, request count and timeout limits unchanged. ## Verification - Author verification: the readiness suite passed all nine tests; server typecheck passed. The regression failed before the fix and passed after it. - The later task review recorded 172 passing workspace tests and seven additional readiness checks. Historical author baseline failures are not claimed as passing local runs. - Latest head `936a374a08d0e74d87d588ba034f674388e8d508`: CI passed with 54 successful checks and two intentional skips. Fresh Apex review is 5/5 with no unresolved findings or recommendations. - A test merge with current master is clean. ## Risks - Error text changes when a service first fails and then hangs. The earlier observed failure is retained. - A hang without a prior service failure still reports the abort. - No data model, API or permission change. ## Model Used Anthropic Claude Opus 5 (`claude-opus-5`) authored the fix through Claude Code with reasoning, file editing and test tools. OpenAI GPT-5.6 assisted the original diagnosis. OpenAI GPT-6 (`gpt-6`) through Codex assisted this final review and PR preparation with repository and terminal tools. This session does not expose an exact context-window size. ## Checklist - [x] I have included a thinking path that traces from project context to this change - [x] I have specified the model used (with version and capability details) - [x] I have checked ROADMAP.md and confirmed this PR does not duplicate planned core work - [x] I have searched GitHub for duplicate or related PRs and linked them above - [x] I have either (a) linked existing issues with `Fixes: #` / `Closes #` / `Refs #` OR (b) described the issue in-PR following the relevant issue template - [x] I have not referenced internal/instance-local Paperclip issues or links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip` URLs) - [x] My branch name describes the change (e.g. `docs/...`, `fix/...`) and contains no internal Paperclip ticket id or instance-derived details - [x] I have run tests locally and they pass - [x] I have added or updated tests where applicable - [x] I have updated relevant documentation to reflect my changes - [x] I have considered and documented any risks above - [x] All Paperclip CI gates are green - [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Claude Opus 5 <noreply@anthropic.com>
238 lines
10 KiB
TypeScript
238 lines
10 KiB
TypeScript
import { setTimeout as delay } from "node:timers/promises";
|
|
import { afterEach, describe, expect, it } from "vitest";
|
|
import {
|
|
RUNTIME_SERVICE_READINESS_PROBE_TIMEOUT_MS,
|
|
allocateRuntimeServicePort,
|
|
claimRuntimeServiceBindPort,
|
|
resetRuntimeServicePortReservationsForTests,
|
|
waitForRuntimeServiceReadiness,
|
|
} from "../services/workspace-runtime.js";
|
|
|
|
/**
|
|
* Regression fixture for the adverse report on PAP-17207: two exclusive isolated workspaces
|
|
* asked for the same configured app/HMR pair at the same moment. One lane came up healthy,
|
|
* the loser was reallocated onto a port owned by an unrelated listener, and its managed start
|
|
* never reached a terminal state — leaving an active operation that rejected managed cleanup.
|
|
*
|
|
* The two mechanisms that produced the non-terminality are covered here:
|
|
* 1. a readiness probe against a socket that accepts but never answers, and
|
|
* 2. concurrent allocation handing the same port to two starts.
|
|
*/
|
|
describe("managed runtime start terminality", () => {
|
|
afterEach(() => {
|
|
resetRuntimeServicePortReservationsForTests();
|
|
});
|
|
|
|
const hangingService = {
|
|
readiness: { type: "http", timeoutSec: 1, intervalMs: 50 },
|
|
} as Record<string, unknown>;
|
|
|
|
it("reports the fetch transport cause and probe count without extending the deadline", async () => {
|
|
const transportError = new Error("connect ECONNREFUSED 127.0.0.1:42000");
|
|
const fetchError = new TypeError("fetch failed", { cause: transportError });
|
|
let now = 0;
|
|
const refusingFetch = (async () => {
|
|
now = 1_000;
|
|
throw fetchError;
|
|
}) as typeof fetch;
|
|
|
|
await expect(waitForRuntimeServiceReadiness({
|
|
service: hangingService,
|
|
url: "http://127.0.0.1:42000/",
|
|
readinessUrl: null,
|
|
fetchImpl: refusingFetch,
|
|
now: () => now,
|
|
})).rejects.toMatchObject({
|
|
message: "Readiness check failed for http://127.0.0.1:42000/: fetch failed: connect ECONNREFUSED 127.0.0.1:42000 (1 probes over 1000ms)",
|
|
cause: fetchError,
|
|
});
|
|
});
|
|
|
|
it("fails a readiness check whose probes never answer instead of hanging forever", async () => {
|
|
let probes = 0;
|
|
const abortedProbes: string[] = [];
|
|
/** Accepts the request and only ever settles when the caller aborts, like a foreign listener. */
|
|
const neverAnsweringFetch = (async (_url: string | URL | Request, init?: RequestInit) => {
|
|
probes += 1;
|
|
return await new Promise<Response>((_resolve, reject) => {
|
|
init?.signal?.addEventListener("abort", () => {
|
|
abortedProbes.push(String(init?.signal?.reason ?? "aborted"));
|
|
reject(new Error("The operation was aborted due to timeout"));
|
|
});
|
|
});
|
|
}) as unknown as typeof fetch;
|
|
|
|
const startedAt = Date.now();
|
|
await expect(
|
|
waitForRuntimeServiceReadiness({
|
|
service: hangingService,
|
|
serviceName: "app",
|
|
command: "pnpm dev",
|
|
url: "http://127.0.0.1:45439/",
|
|
readinessUrl: null,
|
|
fetchImpl: neverAnsweringFetch,
|
|
}),
|
|
).rejects.toThrow(/Readiness check failed for http:\/\/127\.0\.0\.1:45439\//);
|
|
const elapsedMs = Date.now() - startedAt;
|
|
|
|
expect(probes).toBeGreaterThan(0);
|
|
expect(abortedProbes.length).toBeGreaterThan(0);
|
|
// Terminal well inside the 1s readiness budget plus one probe budget.
|
|
expect(elapsedMs).toBeLessThan(1_000 + RUNTIME_SERVICE_READINESS_PROBE_TIMEOUT_MS);
|
|
});
|
|
|
|
it("negative control: an unbounded probe loop never terminalizes the same start", async () => {
|
|
// This is the shape of the code that shipped: `fetch` with no abort signal, so the
|
|
// deadline at the top of the loop is never re-evaluated once a probe parks.
|
|
const legacyWait = async () => {
|
|
const deadline = Date.now() + 1_000;
|
|
while (Date.now() < deadline) {
|
|
await new Promise<never>(() => {});
|
|
await delay(50);
|
|
}
|
|
throw new Error("Readiness check failed");
|
|
};
|
|
|
|
const settled = await Promise.race([
|
|
legacyWait().then(() => "settled").catch(() => "settled"),
|
|
delay(1_500).then(() => "still-hanging"),
|
|
]);
|
|
expect(settled).toBe("still-hanging");
|
|
});
|
|
|
|
it("stops probing as soon as the readiness budget is spent", async () => {
|
|
let probes = 0;
|
|
const refusingFetch = (async () => {
|
|
probes += 1;
|
|
throw new Error("connect ECONNREFUSED 127.0.0.1:45439");
|
|
}) as unknown as typeof fetch;
|
|
|
|
await expect(
|
|
waitForRuntimeServiceReadiness({
|
|
service: { readiness: { type: "http", timeoutSec: 1, intervalMs: 200 } },
|
|
url: "http://127.0.0.1:45439/",
|
|
readinessUrl: null,
|
|
fetchImpl: refusingFetch,
|
|
}),
|
|
).rejects.toThrow(/ECONNREFUSED/);
|
|
// ~1s budget at a 200ms interval: a bounded handful of probes, never an unbounded spin.
|
|
expect(probes).toBeGreaterThan(1);
|
|
expect(probes).toBeLessThan(12);
|
|
});
|
|
|
|
it("preserves the last HTTP failure when the deadline-clamped probe aborts", async () => {
|
|
// The readiness budget (1s) is smaller than the per-probe timeout, so every probe is bounded
|
|
// by the deadline. The first probe observes the real failure (503); the second is admitted
|
|
// with 1ms left and aborts immediately. That abort says the budget ran out, not that the
|
|
// service misbehaved, so it must not overwrite the 503 in the thrown message.
|
|
let nowMs = 0;
|
|
let probes = 0;
|
|
const fetchImpl = (async (_url: string | URL | Request, init?: RequestInit) => {
|
|
probes += 1;
|
|
if (probes === 1) {
|
|
nowMs = 999;
|
|
return new Response(null, { status: 503 });
|
|
}
|
|
return await new Promise<Response>((_resolve, reject) => {
|
|
const rejectOnAbort = () => {
|
|
nowMs = 1_000;
|
|
reject(new Error("The operation was aborted"));
|
|
};
|
|
if (init?.signal?.aborted) {
|
|
rejectOnAbort();
|
|
return;
|
|
}
|
|
init?.signal?.addEventListener("abort", rejectOnAbort, { once: true });
|
|
});
|
|
}) as unknown as typeof fetch;
|
|
|
|
await expect(
|
|
waitForRuntimeServiceReadiness({
|
|
service: { readiness: { type: "http", timeoutSec: 1, intervalMs: 100 } },
|
|
url: "http://127.0.0.1:45439/",
|
|
readinessUrl: null,
|
|
fetchImpl,
|
|
now: () => nowMs,
|
|
}),
|
|
).rejects.toThrow("Readiness check failed for http://127.0.0.1:45439/: received HTTP 503");
|
|
expect(probes).toBe(2);
|
|
});
|
|
|
|
it("hands two concurrent starts distinct ports even when the kernel repeats a candidate", async () => {
|
|
// The kernel really does hand the same ephemeral port to two `listen(0)` probes once the
|
|
// first probe socket has closed, which is exactly the reallocation collision in the report.
|
|
const candidates = [49871, 49871, 49871, 49872];
|
|
let index = 0;
|
|
const probe = async () => candidates[Math.min(index++, candidates.length - 1)]!;
|
|
const portOwnerLookup = async () => null;
|
|
|
|
const [first, second] = await Promise.all([
|
|
allocateRuntimeServicePort({ probe, portOwnerLookup }),
|
|
allocateRuntimeServicePort({ probe, portOwnerLookup }),
|
|
]);
|
|
|
|
expect(first).not.toBe(second);
|
|
expect(new Set([first, second])).toEqual(new Set([49871, 49872]));
|
|
});
|
|
|
|
it("skips a candidate port that a live process already owns", async () => {
|
|
const candidates = [49881, 49882];
|
|
let index = 0;
|
|
const probe = async () => candidates[Math.min(index++, candidates.length - 1)]!;
|
|
const portOwnerLookup = async (port: number) => (port === 49881 ? 4242 : null);
|
|
|
|
await expect(allocateRuntimeServicePort({ probe, portOwnerLookup })).resolves.toBe(49882);
|
|
// The rejected candidate must not stay reserved, or later starts would leak allocations.
|
|
await expect(
|
|
allocateRuntimeServicePort({ probe: async () => 49881, portOwnerLookup: async () => null }),
|
|
).resolves.toBe(49881);
|
|
});
|
|
|
|
it("skips a candidate port inside the runtime exposure app-port range", async () => {
|
|
// The kernel can hand an ephemeral port inside the exposure app-port range
|
|
// (42000-42999). The reconciler classifies a persisted row by its port: a
|
|
// port in that range marks the row as an exposure reservation, not a managed
|
|
// auto port. So the allocator must never return an in-range port; it drops
|
|
// the in-range candidate and takes the next out-of-range one.
|
|
const candidates = [42500, 49883];
|
|
let index = 0;
|
|
const probe = async () => candidates[Math.min(index++, candidates.length - 1)]!;
|
|
const portOwnerLookup = async () => null;
|
|
|
|
await expect(allocateRuntimeServicePort({ probe, portOwnerLookup })).resolves.toBe(49883);
|
|
// The allocator skipped 42500 before it reserved a candidate, so the in-range
|
|
// port stays free. A later start can still claim it through the exposure path.
|
|
expect(claimRuntimeServiceBindPort(42500, null)).toBe(true);
|
|
});
|
|
|
|
it("refuses a configured port a sibling start is already claiming", () => {
|
|
// The reported collision was on a *configured* app/HMR pair, not an auto-allocated one:
|
|
// both lanes read the pair as free because neither had bound or persisted a row yet.
|
|
expect(claimRuntimeServiceBindPort(42003, null)).toBe(true);
|
|
expect(claimRuntimeServiceBindPort(42003, null)).toBe(false);
|
|
// The HMR companion is claimed independently, so a lane can lose on either port.
|
|
expect(claimRuntimeServiceBindPort(42004, null)).toBe(true);
|
|
expect(claimRuntimeServiceBindPort(42004, null)).toBe(false);
|
|
});
|
|
|
|
it("never lets a start be refused by its own allocation", async () => {
|
|
// An auto-allocated port arrives already reserved by this start, and its identity port can
|
|
// resolve to that same value. Treating that as a sibling's claim would fail the start on its
|
|
// own reservation.
|
|
const held = await allocateRuntimeServicePort({
|
|
probe: async () => 49901,
|
|
portOwnerLookup: async () => null,
|
|
});
|
|
expect(held).toBe(49901);
|
|
expect(claimRuntimeServiceBindPort(49901, held)).toBe(true);
|
|
// A different start still loses against that held reservation.
|
|
expect(claimRuntimeServiceBindPort(49901, null)).toBe(false);
|
|
});
|
|
|
|
it("fails terminally rather than looping when no free port can be found", async () => {
|
|
await expect(
|
|
allocateRuntimeServicePort({ probe: async () => 49891, portOwnerLookup: async () => 99 }),
|
|
).rejects.toThrow(/Could not allocate a free loopback port/);
|
|
});
|
|
});
|