fix(engine): rescue auto-merge handoff from stale mergeActive entries
The 15s `scheduleMergeRetry` sweep was silently re-skipping in-review tasks whose `mergeActive` entry leaked from a wedged prior attempt (uncaught error inside `drainMergeQueue`, restart between push and finally, etc.). FN-002, FN-004, FN-3898, FN-3899 all sat in in-review until the 15-min maintenance loop logged "Auto-recovered: eligible in-review task re-enqueued for merge". Two changes: * `reconcileStaleMergeActive()` runs before each 15s sweep. Any `mergeActive` taskId that isn't in `mergeQueue` and isn't the `activeMergeTaskId` is treated as leaked and dropped, so the next enqueue actually pushes through. * The `task:moved → in-review` immediate handoff (`wireAutoMerge`) now logs every skip reason instead of returning silently, clears its own stale `mergeActive` entry before enqueueing, and identifies the task in its catch-block warning. `internalEnqueueMerge` also warns when a leaked entry causes a skip — the next regression won't be invisible. Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
8
.changeset/auto-merge-handoff-stale-mergeactive.md
Normal file
8
.changeset/auto-merge-handoff-stale-mergeactive.md
Normal file
@@ -0,0 +1,8 @@
|
|||||||
|
---
|
||||||
|
"@runfusion/fusion": patch
|
||||||
|
---
|
||||||
|
|
||||||
|
Fix in-review tasks getting stranded after pre-merge workflow completes. Two regressions piled up:
|
||||||
|
|
||||||
|
1. The `task:moved → in-review` immediate-handoff path silently no-op'd whenever `internalEnqueueMerge` short-circuited on a leaked `mergeActive` entry — and every skip reason ("paused", "blocker", "autoMerge off", "engine paused") returned without logging, so the silence was opaque. Each branch now logs at info or warn level, the handler clears its own stale `mergeActive` entry before enqueueing, and the catch block's message identifies the task instead of pretending the failure was always a settings read.
|
||||||
|
2. The 15s `scheduleMergeRetry` sweep ran `enqueueEligibleInReviewTasks` → `internalEnqueueMerge` blindly, so a leaked `mergeActive` entry from a wedged prior attempt would skip the same task on every poll forever. Tasks were only rescued by the 15-min maintenance recovery loop ("Auto-recovered: eligible in-review task re-enqueued for merge"). Added `reconcileStaleMergeActive()` which drops `mergeActive` entries that aren't queued and aren't the active merge target, and call it before each 15s sweep. `internalEnqueueMerge` also now warns when a leaked entry causes a skip, so the next regression is visible.
|
||||||
@@ -1766,7 +1766,7 @@ describe("ProjectEngine swallowed error hardening", () => {
|
|||||||
await vi.advanceTimersByTimeAsync(500);
|
await vi.advanceTimersByTimeAsync(500);
|
||||||
|
|
||||||
expect(warnSpy).toHaveBeenCalledWith(
|
expect(warnSpy).toHaveBeenCalledWith(
|
||||||
expect.stringContaining("Auto-merge: failed to read settings for task:moved on FN-001"),
|
expect.stringContaining("Auto-merge handoff (FN-001) failed: db locked"),
|
||||||
);
|
);
|
||||||
|
|
||||||
await engine.stop();
|
await engine.stop();
|
||||||
|
|||||||
@@ -1123,7 +1123,22 @@ export class ProjectEngine {
|
|||||||
|
|
||||||
private internalEnqueueMerge(taskId: string): void {
|
private internalEnqueueMerge(taskId: string): void {
|
||||||
if (this.shuttingDown) return;
|
if (this.shuttingDown) return;
|
||||||
if (this.mergeActive.has(taskId)) return;
|
if (this.mergeActive.has(taskId)) {
|
||||||
|
// Distinguish "actually being processed" (queued or active) from a
|
||||||
|
// leaked entry. Leaks are dropped by reconcileStaleMergeActive() on the
|
||||||
|
// next 15s sweep, so we only log the genuinely-busy case at debug
|
||||||
|
// verbosity. Without this log the de-dup was invisible — a leaked
|
||||||
|
// entry made every subsequent enqueue silently no-op until the 15-min
|
||||||
|
// maintenance loop woke up.
|
||||||
|
const isActuallyLive =
|
||||||
|
this.mergeQueue.includes(taskId) || this.activeMergeTaskId === taskId;
|
||||||
|
if (!isActuallyLive) {
|
||||||
|
runtimeLog.warn(
|
||||||
|
`internalEnqueueMerge(${taskId}): skipped — mergeActive entry is leaked (not queued, not active). reconcileStaleMergeActive() will clear it on the next sweep.`,
|
||||||
|
);
|
||||||
|
}
|
||||||
|
return;
|
||||||
|
}
|
||||||
this.mergeActive.add(taskId);
|
this.mergeActive.add(taskId);
|
||||||
this.mergeQueue.push(taskId);
|
this.mergeQueue.push(taskId);
|
||||||
void this.drainMergeQueue().catch((err: unknown) => {
|
void this.drainMergeQueue().catch((err: unknown) => {
|
||||||
@@ -1758,17 +1773,49 @@ export class ProjectEngine {
|
|||||||
// Re-validate eligibility after the grace period — the task may
|
// Re-validate eligibility after the grace period — the task may
|
||||||
// have been paused, moved, or had its merge blocked.
|
// have been paused, moved, or had its merge blocked.
|
||||||
const latestTask = await store.getTask(task.id).catch(() => null);
|
const latestTask = await store.getTask(task.id).catch(() => null);
|
||||||
if (!latestTask) return;
|
if (!latestTask) {
|
||||||
if (latestTask.column !== "in-review") return;
|
runtimeLog.warn(`Auto-merge handoff (${task.id}): task disappeared during grace period`);
|
||||||
if (latestTask.paused) return;
|
return;
|
||||||
if (this.options.getTaskMergeBlocker?.(latestTask)) return;
|
}
|
||||||
|
if (latestTask.column !== "in-review") {
|
||||||
|
runtimeLog.log(`Auto-merge handoff (${task.id}) skipped: column changed to ${latestTask.column}`);
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
if (latestTask.paused) {
|
||||||
|
runtimeLog.log(`Auto-merge handoff (${task.id}) skipped: task paused`);
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
const blockerReason = this.options.getTaskMergeBlocker?.(latestTask);
|
||||||
|
if (blockerReason) {
|
||||||
|
runtimeLog.log(`Auto-merge handoff (${task.id}) skipped: ${blockerReason}`);
|
||||||
|
return;
|
||||||
|
}
|
||||||
const settings = await store.getSettings();
|
const settings = await store.getSettings();
|
||||||
if (settings.globalPause || settings.enginePaused) return;
|
if (settings.globalPause || settings.enginePaused) {
|
||||||
if (!settings.autoMerge) return;
|
runtimeLog.log(`Auto-merge handoff (${task.id}) skipped: ${settings.globalPause ? "globalPause" : "enginePaused"} active`);
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
if (!settings.autoMerge) {
|
||||||
|
runtimeLog.log(`Auto-merge handoff (${task.id}) skipped: autoMerge disabled`);
|
||||||
|
return;
|
||||||
|
}
|
||||||
|
// Belt-and-braces: clear any stale mergeActive entry from a wedged
|
||||||
|
// prior attempt so this enqueue isn't silently no-op'd. The 15s
|
||||||
|
// sweep also reconciles via reconcileStaleMergeActive(), but waiting
|
||||||
|
// up to 15s for a fresh in-review task to start merging is the
|
||||||
|
// exact regression we're fixing.
|
||||||
|
if (
|
||||||
|
this.mergeActive.has(task.id) &&
|
||||||
|
!this.mergeQueue.includes(task.id) &&
|
||||||
|
this.activeMergeTaskId !== task.id
|
||||||
|
) {
|
||||||
|
runtimeLog.warn(`Auto-merge handoff (${task.id}): clearing stale mergeActive before enqueue`);
|
||||||
|
this.mergeActive.delete(task.id);
|
||||||
|
}
|
||||||
this.internalEnqueueMerge(task.id);
|
this.internalEnqueueMerge(task.id);
|
||||||
} catch (err: unknown) {
|
} catch (err: unknown) {
|
||||||
runtimeLog.warn(
|
runtimeLog.warn(
|
||||||
`Auto-merge: failed to read settings for task:moved on ${task.id}: ${err instanceof Error ? err.message : String(err)}`,
|
`Auto-merge handoff (${task.id}) failed: ${err instanceof Error ? err.message : String(err)}`,
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
}, MERGE_HANDOFF_GRACE_MS);
|
}, MERGE_HANDOFF_GRACE_MS);
|
||||||
|
|||||||
Reference in New Issue
Block a user