diff --git a/CHANGELOG.md b/CHANGELOG.md index 52cfd5aff43..725aa48dd9e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -290,6 +290,7 @@ Docs: https://docs.openclaw.ai - QA Lab: stop gateway children when the suite parent disappears, so interrupted local QA runs cannot leave hot orphaned gateways behind. - Codex/app-server: tolerate a second connection close during startup recovery and include retry counts plus stringified errors in the restart warning, so concurrent lanes do not fail after one shared-client race. - Plugins/CLI: cache plugin CLI registration entries per command program so completion state generation does not repeat the full plugin sweep in one invocation. Thanks @ScientificProgrammer. +- Voice Call: summarize restored-call verification logs during startup while preserving expired-call cleanup, reducing duplicate per-call skip messages. Thanks @jckm14. - Plugins: reuse gateway-bindable plugin loader cache entries for later default-mode loads without serving default-built registries to gateway-bound requests, reducing repeated plugin registration during dispatch. Refs #61756. Thanks @DmitryPogodaev. - Gateway/secrets: include the caught error message in `secrets.reload` and `secrets.resolve` warning logs while keeping RPC errors generic, so operators can diagnose reload and permission failures. Thanks @davidangularme. - Providers/OpenRouter: fill DeepSeek V4 `reasoning_content` replay placeholders for `openrouter/deepseek/deepseek-v4-flash` and `openrouter/deepseek/deepseek-v4-pro`, so thinking/tool follow-up turns do not fail with DeepSeek's replay-shape error. Fixes #76018. Thanks @cloph-dsp. diff --git a/extensions/voice-call/src/manager.restore.test.ts b/extensions/voice-call/src/manager.restore.test.ts index 4e70d31e713..b00c4f8a8e3 100644 --- a/extensions/voice-call/src/manager.restore.test.ts +++ b/extensions/voice-call/src/manager.restore.test.ts @@ -22,6 +22,7 @@ function requireSingleActiveCall(manager: CallManager) { describe("CallManager verification on restore", () => { afterEach(() => { vi.useRealTimers(); + vi.restoreAllMocks(); }); async function initializeManager(params?: { @@ -121,6 +122,129 @@ describe("CallManager verification on restore", () => { expect(activeCall.state).toBe(call.state); }); + it("summarizes repeated restored-call verification outcomes", async () => { + const now = Date.now(); + const storePath = createTestStorePath(); + const calls = [ + makePersistedCall({ + callId: "missing-provider-a", + providerCallId: undefined, + state: "initiated", + startedAt: now - 10_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "missing-provider-b", + providerCallId: undefined, + state: "initiated", + startedAt: now - 10_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "expired-a", + providerCallId: "expired-provider-a", + state: "initiated", + startedAt: now - 600_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "terminal-a", + providerCallId: "terminal-provider-a", + state: "initiated", + startedAt: now - 20_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "terminal-b", + providerCallId: "terminal-provider-b", + state: "initiated", + startedAt: now - 20_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "unknown-a", + providerCallId: "unknown-provider-a", + state: "initiated", + startedAt: now - 20_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "active-a", + providerCallId: "active-provider-a", + state: "initiated", + startedAt: now - 20_000, + answeredAt: undefined, + }), + makePersistedCall({ + callId: "failure-a", + providerCallId: "failure-provider-a", + state: "initiated", + startedAt: now - 20_000, + answeredAt: undefined, + }), + ]; + writeCallsToStore(storePath, calls); + + const provider = new FakeProvider(); + provider.getCallStatus = async ({ providerCallId }) => { + if (providerCallId.startsWith("terminal-provider")) { + return { status: "completed", isTerminal: true }; + } + if (providerCallId.startsWith("unknown-provider")) { + return { status: "unknown", isTerminal: false, isUnknown: true }; + } + if (providerCallId.startsWith("active-provider")) { + return { status: "in-progress", isTerminal: false }; + } + throw new Error("network failure"); + }; + const config = VoiceCallConfigSchema.parse({ + enabled: true, + provider: "plivo", + fromNumber: "+15550000000", + maxDurationSeconds: 300, + }); + const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); + const manager = new CallManager(config, storePath); + + await manager.initialize(provider, "https://example.com/voice/webhook"); + + expect( + manager + .getActiveCalls() + .map((call) => call.callId) + .toSorted(), + ).toEqual(["active-a", "failure-a", "unknown-a"]); + expect(provider.hangupCalls).toEqual([ + expect.objectContaining({ + callId: "expired-a", + providerCallId: "expired-provider-a", + reason: "timeout", + }), + ]); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Skipped 2 restored call(s) with no providerCallId", + ); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Skipped 1 restored call(s) older than maxDurationSeconds", + ); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Skipped 2 restored call(s) with provider status: completed", + ); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Kept 1 restored call(s) confirmed active by provider", + ); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Kept 1 restored call(s) with unknown provider status (relying on timer)", + ); + expect(logSpy).toHaveBeenCalledWith( + "[voice-call] Kept 1 restored call(s) after verification failure (relying on timer)", + ); + expect(logSpy.mock.calls.map((call) => String(call[0])).join("\n")).not.toContain("terminal-a"); + + logSpy.mockRestore(); + }); + it("uses only remaining max duration for restored answered calls", async () => { vi.useFakeTimers(); const now = new Date("2026-03-17T03:07:00Z"); diff --git a/extensions/voice-call/src/manager.ts b/extensions/voice-call/src/manager.ts index fe4f511696c..d8df26e4b0c 100644 --- a/extensions/voice-call/src/manager.ts +++ b/extensions/voice-call/src/manager.ts @@ -37,6 +37,14 @@ function markRestoredCallSkipped(call: CallRecord, endReason: "completed" | "tim call.state = endReason; } +function incrementRestoreStatusCount( + counts: Map, + status: string | undefined, +): void { + const key = normalizeOptionalString(status) ?? "terminal"; + counts.set(key, (counts.get(key) ?? 0) + 1); +} + function resolveDefaultStoreBase(config: VoiceCallConfig, storePath?: string): string { const rawOverride = storePath?.trim() || config.store?.trim(); if (rawOverride) { @@ -110,6 +118,7 @@ export class CallManager { } // Restart max-duration timers for restored calls that are past the answered state + let skippedAlreadyElapsedTimers = 0; for (const [callId, call] of verified) { if (call.answeredAt && !TerminalStates.has(call.state)) { const elapsed = Date.now() - call.answeredAt; @@ -120,9 +129,7 @@ export class CallManager { if (call.providerCallId) { this.providerCallIdMap.delete(call.providerCallId); } - console.log( - `[voice-call] Skipping restored call ${callId} (max duration already elapsed)`, - ); + skippedAlreadyElapsedTimers += 1; continue; } startMaxDurationTimer({ @@ -136,6 +143,11 @@ export class CallManager { console.log(`[voice-call] Restarted max-duration timer for restored call ${callId}`); } } + if (skippedAlreadyElapsedTimers > 0) { + console.log( + `[voice-call] Skipped ${skippedAlreadyElapsedTimers} restored call(s) whose max-duration timer already elapsed`, + ); + } if (verified.size > 0) { console.log(`[voice-call] Restored ${verified.size} active call(s) from store`); @@ -159,19 +171,23 @@ export class CallManager { const now = Date.now(); const verified = new Map(); const verifyTasks: Array<{ callId: CallId; call: CallRecord; promise: Promise }> = []; + let skippedNoProviderCallId = 0; + let skippedOlderThanMaxDuration = 0; + const skippedTerminalStatuses = new Map(); + let keptVerifiedActive = 0; + let keptUnknownProviderStatus = 0; + let keptVerificationFailures = 0; for (const [callId, call] of candidates) { // Skip calls without a provider ID — can't verify if (!call.providerCallId) { - console.log(`[voice-call] Skipping restored call ${callId} (no providerCallId)`); + skippedNoProviderCallId += 1; continue; } // Skip calls older than maxDurationSeconds (time-based fallback) if (now - call.startedAt > maxAgeMs) { - console.log( - `[voice-call] Skipping restored call ${callId} (older than maxDurationSeconds)`, - ); + skippedOlderThanMaxDuration += 1; markRestoredCallSkipped(call, "timeout"); persistCallRecord(this.storePath, call); await provider @@ -196,25 +212,20 @@ export class CallManager { .getCallStatus({ providerCallId: call.providerCallId }) .then((result) => { if (result.isTerminal) { - console.log( - `[voice-call] Skipping restored call ${callId} (provider status: ${result.status})`, - ); + incrementRestoreStatusCount(skippedTerminalStatuses, result.status); markRestoredCallSkipped(call, "completed"); persistCallRecord(this.storePath, call); } else if (result.isUnknown) { - console.log( - `[voice-call] Keeping restored call ${callId} (provider status unknown, relying on timer)`, - ); + keptUnknownProviderStatus += 1; verified.set(callId, call); } else { + keptVerifiedActive += 1; verified.set(callId, call); } }) .catch(() => { // Verification failed entirely — keep the call, rely on timer - console.log( - `[voice-call] Keeping restored call ${callId} (verification failed, relying on timer)`, - ); + keptVerificationFailures += 1; verified.set(callId, call); }), }; @@ -222,6 +233,36 @@ export class CallManager { } await Promise.allSettled(verifyTasks.map((t) => t.promise)); + if (skippedNoProviderCallId > 0) { + console.log( + `[voice-call] Skipped ${skippedNoProviderCallId} restored call(s) with no providerCallId`, + ); + } + if (skippedOlderThanMaxDuration > 0) { + console.log( + `[voice-call] Skipped ${skippedOlderThanMaxDuration} restored call(s) older than maxDurationSeconds`, + ); + } + for (const [status, count] of [...skippedTerminalStatuses].toSorted(([a], [b]) => + a.localeCompare(b), + )) { + console.log(`[voice-call] Skipped ${count} restored call(s) with provider status: ${status}`); + } + if (keptVerifiedActive > 0) { + console.log( + `[voice-call] Kept ${keptVerifiedActive} restored call(s) confirmed active by provider`, + ); + } + if (keptUnknownProviderStatus > 0) { + console.log( + `[voice-call] Kept ${keptUnknownProviderStatus} restored call(s) with unknown provider status (relying on timer)`, + ); + } + if (keptVerificationFailures > 0) { + console.log( + `[voice-call] Kept ${keptVerificationFailures} restored call(s) after verification failure (relying on timer)`, + ); + } return verified; }