test: observe GitHub enrollment after worker settlement (#18506)

## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work.
> - GitHub connection events use a worker that must return to quiet
after it drains an event.
> - The integration test checks that work with real PostgreSQL and
signed loopback requests.
> - The loopback server can receive an ACK before the worker completes
that request.
> - The test reads the next deadline too early and can reject valid work
in progress.
> - This pull request waits for the observed work state without moving
the fake clock.
> - It keeps the exact work counts, identity checks, deadline bound and
quietness checks.

## Linked Issues or Issue Description

Refs #18395 and #18351. This is a test-only repair for the event-worker
integration fixture.

**What happened?**

[CI run
41257779002](https://github.com/paperclipai/paperclip/actions/runs/41257779002/job/124704574485)
failed at the replacement follow-up deadline assertion.
`coordinator.nextWakeAt()` was `null` after the server received the
second ACK. The worker can still be waiting for that ACK response at
this point.

**Expected behavior**

Wait for the worker to expose a deadline or finish the exact expected
follow-up. Do not drive fake time during an observation. Require the
scheduled follow-up to stay within five seconds of the first
observation. Keep one empty follow-up, the new identity and no I/O after
the worker becomes quiet.

**Steps to reproduce**

1. Run the existing enrollment integration test on the original CI merge
`a1e25444a95f3698c3761cd1796bd1e11567224c`.
2. Hold only the second loopback ACK response after its server counter
increments.
3. The original deadline assertion fails while the worker remains
active.

**Paperclip version or commit**

The causal control used the exact CI merge above. This repair starts
from verified master `66e8fab9447aa21350f87ddec79fcd027f3e23ad`. The
fixture and relevant worker files match the earlier `b889` inputs. The
original failure remains preserved. The controlled race does not prove
the unique historical scheduling of that CI attempt.

## What Changed

- Use bounded real I/O yields for observations. Assert that the fake
clock stays fixed during each observation.
- Advance fake time only to actual pending follow-up deadlines. Keep one
fixed five-second reference for each drain.
- Accept an already finished follow-up only when the exact expected
lease count is present. Quietness must still follow.
- Hold the replacement ACK on a Promise gate in the existing test.
Release it during normal work and in cleanup. This keeps a deterministic
regression without a sleep.
- Keep the signed request, identity replacement, exact lease counts,
25-minute no-I/O checks and 30-second test budget.

## Verification

- Original CI: one assertion failure at line 126; 2,619 other tests
passed in that lane. It was not a test timeout or host failure.
- Earlier controls: the same test and relevant worker inputs passed in
two fresh CI lanes. Both used zero Turbo cache hits. Input identity
alone is not the cause proof.
- Causal controls on the original CI source: unchanged baseline passed;
held ACK failed at the original assertion with active work; a settlement
barrier passed all original assertions; a missing second hint still
failed.
- Final patch with real PostgreSQL 17 and current source migrations: the
direct test passes, including its deterministic ACK gate. An extra 750
ms ACK delay also passes. The missing-second-hint negative still fails
at the expected observation.
- Focused command: `pnpm exec vitest run --project server
server/src/__tests__/github-connection-enrollment-work.test.ts`. Local
checks used current-source package aliases and one disposable loopback
PostgreSQL instance. The test creates a unique database and no user
data.
- Fresh Greptile review is 5/5 for
`519c3fd4a99bf77aea7b085b67c38701358fef95`. The exact head has no open
review threads. The current Paperclip assessment is also 5/5 with a
final response footer for that full commit. Its check conclusion is
neutral.
- [Canonical CI
41260540629](https://github.com/paperclipai/paperclip/actions/runs/41260540629)
completed successfully for the exact head. All 57 checks are terminal
with no failures or pending checks. This includes `ci / verify` and
Snyk. The PR is mergeable and clean.
- `git diff --check` passes. Full repository typecheck, tests and build
are delegated to fresh PR CI. No QA journey, model run, deployment or CI
retry was performed for this repair.

## Risks

This change affects one integration fixture. Production worker logic,
schedules and deadlines do not change. The observer retains a one-second
real-time bound and the test retains its 30-second budget. The test
still fails on missing work, extra work, a late deadline, a wrong
identity or I/O after quiet. The database and HTTP server remain owned
by the fixture.

## Model Used

OpenAI Codex, GPT-6 family. The session does not expose a more specific
backend model ID or fixed context window. Used reasoning, repository
tools and test execution.

## 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
- [x] My branch name describes the change and contains no internal
Paperclip ticket id or instance-derived details
- [x] I have run the focused tests locally and they pass
- [x] I have added or updated tests where applicable
- [x] I have updated relevant documentation to reflect my changes
(test-only behavior; described here)
- [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: Paperclip <noreply@paperclip.ing>
This commit is contained in:
DottaandPaperclip authored and GitHub committed 2026-10-31 20:40:35 -05:00
1 parent 756599e4ea
commit b110271c9b
1 file changed
+42 -13
@@ -3,6 +3,7 @@ import os from "node:os";
import path from "node:path";
import { createServer, type Server } from "node:http";
import { once } from "node:events";
import { setImmediate as yieldForIo } from "node:timers/promises";
import { createCipheriv, createPublicKey, diffieHellman, generateKeyPairSync, hkdfSync, randomBytes, randomUUID, verify } from "node:crypto";
import { afterAll, beforeAll, describe, expect, it, vi } from "vitest";
import { companies, connectionEventDeliveries, connectionGrants, createDb, toolApplications, toolConnections } from "@paperclipai/db";
@@ -38,6 +39,8 @@ const support = await getEmbeddedPostgresTestSupport();
let origin = "", eventId = randomUUID(), grantId = "", companyId = "";
const identities: string[] = [];
const delivered = new Set<string>();
let releaseReplacementAck!: () => void;
const replacementAck = new Promise<void>(resolve => { releaseReplacementAck = resolve; });
try {
server = createServer(async (req, res) => {
try {
@@ -59,7 +62,11 @@ const support = await getEmbeddedPostgresTestSupport();
res.end(JSON.stringify({ id: enrollment!.instanceId, environment: "test", origins: [enrollment!.origin] })); return;
}
identities.push(claims.iss);
if (req.url === "/v1/connector/events/ack") { acknowledged++; delivered.add(eventId); res.end(JSON.stringify({ acknowledged: 1 })); return; }
if (req.url === "/v1/connector/events/ack") {
acknowledged++; delivered.add(eventId);
if (acknowledged === 2) await replacementAck;
res.end(JSON.stringify({ acknowledged: 1 })); return;
}
expect(req.url).toBe("/v1/connector/events/lease"); leases++;
if (delivered.has(eventId)) { res.end(JSON.stringify({ events: [], eventWakeVersion: 1 })); return; }
const ephemeral = generateKeyPairSync("x25519"), epk = ephemeral.publicKey.export({ format: "jwk" }).x!;
@@ -83,13 +90,37 @@ const support = await getEmbeddedPostgresTestSupport();
grantId = grant!.id;
const env = { PAPERCLIP_CLOUD_CONNECTOR_BASE_URL: origin, PAPERCLIP_CLOUD_CONNECTOR_ENVIRONMENT: "test" };
const service = githubConnectionEventService(db, { env });
vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true });
vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"] });
coordinator = createDeliveryWorkCoordinator({ owner: db, canRun: () => true, onError: e => errors.push(e) });
const selects = vi.spyOn(db, "select"), transactions = vi.spyOn(db, "transaction"), executes = vi.spyOn(db, "execute");
worker = registerGitHubConnectionEventWork(db, coordinator, service, () => true);
await worker.ready;
async function observe(assertion: () => void) {
const observedAt = Date.now(), until = performance.now() + 1_000;
let failure: unknown;
do {
expect(Date.now()).toBe(observedAt);
try { assertion(); return; } catch (error) { failure = error; }
await yieldForIo();
} while (performance.now() < until);
throw failure;
}
async function drainFollowup(expectedLeases: number) {
const observedAt = Date.now();
while (leases < expectedLeases) {
await observe(() => {
expect(leases).toBeLessThanOrEqual(expectedLeases);
expect(coordinator!.nextWakeAt() !== null || leases === expectedLeases).toBe(true);
});
const followup = coordinator!.nextWakeAt();
if (followup === null) break;
expect(followup - observedAt).toBeLessThanOrEqual(5_000);
await vi.advanceTimersByTimeAsync(Math.max(0, followup - Date.now()) + 1);
}
await observe(() => expect(leases).toBe(expectedLeases));
}
async function quiet(stage: string) {
await vi.waitFor(() => { expect(idleWorkSnapshot().active, stage).toBe(0); expect(coordinator!.nextWakeAt(), stage).toBeNull(); });
await observe(() => { expect(idleWorkSnapshot().active, stage).toBe(0); expect(coordinator!.nextWakeAt(), stage).toBeNull(); });
selects.mockClear(); transactions.mockClear(); executes.mockClear(); const before = requests;
await vi.advanceTimersByTimeAsync(25 * 60_000);
expect(selects).not.toHaveBeenCalled(); expect(transactions).not.toHaveBeenCalled(); expect(executes).not.toHaveBeenCalled(); expect(requests).toBe(before);
@@ -104,31 +135,29 @@ const support = await getEmbeddedPostgresTestSupport();
const firstIdentity = await enroll();
expect(wakeConnectionEvents(db)).toBe(true);
await vi.advanceTimersByTimeAsync(6_000);
await vi.waitFor(() => expect(acknowledged).toBe(1));
await observe(() => expect(acknowledged).toBe(1));
expect(await db.select().from(connectionEventDeliveries).where(eq(connectionEventDeliveries.providerDeliveryId, eventId))).toMatchObject([{ status: "processed" }]);
expect((await db.select().from(connectionGrants).where(eq(connectionGrants.id, grantId)))[0]!.providerTenant!.github!.webhookHealth).toBe("healthy");
// The applied installation update publishes one credential-change hint.
// Join that existing minimum-spacing pass once; the broker now has no debt.
const followup = coordinator.nextWakeAt(); expect(followup).not.toBeNull();
expect(followup! - Date.now()).toBeLessThanOrEqual(5_000);
await vi.advanceTimersByTimeAsync(Math.max(0, followup! - Date.now()) + 1);
await vi.waitFor(() => expect(leases).toBe(2));
await drainFollowup(2);
await quiet("first event plus its one empty follow-up");
await rm(paperclipCloudConnectorIdentityPath());
const oldLeases = leases; expect(wakeConnectionEvents(db)).toBe(true); await vi.advanceTimersByTimeAsync(6_000);
await quiet("removed identity"); expect(leases).toBe(oldLeases);
eventId = randomUUID(); const secondIdentity = await enroll(); expect(secondIdentity).not.toBe(firstIdentity);
expect(wakeConnectionEvents(db)).toBe(true); await vi.advanceTimersByTimeAsync(6_000);
await vi.waitFor(() => expect(acknowledged).toBe(2));
await observe(() => expect(acknowledged).toBe(2));
expect(identities).toContain(firstIdentity); expect(identities).toContain(secondIdentity);
expect(identities.slice(identities.indexOf(secondIdentity))).toEqual(expect.arrayContaining([secondIdentity, secondIdentity]));
expect(identities.slice(identities.indexOf(secondIdentity)).every(id => id === secondIdentity)).toBe(true);
const replacementFollowup = coordinator.nextWakeAt(); expect(replacementFollowup).not.toBeNull();
expect(replacementFollowup! - Date.now()).toBeLessThanOrEqual(5_000);
await vi.advanceTimersByTimeAsync(Math.max(0, replacementFollowup! - Date.now()) + 1);
await vi.waitFor(() => expect(leases).toBe(oldLeases + 2));
expect(idleWorkSnapshot().active).toBeGreaterThan(0);
expect(coordinator.nextWakeAt()).toBeNull();
releaseReplacementAck();
await drainFollowup(oldLeases + 2);
await quiet("replacement event plus its one empty follow-up"); expect(errors).toEqual([]); expect(httpErrors).toEqual([]);
} finally {
releaseReplacementAck();
await worker?.stop(); await coordinator?.stop(); vi.restoreAllMocks(); vi.useRealTimers();
if (server) { const closed = once(server, "close"); server.close(); server.closeAllConnections(); await closed; }
if (previous.home === undefined) delete process.env.PAPERCLIP_HOME; else process.env.PAPERCLIP_HOME = previous.home;