[AI-689] ACP observability: lifecycle logging + opt-in debug-frame gate + metrics (PR 3/4)

[realtonyyoung]

What & why

AI-689 Workstream B — PR 3 of 4 (observability). Design-of-record in #315. Stacked on #316 (diagnostics) — base is ai-689-diagnostics; retarget to main once #316 merges.

An operator watching at the default level currently sees nothing ACP-specific unless something fails, and two Debug logs leak unredacted content. This PR fixes both, plus adds minimal metrics.

• B1 — Info-level lifecycle logging (source-gen [LoggerMessage], payload-free — ids/kinds/metadata only, never prompt/tool/assistant content): hosted-agent launch, handshake OK (protocolVersion + loadSession + resolved model), session started, blocking-request issued+resolved (kind + decision only), session ended.
• B3/B4 — close two Debug payload-leak vectors behind an opt-in flag. New KCAP_ACP_DEBUG_FRAMES (default off): when off, the Unknown-kind update dump and cursor-agent stderr log shape only (kind + length), and AcpConnection keeps its existing shape-only frame logging. When on, full raw updates / stderr lines / inbound+outbound frames are logged at Debug under a dedicated path, length-capped, with a one-time loud "may contain full prompts, tool arguments, and file contents" Warning. Nothing is ever written to the transcript or forwarded to the server.
• B2 — minimal metrics (Meter "Capacitor.Cli.Daemon.Acp": acp.launches, acp.sessions_started, acp.blocking_requests{kind}, acp.failures{stage}). No exporter — observable via dotnet-counters. Confirmed NativeAOT-clean.

Tests & gates

New: AcpEventTranslatorTests, AcpDebugFrameLogTests, AcpMetricsTests, DaemonDebugFramesFlagTests, AcpHostedAgentRuntimeFactoryTests, plus extended AcpConnectionTests / AcpInteractionBridgeTests — assert default-off gating logs shape-not-content, the enable-warning fires once, and blocking-request logs carry kind+decision but no content. Full unit suite 2896/2898 (2 pre-existing KCAP_ACP_LIVE-gated skips); NativeAOT osx-arm64 gate warning-free (incl. metrics).

Follow-up

Reconnect/resume + its lifecycle events/metrics land in PR 4/4.

🤖 Generated with Claude Code

[linear-code]

AI-689

[qodo-code-review]

PR Summary by Qodo

ACP observability: lifecycle logs, gated debug frames, and minimal metrics

✨ Enhancement 🐞 Bug fix 🧪 Tests ⚙️ Configuration changes 🕐 40+ Minutes

AI Description

• Add payload-free ACP lifecycle Info logs and minimal process-wide counters.
• Gate sensitive Debug frame/stderr/raw-update logging behind KCAP_ACP_DEBUG_FRAMES with truncation.
• Expand unit tests to assert default-off behavior, opt-in warnings, and metric publication.

Diagram

graph TD
  DR["DaemonRunner"] --> DC["DaemonConfig"] --> F["AcpRuntimeFactory"] --> C["AcpConnection"] --> R["AcpHostedRuntime"] --> T["AcpEventTranslator"]
  F --> P["AcpChildProcess"]
  R --> B["AcpInteractionBridge"]
  C --> O["Logs + Metrics"]
  P --> O
  R --> O
  B --> O

Loading

High-Level Assessment

The following are alternative approaches to this PR:

1. Use OpenTelemetry-first instrumentation

• ➕ Standardized metrics/log correlation (Resource, attributes, exporters)
• ➕ Easier future integration with centralized observability stacks
• ➖ Adds dependency/configuration surface area beyond the current minimal counters
• ➖ Potentially more work to keep NativeAOT-clean and low-overhead

2. Centralize debug-frame gating via ILogger category/filtering only

• ➕ Avoids plumbing a debugFrames boolean through constructors
• ➕ Leverages existing logging configuration mechanisms
• ➖ Harder to guarantee content never logs without explicit opt-in (risk of filter misconfiguration)
• ➖ Doesn’t provide a single place for one-time consent warning + shared truncation policy

Recommendation: Current approach is appropriate for the stated goals: explicit operator opt-in (KCAP_ACP_DEBUG_FRAMES), a one-time warning at daemon startup, and shared length-capping provide strong safety guarantees against accidental payload leaks while still enabling deep troubleshooting when needed. Consider OpenTelemetry exporters later if/when the daemon needs production-grade metrics pipelines; the current Meter usage is a good low-risk foundation.

Files changed (18) +814 / -38

