mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-07 14:21:16 -10:00
fix(recovery): do not race a just-accepted interaction's own continuation wake (#19332)
## Thinking Path
> - Paperclip is the open source app people use to manage AI agents for
work
> - Agents ask humans for decisions through thread interactions, such as
a plan approval
> - When a human accepts an interaction, the accept route enqueues a
continuation wake for the agent
> - A recovery sweep also re-wakes the agent when an accepted
interaction appears to have no continuation
> - The sweep can read the issue in the short gap between the accept and
the accept-time wake, so it queues a second continuation for the same
approval
> - That redundant wake carries the interaction receipt, so the composer
queue shows an immutable "Accepted: <plan>" item that the user cannot
edit or discard
> - This pull request makes the sweep wait a short grace window after
resolution before it treats an accepted interaction as stranded
> - The benefit is that one approval produces one continuation, and the
queue state agrees with the approval
## Linked Issues or Issue Description
No public issue exists. This bug was found in a hands-on onboarding test
on a staging cloud workspace.
**What happened?**
After the user approved the plan, a queued item stayed in the composer
queue. The user could not edit or discard it. The same item stayed.
Approval did not create a new item each time.
Evidence from the staging workspace (wake diagnostics and run records):
- The plan approval resolved at 17:42:05.692.
- The accept-time wake and its run were created at 17:42:05.992. That
run delivered the approval and succeeded at 17:42:51.
- The recovery sweep (`source: issue.interaction_continuation_recovery`)
requested a second wake for the same approval at 17:42:06.201. Its
`retryOfRunId` fell back to the interaction's source run. This shows
that the sweep saw no run after the resolution, so it read the issue
before the accept-time wake existed.
- The redundant wake was deferred behind later runs and a busy shared
workspace. It ran only at 18:19. During that time, `GET
/issues/:id/queued-comments` returned it as an immutable interaction
entry ("Accepted: Approve storefront prototype plan").
**Expected behavior**
One accepted interaction produces one continuation. A delivered approval
does not stay in the composer queue.
**Steps to reproduce**
1. An agent asks for plan approval on a task.
2. A user accepts the plan.
3. The stranded-issue recovery sweep runs within the moment between the
accept and the accept-time wake enqueue.
4. The sweep queues a second continuation that carries the same
approval. The composer queue shows it as an uneditable item until that
duplicate run finishes.
## What Changed
- `server/src/services/recovery/service.ts`: the accepted-interaction
recovery branch now skips the requeue while the interaction resolved
less than `INTERACTION_CONTINUATION_RECOVERY_GRACE_MS` (2 minutes) ago.
The check applies only when no successful run has delivered the
interaction yet. All other recovery branches for the issue keep their
behavior.
- The skip reports the grace deadline through `onDeferredDeadline`. The
sleep-aware recovery scheduler then rechecks the issue at that deadline,
so a lost accept-time wake still recovers without another write.
- `server/src/__tests__/heartbeat-process-recovery.test.ts`: two
regression tests.
- `does not race a just-accepted plan approval before its accept-time
wake is visible` reproduces the staging race and is the red/green test.
It also asserts that the skip registers the deadline, and that a sweep
after the deadline requeues the approval.
- `does not requeue an accepted plan approval whose accept-time wake is
deferred behind another run` guards the deferred accept-time wake case.
This test already passed on `master`.
- `dispatches the onboarding first task once the user answered the
opening card` now seeds an answer 3 minutes old instead of "now". The
test checks that a lost continuation is requeued. An answer inside the
grace window is not yet lost, so the older seed keeps the test's intent.
Related: the Slack connector cancel bug from the same onboarding test (a
stuck steering item after the user declined the connector) is likely the
same redundant plan-approval wake. At 17:52:10, right after the decline,
the item still queued was a retry of this duplicate wake (it carried the
plan approval, not the Slack interaction). This PR removes the
duplicate, so it most likely covers that symptom too. That bug has its
own investigation.
## Verification
Red, on `master` code with only the new tests added:
```
$ cd server && npx vitest run src/__tests__/heartbeat-process-recovery.test.ts -t "plan approval"
× does not race a just-accepted plan approval before its accept-time wake is visible 1029ms
FAIL src/__tests__/heartbeat-process-recovery.test.ts > heartbeat orphaned process recovery > does not race a just-accepted plan approval before its accept-time wake is visible
AssertionError: expected 1 to be +0 // Object.is equality
Test Files 1 failed (1)
Tests 1 failed | 3 passed | 411 skipped (415)
```
Green, with the fix (the final commit also checks the registered
deadline and the requeue after it):
```
$ cd server && npx vitest run src/__tests__/heartbeat-process-recovery.test.ts -t "plan approval"
Test Files 1 passed (1)
Tests 4 passed | 411 skipped (415)
```
Neighbouring interaction-recovery tests on the final commit (`-t "plan
approval|accepted interaction|answered question|answered interaction"`):
9 passed and 1 failed. The failing test, `schedules bounded retries for
failed accepted interaction continuation wakes`, is a timing flake. It
uses a resolution time in March 2026, so the grace window does not apply
to it. It failed 3 of 3 runs with the original `service.ts` on the same
machine under load, and it passed 1 of 2 runs with the fix.
- `pnpm --filter @paperclipai/server... typecheck`: passes.
- `-t "onboarding first task|plan approval"` on the final commit: 8
passed.
- CI runs the full `heartbeat-process-recovery` suite in the serialized
server shards.
## Risks
- Low risk. If an accept-time wake is really lost, recovery now re-wakes
the agent up to 2 minutes later than before. The sweep already runs on
an interval, so this adds at most one sweep of delay.
- The grace window does not change behavior when a successful run
already delivered the interaction.
## Model Used
- Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, used in Claude Code
with tool use (shell, file edits, browser inspection of the staging
workspace API).
## 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
- [ ] All Paperclip CI gates are green
- [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups
- [x] I will address all Greptile and reviewer comments before
requesting merge
🤖 Generated with [Claude Code](https://claude.com/claude-code)
---------
Co-authored-by: Claude Opus 5.5 <[email protected]>
This commit is contained in:
1 parent
2bd2e650fe
commit
da3084a05d
2 files changed
+87
-1
No files matched your search
@@ -9889,7 +9889,9 @@ describeEmbeddedPostgres("heartbeat orphaned process recovery", () => {
|
||||
continuationPolicy: "wake_assignee",
|
||||
createdByAgentId: agentId,
|
||||
resolvedByUserId: "local-board",
|
||||
resolvedAt: new Date(),
|
||||
// Older than the accepted-interaction grace window: the answer-time
|
||||
// wake has had time to appear, so a missing run is a lost continuation.
|
||||
resolvedAt: new Date(Date.now() - 3 * 60_000),
|
||||
payload: {
|
||||
version: 1,
|
||||
questions: [
|
||||
@@ -11211,6 +11213,71 @@ describeEmbeddedPostgres("heartbeat orphaned process recovery", () => {
|
||||
expect(runs).toHaveLength(1);
|
||||
});
|
||||
|
||||
// BUG-03 (onboarding staging, ONB-1): the sweep read the plan approval
|
||||
// ~500ms after it resolved, before its accept-time run existed, and queued
|
||||
// a second continuation for the same approval. That redundant wake waited
|
||||
// behind later runs for ~37 minutes and showed as an immutable
|
||||
// "Accepted: <plan>" item in the composer queue.
|
||||
async function seedJustAcceptedPlanApproval(title: string) {
|
||||
const fixture = await seedResolvedInteractionRecoveryFixture({ title });
|
||||
const resolvedAt = new Date(Date.now() - 500);
|
||||
await db.update(issueThreadInteractions)
|
||||
.set({ continuationPolicy: "wake_assignee", resolvedAt, updatedAt: resolvedAt })
|
||||
.where(eq(issueThreadInteractions.id, fixture.interactionId));
|
||||
return { ...fixture, resolvedAt };
|
||||
}
|
||||
|
||||
async function interactionRecoveryRuns(agentId: string) {
|
||||
return db
|
||||
.select({ id: heartbeatRuns.id })
|
||||
.from(heartbeatRuns)
|
||||
.where(and(
|
||||
eq(heartbeatRuns.agentId, agentId),
|
||||
sql`${heartbeatRuns.contextSnapshot} ->> 'source' = 'issue.interaction_continuation_recovery'`,
|
||||
));
|
||||
}
|
||||
|
||||
it("does not race a just-accepted plan approval before its accept-time wake is visible", async () => {
|
||||
const { agentId, interactionId, resolvedAt } = await seedJustAcceptedPlanApproval("Plan approved moments ago");
|
||||
const deadlines: number[] = [];
|
||||
|
||||
const result = await heartbeatService(db).reconcileStrandedAssignedIssues({
|
||||
onDeferredDeadline: (at) => deadlines.push(at),
|
||||
});
|
||||
|
||||
expect(result.continuationRequeued).toBe(0);
|
||||
expect(await interactionRecoveryRuns(agentId)).toEqual([]);
|
||||
// The skip registers a re-check, so a lost accept-time wake still recovers.
|
||||
expect(deadlines).toContain(resolvedAt.getTime() + 2 * 60_000);
|
||||
|
||||
// After the grace window, with no other write, the next sweep requeues it.
|
||||
const expiredAt = new Date(Date.now() - 2 * 60_000 - 1_000);
|
||||
await db.update(issueThreadInteractions)
|
||||
.set({ resolvedAt: expiredAt, updatedAt: expiredAt })
|
||||
.where(eq(issueThreadInteractions.id, interactionId));
|
||||
const later = await heartbeatService(db).reconcileStrandedAssignedIssues();
|
||||
expect(later.continuationRequeued).toBe(1);
|
||||
expect(await interactionRecoveryRuns(agentId)).toHaveLength(1);
|
||||
});
|
||||
|
||||
it("does not requeue an accepted plan approval whose accept-time wake is deferred behind another run", async () => {
|
||||
const { companyId, agentId, issueId, interactionId } =
|
||||
await seedResolvedInteractionRecoveryFixture({ title: "Plan approval waiting for the active run" });
|
||||
await db.insert(agentWakeupRequests).values({
|
||||
companyId, agentId, source: "automation", triggerDetail: "system", reason: "issue_commented",
|
||||
status: "deferred_issue_execution", requestedByActorType: "user", requestedByActorId: "responsible-user",
|
||||
payload: { issueId, mutation: "interaction", interactionId, interactionStatus: "accepted" },
|
||||
});
|
||||
|
||||
const result = await heartbeatService(db).reconcileStrandedAssignedIssues();
|
||||
|
||||
expect(result.continuationRequeued).toBe(0);
|
||||
expect(await interactionRecoveryRuns(agentId)).toEqual([]);
|
||||
const wakes = await db.select({ status: agentWakeupRequests.status }).from(agentWakeupRequests)
|
||||
.where(and(eq(agentWakeupRequests.agentId, agentId), eq(agentWakeupRequests.companyId, companyId)));
|
||||
expect(wakes).toEqual([{ status: "deferred_issue_execution" }]);
|
||||
});
|
||||
|
||||
it("requeues accepted interaction continuations even when a later successful run is unrelated", async () => {
|
||||
const { companyId, agentId, issueId, interactionId, resolvedAt } =
|
||||
await seedResolvedInteractionRecoveryFixture({ title: "Accepted plan masked by unrelated run" });
|
||||
|
||||
@@ -575,6 +575,13 @@ const NON_RETRYABLE_CONTINUATION_ERROR_CODES = new Set<string>([
|
||||
const CONTINUATION_WAITING_ON_REVIEW_ERROR_CODE =
|
||||
"issue_continuation_waiting_on_review";
|
||||
const INTERACTION_CONTINUATION_REQUEUE_MAX_ATTEMPTS = 3;
|
||||
// The accept route resolves an interaction and then enqueues its own
|
||||
// continuation wake. A sweep that reads the issue inside that gap would see an
|
||||
// accepted interaction with no wake or run and queue a second, redundant
|
||||
// continuation for the same response, which then shows as an immutable queued
|
||||
// item. Treat an accepted interaction as stranded only once its accept-time
|
||||
// wake has had time to appear.
|
||||
const INTERACTION_CONTINUATION_RECOVERY_GRACE_MS = 2 * 60_000;
|
||||
|
||||
const CONTINUATION_RECOVERY_TRANSIENT_MAX_ATTEMPTS = 3;
|
||||
const CONTINUATION_RECOVERY_DEFAULT_MAX_ATTEMPTS = 1;
|
||||
@@ -4995,6 +5002,18 @@ export function recoveryService(
|
||||
);
|
||||
|
||||
if (!successfulRunSinceResolution) {
|
||||
if (
|
||||
recoveryNow.getTime() - acceptedInteractionResolvedAt.getTime() <
|
||||
INTERACTION_CONTINUATION_RECOVERY_GRACE_MS
|
||||
) {
|
||||
// Re-check at the deadline so a lost accept-time wake still recovers.
|
||||
opts?.onDeferredDeadline?.(
|
||||
acceptedInteractionResolvedAt.getTime() +
|
||||
INTERACTION_CONTINUATION_RECOVERY_GRACE_MS,
|
||||
);
|
||||
result.skipped += 1;
|
||||
continue;
|
||||
}
|
||||
if (!agentInvokable) {
|
||||
result.skipped += 1;
|
||||
continue;
|
||||
|
||||
Reference in new issue
Block a user