fix(v1.46.1): remove bogus 3s TESTIMIZE UNHEALTHY grace window

The 3-second grace in GenerationAgent was based on a wrong assumption
about how fast the Copilot CLI's MCP client handshakes with a server.
In reality it takes ~60s to attempt + time out an initialize against
a non-spec-compliant server (JSON-RPC error -32001). Our grace fired
well before the real SessionMcpServersLoadedEvent came through,
producing a false UNHEALTHY line. Then the real event arrived ~60s
later with status=Failed and the actual error message.

Fix: trust the SDK event entirely. When it fires (success or failure),
log the real status with the real error. Session creation is
non-blocking with respect to MCP loading, so generation starts
immediately and the MCP handshake runs in parallel.

## Separate fix (Testimize.MCP.Server, not this repo)

The underlying reason the CLI's -32001 timeout fires at all: testimize
was emitting responses with both "result":{...} AND "error":null,
which is a JSON-RPC 2.0 spec violation. Strict MCP clients reject
malformed responses and wait forever for a valid one. Updated
testimize's Program.cs to serialize only the applicable field per
spec (requires rebuild + reinstall of testimize-mcp 1.1.10).

## Expected debug log after both fixes

  [generate] TESTIMIZE CONFIGURED server=testimize command=testimize-mcp ...
  [generate] TESTIMIZE LOADED server=testimize status=Connected source=...
  [generate] TESTIMIZE DISPOSED (session closed)

No more false UNHEALTHY line. LOADED fires with Connected instead of
Failed once testimize-mcp's JSON-RPC output is spec-compliant.

Tests: 1647/1647.

Author: angelovstanton

CHANGELOG.md

@@ -5,6 +5,16 @@ All notable changes to this project will be documented in this file.
 The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/),
 and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html).
 
+## [1.46.1] - 2026-04-11
+
+### Fixed
+- **False `TESTIMIZE UNHEALTHY no_load_event_within_3s` line in debug log.** The 3-second grace window in `GenerationAgent` was based on a wrong assumption about how fast the Copilot CLI's MCP client handshakes with a server — in reality it takes ~60s to attempt + time out an initialize against a non-spec-compliant server. Removed the grace window entirely. The SDK's `SessionMcpServersLoadedEvent` is the single source of truth; when it fires (success or failure), the real status is logged with the real error message. Generation proceeds immediately because the SDK does not block session creation on MCP loading.
+- **Session-companion fix in `Testimize.MCP.Server`** (separate repo): the server previously emitted JSON-RPC responses with both `"result"` and `"error":null`, which is a [JSON-RPC 2.0 spec violation](https://www.jsonrpc.org/specification#response_object) — the spec says a response MUST contain `result` OR `error`, not both. The Copilot CLI's MCP client (built on `@modelcontextprotocol/sdk`) correctly rejects malformed responses and times out at ~60s with `MCP error -32001: Request timed out`. Fix: serialize only the field that applies. See `Testimize.MCP.Server/Program.cs` change; requires rebuilding testimize-mcp 1.1.10 from source and reinstalling.
+
+### Notes
+- **Zero code-path changes beyond the 3s grace removal** — token tracking, debug log formatting, run summary, `RUN TOTAL` line, and the native `SessionConfig.McpServers` wiring from v1.46.0 are all untouched.
+- The SDK's behavior (blocking vs non-blocking session creation on MCP load) was empirically verified by observing the timing in `.spectra-debug.log`: session creation completed immediately, generation ran in parallel with the MCP handshake, and the load event arrived ~68s later with `status=Failed`.
+
 ## [1.46.0] - 2026-04-11
 
 ### Added

CLAUDE.md

@@ -209,6 +209,7 @@ spectra config list-automation-dirs                 # List dirs with existence s
 - **Tests:** xUnit with structured results (never throw on validation errors)
 
 ## Recent Changes
+- v1.46.1: removed the bogus 3-second TESTIMIZE UNHEALTHY grace window. The Copilot CLI's MCP client takes ~60s to attempt + time out an initialize handshake against a non-spec-compliant server, so the 3s wait always fired a false UNHEALTHY before the real SessionMcpServersLoadedEvent came through. Fix: trust the SDK event entirely — when it fires (success or failure), log the real status with the real error message. Companion fix in `Testimize.MCP.Server` (separate repo): the server was emitting JSON-RPC responses with both `"result":{...}` AND `"error":null`, which is a JSON-RPC 2.0 spec violation — the Copilot CLI's MCP client correctly rejected these as malformed and timed out with `MCP error -32001: Request timed out`. Updated `Testimize.MCP.Server/Program.cs` to serialize only the applicable field per spec. Requires rebuild + reinstall of testimize-mcp.
 - v1.46.0: Testimize integration migrated to the Copilot SDK's native `SessionConfig.McpServers` API. The SDK owns spawn, initialize handshake, framing, tool discovery, and lifecycle — deleted the custom `TestimizeMcpClient` (which had a broken Content-Length framing assumption that deadlocked against testimize-mcp's newline-delimited protocol) and `TestimizeTools.CreateGenerateTestDataTool` wrapper. New `McpConfigBuilder.BuildTestimizeServer` helper translates `TestimizeConfig` → `McpLocalServerConfig`. Generation agent subscribes to `SessionMcpServersLoadedEvent` / `SessionMcpServerStatusChangedEvent` and logs `TESTIMIZE CONFIGURED / LOADED / STATUS_CHANGED / DISPOSED` lines with the SDK's status enum (`Connected / Failed / NeedsAuth / Pending / Disabled / NotConfigured`). 3-second defensive grace window before falling back. `{{testimize_strategy}}` placeholder added to `test-generation.md` so the AI knows to prefer `testimize/generate_hybrid_test_cases` (default) or `testimize/generate_pairwise_test_cases`. `AnalyzeFieldSpec` moved to new `FieldSpecAnalysisTools.cs` (no behavior change). User-facing `testimize.*` config schema is unchanged.
 - v1.45.2: run header block at the start of every `.spectra-debug.log` run (`=== SPECTRA v<version> | <command line> | <UTC timestamp> ===` preceded by a 62-char horizontal separator). New `debug.mode` config (`append` default / `overwrite`) controls whether the file is truncated or prepended at run start. New `DebugLogger.BeginRun()` wired from `GenerateHandler` and `UpdateHandler`. Version pulled from `AssemblyInformationalVersionAttribute`, command line from `Environment.GetCommandLineArgs()`. **Deleted** `.spectra-debug-analysis.txt` and `.spectra-debug-response.txt` writers — all debug output now lives in `.spectra-debug.log` only. `SaveDebugResponse` method removed from `GenerationAgent`. Testimize lifecycle lines survive the overwrite-mode truncate (regression-tested).
 - v1.45.1 (Spec 040 follow-up): real token counts at every AI call site via `AssistantUsageEvent` subscription through new `CopilotUsageObserver`. Falls back to `text.Length / 4` via new `TokenEstimator` when the usage event misses the 200ms grace window. Fallback values are flagged with `~` prefix in debug log (`~tokens_in=` / `~tokens_out=`) and `"estimated": true` on `token_usage` in JSON. New `RUN TOTAL` summary line emitted to `.spectra-debug.log` at the end of every generate/update run via `RunSummaryDebugFormatter` — format `RUN TOTAL command=… suite=… calls=… tokens_in=… tokens_out=… elapsed=… phases=analysis:1/18.5s,generation:3/52.3s,critic:20/1m34s`. Discovered during implementation: `AssistantUsageData.InputTokens`/`OutputTokens` are actually `double?` in the SDK assembly (XML doc said `int`) — cast via `(int)(v ?? 0)`.