Enhancement (6) +173 / -18

AcpConnection.csOpt-in full inbound/outbound ACP frame Debug logging with shared truncation +26/-2

Opt-in full inbound/outbound ACP frame Debug logging with shared truncation

• Threads a debugFrames flag into AcpConnection and, when enabled, logs full inbound/outbound JSON-RPC frames (capped) in addition to existing shape-only error logging. Adds LoggerMessage source-gen methods for the new debug logs.

src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs

AcpDebugFrameLog.csAdd shared length-cap utility for debug-frame logging +24/-0

Add shared length-cap utility for debug-frame logging

• Introduces a small utility to truncate potentially large debug payloads to a fixed max length and annotate truncation. Used consistently by all KCAP_ACP_DEBUG_FRAMES call sites.

src/Capacitor.Cli.Daemon/Acp/AcpDebugFrameLog.cs

AcpInteractionBridge.csAdd payload-free Info lifecycle logs and blocking-request metrics +39/-3

Add payload-free Info lifecycle logs and blocking-request metrics

• Adds Info-level logs for blocking request issued/resolved events using only kind and outcome, plus counters for permission/elicitation request kinds. Ensures resolution logs avoid leaking option/tool payloads by extracting only the outcome discriminator.

src/Capacitor.Cli.Daemon/Acp/AcpInteractionBridge.cs

AcpMetrics.csIntroduce minimal ACP Meter counters for launches/sessions/requests/failures +27/-0

Introduce minimal ACP Meter counters for launches/sessions/requests/failures

• Adds a process-wide Meter (Capacitor.Cli.Daemon.Acp) and a small set of counters with limited tag vocabularies for local troubleshooting via dotnet-counters. Provides helper methods to record tagged blocking requests and failures.

src/Capacitor.Cli.Daemon/Acp/AcpMetrics.cs

AcpHostedAgentRuntime.csAdd ACP handshake/session lifecycle Info logs and failure metrics +44/-9

Add ACP handshake/session lifecycle Info logs and failure metrics

• Adds payload-free Info logs for session start, handshake completion (protocol/loadSession/resolved model), and session end. Records handshake failure metrics and passes debugFrames through to event translation for unknown-kind gating.

src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs

AcpHostedAgentRuntimeFactory.csPropagate DebugFrames to ACP components; log launches and increment launch metric +13/-4

Propagate DebugFrames to ACP components; log launches and increment launch metric

• Emits an Info-level launch log with agentId/vendor/cwd, increments the launch counter, and threads DebugFrames into AcpConnection, AcpChildProcess, and AcpHostedAgentRuntime construction. Adds LoggerMessage source-gen for launch logging.

src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntimeFactory.cs

Bug fix (2) +54 / -15

AcpChildProcess.csGate cursor-agent stderr Debug logging behind DebugFrames (shape-only by default) +30/-8

Gate cursor-agent stderr Debug logging behind DebugFrames (shape-only by default)

• Adds a debugFrames constructor parameter and switches stderr drain logging to emit only line length unless explicitly opted in. Introduces source-generated LoggerMessage methods and applies a shared truncation cap when full logging is enabled.

src/Capacitor.Cli.Daemon/Acp/AcpChildProcess.cs

AcpEventTranslator.csGate Unknown update raw JSON dump behind DebugFrames; log shape by default +24/-7

Gate Unknown update raw JSON dump behind DebugFrames; log shape by default

• Extends Translate() with a debugFrames parameter and replaces unconditional raw JSON dumping with opt-in full logging (capped) or length-only logging by default. Uses source-generated LoggerMessage methods for both variants.

src/Capacitor.Cli.Daemon/Acp/AcpEventTranslator.cs

Tests (8) +555 / -5

AcpConnectionTests.csAdd tests for debugFrames opt-in full-frame logging behavior +113/-2

Add tests for debugFrames opt-in full-frame logging behavior

• Extends the harness to accept a logger and debugFrames flag, introduces a capture logger, and adds tests asserting default-off behavior and opt-in inbound/outbound frame logging. Also verifies malformed-line shape-only logging behavior remains intact when debugFrames is enabled.

test/Capacitor.Cli.Tests.Unit/Acp/AcpConnectionTests.cs

AcpDebugFrameLogTests.csUnit test shared truncation/cap behavior for debug-frame logging +46/-0

Unit test shared truncation/cap behavior for debug-frame logging

• Adds isolated tests for AcpDebugFrameLog.Cap covering empty, short, exact-limit, and over-limit inputs. Ensures truncation includes an annotation of the truncated length.

