mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-11 05:11:49 +01:00
fix(run-log): wait for a just-written journal head instead of failing the claim (#20509)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - In cloud mode, run logs use the `s3_segments` store: an object byte journal whose `head.json` names the current writer > - Each run start (and each resume after a restart) claims the journal: it reads the head and publishes the next generation with a conditional write > - On an S3-compatible store with read-after-write lag, the head that the previous generation just published can read as `NoSuchKey` > - The claim then tries to create a new head, the store rejects the create because the head exists, and the run fails with `object_journal_writer_conflict` > - This pull request makes the claim wait for the head to become readable when its read said "missing" but the store says it exists > - The benefit is that a run that resumes right after a restart survives a store that shows new objects a few seconds late ## Linked Issues or Issue Description **What happened?** In restart-chaos wave w-20261110T085328-s701 (local, A1/C1, K1/K2, `--storage s3 --storage-faults ST7`), 3 of 4 tasks failed R3 with `retry_needed (adapter_failed)`. Every failed run has `failureCause: object_journal_writer_conflict` and the error "The output journal is owned by another writer" at `object-byte-journal.ts` `publish` from `object-run-log-store.ts` `begin`. All six failures happened in the ST7 window (GET/HEAD of a just-written key answers 404 `NoSuchKey` for 24 s), right after back-to-back K1 restarts. The proxy lagged 34 `GetObject` reads. **Expected behavior** A resuming run claims the run log and continues. A store that is slow to show a new object must not look like another writer. **Steps to reproduce** Claim a journal, then claim it again while the store answers `NoSuchKey` for `head.json` for a short time. The second claim fails with `ObjectJournalConflictError`. ## What Changed - `server/src/services/object-byte-journal.ts`: `claim()` reads the head and claims from it. When the head read as missing and the create fails as a conflict, it waits with backoff (250 ms doubling to 4 s, up to 60 s) and claims again from the head it then reads. A conflict on a head it could read, or a deletion tombstone, still fails at once. - `server/src/services/object-byte-journal.test.ts`: a new test hides a just-written head for three reads. Before this change the second claim fails with "The output journal is owned by another writer". After it, the claim gets the next generation and keeps the committed bytes. ## Verification - `cd server && npx vitest run src/services/object-byte-journal.test.ts src/services/object-run-log-store-tail-read.test.ts src/services/object-run-log-store.test.ts src/services/run-log-store-cancellation.test.ts src/services/run-log-store.test.ts`: 83 pass. The new test fails before the fix and passes after. - `cd server && npx tsc --noEmit -p tsconfig.json` passes. - Live: an ST7 rerun on a build with this fix follows in a comment. ## Risks - A claim on a journal that a truly concurrent first writer just created waits up to 60 s for that head and then claims after it. The caller already asserted execution authority, so it is the owner; it would claim after that head anyway once the head is readable. - A store that never shows the head makes the claim fail after 60 s instead of at once. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, with tool use and code execution in Claude Code. ## 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 <noreply@anthropic.com>
This commit is contained in:
1 parent
7964433cd0
commit
57def75d01
2 files changed
+74
-1
No files matched your search
@@ -257,6 +257,64 @@ describe("object byte journal", () => {
|
||||
expect(await journal.readRange(writer.head, 0, 100)).toEqual(Buffer.from("once"));
|
||||
expect(conflicts).toBe(2);
|
||||
});
|
||||
it("waits for a just-written head to become readable instead of failing the claim as another writer's", async () => {
|
||||
const s = storage(),
|
||||
journal = createObjectByteJournal({ provider: s.provider, prefix: "c/r/log" });
|
||||
let writer = await journal.claim({ assertAuthority: authority });
|
||||
writer = await journal.append(writer, Buffer.from("kept"));
|
||||
const original = s.provider.getObject;
|
||||
let hidden = 3;
|
||||
s.provider.getObject = async (input) => {
|
||||
if (input.objectKey.endsWith("/head.json") && hidden > 0) {
|
||||
hidden--;
|
||||
throw Object.assign(new Error("not yet visible"), { name: "NoSuchKey", $metadata: { httpStatusCode: 404 } });
|
||||
}
|
||||
return original(input);
|
||||
};
|
||||
const next = await journal.claim({ assertAuthority: authority });
|
||||
expect(next.head).toMatchObject({ generation: writer.head.generation + 1, end: 4 });
|
||||
expect(next.head.owner).not.toBe(writer.head.owner);
|
||||
expect(hidden).toBe(0);
|
||||
expect(await journal.readRange(next.head, 0, 100)).toEqual(Buffer.from("kept"));
|
||||
});
|
||||
function hideHead(s: ReturnType<typeof storage>, onRead: () => void = () => undefined) {
|
||||
const original = s.provider.getObject;
|
||||
let reads = 0;
|
||||
s.provider.getObject = async (input) => {
|
||||
if (input.objectKey.endsWith("/head.json")) {
|
||||
reads++;
|
||||
onRead();
|
||||
throw Object.assign(new Error("not yet visible"), { name: "NoSuchKey", $metadata: { httpStatusCode: 404 } });
|
||||
}
|
||||
return original(input);
|
||||
};
|
||||
return { reads: () => reads };
|
||||
}
|
||||
it("stops waiting for an unreadable head at the deadline and makes no further storage calls", async () => {
|
||||
vi.useFakeTimers({ toFake: ["Date"] });
|
||||
const s = storage(),
|
||||
journal = createObjectByteJournal({ provider: s.provider, prefix: "c/r/log" });
|
||||
await journal.claim({ assertAuthority: authority });
|
||||
const hidden = hideHead(s, () => vi.setSystemTime(Date.now() + 15_000));
|
||||
await expect(journal.claim({ assertAuthority: authority })).rejects.toBeInstanceOf(ObjectJournalConflictError);
|
||||
const reads = hidden.reads(), puts = s.calls.put;
|
||||
expect(reads).toBeGreaterThan(1);
|
||||
await new Promise((resolve) => setTimeout(resolve, 1_500));
|
||||
expect([hidden.reads(), s.calls.put]).toEqual([reads, puts]);
|
||||
});
|
||||
it("stops a claim that waits for an unreadable head when its caller aborts", async () => {
|
||||
const s = storage(),
|
||||
journal = createObjectByteJournal({ provider: s.provider, prefix: "c/r/log" });
|
||||
await journal.claim({ assertAuthority: authority });
|
||||
const hidden = hideHead(s);
|
||||
const controller = new AbortController();
|
||||
const claiming = journal.claim({ assertAuthority: authority, signal: controller.signal });
|
||||
setTimeout(() => controller.abort(new Error("caller stopped")), 100);
|
||||
await expect(claiming).rejects.toMatchObject({ name: "AbortError" });
|
||||
const reads = hidden.reads(), puts = s.calls.put;
|
||||
await new Promise((resolve) => setTimeout(resolve, 600));
|
||||
expect([hidden.reads(), s.calls.put]).toEqual([reads, puts]);
|
||||
});
|
||||
it("does not accept a provider's 409 response as proof of conditional enforcement", async () => {
|
||||
const s = storage(),
|
||||
original = s.provider.putObjectConditional!;
|
||||
|
||||
@@ -6,6 +6,7 @@ import type { StorageProvider } from "../storage/types.js";
|
||||
|
||||
const MAX_INDEX_LEVEL = 52;
|
||||
const MAX_OBJECT_BYTES = 4 * 1024 * 1024;
|
||||
const HEAD_VISIBILITY_WAIT_MS = 60_000;
|
||||
const offset = z.number().int().nonnegative().max(Number.MAX_SAFE_INTEGER);
|
||||
const referenceSchema = z
|
||||
.object({
|
||||
@@ -539,7 +540,21 @@ export function createObjectByteJournal(options: ObjectByteJournalOptions) {
|
||||
assertAuthority: () => Promise<void>;
|
||||
signal?: AbortSignal;
|
||||
}) {
|
||||
const current = await head(input.signal);
|
||||
const deadline = Date.now() + HEAD_VISIBILITY_WAIT_MS;
|
||||
for (let wait = 250; ; wait = Math.min(wait * 2, 4_000)) {
|
||||
const current = await head(input.signal);
|
||||
try {
|
||||
return await claimFrom(current, input);
|
||||
} catch (error) {
|
||||
if (current || !(error instanceof ObjectJournalConflictError) || Date.now() + wait > deadline) throw error;
|
||||
await delay(wait, undefined, { signal: input.signal });
|
||||
}
|
||||
}
|
||||
}
|
||||
async function claimFrom(current: ObjectJournalWriter | null, input: {
|
||||
assertAuthority: () => Promise<void>;
|
||||
signal?: AbortSignal;
|
||||
}) {
|
||||
if (current?.head.deleted) throw new ObjectJournalConflictError();
|
||||
await input.assertAuthority();
|
||||
await qualifyConditionalWrites(provider, prefix, input.signal);
|
||||
|
||||
Reference in new issue
Block a user