mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-18 15:39:47 +02:00
fix(e2e): wait on the server's own deferral signal in the signoff wakeup helper (#15345)
## Thinking Path > - Paperclip coordinates work for AI agents through server-managed tasks and heartbeats > - Signoff policy tests exercise stage transitions that wake the next participant > - A stage transition can defer a wake while the previous run still holds the issue execution lock > - The test helper used a fixed wait and could fail before the server released that lock > - This pull request waits on the server deferral signal and verifies the returned run identity > - The benefit is a stable test with clear failure details and no repeated wake request ## Linked Issues or Issue Description **What happened?** The signoff policy end-to-end spec failed intermittently with `No issue-bound heartbeat run became available for agent <id>`. The server had deferred the wake while another run held the issue execution lock. **Expected behavior** The test helper waits for the named blocking run to finish, then reads and verifies the new run for the requested agent and issue. **Steps to reproduce** 1. Run `npx playwright test --config tests/e2e/playwright.config.ts tests/e2e/signoff-policy.spec.ts`. 2. Exercise a signoff stage transition while the previous stage run still holds the issue execution lock. 3. Confirm that the helper waits on the server deferral signal and returns only a matching run. This change relates to [PR #11299](https://github.com/paperclipai/paperclip/pull/11299), which also touches the signoff policy end-to-end spec. ## What Changed - Call the wakeup endpoint that reports the server deferral reason. - Wait for the named blocking run instead of using a fixed delay. - Verify that each returned run belongs to the requested agent and issue. - Bound read and wait loops and report the last server signal and lock fields on failure. - Keep one wakeup request per helper call. ## Verification - `npx playwright test --config tests/e2e/playwright.config.ts tests/e2e/signoff-policy.spec.ts` passed locally. - All five signoff policy cases passed locally. - The spec keeps all 60 assertions. - The diff contains only `tests/e2e/signoff-policy.spec.ts`. - The full CI end-to-end shards must pass before merge. ## Risks - The helper now depends on the wakeup endpoint's deferral fields. - A server change to those fields can fail the test with a named diagnostic. - The change affects end-to-end test behavior only. ## Model Used OpenAI GPT-5 Codex, exact runtime model `gpt-5-codex`, with tool use and code review assistance. The runtime does not expose a separate context-window value. ## 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: nickyleach <331803+nickyleach@users.noreply.github.com> Co-authored-by: Paperclip <noreply@paperclip.ing>
This commit is contained in:
1 file changed
+172
-32
@@ -57,14 +57,91 @@ async function createAgentRequest(token: string): Promise<APIRequestContext> {
|
||||
});
|
||||
}
|
||||
|
||||
/** Invoke a heartbeat run for an agent, returning the run ID. */
|
||||
// The wait below follows the server's own deferral signal. It does not guess
|
||||
// a delay. WAKEUP_WAIT_TOTAL_MS is a per-call ceiling, not a fixed wait: one
|
||||
// test can call invokeHeartbeat several times under the suite's 60_000 ms
|
||||
// per-test timeout (see tests/e2e/playwright.config.ts), so each call caps
|
||||
// itself to the test's own remaining time, minus a reserve left for the
|
||||
// assertions that still have to run after the call returns. A stuck wait
|
||||
// then throws a named error, not a generic Playwright timeout.
|
||||
// The server's rewake cooldown (ISSUE_REWAKE_BASE_COOLDOWN_MS, 120_000 ms in
|
||||
// server/src/services/issue-rewake-throttle.ts) can outlast one test's life.
|
||||
// When that happens, this helper still fails fast and states the reason.
|
||||
const WAKEUP_WAIT_TOTAL_MS = 45_000;
|
||||
const WAKEUP_WAIT_RESERVE_MS = 10_000;
|
||||
const WAKEUP_POLL_INTERVAL_MS = 100;
|
||||
const MAX_CONSECUTIVE_RUN_READ_FAILURES = 5;
|
||||
|
||||
// First-seen start time for the current test, keyed by Playwright's own
|
||||
// TestInfo object. Playwright does not expose a test start timestamp, so
|
||||
// this helper records one the first time a test calls invokeHeartbeat.
|
||||
const testStartTimesMs = new WeakMap<ReturnType<typeof test.info>, number>();
|
||||
|
||||
/**
|
||||
* Return how long one invokeHeartbeat call may wait this time: the smaller
|
||||
* of WAKEUP_WAIT_TOTAL_MS and the current test's remaining time, after
|
||||
* WAKEUP_WAIT_RESERVE_MS is set aside for whatever the test still does once
|
||||
* this call returns. Returns 0 when the test has no time left to spare, so
|
||||
* the caller fails fast instead of starting a wait it cannot finish.
|
||||
*/
|
||||
function wakeupWaitBudgetMs(): number {
|
||||
const info = test.info();
|
||||
const testTimeoutMs = info.timeout;
|
||||
if (testTimeoutMs <= 0) return WAKEUP_WAIT_TOTAL_MS; // no test timeout set
|
||||
|
||||
let startedAtMs = testStartTimesMs.get(info);
|
||||
if (startedAtMs === undefined) {
|
||||
startedAtMs = Date.now();
|
||||
testStartTimesMs.set(info, startedAtMs);
|
||||
}
|
||||
|
||||
const elapsedMs = Date.now() - startedAtMs;
|
||||
const remainingMs = testTimeoutMs - elapsedMs - WAKEUP_WAIT_RESERVE_MS;
|
||||
return Math.max(0, Math.min(WAKEUP_WAIT_TOTAL_MS, remainingMs));
|
||||
}
|
||||
|
||||
/**
|
||||
* Fetch a candidate run and confirm it belongs to this agent and this issue.
|
||||
* Return null when the run fails to load, or when it names a different
|
||||
* agent or a different issue. A caller must never treat an unverified lock
|
||||
* field as the answer.
|
||||
*/
|
||||
async function fetchVerifiedRun(
|
||||
board: APIRequestContext,
|
||||
candidateRunId: string | null | undefined,
|
||||
agentId: string,
|
||||
issueId: string,
|
||||
): Promise<{ id: string; status: string } | null> {
|
||||
if (!candidateRunId) return null;
|
||||
const runRes = await board.get(`${BASE_URL}/api/heartbeat-runs/${candidateRunId}`);
|
||||
if (!runRes.ok()) return null;
|
||||
const candidateRun = await runRes.json();
|
||||
const context = candidateRun.contextSnapshot ?? {};
|
||||
if (candidateRun.agentId !== agentId) return null;
|
||||
if (context.issueId !== issueId && context.taskId !== issueId) return null;
|
||||
return { id: candidateRunId, status: candidateRun.status };
|
||||
}
|
||||
|
||||
/**
|
||||
* Invoke a heartbeat run for an agent, returning the run ID.
|
||||
*
|
||||
* Posts the wakeup exactly once. A second on-demand wake for the same
|
||||
* (agent, issue) pair while the first has not yet produced visible progress
|
||||
* reads as a redundant re-poll to the server's rewake throttle, so this
|
||||
* never re-posts — it only reads state after the single post.
|
||||
*
|
||||
* Every returned run ID passes `fetchVerifiedRun` first. The issue's
|
||||
* run-lock fields name a candidate, not a verified answer, because the lock
|
||||
* holder and the issue assignee can differ during a stage transition.
|
||||
*/
|
||||
async function invokeHeartbeat(
|
||||
board: APIRequestContext,
|
||||
agentId: string,
|
||||
issueId: string,
|
||||
): Promise<string> {
|
||||
const res = await board.post(`${BASE_URL}/api/agents/${agentId}/heartbeat/invoke`, {
|
||||
const res = await board.post(`${BASE_URL}/api/agents/${agentId}/wakeup`, {
|
||||
data: {
|
||||
source: "on_demand",
|
||||
reason: "issue_assigned",
|
||||
payload: { issueId, taskId: issueId, taskKey: issueId },
|
||||
},
|
||||
@@ -73,49 +150,112 @@ async function invokeHeartbeat(
|
||||
const run = await res.json();
|
||||
if (typeof run.id === "string" && run.id.length > 0) return run.id;
|
||||
|
||||
// A stage transition can already be replacing the previous executor's run
|
||||
// with the participant's queued run. If the legacy invoke is skipped and
|
||||
// that run has already released the issue lock, recover it from the agent's
|
||||
// recent run receipts.
|
||||
const deadline = Date.now() + 3_000;
|
||||
do {
|
||||
const waitBudgetMs = wakeupWaitBudgetMs();
|
||||
const deadline = Date.now() + waitBudgetMs;
|
||||
const lastSeen = {
|
||||
reason: typeof run.reason === "string" ? run.reason : null,
|
||||
checkoutRunId: null as string | null,
|
||||
executionRunId: typeof run.executionRunId === "string" ? run.executionRunId : null,
|
||||
blockingRunStatus: null as string | null,
|
||||
blockingRunReadFailed: false,
|
||||
};
|
||||
|
||||
// A stage transition can invoke the next participant before the prior
|
||||
// stage's run releases the issue's execution lock. The server names the
|
||||
// run that holds the lock for two skip reasons: `issue_execution_deferred`
|
||||
// (an active execution run) and `execution_reconciliation_required` (an
|
||||
// execution blocker). Both name the blocking run in the same two fields,
|
||||
// so this code handles them the same way.
|
||||
// A third reason, `wakeup_skipped`, can also carry an `executionRunId`,
|
||||
// but only when that run already finished. A finished run is never this
|
||||
// agent's turn. So for `wakeup_skipped`, this code ignores `executionRunId`
|
||||
// and falls through to the verified wait below.
|
||||
if (
|
||||
(lastSeen.reason === "issue_execution_deferred" || lastSeen.reason === "execution_reconciliation_required") &&
|
||||
typeof run.executionRunId === "string"
|
||||
) {
|
||||
if (run.executionAgentId === agentId) {
|
||||
// A run for this same agent on this same issue already holds the lock
|
||||
// (for example one started when the issue was assigned). Verify it
|
||||
// before this code treats it as the agent's current turn.
|
||||
const verified = await fetchVerifiedRun(board, run.executionRunId, agentId, issueId);
|
||||
if (verified) return verified.id;
|
||||
} else {
|
||||
// A different agent holds the lock (the prior stage's participant, or
|
||||
// the blocker's owner). Wait for that run to finish. It promotes this
|
||||
// wake into a real run as part of releasing the lock, so this code
|
||||
// waits for that instead of guessing how long the release takes.
|
||||
let consecutiveRunReadFailures = 0;
|
||||
while (Date.now() < deadline) {
|
||||
const runRes = await board.get(`${BASE_URL}/api/heartbeat-runs/${run.executionRunId}`);
|
||||
if (runRes.ok()) {
|
||||
consecutiveRunReadFailures = 0;
|
||||
const blockingRun = await runRes.json();
|
||||
lastSeen.blockingRunStatus = typeof blockingRun.status === "string" ? blockingRun.status : null;
|
||||
if (lastSeen.blockingRunStatus !== "queued" && lastSeen.blockingRunStatus !== "running") break;
|
||||
} else {
|
||||
// A 404 or a 500 response must not spin this loop forever. Count
|
||||
// repeated read failures and stop once they dominate the wait.
|
||||
// The failure then reads as "the run read kept failing", not as a
|
||||
// generic timeout.
|
||||
consecutiveRunReadFailures += 1;
|
||||
if (consecutiveRunReadFailures >= MAX_CONSECUTIVE_RUN_READ_FAILURES) {
|
||||
lastSeen.blockingRunReadFailed = true;
|
||||
break;
|
||||
}
|
||||
}
|
||||
await new Promise((resolve) => setTimeout(resolve, WAKEUP_POLL_INTERVAL_MS));
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Read the issue's own run-lock fields, and this agent's recent runs,
|
||||
// until this agent's run for this issue appears and passes verification.
|
||||
// Negative-authorization tests invoke a non-participant on purpose, so an
|
||||
// assignee mismatch is a genuine rejection to return untouched, not a
|
||||
// signal to keep waiting for a run that must never exist for that agent.
|
||||
while (Date.now() < deadline) {
|
||||
const issueRunLock = await getIssueRunLockState(board, issueId);
|
||||
lastSeen.checkoutRunId = issueRunLock.checkoutRunId;
|
||||
lastSeen.executionRunId = issueRunLock.executionRunId;
|
||||
if (issueRunLock.assigneeAgentId !== agentId) {
|
||||
// Negative authorization cases intentionally invoke a non-participant.
|
||||
// Preserve the server rejection instead of waiting for a run that must
|
||||
// never be assigned to that agent.
|
||||
return issueRunLock.executionRunId ?? issueRunLock.checkoutRunId ?? "";
|
||||
}
|
||||
const candidates = new Set<string>([
|
||||
run.executionRunId,
|
||||
issueRunLock.executionRunId,
|
||||
issueRunLock.checkoutRunId,
|
||||
].filter((candidate): candidate is string => Boolean(candidate)));
|
||||
|
||||
const verifiedCheckout = await fetchVerifiedRun(board, issueRunLock.checkoutRunId, agentId, issueId);
|
||||
if (verifiedCheckout) return verifiedCheckout.id;
|
||||
const verifiedExecution = await fetchVerifiedRun(board, issueRunLock.executionRunId, agentId, issueId);
|
||||
if (verifiedExecution) return verifiedExecution.id;
|
||||
|
||||
const recentRunsRes = await board.get(
|
||||
`${BASE_URL}/api/companies/${issueRunLock.companyId}/heartbeat-runs?agentId=${agentId}&limit=20`,
|
||||
);
|
||||
if (recentRunsRes.ok()) {
|
||||
const recentRuns = await recentRunsRes.json();
|
||||
for (const recentRun of Array.isArray(recentRuns) ? recentRuns : []) {
|
||||
if (typeof recentRun.id === "string") candidates.add(recentRun.id);
|
||||
const context = recentRun.contextSnapshot ?? {};
|
||||
if (
|
||||
typeof recentRun.id === "string" &&
|
||||
recentRun.agentId === agentId &&
|
||||
(context.issueId === issueId || context.taskId === issueId)
|
||||
) {
|
||||
return recentRun.id;
|
||||
}
|
||||
}
|
||||
}
|
||||
for (const candidate of candidates) {
|
||||
const runRes = await board.get(`${BASE_URL}/api/heartbeat-runs/${candidate}`);
|
||||
if (!runRes.ok()) continue;
|
||||
const candidateRun = await runRes.json();
|
||||
const context = candidateRun.contextSnapshot ?? {};
|
||||
if (
|
||||
candidateRun.agentId === agentId &&
|
||||
(context.issueId === issueId || context.taskId === issueId)
|
||||
) {
|
||||
return candidate;
|
||||
}
|
||||
}
|
||||
await new Promise((resolve) => setTimeout(resolve, 50));
|
||||
} while (Date.now() < deadline);
|
||||
await new Promise((resolve) => setTimeout(resolve, WAKEUP_POLL_INTERVAL_MS));
|
||||
}
|
||||
|
||||
throw new Error(`No issue-bound heartbeat run became available for agent ${agentId}`);
|
||||
throw new Error(
|
||||
`No verified heartbeat run became available for agent ${agentId} on issue ${issueId} ` +
|
||||
`within ${waitBudgetMs}ms` +
|
||||
`${waitBudgetMs <= 0 ? " (the test's remaining time budget was already spent before this wait could start)" : ""}. ` +
|
||||
`Last skip reason: ${lastSeen.reason ?? "none"}. ` +
|
||||
`Last checkoutRunId: ${lastSeen.checkoutRunId ?? "none"}. ` +
|
||||
`Last executionRunId: ${lastSeen.executionRunId ?? "none"}. ` +
|
||||
`Blocking run status: ${lastSeen.blockingRunStatus ?? "none"}` +
|
||||
`${lastSeen.blockingRunReadFailed ? " (the blocking run read failed repeatedly)" : ""}.`,
|
||||
);
|
||||
}
|
||||
|
||||
async function getIssueRunLockState(board: APIRequestContext, issueId: string): Promise<IssueRunLockState> {
|
||||
|
||||
Reference in new issue
Block a user