diff --git a/docs/features/telemetry.md b/docs/features/telemetry.md index 66397ef1..b00310a3 100644 --- a/docs/features/telemetry.md +++ b/docs/features/telemetry.md @@ -34,6 +34,7 @@ MCPProxy sends a **daily heartbeat** containing only aggregate, non-identifying | `last_error_code` | `MCPX_DOCKER_CLI_NOT_FOUND` | Most recent stable `MCPX_*` diagnostic code (schema v7). Enum code only, never error text | | `tpa_scanner` | `{"scans_completed":4,"scans_failed":0,"scans_with_findings":1,"findings":{"high":2}}` | Security/TPA scanner activity (schema v8) — counts only, keyed by the fixed severity enum. Omitted entirely when no scan ran | | `feature_flags.deep_scan_enabled` | `false` | Whether the opt-in deep-scan layer is turned on (schema v8) | +| `preflight` | `{"filter_diag_emitted_24h":3,"availability_block_24h":2,"availability_block_reasons_24h":{"server_quarantined":2},"discovery_omission_24h":5}` | Preflight baseline counters (issue #969) — counts only, reason map keyed by a fixed enum. Omitted entirely when nothing was counted. See below | The `server_protocol_counts` map uses a **fixed enum of keys** (`stdio`, `http`, `sse`, `streamable_http`, `auto`) — server names and URLs are never included. Unknown or misconfigured protocol values are bucketed into `auto`. @@ -158,6 +159,58 @@ The whole `tpa_scanner` object is **omitted** when every counter is zero, so an **Never transmitted**: the scanned server's name, the scanner id, rule ids, finding titles or descriptions, matched content, file paths, and scan error messages. +## Preflight baseline counters (issue #969) + +The `preflight` sub-object measures two things the proxy currently does silently: +how often a `retrieve_tools` response **explains a filter** it applied (spec 094's +`filter_diagnostics` block) and whether the agent then acted on that explanation, +and how often a tool the caller asked for **existed but was withheld**. + +These counters ship **one release ahead** of the required-tools-preflight feature +on purpose. Without a live pre-feature window there is nothing to compare the +post-feature numbers against, and "did preflight help?" degrades into an argument +about anecdotes. + +| Field | Type | What it counts | +|-------|------|----------------| +| `preflight.filter_diag_emitted_24h` | non-negative integer | `retrieve_tools` responses that **delivered** a `filter_diagnostics` block in the last 24h — the denominator for the rest. Counted after response truncation, so a block that `tool_response_limit` cut back out of the payload is not counted (and cannot be "followed") | +| `preflight.filter_diag_missing_annotation_24h` | non-negative integer | Omissions in those blocks caused by **absent upstream annotations** ("fix the server" class), summed across filters | +| `preflight.filter_diag_explicit_24h` | non-negative integer | Omissions caused by an **explicitly unsafe hint** ("the filter is working" class), summed across filters | +| `preflight.filter_diag_followed_24h` | non-negative integer | Blocks the agent **acted on**: a later `retrieve_tools` call in the same MCP session dropped or relaxed a filter the block blamed | +| `preflight.availability_block_24h` | non-negative integer | Policy **blocks** (quarantine, scope, permissions, tool approval, output policy) in the last 24h. Derived as the sum of the reason split below — each reason is stored with its own 24h window, and a separate stored total would drift out of agreement with the split it summarises | +| `preflight.availability_block_reasons_24h` | map, **fixed enum keys only** → non-negative integer | The same total split by reason: `intent_invalid`, `intent_rejected`, `profile_scope`, `token_scope`, `token_permission`, `server_quarantined`, `tool_pending_approval`, `tool_changed_approval`, `tool_not_callable`, `output_sanitisation`, `output_schema`, `other` | +| `preflight.discovery_omission_24h` | non-negative integer | `retrieve_tools` responses that **withheld locked or quarantined matches** the caller could not see (`include_disabled` unset) — the silent-unavailability substrate | + +**How the reason keys stay safe.** The classification comes from the gate that +fired, not from parsing the message it wrote: every call site of the single +policy-decision funnel (`emitActivityPolicyDecision`) declares a key from the +closed enum above, while the operator-facing prose — which embeds server and tool +names — stays in the activity log and never reaches telemetry. A key outside the +enum is folded into `other` at write time, filtered again at read time and in the +wire form, and the anonymity scanner (rule `preflight_field_invalid`) blocks the +heartbeat outright if a non-enum key ever reaches the serialized payload. + +**The follow-through signal holds no identity.** Detecting "the agent relaxed the +filter" needs only the previous call's blamed filter *keys* plus the session it +belonged to. That note is in-memory, per session, expires after 15 minutes, +is capped, is consumed on first use (one block can be followed at most once), and +is never persisted or transmitted — only the resulting count is. + +Because that note is keyed by session, a transport that mints no session id +cannot be credited with a follow-through, while its emissions still count. Read +`filter_diag_followed_24h / filter_diag_emitted_24h` as a **lower bound** on +engagement, not an exact rate. + +The whole `preflight` object is **omitted** when every counter is zero, so an +install that never trips one emits a payload shape-identical to one from before +the field existed. Counters are gated at **event time**: nothing is written while +telemetry is opted out, so an occurrence observed during opt-out can never become +transmissible if telemetry is re-enabled later. + +**Never transmitted**: the query text, tool or server names, filter values, the +session id, the number of tools in the response, or any part of the suggestion +string the agent saw. + ## One-time opt-out signal When telemetry transitions from **enabled to disabled** (via the CLI, the config diff --git a/internal/runtime/runtime.go b/internal/runtime/runtime.go index 666b0c28..0dd51130 100644 --- a/internal/runtime/runtime.go +++ b/internal/runtime/runtime.go @@ -2789,6 +2789,14 @@ func (r *Runtime) SetTelemetry(version, edition string) { diagStore := telemetry.NewDiagnosticsCounterStore() r.telemetryService.SetDiagnosticsCounterStore(diagStore, db) + // Issue #969 (Phase 0): wire the preflight baseline counter store + // on the same DB, pre-creating its bucket for the same + // first-write-race reason as the diagnostics bucket above. + if err := telemetry.EnsurePreflightCountersBucket(db); err != nil { + r.logger.Warn("Failed to ensure preflight_counters bucket", zap.Error(err)) + } + r.telemetryService.SetPreflightCounterStore(telemetry.NewPreflightCounterStore(), db) + // Wire error-code notifier into supervisor so every classified // DiagnosticError increments the 24h per-code counter. Spec 080 // (US3, FR-012): the same stream also refreshes last_error_code — @@ -2902,6 +2910,50 @@ func (r *Runtime) RecordRetrieveToolsCallForActivation() { } } +// --- Issue #969 (Phase 0): preflight baseline counters --- +// +// These forwarders keep internal/server unaware of BBolt, exactly like +// RecordRetrieveToolsCallForActivation above. Each is nil-safe and the +// telemetry service applies the event-time opt-out gate, so a counter is never +// persisted for an install that has telemetry off. + +// RecordFilterDiagnosticsEmitted counts one retrieve_tools response that +// attached a spec-094 filter_diagnostics block, plus that block's summed +// per-reason-class counts. +func (r *Runtime) RecordFilterDiagnosticsEmitted(missingAnnotation, explicit int) { + if r == nil || r.telemetryService == nil { + return + } + r.telemetryService.RecordFilterDiagnosticsEmitted(missingAnnotation, explicit) +} + +// RecordFilterDiagnosticsFollowed counts one diagnostics block the agent acted +// on within the same MCP session. +func (r *Runtime) RecordFilterDiagnosticsFollowed() { + if r == nil || r.telemetryService == nil { + return + } + r.telemetryService.RecordFilterDiagnosticsFollowed() +} + +// RecordAvailabilityBlock counts one policy block by its structured reason key +// (closed enum; see telemetry.BlockReason*). +func (r *Runtime) RecordAvailabilityBlock(reason string) { + if r == nil || r.telemetryService == nil { + return + } + r.telemetryService.RecordAvailabilityBlock(reason) +} + +// RecordDiscoveryOmission counts one retrieve_tools response that withheld +// locked/quarantined matches the caller could not see. +func (r *Runtime) RecordDiscoveryOmission() { + if r == nil || r.telemetryService == nil { + return + } + r.telemetryService.RecordDiscoveryOmission() +} + // SetSessionClientResolver wires the session -> MCP client lookup that stamps // client_name / client_version onto every activity record at write time. // No-op if the activity service is not wired. diff --git a/internal/server/mcp.go b/internal/server/mcp.go index 29beff01..411993a1 100644 --- a/internal/server/mcp.go +++ b/internal/server/mcp.go @@ -178,6 +178,14 @@ type MCPProxyServer struct { // when observability is disabled; all use sites must nil-guard. observability *observability.Manager + // Issue #969 (Phase 0): per-session note of the last retrieve_tools call + // that carried a spec-094 filter_diagnostics block, used to detect whether + // the agent then RELAXED a blamed filter. In-memory only, never persisted, + // and it holds no query text or tool identities — only the filter keys the + // block already named plus a timestamp. See preflight_telemetry.go. + filterDiagMu sync.Mutex + filterDiagNotes map[string]filterDiagNote + // configFilePath is the ACTIVE configuration FILE this server belongs to, // handed in at construction (Spec 097). It is the authority for anything // derived from the config directory — today the stored-scripts directory. @@ -674,10 +682,23 @@ func (p *MCPProxyServer) emitActivityToolCallCompleted(serverName, toolName, ses // event and the record persisted from it are recognisably one thing. Gates that // fire before a handler would otherwise mint an id have to mint it earlier // rather than pass "" — see mintActivityRequestID. -func (p *MCPProxyServer) emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, decision, reason string) { +// +// reasonKey is the STRUCTURED classification of this decision, declared by the +// call site from the closed telemetry.BlockReason* enum (issue #969). `reason` +// is operator-facing prose that embeds server and tool names and must never +// reach telemetry; reasonKey is what the availability counters aggregate on, so +// the classification comes from the gate that fired rather than from parsing +// the message it wrote. A key outside the enum is folded into "other" by the +// store. +func (p *MCPProxyServer) emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, decision, reason, reasonKey string) { if p.mainServer != nil && p.mainServer.runtime != nil { p.mainServer.runtime.EmitActivityPolicyDecision(serverName, toolName, sessionID, requestID, decision, reason) } + // Issue #969 (Phase 0): availability baseline. Only outright blocks count — + // a warning or a redaction still delivered the call. + if decision == "blocked" { + p.recordAvailabilityBlock(reasonKey) + } } // activityRequestIDSeq disambiguates ids minted within the same nanosecond. @@ -1452,6 +1473,20 @@ func (p *MCPProxyServer) handleRetrieveToolsWithMode(ctx context.Context, reques excludeDestructive := request.GetBool("exclude_destructive", false) excludeOpenWorld := request.GetBool("exclude_open_world", false) + // Issue #969 (Phase 0): filter-diagnostics FOLLOW-THROUGH. If the previous + // retrieve_tools call in this session was handed a spec-094 diagnostics + // block, this call counts as "followed" when it dropped or relaxed at least + // one of the filters that block blamed. The note is consumed either way, so + // one block can be followed at most once. Evaluated here — before this call + // can write a note of its own. The lookup itself is an in-memory map read + // under a dedicated mutex; only the rare positive result reaches the + // counter store, whose write shares the cost profile of the activation + // counters this handler already bumps unconditionally above. + if p.consumeFilterDiagFollowUp(sessionID, + activeFilterKeys(readOnlyOnly, excludeDestructive, excludeOpenWorld), startTime) { + p.recordFilterDiagnosticsFollowed() + } + // Build arguments map for activity logging (Spec 024) args := map[string]interface{}{ "query": query, @@ -1767,6 +1802,17 @@ func (p *MCPProxyServer) handleRetrieveToolsWithMode(ctx context.Context, reques droppedCount) } + // Issue #969 (Phase 0): silent-unavailability baseline. droppedCount is the + // authoritative tally of locked/quarantined matches this response withheld + // (index hits that failed the visibility gate, plus the quarantined + // second-pass entries) — out-of-scope servers are excluded upstream, so this + // counts only tools the caller could have had. Without include_disabled the + // caller never sees them, which is exactly the invisibility preflight exists + // to remove. One increment per response, never per tool. + if !includeDisabled && droppedCount > 0 { + p.recordDiscoveryOmission() + } + // Spec 035 F2: Session risk analysis — analyze all connected servers' tool annotations // to detect the "lethal trifecta" risk combination. // @@ -1861,6 +1907,24 @@ func (p *MCPProxyServer) handleRetrieveToolsWithMode(ctx context.Context, reques ) } + // Issue #969 (Phase 0): baseline engagement counters. Hooked HERE, after + // truncation, rather than at the attach site: tool_response_limit can cut + // the block back out of the payload (SimpleTruncate is a plain tail cut), + // and a block the agent never received is neither an emission to count nor + // something a later call can "follow". `emitted` is the denominator the + // followed/emitted ratio divides by, so overcounting it would silently + // understate engagement — the one number these counters exist to measure. + // Counts only; the note is in-memory and identity-free. + // + // The note is stamped with DELIVERY time (now), not the request's start + // time: overlapping calls in one session can finish out of order, so start + // time would order the notes wrongly, and a follow-up can only react to a + // block that had already reached the agent. + if filterDiag != nil && filterDiag.OmittedTotal >= 1 && filterDiagnosticsSurvived(text, wasTruncated) { + p.recordFilterDiagnosticsEmitted(filterDiag) + p.noteFilterDiagnostics(sessionID, filterDiag, time.Now()) + } + // Emit success event with args and response (Spec 024). The FULL response // goes to the activity log — truncation only shapes what the agent sees // (same order handleReadCache uses). @@ -1962,7 +2026,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. if logTool == "" { logTool = toolName } - p.emitActivityPolicyDecision(logServer, logTool, getSessionID(), requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(logServer, logTool, getSessionID(), requestID, "blocked", errMsg, telemetry.BlockReasonIntentInvalid) return mcp.NewToolResultError(errMsg), nil } @@ -1978,7 +2042,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. if logTool == "" { logTool = toolName } - p.emitActivityPolicyDecision(logServer, logTool, getSessionID(), requestID, "blocked", "Intent validation failed") + p.emitActivityPolicyDecision(logServer, logTool, getSessionID(), requestID, "blocked", "Intent validation failed", telemetry.BlockReasonIntentRejected) return errResult, nil } @@ -2016,7 +2080,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. // filtered, and so a base /mcp session that ran set_profile is bounded too. if _, profileScope := p.resolveActiveProfile(ctx); profileScope != nil && !profileScope.Allows(serverName) { errMsg := fmt.Sprintf("server '%s' is not in profile '%s'", serverName, profileScope.Name) - p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg, telemetry.BlockReasonProfileScope) return mcp.NewToolResultError(errMsg), nil } @@ -2025,7 +2089,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. // Check server scope if !authCtx.CanAccessServer(serverName) { errMsg := fmt.Sprintf("Server '%s' is not in scope for this agent token", serverName) - p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg, telemetry.BlockReasonTokenScope) return mcp.NewToolResultError(errMsg), nil } // Check permission scope — map tool variant to required permission @@ -2040,7 +2104,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. } if requiredPerm != "" && !authCtx.HasPermission(requiredPerm) { errMsg := fmt.Sprintf("Insufficient permissions: '%s' requires '%s' permission", toolVariant, requiredPerm) - p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", errMsg, telemetry.BlockReasonTokenPermission) return mcp.NewToolResultError(errMsg), nil } } @@ -2067,7 +2131,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. if errResult := p.validateIntentAgainstServer(intent, toolVariant, serverName, actualToolName, annotations); errResult != nil { // Record activity error for server annotation mismatch reason := fmt.Sprintf("Intent rejected: tool variant '%s' conflicts with server annotations for %s:%s", toolVariant, serverName, actualToolName) - p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", reason) + p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", reason, telemetry.BlockReasonIntentRejected) return errResult, nil } @@ -2114,7 +2178,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. zap.String("server_name", serverName)) // Emit policy decision event for quarantine block - p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", "Server is quarantined for security review") + p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", "Server is quarantined for security review", telemetry.BlockReasonServerQuarantined) // Server is in quarantine - return security warning with tool analysis return p.handleQuarantinedToolCall(ctx, serverName, actualToolName, activityArgs), nil @@ -2130,7 +2194,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. zap.String("tool_name", actualToolName)) p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", - "Tool is pending approval (new unapproved tool)") + "Tool is pending approval (new unapproved tool)", telemetry.BlockReasonToolPendingApproval) return toolPendingApprovalResult(serverName, actualToolName, approval), nil } @@ -2140,7 +2204,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. zap.String("tool_name", actualToolName)) p.emitActivityPolicyDecision(serverName, actualToolName, getSessionID(), requestID, "blocked", - "Tool description/schema changed since last approval") + "Tool description/schema changed since last approval", telemetry.BlockReasonToolChanged) return toolChangedApprovalResult(serverName, actualToolName, approval), nil } @@ -2150,7 +2214,7 @@ func (p *MCPProxyServer) handleCallToolVariant(ctx context.Context, request mcp. if !p.isToolCallable(serverName, actualToolName) { errMsg := p.blockedToolMessage(serverName, actualToolName) - p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", errMsg, telemetry.BlockReasonToolNotCallable) return mcp.NewToolResultError(errMsg), nil } @@ -2633,7 +2697,7 @@ func (p *MCPProxyServer) handleCallTool(ctx context.Context, request mcp.CallToo zap.String("server_name", serverName)) // Emit policy decision event for quarantine block - p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", "Server is quarantined for security review") + p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", "Server is quarantined for security review", telemetry.BlockReasonServerQuarantined) // Server is in quarantine - return security warning with tool analysis return p.handleQuarantinedToolCall(ctx, serverName, actualToolName, args), nil @@ -2644,7 +2708,7 @@ func (p *MCPProxyServer) handleCallTool(ctx context.Context, request mcp.CallToo if !p.isToolCallable(serverName, actualToolName) { errMsg := p.blockedToolMessage(serverName, actualToolName) - p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", errMsg) + p.emitActivityPolicyDecision(serverName, actualToolName, sessionID, requestID, "blocked", errMsg, telemetry.BlockReasonToolNotCallable) return mcp.NewToolResultError(errMsg), nil } @@ -6206,7 +6270,7 @@ func (p *MCPProxyServer) applyOutputValidation(ctx context.Context, serverName, if sess := mcpserver.ClientSessionFromContext(ctx); sess != nil { sessionID = sess.SessionID() } - p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, d.decision, d.reason) + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, d.decision, d.reason, telemetry.BlockReasonOutputSchema) if d.block { return mcp.NewToolResultError("output schema validation failed: " + d.reason) } diff --git a/internal/server/mcp_direct_callability.go b/internal/server/mcp_direct_callability.go index d2618709..a9c13458 100644 --- a/internal/server/mcp_direct_callability.go +++ b/internal/server/mcp_direct_callability.go @@ -9,6 +9,7 @@ import ( "github.com/smart-mcp-proxy/mcpproxy-go/internal/auth" "github.com/smart-mcp-proxy/mcpproxy-go/internal/config" "github.com/smart-mcp-proxy/mcpproxy-go/internal/storage" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/telemetry" ) type directCallabilityDecision struct { @@ -75,19 +76,51 @@ func (p *MCPProxyServer) filterDirectToolsForAgentCallability(ctx context.Contex // is not callable. It mirrors the call_tool_* policy boundary so direct mode // cannot bypass disabled-tool, server-quarantine, or tool-approval controls. func (p *MCPProxyServer) directToolCallabilityBlock(ctx context.Context, serverName, toolName string, args map[string]interface{}) *mcp.CallToolResult { + result, _ := p.directToolCallabilityBlockWithReason(ctx, serverName, toolName, args) + return result +} + +// directToolCallabilityBlockWithReason is directToolCallabilityBlock plus the +// structured reason key of the gate that fired (issue #969). Direct mode routes +// server-quarantine, pending approval, changed approval, and plain +// not-callable through a SINGLE emit site, so without carrying the key out of +// the evaluator every direct-mode block would be counted as +// tool_not_callable — the availability reason distribution these counters exist +// to measure would be wrong for the whole direct surface. Returns ("" ) when +// the tool is callable. +func (p *MCPProxyServer) directToolCallabilityBlockWithReason(ctx context.Context, serverName, toolName string, args map[string]interface{}) (*mcp.CallToolResult, string) { // Unit tests historically construct a minimal MCPProxyServer with no // storage. Preserve that narrow behavior; production servers always have // storage and therefore enforce the policy below. if p.storage == nil { - return nil + return nil, "" } decision := newDirectCallabilityEvaluator(p).evaluate(serverName, toolName) if decision.callable { - return nil + return nil, "" } - return p.directToolCallabilityResult(ctx, decision, args) + return p.directToolCallabilityResult(ctx, decision, args), directBlockReasonKey(decision) +} + +// directBlockReasonKey classifies a direct-mode callability block onto the +// closed telemetry.BlockReason* enum. The branches mirror +// directToolCallabilityResult exactly, so the counted reason always matches the +// payload the caller was handed. +func directBlockReasonKey(decision directCallabilityDecision) string { + switch { + case decision.serverConfig != nil && decision.serverConfig.Quarantined: + return telemetry.BlockReasonServerQuarantined + case decision.approvalStatus == storage.ToolApprovalStatusPending: + return telemetry.BlockReasonToolPendingApproval + case decision.approvalStatus == storage.ToolApprovalStatusChanged: + return telemetry.BlockReasonToolChanged + default: + // Disabled server, config-denied tool, per-tool disable, and the + // storage-error fallback all present as "not callable". + return telemetry.BlockReasonToolNotCallable + } } func (e *directCallabilityEvaluator) evaluate(serverName, toolName string) directCallabilityDecision { diff --git a/internal/server/mcp_routing.go b/internal/server/mcp_routing.go index 0e2710a2..e186eef2 100644 --- a/internal/server/mcp_routing.go +++ b/internal/server/mcp_routing.go @@ -16,6 +16,7 @@ import ( "github.com/smart-mcp-proxy/mcpproxy-go/internal/config" "github.com/smart-mcp-proxy/mcpproxy-go/internal/contracts" "github.com/smart-mcp-proxy/mcpproxy-go/internal/reqcontext" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/telemetry" ) const ( @@ -154,12 +155,38 @@ func (p *MCPProxyServer) makeDirectModeHandler(serverName, toolName string, anno return func(ctx context.Context, request mcp.CallToolRequest) (*mcp.CallToolResult, error) { startTime := time.Now() + // Get session ID for activity logging + var sessionID string + if sess := mcpserver.ClientSessionFromContext(ctx); sess != nil { + sessionID = sess.SessionID() + } + + // Get request ID from context. Direct-mode calls that did not arrive + // over an HTTP transport carry none, and every activity this handler + // emits — including the agent-token and callability blocks below, which + // fire before anything else — needs an id a consumer can correlate on. + // Mint one rather than emit anonymously; a transport-supplied id always + // wins so the records still line up with the access log. + // + // Both ids are resolved BEFORE the agent-token gates so those denials + // can emit a correlatable policy decision like every other block. + requestID := reqcontext.GetRequestID(ctx) + if requestID == "" { + requestID = mintActivityRequestID(serverName, toolName) + } + // Check auth context for server access and permissions authCtx := auth.AuthContextFromContext(ctx) if authCtx != nil { // Check server access if !authCtx.CanAccessServer(serverName) { - return mcp.NewToolResultError(fmt.Sprintf("Access denied: token does not have access to server '%s'", serverName)), nil + errMsg := fmt.Sprintf("Access denied: token does not have access to server '%s'", serverName) + // Direct mode denied these silently: no activity record and, + // since issue #969, no availability counter either. Emit the + // same policy decision the call_tool_* variants emit at the + // equivalent gate so the funnel has no blind spot. + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", errMsg, telemetry.BlockReasonTokenScope) + return mcp.NewToolResultError(errMsg), nil } // Determine required permission from annotations @@ -170,27 +197,12 @@ func (p *MCPProxyServer) makeDirectModeHandler(serverName, toolName string, anno } if !authCtx.HasPermission(requiredPerm) { - return mcp.NewToolResultError(fmt.Sprintf("Permission denied: token does not have '%s' permission required for tool '%s:%s'", requiredPerm, serverName, toolName)), nil + errMsg := fmt.Sprintf("Permission denied: token does not have '%s' permission required for tool '%s:%s'", requiredPerm, serverName, toolName) + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", errMsg, telemetry.BlockReasonTokenPermission) + return mcp.NewToolResultError(errMsg), nil } } - // Get session ID for activity logging - var sessionID string - if sess := mcpserver.ClientSessionFromContext(ctx); sess != nil { - sessionID = sess.SessionID() - } - - // Get request ID from context. Direct-mode calls that did not arrive - // over an HTTP transport carry none, and every activity this handler - // emits — including the callability block below, which fires before - // anything else — needs an id a consumer can correlate on. Mint one - // rather than emit anonymously; a transport-supplied id always wins so - // the records still line up with the access log. - requestID := reqcontext.GetRequestID(ctx) - if requestID == "" { - requestID = mintActivityRequestID(serverName, toolName) - } - // Get arguments from the request args := request.GetArguments() enrichedArgs := injectAuthMetadata(ctx, args) @@ -198,8 +210,11 @@ func (p *MCPProxyServer) makeDirectModeHandler(serverName, toolName string, anno // Enforce direct-mode callability before emitting a tool-started event or // invoking upstream. Direct mode must not bypass disabled, quarantine, or // approval controls enforced by call_tool_* variants. - if blocked := p.directToolCallabilityBlock(ctx, serverName, toolName, enrichedArgs); blocked != nil { - p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", "direct tool is not callable") + // The reason key comes from the gate that actually fired (quarantine, + // pending/changed approval, or plain not-callable) rather than from + // this one funnel site — see directBlockReasonKey. + if blocked, reasonKey := p.directToolCallabilityBlockWithReason(ctx, serverName, toolName, enrichedArgs); blocked != nil { + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", "direct tool is not callable", reasonKey) return blocked, nil } diff --git a/internal/server/output_sanitisation.go b/internal/server/output_sanitisation.go index 92debf2b..fc0201cf 100644 --- a/internal/server/output_sanitisation.go +++ b/internal/server/output_sanitisation.go @@ -13,6 +13,7 @@ import ( "github.com/smart-mcp-proxy/mcpproxy-go/internal/config" "github.com/smart-mcp-proxy/mcpproxy-go/internal/contracts" "github.com/smart-mcp-proxy/mcpproxy-go/internal/security" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/telemetry" ) // osDecision is the pure outcome of the output-sanitisation decision core @@ -109,7 +110,7 @@ func (p *MCPProxyServer) applyOutputSanitisation(ctx context.Context, serverName } if d.block { - p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", d.reason) + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, "blocked", d.reason, telemetry.BlockReasonOutputSanitisation) return mcp.NewToolResultError("tool output blocked by sanitisation policy: " + d.reason) } @@ -151,7 +152,9 @@ func (p *MCPProxyServer) applyOutputSanitisation(ctx context.Context, serverName if redactedCount > 0 || len(strippedClasses) > 0 { action, reason := summariseSanitisation(redactedCount, redactedCats, strippedClasses) - p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, action, reason) + // Redact/strip are not blocks — the availability counter ignores them — + // but the key is still declared so the funnel has no unclassified sites. + p.emitActivityPolicyDecision(serverName, toolName, sessionID, requestID, action, reason, telemetry.BlockReasonOutputSanitisation) } return nil diff --git a/internal/server/preflight_telemetry.go b/internal/server/preflight_telemetry.go new file mode 100644 index 00000000..d4d18535 --- /dev/null +++ b/internal/server/preflight_telemetry.go @@ -0,0 +1,287 @@ +package server + +import ( + "sort" + "strings" + "time" +) + +// Issue #969 (Phase 0) — preflight BASELINE counters. +// +// These ship one release AHEAD of the required-tools-preflight feature so a +// real live before/after window exists: without it, "did preflight reduce +// silent unavailability?" can only be argued from anecdotes. Everything here is +// counts-only — no tool name, server name, query, session id, or free text ever +// reaches telemetry (see internal/telemetry/preflight_counters.go for the +// enforced contract). + +// recordFilterDiagnosticsEmitted counts one retrieve_tools response that +// attached a spec-094 filter_diagnostics block, summing the block's per-reason +// classes across every filter it blamed. The counts are already computed by +// filterByAnnotationsWithDiagnostics — this only adds them up. nil-safe. +func (p *MCPProxyServer) recordFilterDiagnosticsEmitted(diag *filterDiagnostics) { + if diag == nil || p.mainServer == nil || p.mainServer.runtime == nil { + return + } + missing, explicit := 0, 0 + for _, counts := range diag.OmittedByFilter { + missing += counts.MissingAnnotation + explicit += counts.Explicit + } + p.mainServer.runtime.RecordFilterDiagnosticsEmitted(missing, explicit) +} + +// recordDiscoveryOmission counts one retrieve_tools response that withheld +// locked/quarantined matches the caller could not see. nil-safe. +func (p *MCPProxyServer) recordDiscoveryOmission() { + if p.mainServer == nil || p.mainServer.runtime == nil { + return + } + p.mainServer.runtime.RecordDiscoveryOmission() +} + +// recordFilterDiagnosticsFollowed counts one diagnostics block the agent acted +// on. nil-safe. +func (p *MCPProxyServer) recordFilterDiagnosticsFollowed() { + if p.mainServer == nil || p.mainServer.runtime == nil { + return + } + p.mainServer.runtime.RecordFilterDiagnosticsFollowed() +} + +// recordAvailabilityBlock counts one policy block under its structured reason +// key. nil-safe. +func (p *MCPProxyServer) recordAvailabilityBlock(reason string) { + if p.mainServer == nil || p.mainServer.runtime == nil { + return + } + p.mainServer.runtime.RecordAvailabilityBlock(reason) +} + +// filterDiagnosticsResponseKey is the response key the spec-094 block is +// attached under. Used to confirm the block survived response truncation. +const filterDiagnosticsResponseKey = `"filter_diagnostics"` + +// filterDiagnosticsSurvived reports whether the diagnostics block is present +// AND COMPLETE in the payload the agent will actually receive. +// +// Both truncation paths cut the serialized response at a byte offset and append +// a plain-text notice, so the delivered text is never parseable JSON as a whole +// — testing the block on its own is the only workable check. Mere key presence +// is not enough either: a cut landing inside the block leaves the key with an +// unterminated value, which no agent can act on, so it must not count as an +// emission. An untruncated response always carries what was attached, so none +// of this runs on the common path. +func filterDiagnosticsSurvived(deliveredText string, wasTruncated bool) bool { + if !wasTruncated { + return true + } + idx := strings.Index(deliveredText, filterDiagnosticsResponseKey) + if idx < 0 { + return false + } + rest := deliveredText[idx+len(filterDiagnosticsResponseKey):] + colon := strings.IndexByte(rest, ':') + if colon < 0 { + return false + } + return hasCompleteJSONObject(rest[colon+1:]) +} + +// hasCompleteJSONObject reports whether s opens with a JSON object (after +// optional whitespace) that is also CLOSED within s. String contents are +// skipped, so a brace inside a tool description cannot unbalance the scan. +func hasCompleteJSONObject(s string) bool { + i := 0 + for i < len(s) && (s[i] == ' ' || s[i] == '\t' || s[i] == '\n' || s[i] == '\r') { + i++ + } + if i >= len(s) || s[i] != '{' { + return false + } + + depth := 0 + inString := false + escaped := false + for ; i < len(s); i++ { + c := s[i] + switch { + case escaped: + escaped = false + case inString && c == '\\': + escaped = true + case c == '"': + inString = !inString + case inString: + // Braces inside a JSON string are literal text. + case c == '{': + depth++ + case c == '}': + depth-- + if depth == 0 { + return true + } + } + } + return false +} + +// --- filter-diagnostics follow-through, per session --- + +// filterDiagNote remembers the filters a diagnostics block blamed on the last +// retrieve_tools call of one MCP session. It deliberately carries nothing else: +// no query, no tool ids, no counts — just the closed set of filter parameter +// names the response already told the agent about, plus when it was written so +// stale notes expire. +type filterDiagNote struct { + // filters are the filter keys the block blamed (filterKeyReadOnlyOnly &c), + // sorted so comparisons are order-independent. + filters []string + // at is when the block was DELIVERED to the agent, not when the request + // that produced it started. Overlapping calls in one session can finish out + // of order, so start time is not a valid ordering key: the note that must + // win is the one for the response the agent saw last. Delivery time is also + // the honest origin for the TTL, and it makes the follow-up comparison a + // plain causality test — a reaction can only come from a call that started + // after the block reached the agent. + at time.Time +} + +const ( + // filterDiagNoteTTL bounds how long a note stays eligible. A follow-up an + // hour later is a new task, not a reaction to the diagnostics block. + filterDiagNoteTTL = 15 * time.Minute + + // maxFilterDiagNotes bounds the in-memory note map. Sessions are pruned + // oldest-first past this; a proxy serving thousands of sessions must not + // grow an unbounded map for a telemetry counter. + maxFilterDiagNotes = 256 +) + +// activeFilterKeys renders the filter parameters active on THIS call as the +// same key strings the diagnostics block uses. +func activeFilterKeys(readOnlyOnly, excludeDestructive, excludeOpenWorld bool) []string { + keys := make([]string, 0, 3) + if readOnlyOnly { + keys = append(keys, filterKeyReadOnlyOnly) + } + if excludeDestructive { + keys = append(keys, filterKeyExcludeDestruct) + } + if excludeOpenWorld { + keys = append(keys, filterKeyExcludeOpenWorld) + } + return keys +} + +// noteFilterDiagnostics remembers that this session was just handed a +// diagnostics block blaming `diag`'s filters. `at` is the DELIVERY time of the +// response carrying the block. Sessions without an id (stdio transports that do +// not mint one) are skipped rather than pooled under "", which would let one +// client's call count as another's follow-up. +func (p *MCPProxyServer) noteFilterDiagnostics(sessionID string, diag *filterDiagnostics, at time.Time) { + if sessionID == "" || diag == nil || len(diag.OmittedByFilter) == 0 { + return + } + filters := make([]string, 0, len(diag.OmittedByFilter)) + for key := range diag.OmittedByFilter { + filters = append(filters, key) + } + sort.Strings(filters) + + p.filterDiagMu.Lock() + defer p.filterDiagMu.Unlock() + if p.filterDiagNotes == nil { + p.filterDiagNotes = make(map[string]filterDiagNote) + } + + // Two retrieve_tools calls of one session can be in flight at once. Because + // `at` is delivery time, the later write is by construction the block the + // agent saw last — but goroutine scheduling can still land the two writes + // here in either order, so the comparison is explicit. Letting an older + // delivery win would compare the next call against the wrong filter set and + // back-date the TTL, expiring the note early. + if prev, exists := p.filterDiagNotes[sessionID]; exists { + if !at.After(prev.at) { + return + } + // Replacing an existing key cannot grow the map, so skip the prune — + // at capacity it would evict an unrelated session's still-eligible + // note to make room that is not needed. + p.filterDiagNotes[sessionID] = filterDiagNote{filters: filters, at: at} + return + } + + p.pruneFilterDiagNotesLocked(at) + p.filterDiagNotes[sessionID] = filterDiagNote{filters: filters, at: at} +} + +// consumeFilterDiagFollowUp reports whether THIS call is a follow-up that +// relaxed or dropped at least one filter the previous call's diagnostics block +// blamed. The note is consumed either way: a block gets exactly one chance to +// be followed, so a session that keeps re-running the same filtered query can +// never inflate the counter. +func (p *MCPProxyServer) consumeFilterDiagFollowUp(sessionID string, activeKeys []string, at time.Time) bool { + if sessionID == "" { + return false + } + + p.filterDiagMu.Lock() + defer p.filterDiagMu.Unlock() + note, ok := p.filterDiagNotes[sessionID] + if !ok { + return false + } + + // Causality gate: `at` is when THIS call started and note.at is when the + // block was DELIVERED, so a call that started first cannot be reacting to + // it. Leave the note for the call that genuinely follows — consuming it + // here would both miscount this call and rob the real follow-up of its one + // chance. (A negative age also slips past the TTL check below, which + // compares it against a positive duration.) + if !at.After(note.at) { + return false + } + + delete(p.filterDiagNotes, sessionID) + if at.Sub(note.at) > filterDiagNoteTTL { + return false + } + + active := make(map[string]struct{}, len(activeKeys)) + for _, k := range activeKeys { + active[k] = struct{}{} + } + for _, blamed := range note.filters { + if _, still := active[blamed]; !still { + return true // a blamed filter was dropped → the agent acted on it + } + } + return false +} + +// pruneFilterDiagNotesLocked drops expired notes and, if the map is still at +// capacity, the oldest entries. Caller holds filterDiagMu. +func (p *MCPProxyServer) pruneFilterDiagNotesLocked(now time.Time) { + for sid, note := range p.filterDiagNotes { + if now.Sub(note.at) > filterDiagNoteTTL { + delete(p.filterDiagNotes, sid) + } + } + if len(p.filterDiagNotes) < maxFilterDiagNotes { + return + } + type entry struct { + sid string + at time.Time + } + entries := make([]entry, 0, len(p.filterDiagNotes)) + for sid, note := range p.filterDiagNotes { + entries = append(entries, entry{sid, note.at}) + } + sort.Slice(entries, func(i, j int) bool { return entries[i].at.Before(entries[j].at) }) + // Evict down to capacity-1 so the caller's insert stays within the bound. + for i := 0; i <= len(entries)-maxFilterDiagNotes; i++ { + delete(p.filterDiagNotes, entries[i].sid) + } +} diff --git a/internal/server/preflight_telemetry_test.go b/internal/server/preflight_telemetry_test.go new file mode 100644 index 00000000..dafe4e4c --- /dev/null +++ b/internal/server/preflight_telemetry_test.go @@ -0,0 +1,584 @@ +package server + +import ( + "context" + "fmt" + "testing" + "time" + + "github.com/mark3labs/mcp-go/mcp" + mcpserver "github.com/mark3labs/mcp-go/server" + "github.com/stretchr/testify/require" + + "github.com/smart-mcp-proxy/mcpproxy-go/internal/config" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/runtime" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/storage" + "github.com/smart-mcp-proxy/mcpproxy-go/internal/telemetry" +) + +// Issue #969 (Phase 0) — preflight baseline counters, server side. + +// pinTelemetryEnvEnabledForServer neutralises the env opt-outs so these tests +// exercise the ENABLED path even on a CI machine (CI=true is a telemetry +// opt-out, which would silently turn every increment into a no-op). +func pinTelemetryEnvEnabledForServer(t *testing.T) { + t.Helper() + t.Setenv("CI", "") + t.Setenv("DO_NOT_TRACK", "") + t.Setenv("MCPPROXY_TELEMETRY", "") +} + +// --- follow-through bookkeeping (pure, no runtime needed) --- + +func TestActiveFilterKeys(t *testing.T) { + require.Empty(t, activeFilterKeys(false, false, false)) + require.Equal(t, []string{filterKeyReadOnlyOnly}, activeFilterKeys(true, false, false)) + require.Equal(t, + []string{filterKeyReadOnlyOnly, filterKeyExcludeDestruct, filterKeyExcludeOpenWorld}, + activeFilterKeys(true, true, true)) +} + +func diagBlaming(filters ...string) *filterDiagnostics { + d := &filterDiagnostics{OmittedByFilter: map[string]reasonCounts{}} + for _, f := range filters { + d.OmittedByFilter[f] = reasonCounts{MissingAnnotation: 1} + d.OmittedTotal++ + } + return d +} + +// A follow-up that DROPS the blamed filter counts as followed. +func TestFilterDiagFollowUp_DroppedFilterCounts(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), now) + require.True(t, p.consumeFilterDiagFollowUp("sess-1", nil, now.Add(5*time.Second))) +} + +// A follow-up that RELAXES one of several blamed filters still counts. +func TestFilterDiagFollowUp_RelaxedSubsetCounts(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", + diagBlaming(filterKeyReadOnlyOnly, filterKeyExcludeOpenWorld), now) + // exclude_open_world dropped, read_only_only kept. + require.True(t, p.consumeFilterDiagFollowUp("sess-1", + activeFilterKeys(true, false, false), now.Add(time.Second))) +} + +// Re-running the SAME filters is not a follow-up. +func TestFilterDiagFollowUp_SameFiltersDoNotCount(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), now) + require.False(t, p.consumeFilterDiagFollowUp("sess-1", + activeFilterKeys(true, false, false), now.Add(time.Second))) +} + +// The note is consumed once: a second relaxed call cannot double-count the +// same diagnostics block. +func TestFilterDiagFollowUp_NoteConsumedOnce(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), now) + require.True(t, p.consumeFilterDiagFollowUp("sess-1", nil, now.Add(time.Second))) + require.False(t, p.consumeFilterDiagFollowUp("sess-1", nil, now.Add(2*time.Second))) +} + +// Follow-ups from a DIFFERENT session never match. +func TestFilterDiagFollowUp_SessionScoped(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), now) + require.False(t, p.consumeFilterDiagFollowUp("sess-2", nil, now.Add(time.Second))) + // sess-1's note is untouched by sess-2's call. + require.True(t, p.consumeFilterDiagFollowUp("sess-1", nil, now.Add(2*time.Second))) +} + +// Sessions without an id are never pooled together under "". +func TestFilterDiagFollowUp_AnonymousSessionsIgnored(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("", diagBlaming(filterKeyReadOnlyOnly), now) + require.Empty(t, p.filterDiagNotes) + require.False(t, p.consumeFilterDiagFollowUp("", nil, now)) +} + +// A stale note expires rather than crediting an unrelated later task. +func TestFilterDiagFollowUp_TTLExpiry(t *testing.T) { + p := &MCPProxyServer{} + now := time.Now() + + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), now) + require.False(t, p.consumeFilterDiagFollowUp("sess-1", nil, now.Add(filterDiagNoteTTL+time.Minute))) +} + +// The note map is bounded: a proxy serving many sessions must not grow it +// without limit for a telemetry counter. +func TestFilterDiagNotes_Bounded(t *testing.T) { + p := &MCPProxyServer{} + base := time.Now() + + for i := 0; i < maxFilterDiagNotes*3; i++ { + sid := "sess-" + time.Duration(i).String() + p.noteFilterDiagnostics(sid, diagBlaming(filterKeyReadOnlyOnly), base.Add(time.Duration(i)*time.Millisecond)) + } + require.LessOrEqual(t, len(p.filterDiagNotes), maxFilterDiagNotes) +} + +// Concurrent retrieve_tools calls in ONE session can complete out of order. +// The note the agent most recently received must win, so a LATE-finishing +// earlier call may not clobber it (opencode review, round 1, finding 3). +func TestFilterDiagNotes_StaleWriteDoesNotClobberNewer(t *testing.T) { + p := &MCPProxyServer{} + base := time.Now() + + // Call B (started later) lands first, then call A (started earlier) lands. + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyExcludeDestruct), base.Add(time.Second)) + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), base) + + p.filterDiagMu.Lock() + note := p.filterDiagNotes["sess-1"] + p.filterDiagMu.Unlock() + require.Equal(t, []string{filterKeyExcludeDestruct}, note.filters, + "the newer note must survive the late-landing older write") + require.True(t, note.at.Equal(base.Add(time.Second)), + "the newer timestamp must survive, else the TTL expires early") + + // The follow-up is therefore judged against the filters the agent actually + // saw last: dropping exclude_destructive counts. + require.True(t, p.consumeFilterDiagFollowUp("sess-1", + []string{filterKeyReadOnlyOnly}, base.Add(2*time.Second))) +} + +// Refreshing a session that ALREADY has a note cannot grow the map, so it must +// not evict an unrelated session's still-eligible note (finding 4). +func TestFilterDiagNotes_RefreshAtCapacityEvictsNothing(t *testing.T) { + p := &MCPProxyServer{} + base := time.Now() + + // Fill exactly to capacity; sess-0 is the oldest and therefore the entry a + // capacity eviction would take. + for i := 0; i < maxFilterDiagNotes; i++ { + p.noteFilterDiagnostics(fmt.Sprintf("sess-%d", i), + diagBlaming(filterKeyReadOnlyOnly), base.Add(time.Duration(i)*time.Millisecond)) + } + require.Len(t, p.filterDiagNotes, maxFilterDiagNotes) + + // The NEWEST session gets a second diagnostics block. This replaces its own + // key, so nothing needs to be evicted. + newest := fmt.Sprintf("sess-%d", maxFilterDiagNotes-1) + p.noteFilterDiagnostics(newest, diagBlaming(filterKeyExcludeDestruct), base.Add(time.Hour)) + + require.Len(t, p.filterDiagNotes, maxFilterDiagNotes) + p.filterDiagMu.Lock() + _, oldestSurvived := p.filterDiagNotes["sess-0"] + p.filterDiagMu.Unlock() + require.True(t, oldestSurvived, + "replacing an existing key must not cost an unrelated session its note") +} + +// The consume side has the same out-of-order hazard as the write side: a call +// that STARTED before the note was written cannot be a reaction to it, so it +// must neither count itself as a follow-up nor destroy the note the genuinely +// later call still needs (opencode review, round 2, finding 2). +func TestFilterDiagFollowUp_EarlierCallCannotConsumeNewerNote(t *testing.T) { + p := &MCPProxyServer{} + base := time.Now() + + // Call B is handed the block at base+1s. + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), base.Add(time.Second)) + + // Call A started at base — before that block existed — and drops the + // blamed filter for unrelated reasons. It must not count. + require.False(t, p.consumeFilterDiagFollowUp("sess-1", nil, base), + "a call that predates the block cannot be a reaction to it") + + // And the note must still be there for the call that genuinely follows. + require.True(t, p.consumeFilterDiagFollowUp("sess-1", nil, base.Add(2*time.Second)), + "the stale call must not have consumed the note") +} + +// Notes are ordered by DELIVERY time, so a call that started first but returned +// last correctly owns the note — start time would order these backwards +// (opencode review, round 3, finding 2). +func TestFilterDiagNotes_OrderedByDeliveryNotStart(t *testing.T) { + p := &MCPProxyServer{} + base := time.Now() + + // A started first but delivers last; B started later and delivered first. + // The handler stamps each note at delivery, so A's is the newer note. + bDelivered := base.Add(1 * time.Second) + aDelivered := base.Add(2 * time.Second) + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyExcludeDestruct), bDelivered) + p.noteFilterDiagnostics("sess-1", diagBlaming(filterKeyReadOnlyOnly), aDelivered) + + p.filterDiagMu.Lock() + note := p.filterDiagNotes["sess-1"] + p.filterDiagMu.Unlock() + require.Equal(t, []string{filterKeyReadOnlyOnly}, note.filters, + "the last-DELIVERED block is the one the agent saw last") + + // A call starting after that delivery, having dropped read_only_only, + // counts as the follow-up. + require.True(t, p.consumeFilterDiagFollowUp("sess-1", nil, aDelivered.Add(time.Millisecond))) +} + +// A block that tool_response_limit cut back out of the payload was never +// received, so it is neither an emission nor something a later call can follow +// (opencode review, round 2, finding 3). +func TestFilterDiagnosticsSurvived(t *testing.T) { + withBlock := `{"filter_diagnostics":{"omitted_total":3},"tools":[]}` + simpleTruncateNoticeFixture + cutAway := `{"tools":[{"name":"a"}]}` + simpleTruncateNoticeFixture + + // Untruncated responses always carry what was attached — no scan needed. + require.True(t, filterDiagnosticsSurvived(cutAway, false), + "an untruncated response carries the block the handler attached") + + require.True(t, filterDiagnosticsSurvived(withBlock, true), + "truncation that preserved the block still counts as emitted") + require.False(t, filterDiagnosticsSurvived(cutAway, true), + "a block truncated out of the payload was never delivered") +} + +// A cut landing INSIDE the block leaves the key present but its value +// unterminated. The agent cannot act on that, so it is not an emission +// (opencode review, round 3, finding 1). +func TestFilterDiagnosticsSurvived_PartialBlockDoesNotCount(t *testing.T) { + // The key survived the byte cut; its object did not. + cutMidValue := `{"disabled":[],"filter_diagnostics":{"omitted_total":3,"omitted_by_fil` + + simpleTruncateNoticeFixture + require.False(t, filterDiagnosticsSurvived(cutMidValue, true), + "an unterminated block was never usable by the agent") + + // Nested objects must be balanced all the way out, not just to the first + // closing brace. + cutInNested := `{"filter_diagnostics":{"omitted_by_filter":{"read_only_only":{"missing_annotation":2}` + + simpleTruncateNoticeFixture + require.False(t, filterDiagnosticsSurvived(cutInNested, true)) + + complete := `{"filter_diagnostics":{"omitted_by_filter":{"read_only_only":{"missing_annotation":2}}},"tools":[` + + simpleTruncateNoticeFixture + require.True(t, complete != "" && filterDiagnosticsSurvived(complete, true), + "the block is complete even though the payload as a whole was cut") +} + +// Braces and quotes inside a JSON string must not unbalance the scan, and an +// escape sequence must not desynchronise it — a scanner that mis-tracks string +// state would call a truncated block complete (or vice versa). +func TestHasCompleteJSONObject_IgnoresBracesInStrings(t *testing.T) { + for _, tc := range []struct { + name string + in string + want bool + }{ + {"brace and escaped quote inside string", `{"note":"a } brace and a \" quote"}`, true}, + {"unterminated string swallows the brace", `{"note":"unterminated } brace`, false}, + {"trailing junk after a closed object", ` {"a":1} trailing junk`, true}, + {"not an object", ` "not an object"`, false}, + {"empty input", ``, false}, + {"empty object", `{}`, true}, + {"balanced nested", `{"a":{"b":1}}`, true}, + {"unbalanced nested closes only the inner object", `{"a":{"b":1}`, false}, + // An escaped backslash is consumed as data: the quote that follows + // genuinely closes the string, so the trailing brace must be seen. + {"escaped backslash ends the string", `{"a":"x\\"}`, true}, + {"cut immediately after an escaped backslash", `{"a":"x\\`, false}, + {"escaped quote does not end the string", `{"a":"x\""}`, true}, + {"brace inside string", `{"a":"}"}`, true}, + {"escaped quote then brace inside string", `{"a":"\"}"}`, true}, + } { + t.Run(tc.name, func(t *testing.T) { + require.Equal(t, tc.want, hasCompleteJSONObject(tc.in)) + }) + } +} + +// simpleTruncateNoticeFixture mirrors the plain-text notice both truncation +// paths append. It is why the delivered payload is never parseable JSON as a +// whole, and therefore why the block is checked on its own. +const simpleTruncateNoticeFixture = "\n\n... [truncated by mcpproxy, cache not available]" + +// --- direct-mode block reason classification (finding 5) --- + +// Direct mode funnels every callability block through ONE emit site. The reason +// key must still come from what actually fired, or the whole availability +// reason distribution collapses into tool_not_callable. +func TestDirectBlockReasonKey_ClassifiesPerGate(t *testing.T) { + quarantined := directCallabilityDecision{ + serverConfig: &config.ServerConfig{Name: "github", Enabled: true, Quarantined: true}, + } + require.Equal(t, telemetry.BlockReasonServerQuarantined, directBlockReasonKey(quarantined)) + + pending := directCallabilityDecision{ + serverConfig: &config.ServerConfig{Name: "github", Enabled: true}, + approvalStatus: storage.ToolApprovalStatusPending, + } + require.Equal(t, telemetry.BlockReasonToolPendingApproval, directBlockReasonKey(pending)) + + changed := directCallabilityDecision{ + serverConfig: &config.ServerConfig{Name: "github", Enabled: true}, + approvalStatus: storage.ToolApprovalStatusChanged, + } + require.Equal(t, telemetry.BlockReasonToolChanged, directBlockReasonKey(changed)) + + disabled := directCallabilityDecision{ + serverConfig: &config.ServerConfig{Name: "github", Enabled: false}, + } + require.Equal(t, telemetry.BlockReasonToolNotCallable, directBlockReasonKey(disabled)) + + // Every key the classifier can produce is a member of the closed enum, so a + // direct-mode block can never land in the "other" overflow bucket. + for _, d := range []directCallabilityDecision{quarantined, pending, changed, disabled} { + require.True(t, telemetry.IsAvailabilityBlockReason(directBlockReasonKey(d))) + } +} + +// The reason travels with the block result, so the routing handler emits the +// key that matches the gate that fired. +func TestDirectToolCallabilityBlockWithReason_Quarantine(t *testing.T) { + proxy := createTestMCPProxyServer(t) + require.NoError(t, proxy.storage.SaveUpstreamServer(&config.ServerConfig{ + Name: "github", Enabled: true, Quarantined: true, + })) + + result, reasonKey := proxy.directToolCallabilityBlockWithReason( + context.Background(), "github", "list_repos", map[string]interface{}{}) + require.NotNil(t, result) + require.Equal(t, telemetry.BlockReasonServerQuarantined, reasonKey) +} + +// A callable tool yields no block and no reason key. +func TestDirectToolCallabilityBlockWithReason_CallableIsSilent(t *testing.T) { + proxy := createTestMCPProxyServer(t) + require.NoError(t, proxy.storage.SaveUpstreamServer(&config.ServerConfig{ + Name: "github", Enabled: true, + })) + + result, reasonKey := proxy.directToolCallabilityBlockWithReason( + context.Background(), "github", "list_repos", map[string]interface{}{}) + require.Nil(t, result) + require.Empty(t, reasonKey) +} + +// --- end-to-end through retrieve_tools --- + +// newPreflightCountedProxy builds the spec-094 fixture proxy with a telemetry +// service (and therefore the preflight counter store) wired onto the runtime's +// BBolt DB, so the counters the handler bumps can be read back. +func newPreflightCountedProxy(t *testing.T) (*MCPProxyServer, *runtime.Runtime) { + t.Helper() + pinTelemetryEnvEnabledForServer(t) + + proxy, rt := newFilterDiagnosticsProxy(t) + rt.SetTelemetry("v1.0.0", "personal") + ts := rt.TelemetryService() + require.NotNil(t, ts, "telemetry service must be wired") + require.NotNil(t, ts.PreflightCounterStore(), "preflight counter store must be wired") + return proxy, rt +} + +func preflightSnapshot(t *testing.T, rt *runtime.Runtime) telemetry.PreflightCounters { + t.Helper() + ts := rt.TelemetryService() + require.NotNil(t, ts) + snap, err := ts.PreflightCounterStore().Snapshot(ts.PreflightCounterDB()) + require.NoError(t, err) + return snap +} + +func retrieveWithSession(t *testing.T, proxy *MCPProxyServer, sessionID string, args map[string]interface{}) { + t.Helper() + helper := mcpserver.NewMCPServer("test", "1.0.0") + ctx := helper.WithContext(context.Background(), &fakeClientSession{id: sessionID}) + req := mcp.CallToolRequest{} + req.Params.Arguments = args + _, err := proxy.handleRetrieveTools(ctx, req) + require.NoError(t, err) +} + +// A response that carries a filter_diagnostics block bumps the emitted counter +// and both reason-class sums. +func TestPreflightCounters_FilterDiagnosticsEmitted(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + "read_only_only": true, + }) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 1, snap.FilterDiagEmitted24h) + require.Positive(t, snap.FilterDiagMissingAnnotation24h, + "the fixture omits unannotated tools, so the missing class must be non-zero") + require.Positive(t, snap.FilterDiagExplicit24h, + "the fixture omits an explicitly non-read-only tool") + require.Equal(t, 0, snap.FilterDiagFollowed24h) +} + +// The happy path (no filters) attaches no block and therefore counts nothing. +func TestPreflightCounters_NoDiagnosticsNoCount(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{"query": diagQueryAll}) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 0, snap.FilterDiagEmitted24h) + require.Equal(t, 0, snap.FilterDiagFollowed24h) +} + +// A second call in the SAME session that drops the blamed filter is counted as +// a follow-through; a same-session repeat of the same filters is not. +func TestPreflightCounters_FilterDiagnosticsFollowed(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + "read_only_only": true, + }) + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + }) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 1, snap.FilterDiagEmitted24h) + require.Equal(t, 1, snap.FilterDiagFollowed24h) +} + +func TestPreflightCounters_FilterDiagnosticsNotFollowedWhenFiltersRepeat(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + for i := 0; i < 3; i++ { + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + "read_only_only": true, + }) + } + + snap := preflightSnapshot(t, rt) + require.Equal(t, 3, snap.FilterDiagEmitted24h) + require.Equal(t, 0, snap.FilterDiagFollowed24h, + "re-running the same filters is not a follow-through") +} + +// A different session's later call must not be credited as a follow-through. +func TestPreflightCounters_FollowThroughIsSessionScoped(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + "read_only_only": true, + }) + retrieveWithSession(t, proxy, "sess-2", map[string]interface{}{ + "query": diagQueryAll, + }) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 0, snap.FilterDiagFollowed24h) +} + +// A retrieve_tools response that withheld locked matches bumps the +// silent-unavailability counter; one that withheld nothing does not. +func TestPreflightCounters_DiscoveryOmission(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + // Disable a server so its indexed tools become locked (not callable) and + // are dropped from the default (include_disabled=false) response. + require.NoError(t, proxy.storage.SaveUpstreamServer(&config.ServerConfig{ + Name: "plain", Enabled: false, + })) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{"query": diagQueryAll}) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 1, snap.DiscoveryOmission24h) +} + +func TestPreflightCounters_NoDiscoveryOmissionWhenNothingWithheld(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{"query": diagQueryAll}) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 0, snap.DiscoveryOmission24h) +} + +// --- availability blocks --- + +// A policy BLOCK increments the total and its structured reason bucket; a +// non-block decision (warn / redact) on the same funnel does not. +func TestPreflightCounters_AvailabilityBlockByReason(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + proxy.emitActivityPolicyDecision("srv", "tool", "sess-1", "req-1", + "blocked", "Server is quarantined for security review", + telemetry.BlockReasonServerQuarantined) + proxy.emitActivityPolicyDecision("srv", "tool", "sess-1", "req-2", + "blocked", "Server 'srv' is not in scope for this agent token", + telemetry.BlockReasonTokenScope) + proxy.emitActivityPolicyDecision("srv", "tool", "sess-1", "req-3", + "redacted", "1 secret redacted", telemetry.BlockReasonOutputSanitisation) + + snap := preflightSnapshot(t, rt) + require.Equal(t, 2, snap.AvailabilityBlock24h, "only blocks count") + require.Equal(t, 1, snap.AvailabilityBlockReasons24h[telemetry.BlockReasonServerQuarantined]) + require.Equal(t, 1, snap.AvailabilityBlockReasons24h[telemetry.BlockReasonTokenScope]) + require.Zero(t, snap.AvailabilityBlockReasons24h[telemetry.BlockReasonOutputSanitisation]) +} + +// The operator-facing prose (which embeds server and tool names) never becomes +// a counter key — an unclassified site lands in "other". +func TestPreflightCounters_UnclassifiedBlockFoldsIntoOther(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + + proxy.emitActivityPolicyDecision("acme-internal", "purge_all", "sess-1", "req-1", + "blocked", "Server 'acme-internal' is not in scope for this agent token", + "some-future-unregistered-key") + + snap := preflightSnapshot(t, rt) + require.Equal(t, 1, snap.AvailabilityBlock24h) + require.Equal(t, 1, snap.AvailabilityBlockReasons24h[telemetry.BlockReasonOther]) + for key := range snap.AvailabilityBlockReasons24h { + require.True(t, telemetry.IsAvailabilityBlockReason(key), + "non-enum key %q reached the counters", key) + } +} + +// Every counter path is a no-op when telemetry is opted out at event time. +func TestPreflightCounters_OptOutRecordsNothing(t *testing.T) { + proxy, rt := newPreflightCountedProxy(t) + t.Setenv("DO_NOT_TRACK", "1") + + retrieveWithSession(t, proxy, "sess-1", map[string]interface{}{ + "query": diagQueryAll, + "read_only_only": true, + }) + proxy.emitActivityPolicyDecision("srv", "tool", "sess-1", "req-1", + "blocked", "quarantined", telemetry.BlockReasonServerQuarantined) + + snap := preflightSnapshot(t, rt) + require.Equal(t, telemetry.PreflightCounters{}, snap, + "nothing may be persisted while telemetry is opted out") +} + +// The hooks must be safe on a proxy with no runtime at all (the CLI's +// in-process server), and on a runtime whose telemetry service was never set. +func TestPreflightCounters_NilSafe(t *testing.T) { + bare := &MCPProxyServer{} + bare.recordFilterDiagnosticsEmitted(diagBlaming(filterKeyReadOnlyOnly)) + bare.recordFilterDiagnosticsFollowed() + bare.recordDiscoveryOmission() + bare.recordAvailabilityBlock(telemetry.BlockReasonOther) + + proxy, _ := newFilterDiagnosticsProxy(t) // runtime, but no telemetry service + proxy.recordFilterDiagnosticsEmitted(diagBlaming(filterKeyReadOnlyOnly)) + proxy.recordFilterDiagnosticsFollowed() + proxy.recordDiscoveryOmission() + proxy.recordAvailabilityBlock(telemetry.BlockReasonOther) +} diff --git a/internal/telemetry/anonymity.go b/internal/telemetry/anonymity.go index 0edc95dc..e52629e4 100644 --- a/internal/telemetry/anonymity.go +++ b/internal/telemetry/anonymity.go @@ -97,6 +97,11 @@ type anonymityScanEnvelope struct { // error_code_counts_24h map must be cataloged codes → non-negative counts. // Same not-a-pointer reasoning as TPAScanner. Diagnostics json.RawMessage `json:"diagnostics"` + + // Issue #969 structural check: the preflight baseline counter sub-object, + // whose availability_block_reasons_24h map must be closed-enum reason keys + // → non-negative counts. Same not-a-pointer reasoning as TPAScanner. + Preflight json.RawMessage `json:"preflight"` } // v7FieldViolation builds the violation for a Spec 080 field that broke its @@ -347,6 +352,114 @@ func scanDiagnosticsCounters(raw json.RawMessage) *AnonymityViolation { return nil } +// preflightFieldViolation builds the violation for a preflight counter field +// that broke its documented shape (closed-enum reason keys, non-negative +// counts). +func preflightFieldViolation(field, reason string) *AnonymityViolation { + return &AnonymityViolation{ + Rule: "preflight_field_invalid", + Pattern: field, + Reason: fmt.Sprintf("preflight field %s %s", field, reason), + } +} + +// scanPreflightCounters asserts the preflight sub-object (if present) is a +// CLOSED object of non-negative integer counts whose +// availability_block_reasons_24h map is keyed EXCLUSIVELY by the closed +// availability-block reason enum (issue #969). +// The producer folds unknown reasons into "other" and MarshalJSON filters again; +// this is the wire-form backstop, so a regression that let a reason STRING +// (which embeds server and tool names) become a key is caught before transmit. +// Keys are where identifying strings would leak, so the violation deliberately +// never echoes the offending key. +func scanPreflightCounters(raw json.RawMessage) *AnonymityViolation { + if len(raw) == 0 { + return nil + } + var obj map[string]json.RawMessage + // json.Unmarshal accepts `null` into a nil map; the field, when present, + // must be a real object. + if err := json.Unmarshal(raw, &obj); err != nil || obj == nil { + return preflightFieldViolation("preflight", "must be an object") + } + + // The sub-object is CLOSED: only the documented count keys plus the reason + // map may appear. Validating the known scalars alone would let a future + // field that carries free text (a server name, a query, an error message) + // ride along unchecked — exactly the leak this rule exists to stop. A new + // counter must be added to preflightAllowedKeys deliberately, which is the + // point at which its shape gets reviewed. + for key := range obj { + if !isPreflightAllowedKey(key) { + return preflightFieldViolation("preflight", + "carries a key outside the fixed preflight counter set") + } + } + + // Every scalar the sub-object carries is a non-negative count. + for _, key := range preflightScalarKeys { + v, ok := obj[key] + if !ok { + continue + } + msg := json.RawMessage(v) + if viol := scanNonNegativeInt(&msg, "preflight."+key, preflightFieldViolation); viol != nil { + return viol + } + } + + rawCounts, ok := obj[preflightReasonsKey] + if !ok { + return nil + } + var counts map[string]json.RawMessage + if err := json.Unmarshal(rawCounts, &counts); err != nil || counts == nil { + return preflightFieldViolation("preflight.availability_block_reasons_24h", "must be an object") + } + for reason, v := range counts { + if !IsAvailabilityBlockReason(reason) { + return preflightFieldViolation("preflight.availability_block_reasons_24h", + "carries a key outside the fixed availability-block reason enum") + } + msg := json.RawMessage(v) + if viol := scanNonNegativeInt(&msg, "preflight.availability_block_reasons_24h", preflightFieldViolation); viol != nil { + return viol + } + } + return nil +} + +// preflightScalarKeys is the fixed set of non-negative-integer keys allowed in +// the preflight sub-object. +var preflightScalarKeys = []string{ + "filter_diag_emitted_24h", + "filter_diag_missing_annotation_24h", + "filter_diag_explicit_24h", + "filter_diag_followed_24h", + "availability_block_24h", + "discovery_omission_24h", +} + +// preflightReasonsKey is the one non-scalar key the preflight sub-object may +// carry (a closed-enum map, validated separately). +const preflightReasonsKey = "availability_block_reasons_24h" + +// preflightAllowedKeys is the CLOSED key set of the preflight sub-object: +// preflightScalarKeys plus the reason map. Anything else is a violation. +var preflightAllowedKeys = func() map[string]struct{} { + m := make(map[string]struct{}, len(preflightScalarKeys)+1) + for _, k := range preflightScalarKeys { + m[k] = struct{}{} + } + m[preflightReasonsKey] = struct{}{} + return m +}() + +func isPreflightAllowedKey(key string) bool { + _, ok := preflightAllowedKeys[key] + return ok +} + // ScanForPII scans a serialized telemetry payload (v3+) for PII leaks and // structural violations. Returns nil when the payload is clean; otherwise // returns an *AnonymityViolation. The returned error satisfies @@ -366,6 +479,10 @@ func scanDiagnosticsCounters(raw json.RawMessage) *AnonymityViolation { // exclusively by the fixed severity enum. // 6. diagnostics.error_code_counts_24h, if present, is not a map of // catalog-registered MCPX_* codes to non-negative integer counts. +// 7. preflight (issue #969), if present, is not a CLOSED object of +// non-negative integer counts (keys drawn from preflightAllowedKeys) whose +// availability_block_reasons_24h map is keyed exclusively by the closed +// availability-block reason enum. // // The implementation never logs the payload — it only reports which rule // tripped and the offending pattern (a small literal). Callers should log at @@ -436,6 +553,12 @@ func ScanForPII(payloadJSON []byte) error { return v } + // Rule 7: preflight counters must be closed-enum reason keys → non-negative + // ints, and every scalar a non-negative count. + if v := scanPreflightCounters(env.Preflight); v != nil { + return v + } + return nil } diff --git a/internal/telemetry/payload_preflight_test.go b/internal/telemetry/payload_preflight_test.go new file mode 100644 index 00000000..7d87be31 --- /dev/null +++ b/internal/telemetry/payload_preflight_test.go @@ -0,0 +1,233 @@ +package telemetry + +import ( + "encoding/json" + "path/filepath" + "testing" + "time" + + "go.etcd.io/bbolt" + "go.uber.org/zap" + + "github.com/smart-mcp-proxy/mcpproxy-go/internal/config" +) + +// newPreflightService stands up a telemetry Service with the preflight counter +// store wired onto a throwaway BBolt DB (issue #969). +func newPreflightService(t *testing.T, cfg *config.Config) (*Service, *bbolt.DB) { + t.Helper() + dir := t.TempDir() + db, err := bbolt.Open(filepath.Join(dir, "preflight_payload.db"), 0600, &bbolt.Options{Timeout: 2 * time.Second}) + if err != nil { + t.Fatalf("bbolt.Open: %v", err) + } + t.Cleanup(func() { _ = db.Close() }) + + svc := New(cfg, "", "v1.0.0", "personal", zap.NewNop()) + svc.SetRuntimeStats(&mockRuntimeStats{}) + svc.SetPreflightCounterStore(NewPreflightCounterStore(), db) + return svc, db +} + +// pinTelemetryEnvEnabled neutralises the three env opt-outs so a test that is +// asserting the ENABLED path is not silently turned into a no-op by CI=true on +// a build machine. +func pinTelemetryEnvEnabled(t *testing.T) { + t.Helper() + t.Setenv("CI", "") + t.Setenv("DO_NOT_TRACK", "") + t.Setenv("MCPPROXY_TELEMETRY", "") +} + +func enabledTelemetryConfig() *config.Config { + enabled := true + return &config.Config{ + Telemetry: &config.TelemetryConfig{AnonymousID: "test-id", Enabled: &enabled}, + } +} + +// PF001: the preflight sub-object is omitted entirely when the store is not +// wired — a short-lived CLI process produces a payload shaped exactly like one +// from before this field existed. +func TestBuildPayload_PreflightOmittedWhenStoreNil(t *testing.T) { + pinTelemetryEnvEnabled(t) + svc := New(enabledTelemetryConfig(), "", "v1.0.0", "personal", zap.NewNop()) + svc.SetRuntimeStats(&mockRuntimeStats{}) + + payload := svc.BuildPayload() + if payload.Preflight != nil { + t.Errorf("expected Preflight nil when store is not wired, got %+v", payload.Preflight) + } + + raw, _ := json.Marshal(payload) + var m map[string]json.RawMessage + _ = json.Unmarshal(raw, &m) + if _, ok := m["preflight"]; ok { + t.Error("preflight key present in JSON despite nil pointer (omitempty broken)") + } +} + +// PF002: wired but never incremented → still omitted. +func TestBuildPayload_PreflightOmittedWhenAllZero(t *testing.T) { + pinTelemetryEnvEnabled(t) + svc, _ := newPreflightService(t, enabledTelemetryConfig()) + + if payload := svc.BuildPayload(); payload.Preflight != nil { + t.Errorf("expected Preflight nil when all counters zero, got %+v", payload.Preflight) + } +} + +// PF003: every counter family reaches the payload, through the Service-level +// Record* entry points the server actually calls. +func TestBuildPayload_PreflightPopulated(t *testing.T) { + pinTelemetryEnvEnabled(t) + svc, _ := newPreflightService(t, enabledTelemetryConfig()) + + svc.RecordFilterDiagnosticsEmitted(3, 2) + svc.RecordFilterDiagnosticsEmitted(1, 1) + svc.RecordFilterDiagnosticsFollowed() + svc.RecordAvailabilityBlock(BlockReasonServerQuarantined) + svc.RecordAvailabilityBlock(BlockReasonServerQuarantined) + svc.RecordAvailabilityBlock(BlockReasonToolNotCallable) + svc.RecordDiscoveryOmission() + svc.RecordDiscoveryOmission() + svc.RecordDiscoveryOmission() + + payload := svc.BuildPayload() + if payload.Preflight == nil { + t.Fatal("expected Preflight non-nil after recording counters") + } + pf := payload.Preflight + if pf.FilterDiagEmitted24h != 2 { + t.Errorf("filter_diag_emitted_24h = %d, want 2", pf.FilterDiagEmitted24h) + } + if pf.FilterDiagMissingAnnotation24h != 4 { + t.Errorf("filter_diag_missing_annotation_24h = %d, want 4", pf.FilterDiagMissingAnnotation24h) + } + if pf.FilterDiagExplicit24h != 3 { + t.Errorf("filter_diag_explicit_24h = %d, want 3", pf.FilterDiagExplicit24h) + } + if pf.FilterDiagFollowed24h != 1 { + t.Errorf("filter_diag_followed_24h = %d, want 1", pf.FilterDiagFollowed24h) + } + if pf.AvailabilityBlock24h != 3 { + t.Errorf("availability_block_24h = %d, want 3", pf.AvailabilityBlock24h) + } + if pf.AvailabilityBlockReasons24h[BlockReasonServerQuarantined] != 2 { + t.Errorf("server_quarantined = %d, want 2", pf.AvailabilityBlockReasons24h[BlockReasonServerQuarantined]) + } + if pf.DiscoveryOmission24h != 3 { + t.Errorf("discovery_omission_24h = %d, want 3", pf.DiscoveryOmission24h) + } +} + +// PF004: JSON round-trip — the sub-object is nested under "preflight" with the +// documented key names, and the payload still passes the anonymity scanner. +func TestBuildPayload_PreflightJSONRoundTrip(t *testing.T) { + pinTelemetryEnvEnabled(t) + svc, _ := newPreflightService(t, enabledTelemetryConfig()) + + svc.RecordFilterDiagnosticsEmitted(2, 0) + svc.RecordAvailabilityBlock(BlockReasonTokenPermission) + svc.RecordDiscoveryOmission() + + raw, err := json.Marshal(svc.BuildPayload()) + if err != nil { + t.Fatalf("json.Marshal: %v", err) + } + var wire struct { + Preflight *struct { + FilterDiagEmitted24h int `json:"filter_diag_emitted_24h"` + FilterDiagMissingAnnotation24h int `json:"filter_diag_missing_annotation_24h"` + FilterDiagExplicit24h int `json:"filter_diag_explicit_24h"` + FilterDiagFollowed24h int `json:"filter_diag_followed_24h"` + AvailabilityBlock24h int `json:"availability_block_24h"` + AvailabilityBlockReasons24h map[string]int `json:"availability_block_reasons_24h"` + DiscoveryOmission24h int `json:"discovery_omission_24h"` + } `json:"preflight"` + } + if err := json.Unmarshal(raw, &wire); err != nil { + t.Fatalf("json.Unmarshal: %v", err) + } + if wire.Preflight == nil { + t.Fatal("preflight absent from JSON") + } + if wire.Preflight.FilterDiagEmitted24h != 1 { + t.Errorf("filter_diag_emitted_24h want 1, got %d", wire.Preflight.FilterDiagEmitted24h) + } + if wire.Preflight.FilterDiagMissingAnnotation24h != 2 { + t.Errorf("filter_diag_missing_annotation_24h want 2, got %d", wire.Preflight.FilterDiagMissingAnnotation24h) + } + if wire.Preflight.AvailabilityBlockReasons24h[BlockReasonTokenPermission] != 1 { + t.Errorf("token_permission want 1, got %d", wire.Preflight.AvailabilityBlockReasons24h[BlockReasonTokenPermission]) + } + if wire.Preflight.DiscoveryOmission24h != 1 { + t.Errorf("discovery_omission_24h want 1, got %d", wire.Preflight.DiscoveryOmission24h) + } + if err := ScanForPII(raw); err != nil { + t.Errorf("payload with preflight counters must pass the anonymity scanner: %v", err) + } +} + +// PF005: telemetry opt-out is honoured at EVENT time — an install with +// telemetry disabled persists nothing, so an occurrence observed while off can +// never become transmissible if telemetry is turned back on later. +func TestPreflightCounters_RespectConfigOptOut(t *testing.T) { + pinTelemetryEnvEnabled(t) + disabled := false + cfg := &config.Config{ + Telemetry: &config.TelemetryConfig{AnonymousID: "test-id", Enabled: &disabled}, + } + svc, db := newPreflightService(t, cfg) + + svc.RecordFilterDiagnosticsEmitted(5, 5) + svc.RecordFilterDiagnosticsFollowed() + svc.RecordAvailabilityBlock(BlockReasonServerQuarantined) + svc.RecordDiscoveryOmission() + + snap, err := NewPreflightCounterStore().Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + if !snap.isZero() { + t.Fatalf("opt-out must persist nothing, got %+v", snap) + } + if payload := svc.BuildPayload(); payload.Preflight != nil { + t.Errorf("expected Preflight nil under opt-out, got %+v", payload.Preflight) + } +} + +// PF006: the env opt-out (DO_NOT_TRACK and friends) is honoured on the same +// event-time gate as the config flag. +func TestPreflightCounters_RespectEnvOptOut(t *testing.T) { + pinTelemetryEnvEnabled(t) + t.Setenv("DO_NOT_TRACK", "1") + + svc, db := newPreflightService(t, enabledTelemetryConfig()) + svc.RecordAvailabilityBlock(BlockReasonToolNotCallable) + svc.RecordDiscoveryOmission() + + snap, err := NewPreflightCounterStore().Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + if !snap.isZero() { + t.Fatalf("env opt-out must persist nothing, got %+v", snap) + } +} + +// PF007: every Record* is a safe no-op when the store was never wired. +func TestPreflightCounters_NoStoreIsNoOp(t *testing.T) { + pinTelemetryEnvEnabled(t) + svc := New(enabledTelemetryConfig(), "", "v1.0.0", "personal", zap.NewNop()) + svc.SetRuntimeStats(&mockRuntimeStats{}) + + svc.RecordFilterDiagnosticsEmitted(1, 1) + svc.RecordFilterDiagnosticsFollowed() + svc.RecordAvailabilityBlock(BlockReasonOther) + svc.RecordDiscoveryOmission() + + if payload := svc.BuildPayload(); payload.Preflight != nil { + t.Errorf("expected Preflight nil with no store wired, got %+v", payload.Preflight) + } +} diff --git a/internal/telemetry/preflight_counters.go b/internal/telemetry/preflight_counters.go new file mode 100644 index 00000000..0ea77fc1 --- /dev/null +++ b/internal/telemetry/preflight_counters.go @@ -0,0 +1,456 @@ +package telemetry + +import ( + "encoding/json" + "fmt" + "sort" + "strings" + "time" + + "go.etcd.io/bbolt" +) + +// PreflightCountersBucketName is the BBolt bucket that stores the +// required-tools-preflight BASELINE counters (issue #969, Phase 0). Keys inside +// are defined as constants below and follow the Phase-H counter encoding +// (encodeCounter / readCounterWithDecay), so every counter here is a 24h +// sliding window that decays at read time. +// +// These counters ship ONE RELEASE AHEAD of the preflight feature on purpose: +// without a live pre-feature window there is nothing to compare the post-feature +// numbers against, and "did preflight help?" degrades into an argument about +// anecdotes. +const PreflightCountersBucketName = "preflight_counters" + +const ( + preflightKeyFilterDiagEmitted24h = "filter_diag_emitted_24h" + preflightKeyFilterDiagMissing24h = "filter_diag_missing_annotation_24h" + preflightKeyFilterDiagExplicit24h = "filter_diag_explicit_24h" + preflightKeyFilterDiagFollowed24h = "filter_diag_followed_24h" + preflightKeyDiscoveryOmission24h = "discovery_omission_24h" + preflightKeyAvailabilityReasonPfx = "availability_block_reason_24h_" + // NOTE: there is deliberately no availability_block_24h storage key. The + // wire field of that name is the SUM of the per-reason keys, computed at + // snapshot time so the total and its split can never disagree. +) + +// Availability block reason keys (issue #969). This is a CLOSED enum mirroring +// the structured policy-block sites in internal/server — it is duplicated here +// rather than imported for the same reason tpaSeverityKeys is: the telemetry +// package must not depend on the server package, and the enum IS the anonymity +// contract. Anything outside this list is folded into BlockReasonOther rather +// than transmitted, so a reason STRING (which carries server/tool names) can +// never become a map key. +const ( + BlockReasonIntentInvalid = "intent_invalid" + BlockReasonIntentRejected = "intent_rejected" + BlockReasonProfileScope = "profile_scope" + BlockReasonTokenScope = "token_scope" + BlockReasonTokenPermission = "token_permission" + BlockReasonServerQuarantined = "server_quarantined" + BlockReasonToolPendingApproval = "tool_pending_approval" + BlockReasonToolChanged = "tool_changed_approval" + BlockReasonToolNotCallable = "tool_not_callable" + BlockReasonOutputSanitisation = "output_sanitisation" + BlockReasonOutputSchema = "output_schema" + BlockReasonOther = "other" +) + +// availabilityBlockReasonKeys is the fixed enum emitted under +// preflight.availability_block_reasons_24h. +var availabilityBlockReasonKeys = []string{ + BlockReasonIntentInvalid, + BlockReasonIntentRejected, + BlockReasonProfileScope, + BlockReasonTokenScope, + BlockReasonTokenPermission, + BlockReasonServerQuarantined, + BlockReasonToolPendingApproval, + BlockReasonToolChanged, + BlockReasonToolNotCallable, + BlockReasonOutputSanitisation, + BlockReasonOutputSchema, + BlockReasonOther, +} + +// availabilityBlockReasonAllowList is the set form of availabilityBlockReasonKeys. +var availabilityBlockReasonAllowList = func() map[string]struct{} { + m := make(map[string]struct{}, len(availabilityBlockReasonKeys)) + for _, k := range availabilityBlockReasonKeys { + m[k] = struct{}{} + } + return m +}() + +// IsAvailabilityBlockReason reports whether key is a member of the closed +// availability-block reason enum. +func IsAvailabilityBlockReason(key string) bool { + _, ok := availabilityBlockReasonAllowList[key] + return ok +} + +// NormalizeAvailabilityBlockReason maps any input onto the closed enum: +// members pass through, everything else becomes BlockReasonOther. Callers on +// the hot path use this so a future block site that forgets to declare a key +// still produces a countable — and non-identifying — bucket. +func NormalizeAvailabilityBlockReason(key string) string { + if IsAvailabilityBlockReason(key) { + return key + } + return BlockReasonOther +} + +// maxAvailabilityReasonKeys bounds how many DISTINCT reason keys the bucket +// will ever hold. The allow-list already bounds cardinality at len(enum); this +// is the write-side backstop that keeps a producer regression (or a stale +// bucket written by a newer build) from growing the key set without bound. +// BlockReasonOther is exempt — it is the overflow bucket itself. +const maxAvailabilityReasonKeys = 16 + +// maxPreflightReasonEntries caps availability_block_reasons_24h in +// MarshalJSON: top-N by count desc, key asc on ties. Same posture as +// maxDiagCodeEntries — the wire payload stays bounded regardless of what the +// bucket accumulated. +const maxPreflightReasonEntries = 16 + +// PreflightCounters is the baseline counter snapshot for the required-tools +// preflight roadmap (issue #969, Phase 0). +// +// Privacy contract: counts only. Every field is a non-negative integer, and the +// only map keys that can appear are members of the closed +// availabilityBlockReasonKeys enum. No tool name, server name, query, filter +// value, session id, or free text ever reaches this struct — the Record* +// methods do not accept them. +type PreflightCounters struct { + // FilterDiagEmitted24h counts retrieve_tools responses that carried a + // spec-094 filter_diagnostics block in the last 24h. Spec 094 shipped with + // zero usage measurement; this is the denominator everything else divides by. + FilterDiagEmitted24h int `json:"filter_diag_emitted_24h"` + // FilterDiagMissingAnnotation24h is the sum of the per-filter + // missing_annotation reason counts across every emitted block ("fix the + // upstream server" class). + FilterDiagMissingAnnotation24h int `json:"filter_diag_missing_annotation_24h"` + // FilterDiagExplicit24h is the sum of the per-filter explicit reason counts + // ("the filter is working as intended" class). + FilterDiagExplicit24h int `json:"filter_diag_explicit_24h"` + // FilterDiagFollowed24h counts diagnostics blocks the agent ACTED ON: a + // later retrieve_tools call in the same MCP session dropped or relaxed at + // least one of the filters the block blamed. This is the engagement signal — + // emitted-but-never-followed means the block is being ignored. + FilterDiagFollowed24h int `json:"filter_diag_followed_24h"` + // AvailabilityBlock24h counts policy blocks (the "blocked" decision on the + // single emitActivityPolicyDecision funnel) in the last 24h. Derived: it is + // exactly the sum of AvailabilityBlockReasons24h, since every block bumps + // one reason key. + AvailabilityBlock24h int `json:"availability_block_24h"` + // AvailabilityBlockReasons24h splits AvailabilityBlock24h by the closed + // reason enum. Sparse: reasons with a zero count are omitted. + AvailabilityBlockReasons24h map[string]int `json:"availability_block_reasons_24h,omitempty"` + // DiscoveryOmission24h counts retrieve_tools responses that silently + // withheld locked/quarantined matches from the caller (include_disabled + // unset). This is the substrate for the preflight silent-unavailability + // metric: how often an agent was told "no such tool" when the tool exists. + DiscoveryOmission24h int `json:"discovery_omission_24h"` +} + +// isZero reports whether nothing at all was recorded, in which case the +// heartbeat omits the whole sub-object (same posture as DiagnosticsCounters). +func (p PreflightCounters) isZero() bool { + if p.FilterDiagEmitted24h != 0 || + p.FilterDiagMissingAnnotation24h != 0 || + p.FilterDiagExplicit24h != 0 || + p.FilterDiagFollowed24h != 0 || + p.AvailabilityBlock24h != 0 || + p.DiscoveryOmission24h != 0 { + return false + } + for _, n := range p.AvailabilityBlockReasons24h { + if n != 0 { + return false + } + } + return true +} + +// MarshalJSON drops any reason key outside the closed enum and caps the map to +// maxPreflightReasonEntries before serialising. Both guards are wire-form +// backstops for the producer-side filtering in RecordAvailabilityBlock. +func (p PreflightCounters) MarshalJSON() ([]byte, error) { + counts := p.AvailabilityBlockReasons24h + if len(counts) > 0 { + filtered := make(map[string]int, len(counts)) + for k, v := range counts { + if IsAvailabilityBlockReason(k) { + filtered[k] = v + } + } + counts = filtered + } + if len(counts) > maxPreflightReasonEntries { + type kv struct { + k string + v int + } + entries := make([]kv, 0, len(counts)) + for k, v := range counts { + entries = append(entries, kv{k, v}) + } + sort.Slice(entries, func(i, j int) bool { + if entries[i].v != entries[j].v { + return entries[i].v > entries[j].v // higher count first + } + return entries[i].k < entries[j].k // tie-break by key asc + }) + counts = make(map[string]int, maxPreflightReasonEntries) + for _, e := range entries[:maxPreflightReasonEntries] { + counts[e.k] = e.v + } + } + if len(counts) == 0 { + counts = nil + } + type wire struct { + FilterDiagEmitted24h int `json:"filter_diag_emitted_24h"` + FilterDiagMissingAnnotation24h int `json:"filter_diag_missing_annotation_24h"` + FilterDiagExplicit24h int `json:"filter_diag_explicit_24h"` + FilterDiagFollowed24h int `json:"filter_diag_followed_24h"` + AvailabilityBlock24h int `json:"availability_block_24h"` + AvailabilityBlockReasons24h map[string]int `json:"availability_block_reasons_24h,omitempty"` + DiscoveryOmission24h int `json:"discovery_omission_24h"` + } + return json.Marshal(wire{ + FilterDiagEmitted24h: p.FilterDiagEmitted24h, + FilterDiagMissingAnnotation24h: p.FilterDiagMissingAnnotation24h, + FilterDiagExplicit24h: p.FilterDiagExplicit24h, + FilterDiagFollowed24h: p.FilterDiagFollowed24h, + AvailabilityBlock24h: p.AvailabilityBlock24h, + AvailabilityBlockReasons24h: counts, + DiscoveryOmission24h: p.DiscoveryOmission24h, + }) +} + +// PreflightCounterStore is the persistence contract for the Phase-0 baseline +// counters. Implementations back onto BBolt; every method is individually +// atomic via a bbolt transaction. +type PreflightCounterStore interface { + // RecordFilterDiagnosticsEmitted increments filter_diag_emitted_24h once + // and adds the block's per-reason-class counts (both must be >= 0; negative + // values are clamped to 0). + RecordFilterDiagnosticsEmitted(db *bbolt.DB, missingAnnotation, explicit int) error + + // RecordFilterDiagnosticsFollowed increments filter_diag_followed_24h — a + // later call in the same session relaxed a filter the block blamed. + RecordFilterDiagnosticsFollowed(db *bbolt.DB) error + + // RecordAvailabilityBlock increments availability_block_24h and the + // per-reason counter. Reasons outside the closed enum are folded into + // BlockReasonOther, so free text can never become a key. + RecordAvailabilityBlock(db *bbolt.DB, reason string) error + + // RecordDiscoveryOmission increments discovery_omission_24h. + RecordDiscoveryOmission(db *bbolt.DB) error + + // Snapshot loads the current counter state, applying 24h decay at now. + Snapshot(db *bbolt.DB) (PreflightCounters, error) +} + +// bboltPreflightCounterStore is the production BBolt-backed implementation. +// Zero-value is ready to use; no initialisation required. +type bboltPreflightCounterStore struct{} + +// NewPreflightCounterStore returns a BBolt-backed PreflightCounterStore. +func NewPreflightCounterStore() PreflightCounterStore { + return bboltPreflightCounterStore{} +} + +// EnsurePreflightCountersBucket pre-creates the bucket to avoid write-races on +// first use. Safe to call multiple times. +func EnsurePreflightCountersBucket(db *bbolt.DB) error { + if db == nil { + return fmt.Errorf("nil db") + } + return db.Update(func(tx *bbolt.Tx) error { + _, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + return err + }) +} + +// --- bucket helpers --- + +func preflightBucket(tx *bbolt.Tx) *bbolt.Bucket { + return tx.Bucket([]byte(PreflightCountersBucketName)) +} + +func preflightBucketForWrite(tx *bbolt.Tx) (*bbolt.Bucket, error) { + return tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) +} + +// bumpPreflightCounter adds n (clamped at >= 0) to the 24h counter at key, +// rolling the window when it has expired. +func bumpPreflightCounter(b *bbolt.Bucket, key string, n int, now time.Time) error { + if n <= 0 { + return nil + } + count, windowStart, _ := readCounterWithDecay(b.Get([]byte(key)), now) + count += uint64(n) + return b.Put([]byte(key), encodeCounter(count, windowStart)) +} + +// --- RecordFilterDiagnosticsEmitted --- + +func (bboltPreflightCounterStore) RecordFilterDiagnosticsEmitted(db *bbolt.DB, missingAnnotation, explicit int) error { + if db == nil { + return nil + } + now := time.Now() + return db.Update(func(tx *bbolt.Tx) error { + b, err := preflightBucketForWrite(tx) + if err != nil { + return err + } + if err := bumpPreflightCounter(b, preflightKeyFilterDiagEmitted24h, 1, now); err != nil { + return err + } + if err := bumpPreflightCounter(b, preflightKeyFilterDiagMissing24h, missingAnnotation, now); err != nil { + return err + } + return bumpPreflightCounter(b, preflightKeyFilterDiagExplicit24h, explicit, now) + }) +} + +// --- RecordFilterDiagnosticsFollowed --- + +func (bboltPreflightCounterStore) RecordFilterDiagnosticsFollowed(db *bbolt.DB) error { + if db == nil { + return nil + } + now := time.Now() + return db.Update(func(tx *bbolt.Tx) error { + b, err := preflightBucketForWrite(tx) + if err != nil { + return err + } + return bumpPreflightCounter(b, preflightKeyFilterDiagFollowed24h, 1, now) + }) +} + +// --- RecordAvailabilityBlock --- + +func (bboltPreflightCounterStore) RecordAvailabilityBlock(db *bbolt.DB, reason string) error { + if db == nil { + return nil + } + key := NormalizeAvailabilityBlockReason(reason) + now := time.Now() + return db.Update(func(tx *bbolt.Tx) error { + b, err := preflightBucketForWrite(tx) + if err != nil { + return err + } + // Only the per-reason key is written. The total is DERIVED from the + // reason counts at snapshot time (see snapshotPreflightAt) rather than + // kept as its own counter: every block bumps exactly one reason key, so + // the sum is the total by construction — whereas a separate aggregate + // key carries its own independent 24h window and would drift out of + // agreement with the split it is supposed to summarise. + // + // Write-side cardinality backstop: a key the bucket has never seen is + // only admitted while the distinct-key budget holds; past it, the count + // still lands (in the overflow bucket) but the key set cannot grow. + if key != BlockReasonOther { + reasonKey := preflightKeyAvailabilityReasonPfx + key + if b.Get([]byte(reasonKey)) == nil && countPreflightReasonKeys(b) >= maxAvailabilityReasonKeys { + key = BlockReasonOther + } + } + return bumpPreflightCounter(b, preflightKeyAvailabilityReasonPfx+key, 1, now) + }) +} + +// countPreflightReasonKeys returns how many distinct reason keys the bucket +// currently holds (decayed-but-not-yet-deleted keys included — the budget is +// about key-set growth, not live counts). +func countPreflightReasonKeys(b *bbolt.Bucket) int { + n := 0 + prefix := []byte(preflightKeyAvailabilityReasonPfx) + c := b.Cursor() + for k, _ := c.Seek(prefix); k != nil && strings.HasPrefix(string(k), preflightKeyAvailabilityReasonPfx); k, _ = c.Next() { + n++ + } + return n +} + +// --- RecordDiscoveryOmission --- + +func (bboltPreflightCounterStore) RecordDiscoveryOmission(db *bbolt.DB) error { + if db == nil { + return nil + } + now := time.Now() + return db.Update(func(tx *bbolt.Tx) error { + b, err := preflightBucketForWrite(tx) + if err != nil { + return err + } + return bumpPreflightCounter(b, preflightKeyDiscoveryOmission24h, 1, now) + }) +} + +// --- Snapshot --- + +func (bboltPreflightCounterStore) Snapshot(db *bbolt.DB) (PreflightCounters, error) { + return snapshotPreflightAt(db, time.Now()) +} + +func snapshotPreflightAt(db *bbolt.DB, now time.Time) (PreflightCounters, error) { + var out PreflightCounters + if db == nil { + return out, nil + } + err := db.View(func(tx *bbolt.Tx) error { + b := preflightBucket(tx) + if b == nil { + return nil // bucket absent → all zero + } + + read := func(key string) int { + raw := b.Get([]byte(key)) + if len(raw) < 16 { + return 0 + } + cnt, _, _ := readCounterWithDecay(raw, now) + return int(cnt) + } + + out.FilterDiagEmitted24h = read(preflightKeyFilterDiagEmitted24h) + out.FilterDiagMissingAnnotation24h = read(preflightKeyFilterDiagMissing24h) + out.FilterDiagExplicit24h = read(preflightKeyFilterDiagExplicit24h) + out.FilterDiagFollowed24h = read(preflightKeyFilterDiagFollowed24h) + out.DiscoveryOmission24h = read(preflightKeyDiscoveryOmission24h) + + // per-reason 24h counts; AvailabilityBlock24h is their sum + c := b.Cursor() + prefix := []byte(preflightKeyAvailabilityReasonPfx) + for k, v := c.Seek(prefix); k != nil && strings.HasPrefix(string(k), preflightKeyAvailabilityReasonPfx); k, v = c.Next() { + reason := strings.TrimPrefix(string(k), preflightKeyAvailabilityReasonPfx) + // Read-side twin of the producer guard: a key that is not a member + // of the closed enum never becomes part of the snapshot. + if !IsAvailabilityBlockReason(reason) { + continue + } + if len(v) < 16 { + continue + } + cnt, _, _ := readCounterWithDecay(v, now) + if cnt > 0 { + if out.AvailabilityBlockReasons24h == nil { + out.AvailabilityBlockReasons24h = make(map[string]int) + } + out.AvailabilityBlockReasons24h[reason] = int(cnt) + out.AvailabilityBlock24h += int(cnt) + } + } + return nil + }) + return out, err +} diff --git a/internal/telemetry/preflight_counters_test.go b/internal/telemetry/preflight_counters_test.go new file mode 100644 index 00000000..4b253858 --- /dev/null +++ b/internal/telemetry/preflight_counters_test.go @@ -0,0 +1,625 @@ +package telemetry + +import ( + "encoding/json" + "fmt" + "path/filepath" + "strings" + "testing" + "time" + + "go.etcd.io/bbolt" +) + +// newTestPreflightDB creates a temporary BBolt DB for preflight counter tests. +func newTestPreflightDB(t *testing.T) (*bbolt.DB, func()) { + t.Helper() + dir := t.TempDir() + path := filepath.Join(dir, "preflight_test.db") + db, err := bbolt.Open(path, 0600, &bbolt.Options{Timeout: 2 * time.Second}) + if err != nil { + t.Fatalf("bbolt.Open: %v", err) + } + return db, func() { _ = db.Close() } +} + +// P001: an empty DB snapshots to the zero value (and is therefore omitted from +// the heartbeat). +func TestPreflightCounterStore_Empty(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + snap, err := s.Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + if !snap.isZero() { + t.Fatalf("expected zero snapshot on empty DB, got %+v", snap) + } +} + +// P002: filter-diagnostics emission bumps the response counter once and adds +// the per-reason-class counts. +func TestPreflightCounterStore_FilterDiagnosticsEmitted(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + if err := s.RecordFilterDiagnosticsEmitted(db, 3, 2); err != nil { + t.Fatalf("RecordFilterDiagnosticsEmitted: %v", err) + } + if err := s.RecordFilterDiagnosticsEmitted(db, 1, 0); err != nil { + t.Fatalf("RecordFilterDiagnosticsEmitted: %v", err) + } + + snap, err := s.Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + if snap.FilterDiagEmitted24h != 2 { + t.Errorf("FilterDiagEmitted24h = %d, want 2", snap.FilterDiagEmitted24h) + } + if snap.FilterDiagMissingAnnotation24h != 4 { + t.Errorf("FilterDiagMissingAnnotation24h = %d, want 4", snap.FilterDiagMissingAnnotation24h) + } + if snap.FilterDiagExplicit24h != 2 { + t.Errorf("FilterDiagExplicit24h = %d, want 2", snap.FilterDiagExplicit24h) + } +} + +// P003: a block with zero on one reason class still counts the emission, and +// negative inputs (a caller bug) can never decrement a counter. +func TestPreflightCounterStore_EmittedClampsNegatives(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + _ = s.RecordFilterDiagnosticsEmitted(db, 5, 5) + _ = s.RecordFilterDiagnosticsEmitted(db, -100, -100) + + snap, _ := s.Snapshot(db) + if snap.FilterDiagEmitted24h != 2 { + t.Errorf("FilterDiagEmitted24h = %d, want 2", snap.FilterDiagEmitted24h) + } + if snap.FilterDiagMissingAnnotation24h != 5 || snap.FilterDiagExplicit24h != 5 { + t.Errorf("negative deltas must be dropped, got missing=%d explicit=%d", + snap.FilterDiagMissingAnnotation24h, snap.FilterDiagExplicit24h) + } +} + +// P004: followed / discovery-omission increment paths. +func TestPreflightCounterStore_FollowedAndOmission(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + for i := 0; i < 4; i++ { + if err := s.RecordFilterDiagnosticsFollowed(db); err != nil { + t.Fatalf("RecordFilterDiagnosticsFollowed: %v", err) + } + } + for i := 0; i < 7; i++ { + if err := s.RecordDiscoveryOmission(db); err != nil { + t.Fatalf("RecordDiscoveryOmission: %v", err) + } + } + + snap, _ := s.Snapshot(db) + if snap.FilterDiagFollowed24h != 4 { + t.Errorf("FilterDiagFollowed24h = %d, want 4", snap.FilterDiagFollowed24h) + } + if snap.DiscoveryOmission24h != 7 { + t.Errorf("DiscoveryOmission24h = %d, want 7", snap.DiscoveryOmission24h) + } +} + +// P005: availability blocks increment the total and the per-reason map. +func TestPreflightCounterStore_AvailabilityBlockByReason(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + _ = s.RecordAvailabilityBlock(db, BlockReasonServerQuarantined) + _ = s.RecordAvailabilityBlock(db, BlockReasonServerQuarantined) + _ = s.RecordAvailabilityBlock(db, BlockReasonTokenScope) + + snap, _ := s.Snapshot(db) + if snap.AvailabilityBlock24h != 3 { + t.Errorf("AvailabilityBlock24h = %d, want 3", snap.AvailabilityBlock24h) + } + if got := snap.AvailabilityBlockReasons24h[BlockReasonServerQuarantined]; got != 2 { + t.Errorf("server_quarantined = %d, want 2", got) + } + if got := snap.AvailabilityBlockReasons24h[BlockReasonTokenScope]; got != 1 { + t.Errorf("token_scope = %d, want 1", got) + } +} + +// P006: a reason OUTSIDE the closed enum — e.g. the operator-facing prose that +// embeds a server name — is folded into "other" and never becomes a key. +func TestPreflightCounterStore_UnknownReasonFoldedIntoOther(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + leaky := []string{ + "", + "Server 'acme-internal' is not in scope for this agent token", + "/Users/algis/.mcpproxy/config.db", + "SERVER_QUARANTINED", + } + for _, r := range leaky { + if err := s.RecordAvailabilityBlock(db, r); err != nil { + t.Fatalf("RecordAvailabilityBlock(%q): %v", r, err) + } + } + + snap, _ := s.Snapshot(db) + if snap.AvailabilityBlock24h != len(leaky) { + t.Errorf("AvailabilityBlock24h = %d, want %d", snap.AvailabilityBlock24h, len(leaky)) + } + if got := snap.AvailabilityBlockReasons24h[BlockReasonOther]; got != len(leaky) { + t.Errorf("other = %d, want %d", got, len(leaky)) + } + for key := range snap.AvailabilityBlockReasons24h { + if !IsAvailabilityBlockReason(key) { + t.Errorf("non-enum key %q leaked into the snapshot", key) + } + } +} + +// P007: 24h windowing — a counter whose window opened more than 24h ago reads +// as zero (same decay contract as the Phase H counters). +func TestPreflightCounterStore_24hDecay(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + pastStart := time.Now().Add(-25 * time.Hour) + err := db.Update(func(tx *bbolt.Tx) error { + b, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + if err != nil { + return err + } + if err := b.Put([]byte(preflightKeyFilterDiagEmitted24h), encodeCounter(42, pastStart.Unix())); err != nil { + return err + } + if err := b.Put([]byte(preflightKeyDiscoveryOmission24h), encodeCounter(17, pastStart.Unix())); err != nil { + return err + } + // availability_block_24h has no storage key of its own — it is the sum + // of the reason keys, so seeding a stale reason covers it. + return b.Put([]byte(preflightKeyAvailabilityReasonPfx+BlockReasonToolNotCallable), + encodeCounter(9, pastStart.Unix())) + }) + if err != nil { + t.Fatalf("seeding stale counters: %v", err) + } + + var s bboltPreflightCounterStore + snap, err := s.Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + if !snap.isZero() { + t.Fatalf("expected everything decayed to zero, got %+v", snap) + } + if _, ok := snap.AvailabilityBlockReasons24h[BlockReasonToolNotCallable]; ok { + t.Errorf("decayed reason key must not appear in the snapshot") + } +} + +// P008: 24h windowing — a stale window ROLLS on the next write instead of +// accumulating on top of the expired count. +func TestPreflightCounterStore_StaleWindowRolls(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + pastStart := time.Now().Add(-30 * time.Hour) + err := db.Update(func(tx *bbolt.Tx) error { + b, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + if err != nil { + return err + } + return b.Put([]byte(preflightKeyFilterDiagFollowed24h), encodeCounter(1000, pastStart.Unix())) + }) + if err != nil { + t.Fatalf("seeding stale counter: %v", err) + } + + var s bboltPreflightCounterStore + if err := s.RecordFilterDiagnosticsFollowed(db); err != nil { + t.Fatalf("RecordFilterDiagnosticsFollowed: %v", err) + } + snap, _ := s.Snapshot(db) + if snap.FilterDiagFollowed24h != 1 { + t.Errorf("FilterDiagFollowed24h = %d, want 1 (window must roll, not accumulate)", snap.FilterDiagFollowed24h) + } +} + +// P009: a counter written INSIDE the window survives. +func TestPreflightCounterStore_WithinWindowSurvives(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + recentStart := time.Now().Add(-23 * time.Hour) + err := db.Update(func(tx *bbolt.Tx) error { + b, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + if err != nil { + return err + } + return b.Put([]byte(preflightKeyDiscoveryOmission24h), encodeCounter(5, recentStart.Unix())) + }) + if err != nil { + t.Fatalf("seeding counter: %v", err) + } + + var s bboltPreflightCounterStore + if err := s.RecordDiscoveryOmission(db); err != nil { + t.Fatalf("RecordDiscoveryOmission: %v", err) + } + snap, _ := s.Snapshot(db) + if snap.DiscoveryOmission24h != 6 { + t.Errorf("DiscoveryOmission24h = %d, want 6", snap.DiscoveryOmission24h) + } +} + +// P010: write-side key cap — once the bucket holds maxAvailabilityReasonKeys +// distinct reason keys, a further NEW key folds into "other" instead of growing +// the key set. (The allow-list already bounds this; the cap is the backstop for +// a bucket written by a future build with a wider enum.) +func TestPreflightCounterStore_ReasonKeyCapEnforced(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + // Seed the bucket to the cap with synthetic keys (as a newer build might). + err := db.Update(func(tx *bbolt.Tx) error { + b, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + if err != nil { + return err + } + for i := 0; i < maxAvailabilityReasonKeys; i++ { + key := fmt.Sprintf("%sfuture_reason_%02d", preflightKeyAvailabilityReasonPfx, i) + if err := b.Put([]byte(key), encodeCounter(1, time.Now().Unix())); err != nil { + return err + } + } + return nil + }) + if err != nil { + t.Fatalf("seeding reason keys: %v", err) + } + + var s bboltPreflightCounterStore + if err := s.RecordAvailabilityBlock(db, BlockReasonProfileScope); err != nil { + t.Fatalf("RecordAvailabilityBlock: %v", err) + } + + // The new key must NOT have been created; the count went to "other". + err = db.View(func(tx *bbolt.Tx) error { + b := tx.Bucket([]byte(PreflightCountersBucketName)) + if raw := b.Get([]byte(preflightKeyAvailabilityReasonPfx + BlockReasonProfileScope)); raw != nil { + t.Errorf("key set grew past the cap: profile_scope key was created") + } + if raw := b.Get([]byte(preflightKeyAvailabilityReasonPfx + BlockReasonOther)); raw == nil { + t.Errorf("overflow bucket 'other' was not written") + } + return nil + }) + if err != nil { + t.Fatalf("View: %v", err) + } + + snap, _ := s.Snapshot(db) + if snap.AvailabilityBlock24h != 1 { + t.Errorf("AvailabilityBlock24h = %d, want 1", snap.AvailabilityBlock24h) + } + if got := snap.AvailabilityBlockReasons24h[BlockReasonOther]; got != 1 { + t.Errorf("other = %d, want 1", got) + } + // The synthetic (non-enum) keys are filtered out on the read side too. + for key := range snap.AvailabilityBlockReasons24h { + if strings.HasPrefix(key, "future_reason_") { + t.Errorf("non-enum key %q leaked into the snapshot", key) + } + } +} + +// P011: MarshalJSON caps the reason map to maxPreflightReasonEntries and drops +// any key outside the closed enum — the wire-form backstop. +func TestPreflightCounters_MarshalJSON_CapsAndFilters(t *testing.T) { + counts := make(map[string]int, len(availabilityBlockReasonKeys)+5) + for i, k := range availabilityBlockReasonKeys { + counts[k] = 100 - i + } + // Keys that must never reach the wire. + counts["Server 'acme' is not in scope"] = 999 + counts["/Users/algis/secret"] = 998 + + p := PreflightCounters{AvailabilityBlockReasons24h: counts} + raw, err := json.Marshal(p) + if err != nil { + t.Fatalf("MarshalJSON: %v", err) + } + var out struct { + Reasons map[string]int `json:"availability_block_reasons_24h"` + } + if err := json.Unmarshal(raw, &out); err != nil { + t.Fatalf("Unmarshal: %v", err) + } + if len(out.Reasons) > maxPreflightReasonEntries { + t.Errorf("map has %d entries, cap is %d", len(out.Reasons), maxPreflightReasonEntries) + } + for key := range out.Reasons { + if !IsAvailabilityBlockReason(key) { + t.Errorf("non-enum key %q reached the wire", key) + } + } + if strings.Contains(string(raw), "acme") || strings.Contains(string(raw), "/Users/") { + t.Errorf("PII leaked into the wire form: %s", raw) + } +} + +// P012: MarshalJSON caps deterministically (top-N by count desc, key asc). +func TestPreflightCounters_MarshalJSON_Deterministic(t *testing.T) { + counts := make(map[string]int, len(availabilityBlockReasonKeys)) + for _, k := range availabilityBlockReasonKeys { + counts[k] = 10 // pure alphabetic tie-break + } + p := PreflightCounters{AvailabilityBlock24h: 120, AvailabilityBlockReasons24h: counts} + + var results [3][]byte + for i := range results { + raw, err := json.Marshal(p) + if err != nil { + t.Fatalf("MarshalJSON run %d: %v", i, err) + } + results[i] = raw + } + for i := 1; i < len(results); i++ { + if string(results[i]) != string(results[0]) { + t.Errorf("MarshalJSON is non-deterministic: run 0 != run %d", i) + } + } +} + +// P013: the sub-object is omitted from the wire when nothing was recorded, and +// carries every documented key when it is present. +func TestPreflightCounters_IsZeroAndWireKeys(t *testing.T) { + var zero PreflightCounters + if !zero.isZero() { + t.Fatalf("zero value must report isZero") + } + // A reason key with a zero count is still "nothing recorded". + zero.AvailabilityBlockReasons24h = map[string]int{BlockReasonOther: 0} + if !zero.isZero() { + t.Fatalf("all-zero reason map must still report isZero") + } + + full := PreflightCounters{ + FilterDiagEmitted24h: 1, + FilterDiagMissingAnnotation24h: 2, + FilterDiagExplicit24h: 3, + FilterDiagFollowed24h: 4, + AvailabilityBlock24h: 5, + AvailabilityBlockReasons24h: map[string]int{BlockReasonToolChanged: 5}, + DiscoveryOmission24h: 6, + } + if full.isZero() { + t.Fatalf("populated counters must not report isZero") + } + raw, err := json.Marshal(full) + if err != nil { + t.Fatalf("MarshalJSON: %v", err) + } + var out map[string]json.RawMessage + if err := json.Unmarshal(raw, &out); err != nil { + t.Fatalf("Unmarshal: %v", err) + } + for _, key := range []string{ + "filter_diag_emitted_24h", + "filter_diag_missing_annotation_24h", + "filter_diag_explicit_24h", + "filter_diag_followed_24h", + "availability_block_24h", + "availability_block_reasons_24h", + "discovery_omission_24h", + } { + if _, ok := out[key]; !ok { + t.Errorf("wire form is missing %q", key) + } + } +} + +// P014: the store never persists anything that looks like an identity, even +// when every enum member is exercised. +func TestPreflightCounters_NoLeakPII(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + var s bboltPreflightCounterStore + for _, reason := range availabilityBlockReasonKeys { + _ = s.RecordAvailabilityBlock(db, reason) + } + _ = s.RecordFilterDiagnosticsEmitted(db, 2, 3) + _ = s.RecordFilterDiagnosticsFollowed(db) + _ = s.RecordDiscoveryOmission(db) + + snap, _ := s.Snapshot(db) + raw, err := json.Marshal(snap) + if err != nil { + t.Fatalf("MarshalJSON: %v", err) + } + js := string(raw) + for _, forbidden := range []string{ + "/home/", "/Users/", "C:\\", + "localhost", "127.0.0.1", + "password", "secret", "token:", + } { + if strings.Contains(js, forbidden) { + t.Errorf("PII leak: JSON contains %q\nJSON: %s", forbidden, js) + } + } + envelope := []byte(`{"preflight":` + js + `}`) + if err := ScanForPII(envelope); err != nil { + t.Errorf("preflight sub-object must pass the anonymity scanner: %v", err) + } +} + +// P015: the anonymity scanner rejects a preflight sub-object whose reason map +// carries a key outside the closed enum — the wire-form backstop for a producer +// regression that let operator prose (server/tool names) become a key. +func TestScanForPII_RejectsNonEnumPreflightReasonKey(t *testing.T) { + payload := []byte(`{"preflight":{"availability_block_24h":1,` + + `"availability_block_reasons_24h":{"server acme-internal is quarantined":1}}}`) + err := ScanForPII(payload) + if err == nil { + t.Fatalf("expected an anonymity violation for a non-enum reason key") + } + if !strings.Contains(err.Error(), "availability_block_reasons_24h") { + t.Errorf("violation should name the offending field, got: %v", err) + } + if strings.Contains(err.Error(), "acme-internal") { + t.Errorf("violation must never echo the offending key: %v", err) + } +} + +// P016: the scanner also rejects non-integer / negative preflight scalars. +func TestScanForPII_RejectsMalformedPreflightScalars(t *testing.T) { + cases := []string{ + `{"preflight":{"filter_diag_emitted_24h":-1}}`, + `{"preflight":{"discovery_omission_24h":"3"}}`, + `{"preflight":{"availability_block_24h":1.5}}`, + `{"preflight":null}`, + } + for _, payload := range cases { + if err := ScanForPII([]byte(payload)); err == nil { + t.Errorf("expected a violation for %s", payload) + } + } +} + +// P016b: the preflight sub-object is CLOSED — a key outside the documented +// counter set is rejected before transmit, whatever it carries. This is the +// backstop for a future field that smuggles free text (a server name, a query, +// an error message) into a sub-object whose whole contract is "counts only". +func TestScanForPII_RejectsUnknownPreflightKey(t *testing.T) { + cases := []struct { + payload string + // mustNotEcho is content the violation message may never repeat. The + // generic prefix/regex rules run first and legitimately name their own + // literal pattern, so only rule-7-specific cases assert this. + mustNotEcho string + }{ + {`{"preflight":{"availability_block_24h":1,"last_blocked_server":"acme-internal"}}`, "acme-internal"}, + {`{"preflight":{"availability_block_24h":1,"top_query":"list the deploy keys"}}`, "deploy keys"}, + {`{"preflight":{"filter_diag_emitted_24h":1,"filter_diag_emitted_48h":2}}`, ""}, + } + for _, tc := range cases { + err := ScanForPII([]byte(tc.payload)) + if err == nil { + t.Errorf("expected a violation for an unknown preflight key: %s", tc.payload) + continue + } + if tc.mustNotEcho != "" && strings.Contains(err.Error(), tc.mustNotEcho) { + t.Errorf("violation must never echo the offending content: %v", err) + } + } +} + +// P016c: the closed-key set is exactly what MarshalJSON emits, so a populated +// payload can never trip the rule it is guarded by. +func TestScanForPII_PreflightAllowedKeysMatchWireForm(t *testing.T) { + full := PreflightCounters{ + FilterDiagEmitted24h: 1, + FilterDiagMissingAnnotation24h: 2, + FilterDiagExplicit24h: 3, + FilterDiagFollowed24h: 4, + AvailabilityBlock24h: 5, + AvailabilityBlockReasons24h: map[string]int{BlockReasonOther: 5}, + DiscoveryOmission24h: 6, + } + raw, err := json.Marshal(full) + if err != nil { + t.Fatalf("MarshalJSON: %v", err) + } + var out map[string]json.RawMessage + if err := json.Unmarshal(raw, &out); err != nil { + t.Fatalf("Unmarshal: %v", err) + } + for key := range out { + if !isPreflightAllowedKey(key) { + t.Errorf("wire form emits %q, which the scanner would reject", key) + } + } + if len(out) != len(preflightAllowedKeys) { + t.Errorf("wire form has %d keys, allow-list has %d — they must stay in sync", + len(out), len(preflightAllowedKeys)) + } + if err := ScanForPII([]byte(`{"preflight":` + string(raw) + `}`)); err != nil { + t.Errorf("fully populated preflight must pass the scanner: %v", err) + } +} + +// P017: a well-formed preflight sub-object passes the scanner untouched. +func TestScanForPII_AcceptsWellFormedPreflight(t *testing.T) { + payload := []byte(`{"preflight":{"filter_diag_emitted_24h":3,` + + `"filter_diag_missing_annotation_24h":7,"filter_diag_explicit_24h":2,` + + `"filter_diag_followed_24h":1,"availability_block_24h":4,` + + `"availability_block_reasons_24h":{"server_quarantined":3,"token_scope":1},` + + `"discovery_omission_24h":9}}`) + if err := ScanForPII(payload); err != nil { + t.Errorf("well-formed preflight must pass, got: %v", err) + } +} + +// The total and its per-reason split must never disagree. Each counter key +// carries its OWN window start, so a total whose window opened earlier can +// decay to zero while a reason key that started later survives — producing a +// payload whose reason counts sum to more than the total they supposedly split +// (opencode review, round 4, finding 3). +func TestPreflightSnapshot_TotalAlwaysMatchesReasonSplit(t *testing.T) { + db, cleanup := newTestPreflightDB(t) + defer cleanup() + + now := time.Now() + // reason A's window opened 25h ago (expired); reason B's opened 2h ago. + expired := now.Add(-25 * time.Hour) + recent := now.Add(-2 * time.Hour) + + err := db.Update(func(tx *bbolt.Tx) error { + b, err := tx.CreateBucketIfNotExists([]byte(PreflightCountersBucketName)) + if err != nil { + return err + } + if err := b.Put([]byte(preflightKeyAvailabilityReasonPfx+BlockReasonServerQuarantined), + encodeCounter(1, expired.Unix())); err != nil { + return err + } + return b.Put([]byte(preflightKeyAvailabilityReasonPfx+BlockReasonTokenScope), + encodeCounter(1, recent.Unix())) + }) + if err != nil { + t.Fatalf("seeding counters: %v", err) + } + + var s bboltPreflightCounterStore + snap, err := s.Snapshot(db) + if err != nil { + t.Fatalf("Snapshot: %v", err) + } + + sum := 0 + for _, n := range snap.AvailabilityBlockReasons24h { + sum += n + } + if snap.AvailabilityBlock24h != sum { + t.Errorf("availability_block_24h = %d but its reason split sums to %d; "+ + "the total and the split must be the same number", + snap.AvailabilityBlock24h, sum) + } + // The expired reason is gone, the recent one survives. + if sum != 1 { + t.Errorf("reason split sums to %d, want 1 (the expired reason must decay out)", sum) + } +} diff --git a/internal/telemetry/telemetry.go b/internal/telemetry/telemetry.go index aefc08b7..4583ff82 100644 --- a/internal/telemetry/telemetry.go +++ b/internal/telemetry/telemetry.go @@ -276,6 +276,14 @@ type HeartbeatPayload struct { // MCPX_* enum strings, non-negative int counts. Diagnostics *DiagnosticsCounters `json:"diagnostics,omitempty"` + // Issue #969 (Phase 0): required-tools-preflight BASELINE counters — + // filter-diagnostics engagement + availability/discovery-omission classes. + // Omitted entirely when all counters are zero (omitempty on the pointer), + // so an install that never trips one is shape-identical to a payload from + // before this field existed. No PII: non-negative counts, plus a reason map + // keyed exclusively by the closed availabilityBlockReasonKeys enum. + Preflight *PreflightCounters `json:"preflight,omitempty"` + // Schema v8: anonymous TPA / security-scanner outcome counters. Omitted // entirely when all counters are zero (omitempty on the pointer) — an // install that never scans is shape-identical to a v7 payload. No PII: @@ -353,6 +361,12 @@ type Service struct { diagCounterStore DiagnosticsCounterStore diagCounterDB *bbolt.DB + // Issue #969 (Phase 0): preflight baseline counter store + DB handle. + // Optional — same nil-safety guarantee as activationStore. When nil, the + // preflight sub-object is omitted and every Record* below is a no-op. + preflightStore PreflightCounterStore + preflightDB *bbolt.DB + // Spec 080 (US2): funnel observability store + DB handle. Optional — // same nil-safety guarantee as activationStore. When nil, web_ui_opened, // days_since_install, and active_days_30d are omitted (short-lived CLI @@ -545,6 +559,104 @@ func (s *Service) DiagnosticsCounterDB() *bbolt.DB { return s.diagCounterDB } +// SetPreflightCounterStore wires the BBolt-backed preflight baseline counter +// store (issue #969, Phase 0). Optional; when unset, heartbeat payloads omit +// the preflight object and every Record* below is a no-op. Safe to call once +// during startup. +func (s *Service) SetPreflightCounterStore(store PreflightCounterStore, db *bbolt.DB) { + s.preflightStore = store + s.preflightDB = db +} + +// PreflightCounterStore returns the wired preflight counter store (or nil). +func (s *Service) PreflightCounterStore() PreflightCounterStore { + return s.preflightStore +} + +// PreflightCounterDB returns the BBolt DB handle associated with the preflight +// counter store (or nil). +func (s *Service) PreflightCounterDB() *bbolt.DB { + return s.preflightDB +} + +// preflightSink returns the store/DB pair to write to, or (nil, nil) when +// nothing may be recorded. +// +// The opt-out is evaluated at EVENT time, not only at heartbeat time — the +// strictest of the existing postures (recordUpdateFailure, spec 095 FR-013). +// An occurrence observed while telemetry is off is never persisted, so it can +// never become transmissible if the user turns telemetry back on later. +func (s *Service) preflightSink() (PreflightCounterStore, *bbolt.DB) { + if s == nil || s.preflightStore == nil || s.preflightDB == nil { + return nil, nil + } + if s.optedOut.Load() { + return nil, nil + } + s.mu.Lock() + cfg := s.config + s.mu.Unlock() + if !EffectiveTelemetryEnabled(cfg) { + return nil, nil + } + return s.preflightStore, s.preflightDB +} + +// preflightDebug logs a counter-persistence failure without ever propagating it +// — a telemetry counter must never break the request path that produced it. +func (s *Service) preflightDebug(msg string, err error) { + if err == nil || s.logger == nil { + return + } + s.logger.Debug(msg, zap.Error(err)) +} + +// RecordFilterDiagnosticsEmitted counts one retrieve_tools response that +// carried a spec-094 filter_diagnostics block, plus that block's per-reason +// class totals. Counts only — the filter keys and tool identities stay in the +// response and never reach telemetry. +func (s *Service) RecordFilterDiagnosticsEmitted(missingAnnotation, explicit int) { + store, db := s.preflightSink() + if store == nil { + return + } + s.preflightDebug("Failed to record filter_diagnostics emission", + store.RecordFilterDiagnosticsEmitted(db, missingAnnotation, explicit)) +} + +// RecordFilterDiagnosticsFollowed counts one diagnostics block the agent acted +// on (a later same-session retrieve_tools relaxed a blamed filter). +func (s *Service) RecordFilterDiagnosticsFollowed() { + store, db := s.preflightSink() + if store == nil { + return + } + s.preflightDebug("Failed to record filter_diagnostics follow-up", + store.RecordFilterDiagnosticsFollowed(db)) +} + +// RecordAvailabilityBlock counts one policy block by its structured reason key. +// Reasons outside the closed enum are folded into "other" by the store. +func (s *Service) RecordAvailabilityBlock(reason string) { + store, db := s.preflightSink() + if store == nil { + return + } + s.preflightDebug("Failed to record availability block", + store.RecordAvailabilityBlock(db, reason)) +} + +// RecordDiscoveryOmission counts one retrieve_tools response that withheld +// locked/quarantined matches from the caller. +func (s *Service) RecordDiscoveryOmission() { + store, db := s.preflightSink() + if store == nil { + return + } + s.preflightDebug("Failed to record discovery omission", + store.RecordDiscoveryOmission(db)) +} + // SetConfiguredIDECountProvider wires a function that returns the number of // IDE client config files mcpproxy has registered itself into (Spec 044). // Typically supplied by internal/connect.Service. @@ -989,6 +1101,20 @@ func (s *Service) buildHeartbeat() HeartbeatPayload { } } + // Issue #969 (Phase 0): preflight baseline counters. Same flush shape as + // the Phase H diagnostics block above — load from BBolt (decay applied at + // read time), omit entirely when all counters are zero or the store is not + // wired (short-lived CLI commands). + if s.preflightStore != nil && s.preflightDB != nil { + if snap, err := s.preflightStore.Snapshot(s.preflightDB); err == nil { + if !snap.isZero() { + payload.Preflight = &snap + } + } else { + s.logger.Debug("Failed to load preflight counters for heartbeat", zap.Error(err)) + } + } + return payload }