fix(FN-5627): suppress ntfy notifications for transient merge failures the engine auto-recovers
Even with FN-5627's merger TOCTOU fix + transient-failure self-healing sweep + safety-fallback auto-prerebase landed, the merger can still hit transient failure classes (lease handoff races, brief same-SHA non-FF advances) for tasks whose branches are particularly out-of-sync. The self-healing sweep auto-recovers them within bounded budget \u2014 but each individual failure cycle was firing a ntfy alarm before the recovery cleared the failed state, producing user-facing alarm spam for tasks that were never actually stuck. Two layers of fix: 1. NotificationService.handleTaskUpdated now classifies task.error via the new shared classifyTransientMergeError helper before scheduling the deferred failure notification. Transient classes (lease-handoff-target-not-queued, spurious-concurrent-advance-same-sha) get logged as suppressed and never schedule a ntfy timer. 2. Defense-in-depth: fireDeferredFailureNotification re-classifies the error at dispatch time, so a failure scheduled before the suppression landed on a newer cycle still suppresses if the error matches a transient class. The classifier itself moved from self-healing.ts to a new logger-free transient-merge-error-classifier.ts module so consumers in NotificationService don't pull createLogger through the import chain and break test mocks of ../logger.js (per project-memory rule about new modules using createLogger). self-healing.ts re-exports the symbol for backward compatibility. Log prefix for the recovery actions also changed from '[FN-5627] Auto-recovering...' to 'Auto-recovered:' so that NotificationService.maybeSuppressTransientFailedNotification's existing /^Auto-recovered:/ log-prefix check cancels any already-scheduled failure notification when the sweep runs mid-grace-window. Tests (3 new): - transient lease-handoff-target-not-queued failure NOT notified - transient spurious-concurrent-advance-same-sha failure NOT notified - genuine different-SHAs concurrent-advance still notifies (control) Engine suite: 6166 tests pass. Fusion-Task-Id: FN-5627
This commit is contained in:
21
.changeset/FN-5627-suppress-transient-ntfy.md
Normal file
21
.changeset/FN-5627-suppress-transient-ntfy.md
Normal file
@@ -0,0 +1,21 @@
|
||||
---
|
||||
"@runfusion/fusion": patch
|
||||
---
|
||||
|
||||
fix(FN-5627): suppress ntfy notifications for transient merge failures the engine auto-recovers
|
||||
|
||||
Even with the FN-5627 merger TOCTOU fix + transient-failure self-healing sweep + safety-fallback auto-prerebase landed, the merger can still hit transient failure classes (lease handoff races, brief same-SHA non-FF advances) for tasks whose branches are particularly out-of-sync. The self-healing sweep auto-recovers them within bounded budget — but each individual failure cycle was firing a ntfy alarm before the recovery cleared the failed state, producing user-facing alarm spam for tasks that were never actually stuck.
|
||||
|
||||
Two layers of fix:
|
||||
|
||||
1. `NotificationService.handleTaskUpdated` now classifies `task.error` via the new shared `classifyTransientMergeError` helper before scheduling the deferred failure notification. Transient classes (`lease-handoff-target-not-queued`, `spurious-concurrent-advance-same-sha`) get logged as suppressed and never schedule a ntfy timer.
|
||||
|
||||
2. Defense-in-depth: `fireDeferredFailureNotification` re-classifies the error at dispatch time, so a failure scheduled before the suppression landed on a newer cycle still suppresses if the error matches a transient class.
|
||||
|
||||
The classifier itself moved from `self-healing.ts` to a new logger-free `transient-merge-error-classifier.ts` module so consumers in `NotificationService` don't pull `createLogger` through the import chain and break test mocks of `../logger.js`. `self-healing.ts` re-exports the symbol for backward compatibility.
|
||||
|
||||
Log prefix for the recovery actions also changed from `[FN-5627] Auto-recovering...` to `Auto-recovered:` so that `NotificationService.maybeSuppressTransientFailedNotification`'s existing `/^Auto-recovered:/` log-prefix check cancels any already-scheduled failure notification when the sweep runs mid-grace-window.
|
||||
|
||||
Tests:
|
||||
- 3 new notification-service tests covering transient suppression for both error classes plus a control case ensuring genuine non-transient failures still notify.
|
||||
- Existing transient-recovery tests in self-healing.test.ts continue to pass against the relocated classifier.
|
||||
@@ -98,6 +98,52 @@ describe("NotificationService deferred failure notifications", () => {
|
||||
await service.stop();
|
||||
});
|
||||
|
||||
it("FN-5627: suppresses notification for transient lease-handoff-target-not-queued failures", async () => {
|
||||
const { store, service, sendNotification } = await setup();
|
||||
store.setTask(task({
|
||||
id: "FN-5628",
|
||||
status: "failed",
|
||||
error: "Merge handoff refused (lease-handoff-failed): target-not-queued",
|
||||
}));
|
||||
store.emit("task:updated", task({
|
||||
id: "FN-5628",
|
||||
status: "failed",
|
||||
error: "Merge handoff refused (lease-handoff-failed): target-not-queued",
|
||||
}));
|
||||
|
||||
await vi.advanceTimersByTimeAsync(500);
|
||||
|
||||
expect(sendNotification).not.toHaveBeenCalled();
|
||||
expect(service.getMetrics().failureNotificationSuppressedCount).toBe(1);
|
||||
await service.stop();
|
||||
});
|
||||
|
||||
it("FN-5627: suppresses notification for transient same-SHA spurious-concurrent-advance failures", async () => {
|
||||
const { store, service, sendNotification } = await setup();
|
||||
const transientError = "Integration branch main advanced concurrently (expected 694970b2f186fac31c1819d55ef30a2ad207b5c3, observed 694970b2f186fac31c1819d55ef30a2ad207b5c3) while applying b26f8fe1ee2d3dc36acf3571d42507b24bd8066b for FN-5626";
|
||||
store.setTask(task({ id: "FN-5626", status: "failed", error: transientError }));
|
||||
store.emit("task:updated", task({ id: "FN-5626", status: "failed", error: transientError }));
|
||||
|
||||
await vi.advanceTimersByTimeAsync(500);
|
||||
|
||||
expect(sendNotification).not.toHaveBeenCalled();
|
||||
expect(service.getMetrics().failureNotificationSuppressedCount).toBe(1);
|
||||
await service.stop();
|
||||
});
|
||||
|
||||
it("FN-5627: still dispatches notification for genuine concurrent-advance failures (different SHAs)", async () => {
|
||||
const { store, service, sendNotification } = await setup();
|
||||
const genuineError = "Integration branch main advanced concurrently (expected aaa1111aaa1111aaa1111aaa1111aaa1111aaaa, observed bbb2222bbb2222bbb2222bbb2222bbb2222bbbb) while applying ccc3333ccc3333ccc3333ccc3333ccc3333cccc for FN-genuine";
|
||||
store.setTask(task({ id: "FN-genuine", status: "failed", error: genuineError }));
|
||||
store.emit("task:updated", task({ id: "FN-genuine", status: "failed", error: genuineError }));
|
||||
|
||||
await vi.advanceTimersByTimeAsync(500);
|
||||
|
||||
expect(sendNotification).toHaveBeenCalledTimes(1);
|
||||
expect(sendNotification).toHaveBeenCalledWith("failed", expect.objectContaining({ taskId: "FN-genuine" }));
|
||||
await service.stop();
|
||||
});
|
||||
|
||||
it("Transient failure with Auto-recovered status clear is suppressed", async () => {
|
||||
const { store, service, sendNotification } = await setup();
|
||||
store.setTask(task({ id: "FN-1", status: "failed" }));
|
||||
|
||||
@@ -12,6 +12,7 @@ import type {
|
||||
import { NotificationDispatcher } from "@fusion/core";
|
||||
import { DEFAULT_NTFY_EVENTS } from "../notifier.js";
|
||||
import { schedulerLog } from "../logger.js";
|
||||
import { classifyTransientMergeError } from "../transient-merge-error-classifier.js";
|
||||
import { NtfyNotificationProvider } from "./ntfy-provider.js";
|
||||
import { WebhookNotificationProvider } from "./webhook-provider.js";
|
||||
|
||||
@@ -168,6 +169,24 @@ export class NotificationService {
|
||||
}
|
||||
|
||||
if (task.status === "failed") {
|
||||
// FN-5627: Suppress notifications entirely for transient merge failure
|
||||
// classes recognized by `classifyTransientMergeError`. These are
|
||||
// recovered automatically by `SelfHealingManager.recoverTransientMergeFailures`
|
||||
// and the per-tick auto-recovery in `project-engine.ts` fast-path; the
|
||||
// task either lands cleanly on a retry or stays in in-review for the
|
||||
// bounded recovery budget to handle. Without this guard, every flap
|
||||
// cycle (typically every ~5 min when the merger keeps hitting the same
|
||||
// transient class) fires another ntfy alarm even though the task is
|
||||
// never genuinely stuck — producing user-facing alarm spam with no
|
||||
// actionable information.
|
||||
const transientClass = classifyTransientMergeError(task.error);
|
||||
if (transientClass) {
|
||||
this.failureNotificationSuppressedCount += 1;
|
||||
schedulerLog.log(
|
||||
`[notify] ${task.id} transient merge failure (${transientClass}) — suppressed notification (self-heal in flight)`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
if (this.failureNotificationMode === "all") {
|
||||
this.maybeNotify(task.id, "failed", this.createTaskPayload(task, "failed"));
|
||||
} else {
|
||||
@@ -564,6 +583,20 @@ export class NotificationService {
|
||||
return;
|
||||
}
|
||||
|
||||
// FN-5627 defense-in-depth: even when a failure notification was scheduled
|
||||
// (e.g., the failure happened slightly before the transient classifier
|
||||
// suppression landed on a newer cycle), re-check at dispatch time. Self-
|
||||
// healing may have flipped the error to a transient class via FN-5627
|
||||
// auto-recovery, in which case ntfy stays silent.
|
||||
const transientClassAtDispatch = classifyTransientMergeError(task.error);
|
||||
if (transientClassAtDispatch) {
|
||||
this.failureNotificationSuppressedCount += 1;
|
||||
schedulerLog.log(
|
||||
`[notify] ${taskId} transient merge failure (${transientClassAtDispatch}) at dispatch time — suppressed notification (self-heal in flight)`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
const isTerminal = task.paused === true || task.column === "in-review";
|
||||
if (this.failureNotificationMode === "terminal-only" && !isTerminal) {
|
||||
this.failureNotificationSuppressedCount += 1;
|
||||
|
||||
@@ -1544,9 +1544,12 @@ export class ProjectEngine {
|
||||
runtimeLog.warn(
|
||||
`Auto-merge: ${taskId} fast-path REFUSED — auto-recovering (attempt ${nextRetries}/${ProjectEngine.MAX_AUTO_MERGE_RETRIES}): ${reachability.reason}: ${reachability.diagnostic}`,
|
||||
);
|
||||
// Prefix MUST be "Auto-recovered:" so NotificationService's
|
||||
// maybeSuppressTransientFailedNotification cancels the pending
|
||||
// ntfy fired off the underlying task:failed event.
|
||||
await store.logEntry(
|
||||
taskId,
|
||||
`[FN-5627] Auto-merge fast-path refused — cleared poisoned mergeDetails (commit ${shortSha} not reachable from ${integrationBranchForGate}, ${reachability.reason}). Re-enqueueing for fresh merge attempt ${nextRetries}/${ProjectEngine.MAX_AUTO_MERGE_RETRIES}.`,
|
||||
`Auto-recovered: fast-path refused — cleared poisoned mergeDetails (commit ${shortSha} not reachable from ${integrationBranchForGate}, ${reachability.reason}). Re-enqueueing for fresh merge attempt ${nextRetries}/${ProjectEngine.MAX_AUTO_MERGE_RETRIES} [FN-5627].`,
|
||||
);
|
||||
await store.updateTask(taskId, {
|
||||
mergeDetails: cleanedMergeDetails,
|
||||
|
||||
@@ -320,43 +320,12 @@ export const MAX_AUTO_MERGE_RETRIES = 3;
|
||||
*/
|
||||
export const MAX_TRANSIENT_MERGE_RECOVERIES = 2;
|
||||
|
||||
/**
|
||||
* FN-5627 follow-up: classify an in-review failed-task error message as a
|
||||
* recoverable transient merge failure. Returns a stable class label when the
|
||||
* error matches a known transient pattern; null otherwise.
|
||||
*
|
||||
* Recognized classes:
|
||||
* - `lease-handoff-target-not-queued`: the merge queue lease acquisition saw
|
||||
* the task drop out of the queue between enqueue and handoff. Race with
|
||||
* self-healing sweeps that clean stale `mergeQueue` rows (FN-5353/FN-5363).
|
||||
* - `spurious-concurrent-advance-same-sha`: the merger reported
|
||||
* `Integration branch X advanced concurrently (expected SHA, observed SHA)`
|
||||
* with identical SHA on both sides. This signature shows up in two cases:
|
||||
* (1) Pre-FN-5627 misclassification in `merger-ref-update-advance.ts`
|
||||
* routed real ref-update-refusal failures (lock contention, hook
|
||||
* rejection) through `IntegrationBranchConcurrentAdvanceError`.
|
||||
* (2) Post-FN-5627: the merger's `advanceIntegrationBranchRef` correctly
|
||||
* detects `non-fast-forward-advance` when the freshly built squash
|
||||
* commit does not descend from the current integration ref (typically
|
||||
* because the task branch was started against an older main tip and
|
||||
* auto-prerebase was skipped). The error carries the same SHA in both
|
||||
* the "expected" and "observed" slots because the pre-advance rev-parse
|
||||
* captured the ref state and update-ref refused without moving it. On
|
||||
* the next merge attempt, the lifted auto-prerebase default (threshold
|
||||
* = 1 commit, FN-5627 follow-up to `merger-auto-prerebase.ts`) rebases
|
||||
* the task branch onto current main, so the retry succeeds.
|
||||
*/
|
||||
export function classifyTransientMergeError(error: string | null | undefined): string | null {
|
||||
if (!error) return null;
|
||||
if (/lease-handoff-failed[^a-z]+target-not-queued/i.test(error)) {
|
||||
return "lease-handoff-target-not-queued";
|
||||
}
|
||||
const sameSha = error.match(/advanced concurrently \(expected ([0-9a-f]{7,40}),\s+observed ([0-9a-f]{7,40})\)/i);
|
||||
if (sameSha && sameSha[1].toLowerCase() === sameSha[2].toLowerCase()) {
|
||||
return "spurious-concurrent-advance-same-sha";
|
||||
}
|
||||
return null;
|
||||
}
|
||||
// FN-5627: classifier extracted to `transient-merge-error-classifier.ts`
|
||||
// to avoid pulling `createLogger` into modules that mock `../logger.js`
|
||||
// (notification-service tests in particular). Re-exported here for callers
|
||||
// that already depend on `self-healing.ts` exports.
|
||||
import { classifyTransientMergeError } from "./transient-merge-error-classifier.js";
|
||||
export { classifyTransientMergeError } from "./transient-merge-error-classifier.js";
|
||||
const MAX_STARVATION_DROPS = 3;
|
||||
const DEADLOCK_RECOVERY_COOLDOWN_MS = 15 * 60_000;
|
||||
const DEFAULT_STALE_MERGING_STATUS_MIN_AGE_MS = 5 * 60_000;
|
||||
@@ -5263,9 +5232,15 @@ export class SelfHealingManager {
|
||||
}
|
||||
|
||||
const nextCount = currentCount + 1;
|
||||
// Prefix MUST be "Auto-recovered:" so NotificationService's
|
||||
// maybeSuppressTransientFailedNotification recognizes this as a
|
||||
// recovered transient failure and cancels the pending ntfy. Without
|
||||
// this prefix, ntfy fires for every flap cycle of the recovery loop
|
||||
// (typically every ~5 minutes), producing user-facing alarm spam
|
||||
// even though the task is being auto-recovered cleanly.
|
||||
await this.store.logEntry(
|
||||
task.id,
|
||||
`[FN-5627] Auto-recovering transient merge failure (${transientClass}); resetting mergeRetries=0 and re-enqueueing (recovery ${nextCount}/${MAX_TRANSIENT_MERGE_RECOVERIES}).`,
|
||||
`Auto-recovered: transient merge failure (${transientClass}); resetting mergeRetries=0 and re-enqueueing (recovery ${nextCount}/${MAX_TRANSIENT_MERGE_RECOVERIES}) [FN-5627]`,
|
||||
);
|
||||
await this.store.updateTask(task.id, {
|
||||
mergeRetries: 0,
|
||||
|
||||
47
packages/engine/src/transient-merge-error-classifier.ts
Normal file
47
packages/engine/src/transient-merge-error-classifier.ts
Normal file
@@ -0,0 +1,47 @@
|
||||
/**
|
||||
* FN-5627: Shared classifier for transient merge failure error messages.
|
||||
*
|
||||
* Extracted from `self-healing.ts` to break the import chain that would
|
||||
* otherwise pull in `createLogger` and break `vi.mock("../logger.js")` setups
|
||||
* in tests that don't currently mock the full logger surface (notification-
|
||||
* service.test.ts in particular).
|
||||
*
|
||||
* Used by both `SelfHealingManager.recoverTransientMergeFailures` (the
|
||||
* recovery sweep) and `NotificationService.handleTaskUpdated` (the
|
||||
* notification-suppression gate). Both consumers must agree on what counts
|
||||
* as transient so the user doesn't get ntfy alarms for failures that the
|
||||
* engine will auto-recover within bounded budget.
|
||||
*
|
||||
* Recognized classes:
|
||||
*
|
||||
* - `lease-handoff-target-not-queued`: the merge queue lease acquisition saw
|
||||
* the task drop out of the queue between enqueue and handoff. Race with
|
||||
* self-healing sweeps that clean stale `mergeQueue` rows (FN-5353/FN-5363).
|
||||
*
|
||||
* - `spurious-concurrent-advance-same-sha`: the merger reported
|
||||
* `Integration branch X advanced concurrently (expected SHA, observed SHA)`
|
||||
* with identical SHA on both sides. This signature shows up in two cases:
|
||||
* (1) Pre-FN-5627 misclassification in `merger-ref-update-advance.ts`
|
||||
* routed real ref-update-refusal failures (lock contention, hook
|
||||
* rejection) through `IntegrationBranchConcurrentAdvanceError`.
|
||||
* (2) Post-FN-5627: the merger's `advanceIntegrationBranchRef` correctly
|
||||
* detects `non-fast-forward-advance` when the freshly built squash
|
||||
* commit does not descend from the current integration ref. The error
|
||||
* carries the same SHA in both the "expected" and "observed" slots
|
||||
* because the pre-advance rev-parse captured the ref state and
|
||||
* update-ref refused without moving it. On the next merge attempt,
|
||||
* the safety-fallback auto-prerebase (`merger-auto-prerebase.ts`,
|
||||
* FN-5627) rebases the task branch onto current main, so the retry
|
||||
* succeeds.
|
||||
*/
|
||||
export function classifyTransientMergeError(error: string | null | undefined): string | null {
|
||||
if (!error) return null;
|
||||
if (/lease-handoff-failed[^a-z]+target-not-queued/i.test(error)) {
|
||||
return "lease-handoff-target-not-queued";
|
||||
}
|
||||
const sameSha = error.match(/advanced concurrently \(expected ([0-9a-f]{7,40}),\s+observed ([0-9a-f]{7,40})\)/i);
|
||||
if (sameSha && sameSha[1].toLowerCase() === sameSha[2].toLowerCase()) {
|
||||
return "spurious-concurrent-advance-same-sha";
|
||||
}
|
||||
return null;
|
||||
}
|
||||
Reference in New Issue
Block a user