test/Capacitor.Cli.Tests.Unit/Acp/AcpDebugFrameLogTests.cs

AcpEventTranslatorTests.csTest Unknown update logging is shape-only by default and full only with opt-in +69/-0

Test Unknown update logging is shape-only by default and full only with opt-in

• Adds a capture logger and tests that Unknown-kind raw JSON content is not logged unless debugFrames is explicitly enabled. Verifies behavior with and without a logger supplied to Translate().

test/Capacitor.Cli.Tests.Unit/Acp/AcpEventTranslatorTests.cs

AcpHostedAgentRuntimeProtocolNegotiationTests.csTest payload-free handshake/session lifecycle Info logs +73/-3

Test payload-free handshake/session lifecycle Info logs

• Adds logger capture plumbing to the runtime harness and new assertions that session started/handshake OK/session ended logs appear appropriately. Verifies prompt text never appears in Info logs and that version mismatch suppresses lifecycle logs.

test/Capacitor.Cli.Tests.Unit/Acp/AcpHostedAgentRuntimeProtocolNegotiationTests.cs

AcpInteractionBridgeTests.csTest blocking-request issued/resolved Info logs avoid tool/prompt payloads +85/-0

Test blocking-request issued/resolved Info logs avoid tool/prompt payloads

• Adds capture logger and tests ensuring issued/resolved lifecycle logs include kind and decision only. Verifies no leakage of tool title/prompt content and that malformed requests do not emit lifecycle logs.

test/Capacitor.Cli.Tests.Unit/Acp/AcpInteractionBridgeTests.cs

AcpMetricsTests.csSmoke-test AcpMetrics counters are AOT-safe and publish tagged measurements +79/-0

Smoke-test AcpMetrics counters are AOT-safe and publish tagged measurements

• Adds tests that counter increments do not throw and that MeterListener can observe tagged measurements for blocking_requests(kind) and failures(stage). Focuses on publication behavior rather than internal state.

test/Capacitor.Cli.Tests.Unit/Acp/AcpMetricsTests.cs

DaemonDebugFramesFlagTests.csTest KCAP_ACP_DEBUG_FRAMES parsing semantics +33/-0

Test KCAP_ACP_DEBUG_FRAMES parsing semantics

• Adds unit tests for DaemonRunner.ParseDebugFramesFlag to ensure only "1"/"true" (case-insensitive) enable the flag and everything else disables it. Mirrors existing env-var parsing test patterns.

test/Capacitor.Cli.Tests.Unit/Daemon/DaemonDebugFramesFlagTests.cs

AcpHostedAgentRuntimeFactoryTests.csTest factory emits ACP hosted agent launch Info log +57/-0

Test factory emits ACP hosted agent launch Info log

• Adds a capture ILoggerFactory and a test asserting the launch log contains agentId, vendor, and cwd. Validates payload-free lifecycle logging at the runtime-factory boundary.

test/Capacitor.Cli.Tests.Unit/Services/AcpHostedAgentRuntimeFactoryTests.cs

Other (2) +32 / -0

DaemonConfig.csAdd DebugFrames config flag (KCAP_ACP_DEBUG_FRAMES) with safety semantics +13/-0

Add DebugFrames config flag (KCAP_ACP_DEBUG_FRAMES) with safety semantics

• Introduces DaemonConfig.DebugFrames with documentation describing default-off behavior, opt-in full payload logging, and guarantees that content is not sent server-side or written to transcript. Establishes the config surface used by daemon startup wiring.

src/Capacitor.Cli.Daemon/DaemonConfig.cs

DaemonRunner.csParse KCAP_ACP_DEBUG_FRAMES and emit one-time startup warning when enabled +19/-0

Parse KCAP_ACP_DEBUG_FRAMES and emit one-time startup warning when enabled

• Wires the env var into DaemonConfig.DebugFrames via a testable parse function and emits a single high-signal Warning at daemon startup when enabled. Adds a dedicated LoggerMessage warning for consent/sensitivity disclosure.

src/Capacitor.Cli.Daemon/DaemonRunner.cs

[qodo-code-review]

Code Review by Qodo

🐞 Bugs (0) 📘 Rule violations (0) 📎 Requirement gaps (0) 🎨 UX issues (0) 🔗 Cross-repo conflicts (0) 📜 Skill insights (0)

1. KCAP_ACP_DEBUG_FRAMES undocumented in README ✓ Resolved 📘 Rule violation ⚙ Maintainability

Description

