diff --git a/docs/backend/client-cert-tenant-binding.md b/docs/backend/client-cert-tenant-binding.md index 59378c66..6b67abc1 100644 --- a/docs/backend/client-cert-tenant-binding.md +++ b/docs/backend/client-cert-tenant-binding.md @@ -129,6 +129,19 @@ Outcomes: `Match`, `NotFound`, `NoDeviceIdInCert`, `PermissionMissing`, `Transie `Transient` is retried and left uncached — a missing grant or a foreign device is a state, not an outage. +Graph cost is not a concern, and that is measured rather than assumed: the first live enrollment +produced **136 requests and exactly one Graph call**, because the 30-minute positive cache absorbs +the rest. For comparison, the per-request Autopilot serial validator made 25 calls in the same +window. Lengthening the positive TTL would buy nothing and would delay noticing a device that has +been wiped or removed; shortening the 5-minute negative TTL matters more, since that is how quickly +a device object appearing late is picked up. + +What the 136 requests *did* cost was log lines saying the same thing 136 times, so the shadow log is +gated on `IntuneDeviceBindingResult.ServedFromCache`: one line per real Graph lookup. Cached repeats +add nothing — the reported age just counts up mechanically from the same `enrolledDateTime`. +Outcomes that are never cached (`Transient`, `NoDeviceIdInCert`) still log every time, which is the +right behaviour for an anomaly. + The open question this preview exists to answer is a race, not an attack: a device object can in principle appear in Intune *after* the agent's first call, and enforcing before that is understood would reject legitimate enrollments. Every result therefore carries `enrolledDateTime`, and the log diff --git a/docs/log.md b/docs/log.md index ecd2fe02..69d6f248 100644 --- a/docs/log.md +++ b/docs/log.md @@ -2,6 +2,8 @@ ## 2026-08-24 +* **Update**: `backend/client-cert-tenant-binding.md` — stage 3 verified live (`ea6a375`, gktatooine): 136 requests, all `Match`, device object ~72 s older than the session start, so no enrollment race in that run. Measured Graph cost: **1 call for 136 requests** (30 min positive cache), versus 25 for the per-request Autopilot validator — the positive TTL needs no change. The shadow log is now gated on `ServedFromCache` (one line per real lookup instead of per request); never-cached outcomes still log every time. + * **Update**: `backend/client-cert-tenant-binding.md` — stage 3, the cert-to-device binding: new `IntuneDeviceBindingValidator` resolves the Subject-CN managedDevice id against the tenant's own `deviceManagement/managedDevices` (point-GET, no filter literal), modelled on `CloudPcDeviceValidator` and wired fire-and-forget like the DevPrep shadow so a cold Graph round-trip never enters the agent request path. New GA-only tenant toggle `ValidateIntuneDeviceBinding` (shadow — never touches `deviceValidated`), new optional Graph feature `IntuneDeviceBinding` → `DeviceManagementManagedDevices.Read.All` in `GraphFeatureCatalog` + the customer grant script, and `enrolledAgeSeconds` on every log line so the enrollment race can be measured before this could ever become a gate. Grep marker: `CERT-DEVICE-BINDING-SHADOW`. * **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. diff --git a/src/Backend/AutopilotMonitor.Functions.Tests/IntuneDeviceBindingValidatorTests.cs b/src/Backend/AutopilotMonitor.Functions.Tests/IntuneDeviceBindingValidatorTests.cs index 86f9a3b5..86126fe2 100644 --- a/src/Backend/AutopilotMonitor.Functions.Tests/IntuneDeviceBindingValidatorTests.cs +++ b/src/Backend/AutopilotMonitor.Functions.Tests/IntuneDeviceBindingValidatorTests.cs @@ -172,6 +172,46 @@ public class IntuneDeviceBindingValidatorTests Assert.False(result.IsValid); } + [Fact] + public void AsCacheHit_FlagsTheCopyAndLeavesTheCachedInstanceAlone() + { + // The cached instance is shared across every request for that device. Marking it in place + // would make the first (real) lookup look cached too, and the log gate would then drop the + // one line per lookup we actually want to keep. + var cached = new IntuneDeviceBindingResult + { + Outcome = IntuneDeviceBindingOutcome.Match, + IntuneDeviceId = DeviceId, + DeviceName = "TEST-DEVICE-01", + EnrolledDateTime = new DateTimeOffset(2026, 8, 24, 16, 51, 0, TimeSpan.Zero), + }; + + var hit = cached.AsCacheHit(); + + Assert.True(hit.ServedFromCache); + Assert.False(cached.ServedFromCache); + Assert.NotSame(cached, hit); + + // Everything the log line reports must survive the copy. + Assert.Equal(cached.Outcome, hit.Outcome); + Assert.Equal(cached.IntuneDeviceId, hit.IntuneDeviceId); + Assert.Equal(cached.DeviceName, hit.DeviceName); + Assert.Equal(cached.EnrolledDateTime, hit.EnrolledDateTime); + } + + [Fact] + public void FreshResult_IsNotFlaggedAsCached() + { + // A freshly parsed Graph response must be loggable — that is the one line per lookup. + var body = $$""" + { "id": "{{DeviceId}}", "deviceName": "TEST-DEVICE-01" } + """; + + var result = IntuneDeviceBindingValidator.ParseManagedDeviceResponse(body, DeviceId); + + Assert.False(result.ServedFromCache); + } + [Fact] public void TransientOutcome_IsNeitherValidNorDefinitive() { diff --git a/src/Backend/AutopilotMonitor.Functions/Security/IntuneDeviceBindingValidator.cs b/src/Backend/AutopilotMonitor.Functions/Security/IntuneDeviceBindingValidator.cs index 72da2791..2793f4d9 100644 --- a/src/Backend/AutopilotMonitor.Functions/Security/IntuneDeviceBindingValidator.cs +++ b/src/Backend/AutopilotMonitor.Functions/Security/IntuneDeviceBindingValidator.cs @@ -82,7 +82,7 @@ namespace AutopilotMonitor.Functions.Security var cacheKey = BuildCacheKey(tenantId, normalizedId); if (_cache.TryGetValue(cacheKey, out IntuneDeviceBindingResult? cached) && cached != null) - return cached; + return cached.AsCacheHit(); const int maxAttempts = 2; IntuneDeviceBindingResult? lastTransient = null; @@ -324,5 +324,29 @@ namespace AutopilotMonitor.Functions.Security public DateTimeOffset? EnrolledDateTime { get; set; } public string? ErrorMessage { get; set; } + + /// + /// True when this result came from the in-memory cache rather than a fresh Graph lookup. + /// Callers use it to log once per real lookup instead of once per request: a single + /// enrollment produced 136 requests but only one Graph call, so logging per request said + /// the same thing 136 times. + /// + public bool ServedFromCache { get; set; } + + /// + /// Copy of this result marked as a cache hit, so the shared cached instance is never + /// mutated by a caller. + /// + internal IntuneDeviceBindingResult AsCacheHit() => new() + { + Outcome = Outcome, + IntuneDeviceId = IntuneDeviceId, + DeviceName = DeviceName, + AzureAdDeviceId = AzureAdDeviceId, + ManagementState = ManagementState, + EnrolledDateTime = EnrolledDateTime, + ErrorMessage = ErrorMessage, + ServedFromCache = true + }; } } diff --git a/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs b/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs index 36395894..a849f4c9 100644 --- a/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs +++ b/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs @@ -495,6 +495,16 @@ namespace AutopilotMonitor.Functions.Security TryGetIntuneDeviceIdFromCertSubject(bindingSubject, out var certDeviceId); var binding = await bindingValidator.ValidateAsync(bindingTenant, certDeviceId, bindingSession); + // One line per real Graph lookup, not per request. Measured on the first + // live enrollment: 136 requests produced exactly ONE Graph call (the 30 min + // positive cache did its job), so per-request logging repeated the same + // finding 136 times. Cached repeats add nothing - the age just counts up + // mechanically from the same enrolledDateTime. Uncached outcomes + // (Transient, NoDeviceIdInCert) still log every time, which is what we want + // for anomalies. + if (binding.ServedFromCache) + return; + // Age of the device object at request time: the discriminator between a // genuine enrollment race (object created moments ago, or not yet) and a // certificate that never belonged to this tenant.