From 02423d33fca0bd2bf1c6f96b2e917618a99da3fc Mon Sep 17 00:00:00 2001 From: Shakker Date: Fri, 24 Jul 2026 22:26:00 +0100 Subject: [PATCH] fix: improve cron model preflight errors (#113409) Preserve bounded and redacted local-provider preflight diagnostics, classify the guarded-fetch deadline accurately, and include the failure reason when cron continues with a fallback. Closes #113195. Reported-by: @timme0126 Reviewed-by: @shakkernerd --- CHANGELOG.md | 1 + .../isolated-agent.model-preflight.test.ts | 20 ++- .../model-preflight.runtime.test.ts | 147 ++++++++++++++++++ .../isolated-agent/model-preflight.runtime.ts | 79 +++++++++- src/cron/isolated-agent/run.ts | 2 +- 5 files changed, 238 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 12c8fa0effba..c8210bc76b9c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -51,6 +51,7 @@ Docs: https://docs.openclaw.ai ### Fixes +- **Cron local-provider preflight:** report the guarded-fetch deadline as a bounded preflight timeout, preserve concrete nested non-timeout errors, and carry the failure reason into fallback warnings. Thanks @shakkernerd. - **ClickClack split-origin setup codes:** consume versioned exact claim endpoints without appending a second claim path, validate the returned canonical API base, preserve private API transport overrides, and keep legacy setup URLs working. Fixes #111919. Thanks @shakkernerd. - **Standalone plugin files:** let manifestless files explicitly listed in `plugins.load.paths` pass config validation and load independently when several files share a directory. - **Control UI terminal error messages:** preserve message-only assistant output beginning with `Error:` or a warning marker instead of treating text prefixes as synthetic failures. Thanks @shakkernerd. diff --git a/src/cron/isolated-agent.model-preflight.test.ts b/src/cron/isolated-agent.model-preflight.test.ts index 29516202131c..0cafcd18f422 100644 --- a/src/cron/isolated-agent.model-preflight.test.ts +++ b/src/cron/isolated-agent.model-preflight.test.ts @@ -38,7 +38,7 @@ describe("runCronIsolatedAgentTurn model provider preflight", () => { preflightCronModelProviderMock.mockResolvedValueOnce({ status: "unavailable", reason: - "Agent cron job uses ollama/qwen3:32b but the local provider endpoint is not reachable at http://127.0.0.1:11434.", + "Agent cron job uses ollama/qwen3:32b but the local provider preflight failed at http://127.0.0.1:11434.", provider: "ollama", model: "qwen3:32b", baseUrl: "http://127.0.0.1:11434", @@ -88,16 +88,20 @@ describe("runCronIsolatedAgentTurn model provider preflight", () => { expect(result.provider).toBe("ollama"); expect(result.model).toBe("qwen3:32b"); expect(result.sessionId).toBe("cron-session"); - expect(result.error).toContain("local provider endpoint is not reachable"); + expect(result.error).toContain("local provider preflight failed"); expect(runEmbeddedAgentMock).not.toHaveBeenCalled(); }); it("continues with configured fallback when the local primary preflight is unavailable", async () => { mockRunCronFallbackPassthrough(); + const unavailableReason = + "Agent cron job uses ollama/qwen3:32b but the local provider preflight failed at " + + "http://127.0.0.1:11434. The candidate is unavailable for this cron run; OpenClaw " + + "will retry its provider preflight on a later scheduled run. Last error: " + + "ConnectError: connect ECONNREFUSED (code=ECONNREFUSED)"; preflightCronModelProviderMock.mockResolvedValueOnce({ status: "unavailable", - reason: - "Agent cron job uses ollama/qwen3:32b but the local provider endpoint is not reachable at http://127.0.0.1:11434.", + reason: unavailableReason, provider: "ollama", model: "qwen3:32b", baseUrl: "http://127.0.0.1:11434", @@ -162,17 +166,19 @@ describe("runCronIsolatedAgentTurn model provider preflight", () => { expect(runWithModelFallbackMock.mock.calls[0]?.[0]).toMatchObject({ fallbacksOverride: ["openai/gpt-5.4"], }); - expect(String(logWarnMock.mock.calls[0]?.[0] ?? "")).toContain( + const warning = String(logWarnMock.mock.calls[0]?.[0] ?? ""); + expect(warning).toContain(unavailableReason); + expect(warning).toContain( "continuing with fallback openrouter/nvidia/nemotron-3-super-120b-a12b:free", ); - expect(String(logWarnMock.mock.calls[0]?.[0] ?? "")).not.toContain("Skipping this cron run"); + expect(warning).not.toContain("Skipping this cron run"); }); it("keeps explicit empty payload fallbacks strict when local primary preflight fails", async () => { preflightCronModelProviderMock.mockResolvedValueOnce({ status: "unavailable", reason: - "Agent cron job uses ollama/qwen3:32b but the local provider endpoint is not reachable at http://127.0.0.1:11434.", + "Agent cron job uses ollama/qwen3:32b but the local provider preflight failed at http://127.0.0.1:11434.", provider: "ollama", model: "qwen3:32b", baseUrl: "http://127.0.0.1:11434", diff --git a/src/cron/isolated-agent/model-preflight.runtime.test.ts b/src/cron/isolated-agent/model-preflight.runtime.test.ts index e0d1ed0009a8..3e31890f6643 100644 --- a/src/cron/isolated-agent/model-preflight.runtime.test.ts +++ b/src/cron/isolated-agent/model-preflight.runtime.test.ts @@ -122,6 +122,10 @@ describe("preflightCronModelProvider", () => { expect(first.model).toBe("qwen3:32b"); expect(first.baseUrl).toBe("http://localhost:11434"); expect(first.retryAfterMs).toBe(300000); + expect(first.reason).toContain("the local provider preflight failed"); + expect(first.reason).not.toContain("endpoint is not reachable"); + expect(first.reason).toContain("Last error: Error: ECONNREFUSED"); + expect(first.reason).not.toContain("timed out after"); expect(second.status).toBe("unavailable"); if (second.status !== "unavailable") { throw new Error(`expected second preflight unavailable, got ${second.status}`); @@ -136,6 +140,149 @@ describe("preflightCronModelProvider", () => { expect(request.auditContext).toBe("cron-model-provider-preflight"); }); + it("reports a nested guarded-fetch deadline separately from endpoint failures", async () => { + const timeoutError = new Error("request timed out"); + timeoutError.name = "TimeoutError"; + fetchWithSsrFGuardMock.mockRejectedValueOnce( + new TypeError("fetch failed", { cause: timeoutError }), + ); + + const result = await preflightCronModelProvider({ + cfg: { + models: { + providers: { + ollama: { + api: "ollama", + baseUrl: "http://localhost:11434", + models: [], + }, + }, + }, + }, + provider: "ollama", + model: "qwen3:32b", + }); + + expect(result.status).toBe("unavailable"); + if (result.status !== "unavailable") { + throw new Error(`expected preflight unavailable, got ${result.status}`); + } + expect(result.reason).toContain( + "Last error: Local provider preflight exceeded its configured 2500ms deadline | " + + "TypeError: fetch failed | TimeoutError: request timed out", + ); + expect(result.reason).not.toContain("ECONNREFUSED"); + }); + + it("preserves nested abort details without classifying a generic abort as timeout", async () => { + const connectionError = Object.assign(new Error("connect ECONNREFUSED"), { + name: "ConnectError", + code: "ECONNREFUSED", + }); + const abortError = Object.assign(new Error("request aborted", { cause: connectionError }), { + name: "AbortError", + code: "ABORT_ERR", + }); + fetchWithSsrFGuardMock.mockRejectedValueOnce(abortError); + + const result = await preflightCronModelProvider({ + cfg: { + models: { + providers: { + ollama: { + api: "ollama", + baseUrl: "http://localhost:11434", + models: [], + }, + }, + }, + }, + provider: "ollama", + model: "qwen3:32b", + }); + + expect(result.status).toBe("unavailable"); + if (result.status !== "unavailable") { + throw new Error(`expected preflight unavailable, got ${result.status}`); + } + expect(result.reason).toContain( + "Last error: AbortError: request aborted (code=ABORT_ERR) | " + + "ConnectError: connect ECONNREFUSED (code=ECONNREFUSED)", + ); + expect(result.reason).not.toContain("timed out after"); + expect(result.reason).not.toContain("endpoint is not reachable"); + }); + + it("bounds cyclic cause-chain inspection", async () => { + const errors = Array.from({ length: 12 }, (_, index) => + Object.assign(new Error(`failure-${index}`), { + name: `NestedError${index}`, + code: `ELOOP${index}`, + cause: undefined as unknown, + }), + ); + for (let index = 0; index < errors.length - 1; index += 1) { + errors[index]!.cause = errors[index + 1]; + } + errors.at(-1)!.cause = errors[0]; + fetchWithSsrFGuardMock.mockRejectedValueOnce(errors[0]); + + const result = await preflightCronModelProvider({ + cfg: { + models: { + providers: { + ollama: { + api: "ollama", + baseUrl: "http://localhost:11434", + models: [], + }, + }, + }, + }, + provider: "ollama", + model: "qwen3:32b", + }); + + expect(result.status).toBe("unavailable"); + if (result.status !== "unavailable") { + throw new Error(`expected preflight unavailable, got ${result.status}`); + } + expect(result.reason.match(/failure-0/g)).toHaveLength(1); + expect(result.reason).toContain("NestedError7: failure-7 (code=ELOOP7)"); + expect(result.reason).not.toContain("failure-8"); + }); + + it("bounds long diagnostics without splitting UTF-16 surrogate pairs", async () => { + fetchWithSsrFGuardMock.mockRejectedValueOnce(new Error(`${"x".repeat(992)}😀truncated-detail`)); + + const result = await preflightCronModelProvider({ + cfg: { + models: { + providers: { + ollama: { + api: "ollama", + baseUrl: "http://localhost:11434", + models: [], + }, + }, + }, + }, + provider: "ollama", + model: "qwen3:32b", + }); + + expect(result.status).toBe("unavailable"); + if (result.status !== "unavailable") { + throw new Error(`expected preflight unavailable, got ${result.status}`); + } + const diagnostic = result.reason.split("Last error: ")[1]; + expect(diagnostic).toHaveLength(1_000); + expect(diagnostic).toMatch(/^Error: x+…$/u); + expect(diagnostic).not.toContain("😀"); + expect(diagnostic).not.toContain("truncated-detail"); + expect(/[\uD800-\uDBFF]$/u.test(diagnostic ?? "")).toBe(false); + }); + it("retries an unavailable endpoint after the cache ttl", async () => { fetchWithSsrFGuardMock.mockRejectedValueOnce(new Error("ECONNREFUSED")).mockResolvedValueOnce({ response: { status: 200 }, diff --git a/src/cron/isolated-agent/model-preflight.runtime.ts b/src/cron/isolated-agent/model-preflight.runtime.ts index b4d5c7b36263..73b170c88974 100644 --- a/src/cron/isolated-agent/model-preflight.runtime.ts +++ b/src/cron/isolated-agent/model-preflight.runtime.ts @@ -2,13 +2,17 @@ import { normalizeProviderId } from "@openclaw/model-catalog-core/provider-id"; import { expectDefined } from "@openclaw/normalization-core"; import { normalizeLowercaseStringOrEmpty } from "@openclaw/normalization-core/string-coerce"; +import { truncateUtf16Safe } from "@openclaw/normalization-core/utf16-slice"; import type { ModelProviderConfig } from "../../config/types.models.js"; import type { OpenClawConfig } from "../../config/types.openclaw.js"; import { fetchWithSsrFGuard } from "../../infra/net/fetch-guard.js"; import type { SsrFPolicy } from "../../infra/net/ssrf.js"; +import { redactSensitiveText } from "../../logging/redact.js"; const PREFLIGHT_CACHE_TTL_MS = 5 * 60_000; const PREFLIGHT_TIMEOUT_MS = 2_500; +const MAX_PREFLIGHT_ERROR_CAUSE_DEPTH = 8; +const MAX_PREFLIGHT_ERROR_CHARS = 1_000; type PreflightApi = "ollama" | "openai-completions"; @@ -130,6 +134,75 @@ function buildLocalProviderSsrFPolicy(baseUrl: string): SsrFPolicy | undefined { } } +function readErrorProperty(error: unknown, key: "cause" | "code" | "message" | "name"): unknown { + if ((typeof error !== "object" && typeof error !== "function") || error === null) { + return undefined; + } + try { + return (error as Record)[key]; + } catch { + return undefined; + } +} + +function collectPreflightErrorCauseChain(error: unknown): unknown[] { + const chain: unknown[] = []; + const seen = new Set(); + let current: unknown = error; + while ( + current !== undefined && + current !== null && + chain.length < MAX_PREFLIGHT_ERROR_CAUSE_DEPTH && + !seen.has(current) + ) { + seen.add(current); + chain.push(current); + current = readErrorProperty(current, "cause"); + } + return chain; +} + +function stringifyPreflightErrorValue(error: unknown): string { + try { + return String(error); + } catch { + return "Unknown error"; + } +} + +function formatPreflightErrorDetail(error: unknown): string { + const rawName = readErrorProperty(error, "name"); + const rawMessage = readErrorProperty(error, "message"); + const rawCode = readErrorProperty(error, "code"); + const name = typeof rawName === "string" ? rawName.trim() : ""; + const message = typeof rawMessage === "string" ? rawMessage.trim() : ""; + const code = + typeof rawCode === "string" || typeof rawCode === "number" ? String(rawCode) : undefined; + const detail = + name && message + ? `${name}: ${message}` + : message || name || (code ? `code=${code}` : stringifyPreflightErrorValue(error)); + return code && detail !== `code=${code}` ? `${detail} (code=${code})` : detail; +} + +function formatPreflightError(error: unknown): string { + const causeChain = collectPreflightErrorCauseChain(error); + const details = causeChain + .map(formatPreflightErrorDetail) + .filter((detail, index, all) => detail && all.indexOf(detail) === index); + const causeDetails = details.join(" | ") || stringifyPreflightErrorValue(error); + // fetchWithSsrFGuard propagates only its owned deadline as TimeoutError. + const classified = causeChain.some( + (candidate) => readErrorProperty(candidate, "name") === "TimeoutError", + ) + ? `Local provider preflight exceeded its configured ${PREFLIGHT_TIMEOUT_MS}ms deadline | ${causeDetails}` + : causeDetails; + const redacted = redactSensitiveText(classified); + return redacted.length <= MAX_PREFLIGHT_ERROR_CHARS + ? redacted + : `${truncateUtf16Safe(redacted, MAX_PREFLIGHT_ERROR_CHARS - 1)}…`; +} + function formatUnavailableReason(params: { provider: string; model: string; @@ -137,9 +210,9 @@ function formatUnavailableReason(params: { error: unknown; }): string { return [ - `Agent cron job uses ${params.provider}/${params.model} but the local provider endpoint is not reachable at ${params.baseUrl}.`, - `Skipping this cron run; OpenClaw will retry the provider preflight on a later scheduled run.`, - `Last error: ${String(params.error)}`, + `Agent cron job uses ${params.provider}/${params.model} but the local provider preflight failed at ${params.baseUrl}.`, + `The candidate is unavailable for this cron run; OpenClaw will retry its provider preflight on a later scheduled run.`, + `Last error: ${formatPreflightError(params.error)}`, ].join(" "); } diff --git a/src/cron/isolated-agent/run.ts b/src/cron/isolated-agent/run.ts index ccbc9f8dc79b..4952ca38c822 100644 --- a/src/cron/isolated-agent/run.ts +++ b/src/cron/isolated-agent/run.ts @@ -879,7 +879,7 @@ async function prepareCronRunContext(params: { if (selectedPreflightCandidate && modelFallbacksOverride) { if (firstUnavailablePreflight?.status === "unavailable") { logWarn( - `[cron:${input.job.id}] Local provider preflight failed for ${firstUnavailablePreflight.provider}/${firstUnavailablePreflight.model} at ${firstUnavailablePreflight.baseUrl}; continuing with fallback ${selectedPreflightCandidate.provider}/${selectedPreflightCandidate.model}.`, + `[cron:${input.job.id}] ${firstUnavailablePreflight.reason}; continuing with fallback ${selectedPreflightCandidate.provider}/${selectedPreflightCandidate.model}.`, ); } provider = selectedPreflightCandidate.provider;