This PR introduces a new user-facing daemon environment variable (KCAP_ACP_DEBUG_FRAMES) but does
not document it in README.md, creating user-visible documentation drift. Operators will not
discover the flag or understand its security implications from the canonical CLI docs.

Code

src/Capacitor.Cli.Daemon/DaemonRunner.cs[R131-132]

+        config.DebugFrames = ParseDebugFramesFlag(Environment.GetEnvironmentVariable("KCAP_ACP_DEBUG_FRAMES"));
+

Evidence

The code now reads KCAP_ACP_DEBUG_FRAMES into DaemonConfig.DebugFrames, which is a user-facing
behavior toggle. The README daemon/environment-variable documentation section does not mention
KCAP_ACP_DEBUG_FRAMES, so the change is not documented as required by the checklist.

CLAUDE.md: Update README.md in the same PR for any user-facing CLI surface changes
src/Capacitor.Cli.Daemon/DaemonRunner.cs[119-132]
README.md[684-718]

Agent prompt

The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

## Issue description
A new user-facing daemon env var (`KCAP_ACP_DEBUG_FRAMES`) is added/used, but `README.md` is not updated to document it.

## Issue Context
Per the compliance checklist, any user-facing CLI surface change (including new environment variables that affect behavior/logging) must be documented in `README.md` in the same PR.

## Fix Focus Areas
- README.md[670-718]
- src/Capacitor.Cli.Daemon/DaemonRunner.cs[119-132]

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

---

2. RawLength allocates raw JSON ✓ Resolved 🐞 Bug ➹ Performance

Description

In AcpEventTranslator.Translate(), the default-off (debugFrames=false) unknown-kind log computes
RawLength using update.Raw.GetRawText(), allocating the full raw JSON string just to measure its
length. This allocation can occur even when Debug logging is disabled because the GetRawText()
happens before any log-level check.

Code

src/Capacitor.Cli.Daemon/Acp/AcpEventTranslator.cs[R110-118]

+                if (logger is not null) {
+                    // KCAP_ACP_DEBUG_FRAMES gate (Off by default): the raw update JSON can carry
+                    // prompt/tool/file content, so it is only ever logged verbatim when the operator
+                    // has explicitly opted in — otherwise this logs shape (kind + length) only.
+                    if (debugFrames)
+                        LogUnknownUpdateFull(logger, AcpDebugFrameLog.Cap(update.Raw?.GetRawText() ?? ""));
+                    else
+                        LogUnknownUpdateShape(logger, update.Raw?.GetRawText()?.Length ?? 0);
+                }

Evidence

Translate’s Unknown path calls GetRawText() even in the debugFrames=false branch, and the runtime
passes a logger into Translate on its notification aggregation path.

src/Capacitor.Cli.Daemon/Acp/AcpEventTranslator.cs[108-121]
src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[727-746]

Agent prompt

The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

### Issue description
For Unknown updates, the "shape-only" path still calls `update.Raw?.GetRawText()?.Length`, which materializes the entire raw JSON payload into a string. This defeats the goal of keeping the default-off path lightweight and can create large, avoidable allocations.

### Issue Context
`AcpHostedAgentRuntime` calls `AcpEventTranslator.Translate(..., logger: _logger, debugFrames: _debugFrames)` on the aggregation path; passing a logger means Unknown updates will hit this code.

### Fix Focus Areas
- src/Capacitor.Cli.Daemon/Acp/AcpEventTranslator.cs[108-121]
- src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[727-746]

### Suggested change
- Only compute `GetRawText()` (or its length) when you will actually emit a Debug log, e.g.:
 - `if (logger is null || !logger.IsEnabled(LogLevel.Debug)) return null;`
- Consider changing the "shape-only" log to avoid needing raw length at all (e.g., log `RawPresent` + `RawKind`), which avoids any payload materialization when debugFrames is off.

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

---

3. Spurious session-ended log ✓ Resolved 🐞 Bug ◔ Observability

Description

AcpHostedAgentRuntime.DisposeAsync() logs "ACP hosted agent session ended" unconditionally using an
empty session id when StartAsync fails before session/new, producing a misleading lifecycle line.
This happens in real failure paths because AcpHostedAgentRuntimeFactory disposes the runtime on
handshake failure.

Code

src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[R828-829]

+        LogSessionEnded(_agentId, _sessionId ?? "");
+

Evidence

DisposeAsync always logs a session-ended lifecycle event even if no sessionId exists, and the
factory calls DisposeAsync on StartAsync failure, which can occur before session/new assigns
_sessionId.

