fix(security): carry cert tenant binding on the request row, not a dead log line

Post-deploy verification of 249e39bc found zero AgentCertTenantBinding rows
across 32k agent requests. Cause: the Match outcome was emitted with
LogInformation, and worker-side ILogger below Warning never reaches App
Insights (provider default rule is Warning+, host forwarding of worker logs
is off). The bulk outcome was therefore invisible, which is indistinguishable
from the code never running — the shadow telemetry had no denominator.

Stamp every outcome onto the request row instead (FunctionContext.Items ->
RequestTelemetryMiddleware -> CertTenantBinding dimension). That row already
exists per request and is unsampled, so the denominator costs no extra
telemetry. Non-Match outcomes keep their Warning trace with full context.

FromCache existed only to sample the dead Match line and is removed with it.

Backend 4606/4606, 0 warnings.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

docs/backend/client-cert-tenant-binding.md

@@ -85,12 +85,22 @@ lives in `CertTenantBinding.Evaluate`; the outcome codes (`Match`, `Mismatch`, `
 `WouldRejectUnderEnforcement` records what stage 2 *would* have done, so the telemetry can be read
 without re-deriving the rule at query time.
 
-Volume control: the outcomes that inform the decision (mismatch, missing, undecodable) are always
-logged, because they are expected to be rare and each is individually interesting. The bulk `Match`
-case is logged only when the certificate was freshly validated rather than served from the 5-minute
-thumbprint cache (`CertificateValidationResult.FromCache`). Both numerator and denominator are
-therefore counted per certificate-window rather than per request, which keeps the ratio meaningful
-while cutting the volume by roughly the request-per-device factor.
+The telemetry uses two carriers, because the numerator and the denominator have very different
+costs and answer different questions:
+
+* **Every** outcome, `Match` included, is stamped onto the request row as the `CertTenantBinding`
+  dimension — `SecurityValidator` writes it into `FunctionContext.Items`
+  (`CertTenantBinding.RequestItemKey`) and `RequestTelemetryMiddleware` copies it onto the
+  `RequestTelemetry` it already emits. That row exists per request and is unsampled, so the
+  denominator costs no additional telemetry at all.
+* Outcomes that need an enforcement decision (mismatch, missing, undecodable) are **additionally**
+  logged at Warning with the full context — thumbprint, certificate tenant, session.
+
+`Match` is deliberately not a trace line. Worker-side `LogInformation` never reaches App Insights
+(the ApplicationInsightsLoggerProvider default rule is Warning+ and host-forwarding of worker logs
+is disabled), so a `Match` trace is dead code that silently costs the denominator. The first
+deployment of this feature made exactly that mistake: it emitted zero rows across 32k requests,
+which is indistinguishable from the code never running.
 
 **Stage 2 — enforce.** Once telemetry shows the `ExtensionMissing` rate is negligible, `Mismatch`
 becomes a rejection. The decision that still has to be made is the policy for certificates without
@@ -102,7 +112,18 @@ unaffected by either stage.
 
 # Examples
 
-Read the shadow telemetry:
+Coverage — the question stage 2 depends on ("would enforcing lock anyone out?"):
+
+```kusto
+requests
+| where isnotempty(customDimensions.CertTenantBinding)
+| summarize Requests = sum(itemCount)
+    by Outcome = tostring(customDimensions.CertTenantBinding),
+       Tenant  = tostring(customDimensions.TenantId)
+| order by Requests desc
+```
+
+Detail on the individually actionable ones:
 
 ```kusto
 traces
@@ -113,7 +134,9 @@ traces
 ```
 
 Anything in `Mismatch` is a cross-tenant certificate; anything in `ExtensionMissing` is a device
-that stage-2 enforcement would have to make a policy decision about.
+that stage-2 enforcement would have to make a policy decision about. Note that the trace query
+alone can never show `Match`, so it cannot tell "everything matched" apart from "nothing ran" —
+use the request-row query for that.
 
 # Citations
 

docs/log.md

@@ -2,6 +2,7 @@
 
 ## 2026-08-24
 
+* **Update**: `backend/client-cert-tenant-binding.md` — shadow telemetry moved off the dead `LogInformation` path: the `Match` outcome now rides on the request row as the `CertTenantBinding` dimension (`SecurityValidator` → `FunctionContext.Items` → `RequestTelemetryMiddleware`), which is unsampled and already exists per request, so the denominator costs nothing. Non-Match outcomes keep their Warning trace. Post-deploy verification of 249e39bc found zero rows across 32k requests — worker `LogInformation` never reaches App Insights (provider default rule Warning+), making "everything matched" indistinguishable from "never ran". `CertificateValidationResult.FromCache` removed with the sampling path it existed for.
 * **New**: `backend/client-cert-tenant-binding.md` — the agent's mTLS certificate chains to Microsoft's shared Intune roots, so certificate validation alone never proved tenant membership; tenant scoping rested entirely on the (non-secret) device serial in the downstream validators. The Intune MDM leaf carries the Entra tenant id in OID `1.2.840.113556.5.14` (nested OCTET STRING), which is NOT `…5.6` (Intune Account id, a different GUID) and NOT `…5.4` (device id, stored as 16 bare bytes) — all decoded by one shared `MsDeviceCertificateOids.TryParseGuid` now used by agent and backend. Stage 1 ships as shadow only: `CertTenantBinding.Evaluate` (pure) plus `SecurityValidator.ObserveCertTenantBinding` (returns void, swallows its own exceptions, cannot change an authorization outcome), with `Match` sampled via `CertificateValidationResult.FromCache` so the denominator survives without per-request volume. Grep marker for the stage-2 enforcement change: `CERT-TENANT-BINDING-SHADOW`.
 
 ## 2026-08-23

src/Backend/AutopilotMonitor.Functions.Tests/CertTenantBindingTests.cs

@@ -59,23 +59,19 @@ public class CertTenantBindingTests
     }
 
     [Fact]
-    public void ValidateCertificate_CachedResult_KeepsTenantIdAndFlagsCacheHit()
+    public void ValidateCertificate_CachedResult_KeepsTenantId()
     {
-        // FromCache is what samples the high-volume "Match" telemetry down to ~one line per cert
-        // per cache window, so it has to survive the cache and not corrupt the cached entry.
+        // The tenant id is a pure function of the cert and is cached with the validation result,
+        // so a cache hit must not silently drop it and turn every repeat request into
+        // ExtensionMissing.
         var b64 = SampleCertBase64();
 
         _ = CertificateValidator.ValidateCertificate(b64);
         var second = CertificateValidator.ValidateCertificate(b64);
-        var third = CertificateValidator.ValidateCertificate(b64);
 
-        Assert.True(second.FromCache);
+        Assert.True(second.IsValid);
+        Assert.Equal(CertTenantIdStatus.Present, second.CertTenantIdStatus);
         Assert.Equal(SampleCertTenantId, second.CertTenantId);
-
-        // The cache-hit copy must not have mutated the shared cached instance.
-        Assert.True(third.FromCache);
-        Assert.Equal(SampleCertTenantId, third.CertTenantId);
-        Assert.True(third.IsValid);
     }
 
     // ---------------------------------------------------------------- encoding
@@ -242,14 +238,43 @@ public class CertTenantBindingTests
 
         Assert.True(result.IsValid, $"Matching-tenant request rejected: {result.ErrorMessage}");
 
-        // Match is only logged on a fresh validation; the cache is process-wide and shared with the
-        // other tests here, so assert the outcome only when a line was actually emitted.
-        var observed = logger.Entries.FirstOrDefault(e => e.Message.Contains("AgentCertTenantBinding"));
-        if (observed != null)
-        {
-            Assert.Equal(LogLevel.Information, observed.Level);
-            Assert.Contains(CertTenantBinding.Outcome.Match, observed.Message);
-        }
+        // Match is deliberately NOT a trace line — worker-side LogInformation never reaches App
+        // Insights, so a Match trace would be dead code that silently costs us the denominator.
+        Assert.DoesNotContain(logger.Entries, e => e.Message.Contains("AgentCertTenantBinding"));
+    }
+
+    [Fact]
+    public async Task ValidateRequestAsync_StampsOutcomeOnTheRequestRow()
+    {
+        // The denominator lives here: RequestTelemetryMiddleware copies this item onto the request
+        // row, which already exists per request and is unsampled. Without it, "Match" is invisible
+        // and the shadow telemetry cannot say how often the binding held.
+        var items = new Dictionary<object, object>();
+        var validator = BuildValidator(new CapturingLogger());
+
+        var result = await validator.ValidateRequestAsync(
+            BuildRequestWithCert(SampleCertBase64(), items),
+            tenantId: SampleCertTenantId.ToString());
+
+        Assert.True(result.IsValid, $"Matching-tenant request rejected: {result.ErrorMessage}");
+        Assert.Equal(
+            CertTenantBinding.Outcome.Match,
+            Assert.Contains(CertTenantBinding.RequestItemKey, items));
+    }
+
+    [Fact]
+    public async Task ValidateRequestAsync_StampsMismatchOnTheRequestRowToo()
+    {
+        var items = new Dictionary<object, object>();
+        var validator = BuildValidator(new CapturingLogger());
+
+        await validator.ValidateRequestAsync(
+            BuildRequestWithCert(SampleCertBase64(), items),
+            tenantId: "aaaaaaaa-bbbb-cccc-dddd-eeeeeeeeeeee");
+
+        Assert.Equal(
+            CertTenantBinding.Outcome.Mismatch,
+            Assert.Contains(CertTenantBinding.RequestItemKey, items));
     }
 
     // ---------------------------------------------------------------- harness
@@ -293,9 +318,12 @@ public class CertTenantBindingTests
             deviceAssociationValidator: null);
     }
 
-    private static HttpRequestData BuildRequestWithCert(string certBase64)
+    private static HttpRequestData BuildRequestWithCert(
+        string certBase64,
+        IDictionary<object, object>? items = null)
     {
         var contextMock = new Mock<Microsoft.Azure.Functions.Worker.FunctionContext>();
+        contextMock.SetupGet(c => c.Items).Returns(items ?? new Dictionary<object, object>());
         var reqMock = new Mock<HttpRequestData>(contextMock.Object);
 
         var headers = new HttpHeadersCollection

src/Backend/AutopilotMonitor.Functions/Middleware/RequestTelemetryMiddleware.cs

@@ -5,6 +5,7 @@ using Microsoft.ApplicationInsights.DataContracts;
 using Microsoft.Azure.Functions.Worker;
 using Microsoft.Azure.Functions.Worker.Middleware;
 using AutopilotMonitor.Functions.Helpers;
+using AutopilotMonitor.Functions.Security;
 
 namespace AutopilotMonitor.Functions.Middleware;
 
@@ -114,6 +115,14 @@ public class RequestTelemetryMiddleware : IFunctionsWorkerMiddleware
             if (context.Items.TryGetValue("CorrelationId", out var corrId) && corrId is string correlationId)
                 requestTelemetry.Properties["CorrelationId"] = correlationId;
 
+            // CERT-TENANT-BINDING-SHADOW — set by SecurityValidator.ObserveCertTenantBinding.
+            // Carried on the request row rather than a trace line: worker-side LogInformation never
+            // reaches App Insights (provider default rule is Warning+), so the bulk "Match" outcome
+            // would be invisible and the shadow telemetry would have no denominator. This row already
+            // exists per request and is unsampled, so the outcome costs no additional telemetry.
+            if (context.Items.TryGetValue(CertTenantBinding.RequestItemKey, out var binding) && binding is string bindingOutcome)
+                requestTelemetry.Properties["CertTenantBinding"] = bindingOutcome;
+
             var reqCtx = context.GetRequestContext();
             var tenantId = reqCtx.TenantId;
             if (string.IsNullOrEmpty(tenantId))

src/Backend/AutopilotMonitor.Functions/Security/CertTenantBinding.cs

@@ -21,6 +21,18 @@ namespace AutopilotMonitor.Functions.Security
     /// </remarks>
     public static class CertTenantBinding
     {
+        /// <summary>
+        /// <see cref="Microsoft.Azure.Functions.Worker.FunctionContext"/> item key under which
+        /// <c>SecurityValidator</c> hands the outcome to <c>RequestTelemetryMiddleware</c>, which
+        /// stamps it onto the request row as the <c>CertTenantBinding</c> dimension.
+        /// </summary>
+        /// <remarks>
+        /// The request row is the carrier because worker-side <c>LogInformation</c> never reaches
+        /// App Insights (the provider's default rule is Warning+), so the bulk "Match" outcome
+        /// cannot be observed as a trace and the shadow telemetry would have no denominator.
+        /// </remarks>
+        public const string RequestItemKey = "CertTenantBinding";
+
         /// <summary>
         /// Stable outcome codes emitted in the <c>AgentCertTenantBinding</c> structured log.
         /// Keep these strings stable — they are queried by exact match in KQL

src/Backend/AutopilotMonitor.Functions/Security/CertificateValidator.cs

@@ -139,8 +139,7 @@ namespace AutopilotMonitor.Functions.Security
                     if (cached.ExpiresAt > DateTime.UtcNow)
                     {
                         logger?.LogDebug($"Certificate validation cache HIT for thumbprint {thumbprint}");
-                        // Copy so FromCache is per-call state and never mutates the shared cached instance.
-                        return cached.Result.AsCacheHit();
+                        return cached.Result;
                     }
                     else
                     {
@@ -425,28 +424,6 @@ namespace AutopilotMonitor.Functions.Security
         /// </summary>
         public CertTenantIdStatus CertTenantIdStatus { get; set; }
 
-        /// <summary>
-        /// True when this result was served from the 5-minute thumbprint cache rather than freshly
-        /// validated. Used to sample per-request observability down to roughly one line per
-        /// certificate per cache window.
-        /// </summary>
-        public bool FromCache { get; set; }
-
-        /// <summary>
-        /// Returns a copy of this result marked as a cache hit, so the shared cached instance is
-        /// never mutated by a caller.
-        /// </summary>
-        internal CertificateValidationResult AsCacheHit() => new()
-        {
-            IsValid = IsValid,
-            Thumbprint = Thumbprint,
-            Subject = Subject,
-            Issuer = Issuer,
-            ErrorMessage = ErrorMessage,
-            CertTenantId = CertTenantId,
-            CertTenantIdStatus = CertTenantIdStatus,
-            FromCache = true
-        };
     }
 
     /// <summary>

src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs

@@ -527,12 +527,17 @@ namespace AutopilotMonitor.Functions.Security
         /// changes no state: enforcement is stage 2, after this telemetry shows the miss rate.
         /// </summary>
         /// <remarks>
-        /// Volume control: outcomes that need enforcement decisions (mismatch, missing or
-        /// undecodable extension) are always logged — they are expected to be rare and each one is
-        /// individually interesting. The bulk "Match" case is logged only when the certificate was
-        /// freshly validated rather than served from the 5-minute thumbprint cache, which samples it
-        /// down to roughly one line per certificate per cache window while keeping the ratio between
-        /// numerator and denominator meaningful (both are counted per cert-window, not per request).
+        /// Two carriers, because they answer different questions and have different costs:
+        /// <list type="bullet">
+        /// <item><description>Every outcome is stamped onto the request row via
+        /// <see cref="CertTenantBinding.RequestItemKey"/>. That row already exists per request and is
+        /// unsampled, so the denominator ("how many requests matched") costs no extra telemetry.
+        /// A trace line could not do this: worker-side <c>LogInformation</c> never reaches App
+        /// Insights, so the bulk "Match" case would simply be invisible.</description></item>
+        /// <item><description>Outcomes that need an enforcement decision (mismatch, missing or
+        /// undecodable extension) are additionally logged at Warning with the full context —
+        /// thumbprint, cert tenant, session — because each one is individually actionable.</description></item>
+        /// </list>
         /// </remarks>
         private void ObserveCertTenantBinding(
             CertificateValidationResult certValidation,
@@ -547,7 +552,13 @@ namespace AutopilotMonitor.Functions.Security
                     certValidation.CertTenantIdStatus,
                     tenantId);
 
-                if (outcome == CertTenantBinding.Outcome.Match && certValidation.FromCache)
+                // Denominator: rides along on the request row for every outcome, including Match.
+                var items = req.FunctionContext?.Items;
+                if (items != null)
+                    items[CertTenantBinding.RequestItemKey] = outcome;
+
+                // Everything below is the detail record for outcomes someone has to act on.
+                if (outcome == CertTenantBinding.Outcome.Match)
                     return;
 
                 var agentVersion = req.Headers.Contains("X-Agent-Version")
@@ -564,18 +575,9 @@ namespace AutopilotMonitor.Functions.Security
                 var certTenant = certValidation.CertTenantId?.ToString() ?? "n/a";
                 var wouldReject = CertTenantBinding.WouldRejectUnderEnforcement(outcome);
 
-                if (outcome == CertTenantBinding.Outcome.Match)
-                {
-                    _logger.LogInformation(template,
-                        outcome, false, wouldReject, tenantId, certTenant, certValidation.CertTenantIdStatus,
-                        certValidation.Thumbprint ?? "n/a", sessionId ?? "n/a", agentVersion);
-                }
-                else
-                {
-                    _logger.LogWarning(template,
-                        outcome, false, wouldReject, tenantId, certTenant, certValidation.CertTenantIdStatus,
-                        certValidation.Thumbprint ?? "n/a", sessionId ?? "n/a", agentVersion);
-                }
+                _logger.LogWarning(template,
+                    outcome, false, wouldReject, tenantId, certTenant, certValidation.CertTenantIdStatus,
+                    certValidation.Thumbprint ?? "n/a", sessionId ?? "n/a", agentVersion);
             }
             catch (Exception ex)
             {