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:
@@ -1766,7 +1766,7 @@ describe("ProjectEngine swallowed error hardening", () => {
|
||||
await vi.advanceTimersByTimeAsync(500);
|
||||
|
||||
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();
|
||||
|
||||
@@ -1123,7 +1123,22 @@ export class ProjectEngine {
|
||||
|
||||
private internalEnqueueMerge(taskId: string): void {
|
||||
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.mergeQueue.push(taskId);
|
||||
void this.drainMergeQueue().catch((err: unknown) => {
|
||||
@@ -1758,17 +1773,49 @@ export class ProjectEngine {
|
||||
// Re-validate eligibility after the grace period — the task may
|
||||
// have been paused, moved, or had its merge blocked.
|
||||
const latestTask = await store.getTask(task.id).catch(() => null);
|
||||
if (!latestTask) return;
|
||||
if (latestTask.column !== "in-review") return;
|
||||
if (latestTask.paused) return;
|
||||
if (this.options.getTaskMergeBlocker?.(latestTask)) return;
|
||||
if (!latestTask) {
|
||||
runtimeLog.warn(`Auto-merge handoff (${task.id}): task disappeared during grace period`);
|
||||
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();
|
||||
if (settings.globalPause || settings.enginePaused) return;
|
||||
if (!settings.autoMerge) return;
|
||||
if (settings.globalPause || settings.enginePaused) {
|
||||
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);
|
||||
} catch (err: unknown) {
|
||||
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);
|
||||
|
||||
Reference in New Issue
Block a user