src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[280-377]
src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[824-833]
src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntimeFactory.cs[44-73]

Agent prompt

The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

### Issue description
`AcpHostedAgentRuntime.DisposeAsync()` always emits the Info lifecycle log "ACP hosted agent session ended" even if the runtime never established an ACP session (`session/new` never succeeded). On handshake failures this creates a false “session ended” breadcrumb with an empty `acpSessionId`, which is misleading for operators.

### Issue Context
`AcpHostedAgentRuntimeFactory.StartAsync` wraps `runtime.StartAsync(...)` in a try/catch and calls `runtime.DisposeAsync()` on failure. In that path `_sessionId` is still null because it’s only assigned after a successful `session/new`.

### Fix Focus Areas
- src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[280-377]
- src/Capacitor.Cli.Daemon/Services/AcpHostedAgentRuntime.cs[824-864]

### Suggested change
- Track whether a session was actually established (e.g., `_sessionEstablished` bool set after `_sessionId` is assigned), and only emit `LogSessionEnded(...)` when established.
- Alternatively, guard on `_sessionId is { Length: > 0 }` and skip the log if absent (or emit a separate Debug-level "disposed before session start" log).

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

---

4. Outbound log before write ✓ Resolved 🐞 Bug ◔ Observability

Description

When DebugFrames is enabled, AcpConnection.WriteLineAsync logs the outbound frame before acquiring
the write semaphore and before WriteAsync/FlushAsync. If cancellation happens or the write fails,
debug logs can claim a frame was sent even though it never hit the wire (and log ordering can differ
from the actual wire order).

Code

src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs[R428-433]

+        if (_debugFrames)
+            LogOutboundFrame(AcpDebugFrameLog.Cap(json));
+
        var bytes = Encoding.UTF8.GetBytes(json + "\n");

        await _writeGate.WaitAsync(ct).ConfigureAwait(false);

Evidence

The outbound debug log happens before the cancellation-sensitive semaphore wait and the actual
write/flush, and RequestAsync uses the caller CT for that write path.

src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs[114-137]
src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs[427-440]

Agent prompt

The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

### Issue description
`AcpConnection.WriteLineAsync` logs `ACP >>> {Frame}` before it waits on `_writeGate` and before the write/flush completes. If the provided `CancellationToken` is canceled during the gate wait or the write fails, the log stream can incorrectly imply the frame was transmitted.

### Issue Context
`RequestAsync` passes the caller’s `ct` into `WriteLineAsync`, so cancellation during shutdown is a normal scenario.

### Fix Focus Areas
- src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs[114-137]
- src/Capacitor.Cli.Daemon/Acp/AcpConnection.cs[427-440]

### Suggested change
- Move `LogOutboundFrame(...)` to after `_writeGate.WaitAsync(ct)` and ideally after a successful `WriteAsync`+`FlushAsync`.
- If you intentionally want "attempted send" logging, change the message to reflect that (and optionally add a second log for write failures).

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

---

5. DebugFrames flag not trimmed ✓ Resolved 🐞 Bug ⚙ Maintainability

Description

DaemonRunner.ParseDebugFramesFlag does not Trim() the env var value, so whitespace-padded values
(e.g. " true ") won’t enable debug frames. This is inconsistent with ParseLogLevel, which normalizes
input via Trim().

Code

src/Capacitor.Cli.Daemon/DaemonRunner.cs[R438-439]

+    internal static bool ParseDebugFramesFlag(string? value) =>
+        value == "1" || string.Equals(value, "true", StringComparison.OrdinalIgnoreCase);

Evidence

DaemonRunner uses Trim() in ParseLogLevel but not in ParseDebugFramesFlag, so whitespace affects
only the new debug-frames flag.

src/Capacitor.Cli.Daemon/DaemonRunner.cs[422-440]

Agent prompt

The issue below was found during a code review. Follow the provided context and guidance below and implement a solution

### Issue description
`ParseDebugFramesFlag` does not trim whitespace, so some valid-looking env var values (like `" true "`) are treated as Off.

### Issue Context
`ParseLogLevel` already trims and normalizes its input; `ParseDebugFramesFlag` should behave similarly for operator ergonomics.

### Fix Focus Areas
- src/Capacitor.Cli.Daemon/DaemonRunner.cs[422-440]

### Suggested change
- Use `var v = value?.Trim();` then compare against `"1"`/`"true"` (case-insensitive).

ⓘ Copy this prompt and use it to remediate the issue with your preferred AI generation tools

---