Skip to content

Commit a136c3f

Browse files
Writer-wait test checks the drain against the helper's release time
It measured from when the test process read the helper's LOCKED line, so a slow pipe on a loaded runner shortened the measured wait below its fixed 150 ms floor (133 ms in CI) while the drain behaved correctly. The test now asserts on the shared wall clock that the drain started while the writer held the lock and finished only after it released. Co-authored-by: Alfonso <alfonso-magic-context@users.noreply.github.com>
1 parent ceeb1ef commit a136c3f

1 file changed

Lines changed: 19 additions & 4 deletions

File tree

‎packages/plugin/src/hooks/magic-context/apply-operations.test.ts‎

Lines changed: 19 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -283,9 +283,10 @@ describe("pending drop writer admission", () => {
283283
db.exec("BEGIN IMMEDIATE");
284284
console.log("LOCKED");
285285
setTimeout(() => {
286+
const releasedAt = Date.now();
286287
try { db.exec("ROLLBACK"); }
287-
finally { db.close(); console.log("RELEASED"); }
288-
}, 200);
288+
finally { db.close(); console.log("RELEASED " + releasedAt); }
289+
}, 400);
289290
`;
290291
const locker = Bun.spawn([process.execPath, "-e", script], {
291292
env: { FLUSH_LOCK_DB: databasePath!, PATH: process.env.PATH ?? "" },
@@ -312,13 +313,27 @@ describe("pending drop writer admission", () => {
312313
output += new TextDecoder().decode(next.value);
313314
}
314315
const started = performance.now();
316+
const startedAt = Date.now();
315317
const mutated = withSqliteTransformPass(() =>
316318
applyPendingOperations(SES, db, targets, new Set()),
317319
);
320+
const endedAt = Date.now();
318321
const waitMs = performance.now() - started;
319322
const exitCode = await locker.exited;
320323
expect(exitCode).toBe(0);
321-
expect(waitMs).toBeGreaterThanOrEqual(150);
324+
while (!/RELEASED \d+/.test(output)) {
325+
const next = await reader.read();
326+
if (next.done) break;
327+
output += new TextDecoder().decode(next.value);
328+
}
329+
const releasedAt = Number(output.match(/RELEASED (\d+)/)?.[1]);
330+
// Compare against the helper's own release time, on the shared wall
331+
// clock, not a fixed duration: the moment this process reads LOCKED
332+
// lags the real lock by however long the pipe takes on a loaded
333+
// runner. The drain started while the writer held the lock, and it
334+
// could only finish after the writer let go, so it waited.
335+
expect(startedAt).toBeLessThan(releasedAt);
336+
expect(endedAt).toBeGreaterThanOrEqual(releasedAt);
322337
expect(mutated).toBe(true);
323338
expect(applied).toEqual([1, 2]);
324339
expect([1, 2].map((tag) => getTagById(db, SES, tag)?.status)).toEqual([
@@ -327,7 +342,7 @@ describe("pending drop writer admission", () => {
327342
]);
328343
expect(getPendingOps(db, SES)).toHaveLength(0);
329344
console.log(
330-
`flush writer-lock evidence waitMs=${Math.round(waitMs)} applied=${applied.length} commits=${commits}`,
345+
`flush writer-lock evidence waitMs=${Math.round(waitMs)} heldAfterStartMs=${releasedAt - startedAt} applied=${applied.length} commits=${commits}`,
331346
);
332347
} finally {
333348
reader.releaseLock();

0 commit comments

Comments
 (0)