src/Spectra.CLI/Agent/Copilot/GenerationAgent.cs

@@ -141,10 +141,6 @@ public async Task<GenerationResult> GenerateTestsAsync(
 
             // Track tool calls and schedule delayed composing message
             using var timerCts = CancellationTokenSource.CreateLinkedTokenSource(ct);
-            // v1.46.0: one-shot latch so we know whether testimize reported a
-            // load status within the grace window. Used for the defensive
-            // fallback below.
-            var testimizeLoadReported = false;
             using var subscription = session.On(evt =>
             {
                 if (evt is AssistantUsageEvent usage && usage.Data is { } usageData)
@@ -168,7 +164,6 @@ public async Task<GenerationResult> GenerateTestsAsync(
                         DebugLog($"TESTIMIZE LOADED server={name} status={status} source={s.Source ?? "?"}{errorSuffix}");
                         if (string.Equals(name, "testimize", StringComparison.OrdinalIgnoreCase))
                         {
-                            testimizeLoadReported = true;
                             if (status.Equals("Connected", StringComparison.OrdinalIgnoreCase))
                             {
                                 _onStatus?.Invoke("Testimize connected — algorithmic test data available");
@@ -184,10 +179,6 @@ public async Task<GenerationResult> GenerateTestsAsync(
                 if (evt is SessionMcpServerStatusChangedEvent changed && changed.Data is { } changedData)
                 {
                     DebugLog($"TESTIMIZE STATUS_CHANGED server={changedData.ServerName} status={changedData.Status}");
-                    if (string.Equals(changedData.ServerName, "testimize", StringComparison.OrdinalIgnoreCase))
-                    {
-                        testimizeLoadReported = true;
-                    }
                     return;
                 }
                 if (evt is ToolExecutionStartEvent toolStart)
@@ -218,24 +209,16 @@ public async Task<GenerationResult> GenerateTestsAsync(
                 }
             });
 
-            // v1.46.0: defensive 3-second grace window — if testimize was
-            // configured but the SDK hasn't reported a load status by the
-            // time we're ready to send the prompt, log an UNHEALTHY line and
-            // continue. The SDK still owns the process; we're just warning
-            // the user that the MCP server may not be responding.
-            if (mcpServers is not null)
-            {
-                var graceDeadline = DateTime.UtcNow.AddSeconds(3);
-                while (!testimizeLoadReported && DateTime.UtcNow < graceDeadline)
-                {
-                    await Task.Delay(100, ct);
-                }
-                if (!testimizeLoadReported)
-                {
-                    DebugLog("TESTIMIZE UNHEALTHY server=testimize reason=no_load_event_within_3s");
-                    _onStatus?.Invoke("Testimize server didn't report load status within 3s — AI may still succeed without it");
-                }
-            }
+            // v1.46.1: the old 3-second grace window was deleted. The
+            // Copilot CLI's MCP client takes ~60 seconds to attempt +
+            // time out the initialize handshake (JSON-RPC error -32001),
+            // so a 3-second wait would always fire a false UNHEALTHY
+            // line and then the real LOADED event would arrive much
+            // later. Instead, we let the SDK fire SessionMcpServersLoadedEvent
+            // whenever it's ready — the event handler above logs the
+            // real status (Connected / Failed / NeedsAuth / ...) with
+            // the actual error message. Generation proceeds immediately
+            // because the SDK doesn't block session creation on MCP load.
 
             // Build the combined prompt with system instructions and user request.
             // The profile format (JSON schema sent to the AI) is resolved from