From ced0e84f5d71cb7f49e238e38f445aa7d7134ad5 Mon Sep 17 00:00:00 2001 From: gsxdsm Date: Thu, 16 Jul 2026 20:16:36 -0700 Subject: [PATCH] FN-8184: unify heartbeat multiplier timing Keep scheduler repair and reports health aligned with the effective heartbeat cadence. - Apply heartbeatMultiplier once through shared interval calculations. - Align scheduler repair and reports-health stale thresholds with scaled cadence. - Add multiplier regression coverage and document the effective timing rules. Files changed: .../fn-8184-heartbeat-multiplier-consistency.md | 7 ++ docs/agents.md | 8 +- .../src/__tests__/heartbeat-executor.test.ts | 43 +++++++++ .../src/__tests__/heartbeat-scheduler.test.ts | 46 ++++++++++ packages/engine/src/agent-heartbeat.ts | 101 ++++++++++++++++----- 5 files changed, 176 insertions(+), 29 deletions(-) Fusion-Task-Id: FN-8184 Fusion-Task-Lineage: 05b79c5e-444a-42c3-9073-9c8c05df5def Co-authored-by: Fusion (runfusion.ai) --- ...n-8184-heartbeat-multiplier-consistency.md | 7 ++ docs/agents.md | 8 +- .../src/__tests__/heartbeat-executor.test.ts | 43 ++++++++ .../src/__tests__/heartbeat-scheduler.test.ts | 46 ++++++++ packages/engine/src/agent-heartbeat.ts | 101 +++++++++++++----- 5 files changed, 176 insertions(+), 29 deletions(-) create mode 100644 .changeset/fn-8184-heartbeat-multiplier-consistency.md diff --git a/.changeset/fn-8184-heartbeat-multiplier-consistency.md b/.changeset/fn-8184-heartbeat-multiplier-consistency.md new file mode 100644 index 0000000000..082e10303b --- /dev/null +++ b/.changeset/fn-8184-heartbeat-multiplier-consistency.md @@ -0,0 +1,7 @@ +--- +"@runfusion/fusion": patch +--- + +summary: Fix heartbeat multiplier so long-cadence agents stop false-flagging as stale or zombie. +category: fix +dev: Scheduler repair, reports health, and async heartbeat config now share one effective interval. diff --git a/docs/agents.md b/docs/agents.md index 8fd6a7833a..e04f4f9440 100644 --- a/docs/agents.md +++ b/docs/agents.md @@ -999,7 +999,7 @@ When the bound task is `executor-class` or `blocked`, the default procedure dire The manager-facing reports health block in that prompt is populated from `AgentStore.getAgentsByReportsTo(agent.id)`. Engine code must call that store method with its `AgentStore` instance binding intact because some implementations resolve direct reports through `this.listAgents()`. If the section disappears unexpectedly, look for logs like `Failed to load reports ... Cannot read properties of undefined (reading 'listAgents')`, which indicate an unbound method call regressed. -Direct-report staleness in this reports-health block uses each report's configured heartbeat interval, with threshold `max(heartbeatIntervalMs × 1.5, 5 minutes)`. This matches the CEO manual health-check rule and avoids false positives for long-cadence reports. +Direct-report staleness in this reports-health block uses each report's effective heartbeat interval (after `heartbeatMultiplier` is applied once), with threshold `max(effectiveHeartbeatIntervalMs × 1.5, 10 minutes)`. This matches the CEO manual health-check rule and avoids false positives for long-cadence reports. This behavior is inherited by new non-ephemeral agents because agent creation seeds a per-agent `HEARTBEAT.md` file from the built-in default. If an agent sets `heartbeatProcedurePath`, that markdown file fully replaces the built-in default at runtime for task-scoped heartbeats. No-task heartbeats always fall back to the ambient built-in procedure so the prompt never references task-only tools. @@ -1301,8 +1301,8 @@ Repair outcomes: - **Repeated non-advancing zombie repair**: after the bounded scheduler threshold, metadata includes the consecutive count/escalation flag and logs `reason=heartbeat-rearm-nonadvancing-escalated` instead of silently churning forever Stale threshold: -- Repair staleness defaults to **`2 × heartbeatIntervalMs`** -- This is intentionally separate from dashboard display staleness (`1.5× heartbeatIntervalMs` with a 5-minute floor) +- Repair staleness defaults to **`2 × effectiveHeartbeatIntervalMs`** (after `heartbeatMultiplier` is applied once) +- This is intentionally separate from dashboard display staleness (`1.5× effectiveHeartbeatIntervalMs` with a 10-minute floor) Dashboard surfacing path: - The stale-repair metadata write uses the existing `AgentStore.updateAgent(...)` path @@ -1360,7 +1360,7 @@ Effects: - Safety guards: skip ephemeral/task-worker agents, skip disabled agents, skip non-tickable states, and skip agents with an active heartbeat run - Existing timer entries are left untouched (no interval reset/jitter churn) - Repair metadata: each audit re-arm writes `metadata.heartbeatTimerRepair` with `repairedAt` and a stale-at-repair indicator when the agent had already missed its expected cadence -- Stale-at-repair threshold: defaults to `2 × heartbeatIntervalMs`; override with project setting `heartbeatRepairStaleMultiplier` (> 0) when you need a different sensitivity +- Stale-at-repair threshold: defaults to `2 × effectiveHeartbeatIntervalMs` after one `heartbeatMultiplier` application; override with project setting `heartbeatRepairStaleMultiplier` (> 0) when you need a different sensitivity - Stale repairs emit a WARN log entry and still flow through the existing `agent:updated` refresh path for dashboard surfacing This covers the untracked timer-loss failure mode where no `agent:updated` event fires after a timer entry disappears. Manual stop/start is no longer required to re-arm the timer in that case. diff --git a/packages/engine/src/__tests__/heartbeat-executor.test.ts b/packages/engine/src/__tests__/heartbeat-executor.test.ts index d46df05896..1e0ece5206 100644 --- a/packages/engine/src/__tests__/heartbeat-executor.test.ts +++ b/packages/engine/src/__tests__/heartbeat-executor.test.ts @@ -231,6 +231,7 @@ describe("executeHeartbeat", () => { afterEach(() => { vi.clearAllMocks(); + vi.useRealTimers(); }); describe("reports health check", () => { @@ -259,6 +260,48 @@ describe("executeHeartbeat", () => { expect(section).toContain("healthy"); }); + it("FN-8184: reports runtimeConfig cadence with one multiplier application and strict stale boundary", async () => { + vi.useFakeTimers(); + const now = new Date("2026-01-01T12:00:00.000Z"); + vi.setSystemTime(now); + const intervalMs = 10_800_000; + const effectiveIntervalMs = 81_000_000; + const staleThresholdMs = effectiveIntervalMs * 1.5; + const store = createStoreWithAgentForExec(); + mockTaskStore = createMockTaskStore({ getSettings: vi.fn().mockResolvedValue({ heartbeatMultiplier: 7.5 }) }); + vi.mocked(store.getAgent).mockImplementation(async (agentId: string) => agentId === "agent-runtime" + ? { id: agentId, runtimeConfig: { heartbeatIntervalMs: intervalMs } } as Agent + : mockAgent); + vi.mocked(store.getAgentsByReportsTo).mockResolvedValue([ + { id: "agent-runtime", name: "Runtime Healthy", state: "active", taskId: null, lastHeartbeatAt: new Date(now.getTime() - 4.5 * 60 * 60_000).toISOString(), updatedAt: now.toISOString() } as Agent, + { id: "agent-boundary", name: "Strict Boundary", state: "idle", taskId: null, lastHeartbeatAt: new Date(now.getTime() - staleThresholdMs).toISOString(), updatedAt: now.toISOString() } as Agent, + { id: "agent-overdue", name: "Strict Overdue", state: "active", taskId: null, lastHeartbeatAt: new Date(now.getTime() - staleThresholdMs - 1).toISOString(), updatedAt: now.toISOString() } as Agent, + ]); + vi.mocked(store.getAgent).mockImplementation(async (agentId: string) => ({ id: agentId, runtimeConfig: { heartbeatIntervalMs: intervalMs } } as Agent)); + const monitor = new HeartbeatMonitor({ store, taskStore: mockTaskStore, rootDir: "/tmp" }); + + const section = await (monitor as any).buildReportsHealthSection("agent-001", store); + expect(section).toMatch(/\| Runtime Healthy \| active \| — \| .* \| healthy \|/); + expect(section).toMatch(/\| Strict Boundary \| idle \| — \| .* \| healthy \|/); + expect(section).toMatch(/\| Strict Overdue \| active \| — \| .* \| \*\*stale\*\* \|/); + expect(heartbeatLog.log).toHaveBeenCalledWith(expect.stringContaining("intervalSource=runtimeConfig")); + }); + + it("FN-8184: getAgentHeartbeatConfig scales task-store-backed values exactly once", async () => { + const store = createStoreWithAgentForExec(); + mockTaskStore = createMockTaskStore({ getSettings: vi.fn().mockResolvedValue({ heartbeatMultiplier: 7.5 }) }); + vi.mocked(store.getAgent).mockResolvedValue({ + ...mockAgent, + runtimeConfig: { heartbeatIntervalMs: 10_800_000, heartbeatTimeoutMs: 60_000 }, + } as Agent); + const monitor = new HeartbeatMonitor({ store, taskStore: mockTaskStore, rootDir: "/tmp" }); + + await expect(monitor.getAgentHeartbeatConfig("agent-001")).resolves.toMatchObject({ + pollIntervalMs: 81_000_000, + heartbeatTimeoutMs: 450_000, + }); + }); + it("FN-6954: buildReportsHealthSection suppresses running state for parked task with no live proof", async () => { const now = new Date().toISOString(); const store = createStoreWithAgentForExec(); diff --git a/packages/engine/src/__tests__/heartbeat-scheduler.test.ts b/packages/engine/src/__tests__/heartbeat-scheduler.test.ts index df280f9860..68a20b8e3b 100644 --- a/packages/engine/src/__tests__/heartbeat-scheduler.test.ts +++ b/packages/engine/src/__tests__/heartbeat-scheduler.test.ts @@ -342,6 +342,52 @@ describe("HeartbeatTriggerScheduler", () => { }); describe("scheduler timer audit", () => { + it("FN-8184: shares the 7.5x effective cadence with repair without zombie churn", async () => { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2026-01-01T06:00:00.000Z")); + const agent = { + id: "agent-long-multiplier", + name: "Long Multiplier", + role: "executor", + state: "active", + lastHeartbeatAt: "2026-01-01T00:00:00.000Z", + runtimeConfig: { enabled: true, heartbeatIntervalMs: 10_800_000 }, + createdAt: "2026-01-01T00:00:00.000Z", + updatedAt: "2026-01-01T00:00:00.000Z", + metadata: {}, + } as Agent; + const taskStore = { getSettings: vi.fn().mockResolvedValue({ heartbeatMultiplier: 7.5 }) } as unknown as TaskStore; + vi.mocked(store.listAgents).mockResolvedValue([agent]); + vi.mocked(store.getActiveHeartbeatRun).mockResolvedValue(null); + + scheduler = new HeartbeatTriggerScheduler(store, callback, taskStore); + scheduler.start(); + await vi.advanceTimersByTimeAsync(0); + const timers = (scheduler as unknown as { timers: Map }).timers; + expect(timers.get(agent.id)?.intervalMs).toBe(81_000_000); + vi.mocked(store.updateAgent).mockClear(); + vi.mocked(heartbeatLog.warn).mockClear(); + + await (scheduler as any).auditTimerRegistrations("interval"); + + // Six hours exceeds the former unscaled 2x threshold but is within the + // shared 162m repair window, so a present healthy timer is untouched. + expect(store.updateAgent).not.toHaveBeenCalled(); + expect(heartbeatLog.warn).not.toHaveBeenCalledWith(expect.stringContaining("zombie-timer-rearmed")); + expect((scheduler as any).nonAdvancingRearmState.has(agent.id)).toBe(false); + + agent.lastHeartbeatAt = new Date(Date.now() - 162_000_001).toISOString(); + await (scheduler as any).auditTimerRegistrations("interval"); + expect(heartbeatLog.warn).toHaveBeenCalledWith(expect.stringContaining("zombie-timer-rearmed")); + }); + + it("FN-8184: applies a sub-one multiplier once to repair staleness", async () => { + const agent = { id: "agent-half", runtimeConfig: { heartbeatIntervalMs: 10_800_000 } } as Agent; + scheduler = new HeartbeatTriggerScheduler(store, callback); + (scheduler as any).lastKnownHeartbeatMultiplier = 0.5; + expect((scheduler as any).getRepairStaleThresholdMs(agent, 2)).toBe(10_800_000); + }); + it("re-arms a tickable durable agent when timer entry is missing and no lifecycle event fires", async () => { vi.useFakeTimers(); const agent = { diff --git a/packages/engine/src/agent-heartbeat.ts b/packages/engine/src/agent-heartbeat.ts index 224642dd76..af9647f96a 100644 --- a/packages/engine/src/agent-heartbeat.ts +++ b/packages/engine/src/agent-heartbeat.ts @@ -334,6 +334,16 @@ function resolveHeartbeatMultiplier(rawMultiplier: unknown): number { return rawMultiplier; } +/** + * FNXC:AgentHeartbeat 2026-07-16-12:00: + * FN-8184 requires every heartbeat timing consumer to apply heartbeatMultiplier + * exactly once. Scheduler cadence, repair thresholds, and reports health must + * derive their interval through this shared calculation. + */ +function computeEffectiveIntervalMs(baseIntervalMs: number, multiplier: number): number { + return Math.max(1000, Math.round(baseIntervalMs * resolveHeartbeatMultiplier(multiplier))); +} + async function terminatePersistedHeartbeatRun( store: AgentStore, agentId: string, @@ -656,6 +666,11 @@ export class HeartbeatMonitor { private agentStartLocks: Map> = new Map(); private pollInterval: NodeJS.Timeout | null = null; private isRunning = false; + /** + * FNXC:AgentHeartbeat 2026-07-16-12:00: + * FN-8184 keeps the last settings-derived multiplier warm for synchronous + * config resolution and reports-health so each applies it exactly once. + */ private cachedHeartbeatMultiplier = 1; private cachedHeartbeatMultiplierAt = 0; @@ -3513,6 +3528,7 @@ export class HeartbeatMonitor { return null; } + await this.warmHeartbeatMultiplierCache(); const now = Date.now(); const rows = await Promise.all(reports.map(async (report) => { const resolvedConfig = this.resolveAgentConfig(report.id); @@ -3527,7 +3543,16 @@ export class HeartbeatMonitor { ? await storeWithReports.getAgent(report.id) : (this.configStore.getCachedAgent?.(report.id) ?? null); if (agent?.runtimeConfig && typeof agent.runtimeConfig.heartbeatIntervalMs === "number" && Number.isFinite(agent.runtimeConfig.heartbeatIntervalMs)) { - pollIntervalMs = Math.max(1000, agent.runtimeConfig.heartbeatIntervalMs); + /* + * FNXC:AgentHeartbeat 2026-07-16-12:00: + * FN-8184 keeps the runtimeConfig label while scaling its value once, + * so reports-health evaluates the timer's effective cadence rather + * than falsely marking multiplier-adjusted reports as stale. + */ + pollIntervalMs = computeEffectiveIntervalMs( + Math.max(1000, agent.runtimeConfig.heartbeatIntervalMs), + this.getCachedHeartbeatMultiplier(), + ); intervalSource = "runtimeConfig"; } } catch (reportsHealthConfigErr) { @@ -3810,10 +3835,17 @@ export class HeartbeatMonitor { * Used by both sync and async config resolvers so isAgentHealthy (sync) and * checkMissedHeartbeats (async) apply the same scaling. */ + private getCachedHeartbeatMultiplier(): number { + return this.cachedHeartbeatMultiplierAt > 0 ? this.cachedHeartbeatMultiplier : 1; + } + + private applyHeartbeatMultiplier(result: ResolvedHeartbeatConfig, multiplier: number): void { + result.pollIntervalMs = computeEffectiveIntervalMs(result.pollIntervalMs, multiplier); + result.heartbeatTimeoutMs = Math.max(5000, computeEffectiveIntervalMs(result.heartbeatTimeoutMs, multiplier)); + } + private applyCachedMultiplier(result: ResolvedHeartbeatConfig): void { - const multiplier = this.cachedHeartbeatMultiplierAt > 0 ? this.cachedHeartbeatMultiplier : 1; - result.pollIntervalMs = Math.max(1000, Math.round(result.pollIntervalMs * multiplier)); - result.heartbeatTimeoutMs = Math.max(5000, Math.round(result.heartbeatTimeoutMs * multiplier)); + this.applyHeartbeatMultiplier(result, this.getCachedHeartbeatMultiplier()); } /** @@ -3870,24 +3902,21 @@ export class HeartbeatMonitor { heartbeatLog.warn(`getAgentConfig(${agentId}) agent lookup failed: ${agentLookupErr instanceof Error ? agentLookupErr.message : String(agentLookupErr)} — using monitor defaults`); } - this.applyCachedMultiplier(result); - - if (!this.taskStore) { - return result; - } - - try { - const settings = await getHeartbeatMemorySettings(this.taskStore); - const multiplier = resolveHeartbeatMultiplier(settings?.heartbeatMultiplier); - this.cachedHeartbeatMultiplier = multiplier; - this.cachedHeartbeatMultiplierAt = Date.now(); - - result.pollIntervalMs = Math.max(1000, Math.round(result.pollIntervalMs * multiplier)); - result.heartbeatTimeoutMs = Math.max(5000, Math.round(result.heartbeatTimeoutMs * multiplier)); - } catch (settingsErr) { - heartbeatLog.warn(`getAgentConfig(${agentId}) settings lookup failed: ${settingsErr instanceof Error ? settingsErr.message : String(settingsErr)} — using base interval`); + let multiplier = this.getCachedHeartbeatMultiplier(); + if (this.taskStore) { + try { + const settings = await getHeartbeatMemorySettings(this.taskStore); + multiplier = resolveHeartbeatMultiplier(settings?.heartbeatMultiplier); + this.cachedHeartbeatMultiplier = multiplier; + this.cachedHeartbeatMultiplierAt = Date.now(); + } catch (settingsErr) { + heartbeatLog.warn(`getAgentConfig(${agentId}) settings lookup failed: ${settingsErr instanceof Error ? settingsErr.message : String(settingsErr)} — using cached multiplier`); + } } + // Apply the resolved multiplier only after settings lookup: applying the + // cache before this step used to double-scale task-store-backed configs. + this.applyHeartbeatMultiplier(result, multiplier); return result; } @@ -4132,6 +4161,12 @@ export class HeartbeatTriggerScheduler { private timerAuditWatchdogHandle: ReturnType | null = null; private lastAuditRanAtMs = 0; private nonAdvancingRearmState: Map = new Map(); + /** + * FNXC:AgentHeartbeat 2026-07-16-12:00: + * FN-8184 caches the settings-derived multiplier for syncTimerForAgent, + * which cannot perform settings I/O but must share repair timing with audit. + */ + private lastKnownHeartbeatMultiplier = 1; private static readonly TIMER_AUDIT_INTERVAL_MS = 60_000; private static readonly TIMER_AUDIT_WATCHDOG_INTERVAL_MS = 60_000; @@ -4320,6 +4355,8 @@ export class HeartbeatTriggerScheduler { multiplier = 1; } + this.lastKnownHeartbeatMultiplier = multiplier; + // Guard against stale async completions after subsequent register/unregister calls. if (this.registrationEpochs.get(agentId) !== expectedEpoch) { return; @@ -4361,7 +4398,7 @@ export class HeartbeatTriggerScheduler { usingDefaultInterval: boolean, lastHeartbeatAt: string | null, ): void { - const effectiveIntervalMs = Math.max(1000, Math.round(baseIntervalMs * multiplier)); + const effectiveIntervalMs = computeEffectiveIntervalMs(baseIntervalMs, multiplier); const initialDelayMs = HeartbeatTriggerScheduler.computeInitialDelayMs( effectiveIntervalMs, lastHeartbeatAt, @@ -4822,14 +4859,23 @@ export class HeartbeatTriggerScheduler { return value; } - private getRepairStaleThresholdMs(agent: Agent, staleMultiplier: number): number { + private getRepairStaleThresholdMs( + agent: Agent, + staleMultiplier: number, + heartbeatMultiplier: number = this.lastKnownHeartbeatMultiplier, + ): number { const config = this.getAgentTimerConfig(agent); let rawIntervalMs = config.heartbeatIntervalMs; if (!rawIntervalMs || typeof rawIntervalMs !== "number" || !Number.isFinite(rawIntervalMs) || rawIntervalMs <= 0) { rawIntervalMs = HeartbeatTriggerScheduler.DEFAULT_HEARTBEAT_INTERVAL_MS; } - const intervalMs = Math.max(1000, Math.round(rawIntervalMs)); - return Math.round(intervalMs * staleMultiplier); + /* + * FNXC:AgentHeartbeat 2026-07-16-12:00: + * FN-8184 prevents healthy long-cadence timers from false-positive + * zombie re-arms by measuring repair staleness from the same effective + * interval that arms the timer, then applying only staleMultiplier here. + */ + return Math.round(computeEffectiveIntervalMs(rawIntervalMs, heartbeatMultiplier) * staleMultiplier); } private getActiveRunStaleThresholdMs(agent: Agent, staleMultiplier: number): number { @@ -4914,6 +4960,7 @@ export class HeartbeatTriggerScheduler { ? await this.taskStore.getSettings() : null; const staleMultiplier = this.resolveRepairStaleMultiplier(settings); + this.lastKnownHeartbeatMultiplier = HeartbeatTriggerScheduler.resolveHeartbeatMultiplier(settings?.heartbeatMultiplier); this.updateErrorRecoveryLimit(settings); const agents = await this.store.listAgents(); let rearmedCount = 0; @@ -4946,7 +4993,11 @@ export class HeartbeatTriggerScheduler { } const hasTimerEntry = this.timers.has(agent.id); - const staleThresholdMs = this.getRepairStaleThresholdMs(agent, staleMultiplier); + const staleThresholdMs = this.getRepairStaleThresholdMs( + agent, + staleMultiplier, + this.lastKnownHeartbeatMultiplier, + ); const elapsedMs = getHeartbeatAgeMs(agent); const staleAtRepair = Number.isFinite(elapsedMs) && elapsedMs > staleThresholdMs;