From bf6850dedcc901cce3db4458d224bab2310fb1fa Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Mon, 24 Aug 2026 20:18:57 +0200 Subject: [PATCH] perf(security): log DevPrep association shadow once per lookup, not per request Same gate the cert-device-binding shadow got in 35a3ed0c, applied to its sibling. Measured on the live enrollment: 263 identical shadow lines for one device off a handful of Graph calls, because the cache answered nearly every request and the log sat outside it. DeviceAssociationResult.AsCacheHit() copies rather than marking the shared cached instance, so the first real lookup is never mistaken for a cache hit and dropped. Transient outcomes are not cached and keep logging every time. Backend 4633/4633, 0 warnings. Co-Authored-By: Claude Opus 5 (1M context) --- docs/log.md | 2 + .../DeviceAssociationValidatorTests.cs | 43 +++++++++++++++++++ .../Security/DeviceAssociationResult.cs | 29 ++++++++++++- .../Security/DeviceAssociationValidator.cs | 4 +- .../Security/SecurityValidator.cs | 8 ++++ 5 files changed, 83 insertions(+), 3 deletions(-) diff --git a/docs/log.md b/docs/log.md index 69d6f248..9963383a 100644 --- a/docs/log.md +++ b/docs/log.md @@ -2,6 +2,8 @@ ## 2026-08-24 +* **Change**: `DeviceAssociationValidator` / `SecurityValidator` — the DevPrep association shadow now logs one line per real Graph lookup instead of one per request (`DeviceAssociationResult.ServedFromCache`, `AsCacheHit()` copies rather than marking the shared cached instance), the same gate the cert-device-binding shadow uses. Measured: one enrollment produced 263 identical lines off a handful of calls. Status of that preview, for the record: the `/beta/deviceManagement/tenantAssociatedDevices` endpoint answers (6 calls, all HTTP 200, `transient=False`), but every result so far is `matched=False` from a single Autopilot **v1** device — which is the correct answer for a device that was never part of a Device Preparation policy. The matching itself is therefore still unproven, and the endpoint remains undocumented in both v1.0 and beta Graph reference, so it is not a basis for enforcement. + * **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`. diff --git a/src/Backend/AutopilotMonitor.Functions.Tests/DeviceAssociationValidatorTests.cs b/src/Backend/AutopilotMonitor.Functions.Tests/DeviceAssociationValidatorTests.cs index 4cc5fa35..2c712634 100644 --- a/src/Backend/AutopilotMonitor.Functions.Tests/DeviceAssociationValidatorTests.cs +++ b/src/Backend/AutopilotMonitor.Functions.Tests/DeviceAssociationValidatorTests.cs @@ -127,4 +127,47 @@ public class DeviceAssociationValidatorTests Assert.True(result.IsValid); } + [Fact] + public void AsCacheHit_FlagsTheCopyAndLeavesTheCachedInstanceAlone() + { + // The cached instance is shared across every request for that serial. Marking it in place + // would make the first (real) lookup look cached too, and the shadow log gate would then + // drop the one line per lookup that carries the finding. + var cached = new DeviceAssociationResult + { + IsValid = true, + SerialNumber = Serial, + AssociationState = "preassociated", + DevicePreparationPolicyId = "11111111-2222-3333-4444-555555555555", + AssignedToUserPrincipalName = "someone@example.invalid", + ManagedDeviceId = "66666666-7777-8888-9999-000000000000", + }; + + var hit = cached.AsCacheHit(); + + Assert.True(hit.ServedFromCache); + Assert.False(cached.ServedFromCache); + Assert.NotSame(cached, hit); + + // Every field the shadow log reports must survive the copy. + Assert.Equal(cached.IsValid, hit.IsValid); + Assert.Equal(cached.IsTransient, hit.IsTransient); + Assert.Equal(cached.SerialNumber, hit.SerialNumber); + Assert.Equal(cached.AssociationState, hit.AssociationState); + Assert.Equal(cached.DevicePreparationPolicyId, hit.DevicePreparationPolicyId); + Assert.Equal(cached.AssignedToUserPrincipalName, hit.AssignedToUserPrincipalName); + Assert.Equal(cached.ManagedDeviceId, hit.ManagedDeviceId); + } + + [Fact] + public void FreshlyParsedResult_IsNotFlaggedAsCached() + { + // A result straight from a Graph response must be loggable — that is the one line per lookup. + var body = $@"{{""value"":[{{""serialNumber"":""{Serial}"",""associationState"":""preassociated""}}]}}"; + + var result = DeviceAssociationValidator.ParseTenantAssociatedDevicesResponse(body, Serial); + + Assert.False(result.ServedFromCache); + } + } diff --git a/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationResult.cs b/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationResult.cs index 379e53fa..554b550a 100644 --- a/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationResult.cs +++ b/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationResult.cs @@ -1,4 +1,4 @@ -using System; +using System; namespace AutopilotMonitor.Functions.Security { @@ -55,5 +55,32 @@ namespace AutopilotMonitor.Functions.Security public string? ManagedDeviceId { get; set; } public string? ErrorMessage { get; set; } + + /// + /// True when this result came from the in-memory cache rather than a fresh Graph lookup. + /// The shadow log uses it to emit one line per real lookup instead of one per request: + /// a single enrollment produced 263 identical lines off a handful of Graph calls. + /// + 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 DeviceAssociationResult AsCacheHit() => new() + { + IsValid = IsValid, + IsTransient = IsTransient, + SerialNumber = SerialNumber, + AssociationState = AssociationState, + DevicePreparationPolicyId = DevicePreparationPolicyId, + PreAssociatedByUserPrincipalName = PreAssociatedByUserPrincipalName, + AssignedToUserPrincipalName = AssignedToUserPrincipalName, + PreAssociationDateTime = PreAssociationDateTime, + AssociationDateTime = AssociationDateTime, + ManagedDeviceId = ManagedDeviceId, + ErrorMessage = ErrorMessage, + ServedFromCache = true + }; } } diff --git a/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationValidator.cs b/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationValidator.cs index 2b2c6866..d609d7f2 100644 --- a/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationValidator.cs +++ b/src/Backend/AutopilotMonitor.Functions/Security/DeviceAssociationValidator.cs @@ -1,4 +1,4 @@ -using AutopilotMonitor.Shared; +using AutopilotMonitor.Shared; using System; using System.Linq; using System.Net.Http; @@ -63,7 +63,7 @@ namespace AutopilotMonitor.Functions.Security if (_cache.TryGetValue(cacheKey, out DeviceAssociationResult? cached) && cached != null) { - return cached; + return cached.AsCacheHit(); } const int maxAttempts = 2; diff --git a/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs b/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs index a849f4c9..581cce6d 100644 --- a/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs +++ b/src/Backend/AutopilotMonitor.Functions/Security/SecurityValidator.cs @@ -453,6 +453,14 @@ namespace AutopilotMonitor.Functions.Security try { var devPrepResult = await validator.LookupAsync(capturedTenant, capturedSerial, capturedSession); + + // One line per real Graph lookup, not per request — the same gate the + // cert-device-binding shadow uses. Measured 2026-08-24: a single enrollment + // produced 263 identical lines because the cache answered nearly every + // request. Uncached outcomes (transient failures) still log every time. + if (devPrepResult.ServedFromCache) + return; + logger.LogWarning( "DevPrep association lookup (shadow) for tenant {TenantId}, session {SessionId}, serial {SerialNumber}: matched={Matched}, transient={Transient}, state={State}, policy={PolicyId}", capturedTenant, capturedSession ?? "", capturedSerial,