Agents: log cooldown attempt success

src/agents/model-fallback.probe.test.ts

@@ -1,5 +1,8 @@
+import os from "node:os";
+import path from "node:path";
 import { afterEach, beforeEach, describe, expect, it, vi } from "vitest";
 import type { OpenClawConfig } from "../config/config.js";
+import { registerLogTransport, resetLogger, setLoggerOverride } from "../logging/logger.js";
 import type { AuthProfileStore } from "./auth-profiles.js";
 import { makeModelFallbackCfg } from "./test-helpers/model-fallback-config-fixture.js";
 
@@ -28,6 +31,7 @@ const mockedResolveProfilesUnavailableReason = vi.mocked(resolveProfilesUnavaila
 const mockedResolveAuthProfileOrder = vi.mocked(resolveAuthProfileOrder);
 
 const makeCfg = makeModelFallbackCfg;
+let unregisterLogTransport: (() => void) | undefined;
 
 function expectFallbackUsed(
   result: { result: unknown; attempts: Array<{ reason?: string }> },
@@ -149,6 +153,10 @@ describe("runWithModelFallback – probe logic", () => {
 
   afterEach(() => {
     Date.now = realDateNow;
+    unregisterLogTransport?.();
+    unregisterLogTransport = undefined;
+    setLoggerOverride(null);
+    resetLogger();
     vi.restoreAllMocks();
   });
 
@@ -194,6 +202,53 @@ describe("runWithModelFallback – probe logic", () => {
     expectPrimaryProbeSuccess(result, run, "probed-ok");
   });
 
+  it("logs candidate_succeeded after a successful primary cooldown probe", async () => {
+    const cfg = makeCfg();
+    const records: Array<Record<string, unknown>> = [];
+    mockedGetSoonestCooldownExpiry.mockReturnValue(NOW + 60 * 1000);
+    setLoggerOverride({
+      level: "trace",
+      consoleLevel: "silent",
+      file: path.join(os.tmpdir(), `openclaw-model-fallback-probe-${Date.now()}.log`),
+    });
+    unregisterLogTransport = registerLogTransport((record) => {
+      records.push(record);
+    });
+
+    const run = vi.fn().mockResolvedValue("probed-ok");
+
+    const result = await runPrimaryCandidate(cfg, run);
+
+    expectPrimaryProbeSuccess(result, run, "probed-ok");
+
+    const decisionPayloads = records
+      .filter(
+        (record) =>
+          record["2"] === "model fallback decision" &&
+          record["1"] &&
+          typeof record["1"] === "object",
+      )
+      .map((record) => record["1"] as Record<string, unknown>);
+
+    expect(decisionPayloads).toEqual(
+      expect.arrayContaining([
+        expect.objectContaining({
+          event: "model_fallback_decision",
+          decision: "probe_cooldown_candidate",
+          candidateProvider: "openai",
+          candidateModel: "gpt-4.1-mini",
+          allowTransientCooldownProbe: true,
+        }),
+        expect.objectContaining({
+          event: "model_fallback_decision",
+          decision: "candidate_succeeded",
+          candidateProvider: "openai",
+          candidateModel: "gpt-4.1-mini",
+        }),
+      ]),
+    );
+  });
+
   it("probes primary model when cooldown already expired", async () => {
     const cfg = makeCfg();
     // Cooldown expired 5 min ago

src/agents/model-fallback.ts

@@ -527,6 +527,7 @@ export async function runWithModelFallback<T>(params: {
   for (let i = 0; i < candidates.length; i += 1) {
     const candidate = candidates[i];
     let runOptions: ModelFallbackRunOptions | undefined;
+    let attemptedDuringCooldown = false;
     if (authStore) {
       const profileIds = resolveAuthProfileOrder({
         cfg: params.cfg,
@@ -589,6 +590,7 @@ export async function runWithModelFallback<T>(params: {
         ) {
           runOptions = { allowTransientCooldownProbe: true };
         }
+        attemptedDuringCooldown = true;
         logModelFallbackDecision({
           decision: "probe_cooldown_candidate",
           runId: params.runId,
@@ -615,7 +617,7 @@ export async function runWithModelFallback<T>(params: {
       options: runOptions,
     });
     if ("success" in attemptRun) {
-      if (i > 0 || attempts.length > 0) {
+      if (i > 0 || attempts.length > 0 || attemptedDuringCooldown) {
         logModelFallbackDecision({
           decision: "candidate_succeeded",
           runId: params.runId,