From fa3187290351fdd5527916de9f0305fc9bde6128 Mon Sep 17 00:00:00 2001 From: Oliver Kieselbach Date: Thu, 10 Sep 2026 01:55:31 +0200 Subject: [PATCH] fix(agent,engine,web): keep the due time as the deadline stamp; draw timeout verdicts hollow in the Network Timeline (D-238 revised) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Revises 14b185db after the pre-release review. The fleet measurement (30 days, all tenants) showed 87 of 821 sessions with a sleep episode had their verdict inside the episode — 59 of them one tenant's self-deploying devices closed two minutes before the device-only detection came due and reopened 5–7 days later. Stamping the firing clock would have turned those outages into session duration and pushed the tenant's mean duration from minutes to days. - OnDeadlineFired posts OccurredAtUtc = DueAtUtc again; the due time stays in the payload and the two stale-fire guards keep reading it (any stamp stays safe). - Network Timeline: a timeout verdict (helloOutcome timeout, device-only detection window) is drawn as a hollow marker "Completed (timeout)" with a legend line and a plain-language tooltip — a wait expired, nothing observed on the device; the Asleep block is never split at it. finalizing_grace alone is not an indicator. - Session Info standby note clips to the two WhiteGlove spans when the card shows the combined WhiteGlove duration; the dedup key is consumed only by a usable observation (review findings). - Stale comments describing the firing-clock contract corrected. Tests: DeadlineFireTimeStampTests (reducer stays correct for any stamp), EnrollmentOrchestratorTests (due-time stamp + payload), networkTimelineModel timeout markers (3), standby windows, WhiteGlove windows. Co-Authored-By: Claude Fable 5.1 --- internal | 2 +- .../EnrollmentOrchestratorTests.cs | 10 ++-- .../Orchestration/DeadlineFiredEventArgs.cs | 11 ++-- .../Orchestration/EnrollmentOrchestrator.cs | 13 +++-- .../Orchestration/IDeadlineScheduler.cs | 3 +- .../DeadlineFireTimeStampTests.cs | 19 ++++--- .../RealmJoinGateTests.cs | 2 +- .../SelfDeployingDeadlineTerminalTests.cs | 7 +-- .../sessions/hooks/useSessionDerivedData.ts | 33 ++++++------ .../sessions/network-timeline/NetworkBand.tsx | 15 +++++- .../__tests__/networkTimelineModel.test.ts | 46 +++++++++++++++++ .../network-timeline/networkTimelineModel.ts | 39 +++++++++++---- .../app/sessions/utils/eventHelpers.ts | 23 +++++++-- .../lib/__tests__/standby.test.ts | 50 ++++++++++++------- .../lib/__tests__/whiteGloveDurations.test.ts | 3 ++ src/Web/autopilot-monitor-web/lib/standby.ts | 44 ++++++++++------ 16 files changed, 222 insertions(+), 98 deletions(-) diff --git a/internal b/internal index 398d32a4..6c79026c 160000 --- a/internal +++ b/internal @@ -1 +1 @@ -Subproject commit 398d32a48bd2f0fabca8746ab17272357a1d7241 +Subproject commit 6c79026c33bb9d7cd305117a1c9654d5c9e98150 diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/EnrollmentOrchestratorTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/EnrollmentOrchestratorTests.cs index 14822ce3..84619da5 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/EnrollmentOrchestratorTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Orchestration/EnrollmentOrchestratorTests.cs @@ -266,12 +266,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration } [Fact] - public void Deadline_fired_late_is_stamped_with_the_firing_clock_and_carries_its_due_time() + public void Deadline_fired_late_keeps_the_due_time_as_stamp_and_carries_it_in_the_payload() { // A deadline that was due while the device slept (or the agent was down) fires only - // afterwards. The signal must carry the firing clock as OccurredAtUtc — that time - // stamps every effect of the step, and a due time inside the outage would place the - // verdict there — while the due time travels in the payload for the stale-fire guards. + // afterwards. The signal keeps the due time as OccurredAtUtc (D-238: the outage must not + // become session duration) and repeats it in the payload so the stale-fire guards + // identify the incarnation independently of the stamp. using var rig = new EnrollmentOrchestratorRig(At); var sut = rig.Build(); sut.Start(); @@ -293,7 +293,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration if (sig.Kind == DecisionSignalKind.DeadlineFired) { fired = sig; break; } } Assert.NotNull(fired); - Assert.Equal(At, fired!.OccurredAtUtc); + Assert.Equal(dueAt, fired!.OccurredAtUtc); Assert.NotNull(fired.Payload); Assert.Equal("hello_safety", fired.Payload![SignalPayloadKeys.Deadline]); Assert.Equal(dueAt.ToString("O"), fired.Payload[SignalPayloadKeys.DeadlineDueAtUtc]); diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DeadlineFiredEventArgs.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DeadlineFiredEventArgs.cs index 0033a8ce..3df4a9c1 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DeadlineFiredEventArgs.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/DeadlineFiredEventArgs.cs @@ -9,10 +9,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration /// /// The orchestrator consumes this event and translates it into a synthetic /// DeadlineFired- - /// whose OccurredAtUtc is — the moment the agent actually - /// decided — and whose payload carries the deadline's . - /// A timer that was due during Modern Standby or a reboot fires only afterwards; stamping - /// the due time instead would date the verdict into the outage. + /// whose OccurredAtUtc equals the deadline's + /// (the policy instant the wait expired), with the due time repeated in the payload. The + /// firing clock is deliberately NOT the stamp: a timer due during Modern Standby or a + /// reboot fires only afterwards, and the outage would otherwise become session duration + /// (D-238). /// /// public sealed class DeadlineFiredEventArgs : EventArgs @@ -25,7 +26,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration public ActiveDeadline Deadline { get; } - /// Wall-clock time the timer fired; becomes the signal's OccurredAtUtc. + /// Wall-clock time the event was raised. For observability; does NOT influence the signal's OccurredAtUtc. public DateTime FiredAtUtc { get; } } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs index b2d4a618..a63d0185 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/EnrollmentOrchestrator.cs @@ -1181,15 +1181,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration payload[SignalPayloadKeys.Deadline] = e.Deadline.Name; } - // OccurredAtUtc = the firing clock, never DueAtUtc: every effect of the resulting - // step (phase_transition, enrollment_complete) is stamped with the signal time, and a - // due time that passed during Modern Standby or a reboot would place the verdict - // inside the outage. The due time travels in the payload for the stale-fire guards. + // OccurredAtUtc = DueAtUtc, not the firing clock (D-238). Every effect of the + // resulting step (phase_transition, enrollment_complete) is stamped with the signal + // time; a timer that came due during Modern Standby or a reboot fires only afterwards, + // and the firing clock would make the verdict — and the session duration — grow by + // the whole outage (measured: days for devices closed right after provisioning). + // The due time also travels in the payload so the stale-fire guards identify the + // deadline incarnation independently of the stamp. payload[SignalPayloadKeys.DeadlineDueAtUtc] = e.Deadline.DueAtUtc.ToString("O", CultureInfo.InvariantCulture); _ingress.Post( kind: DecisionSignalKind.DeadlineFired, - occurredAtUtc: e.FiredAtUtc, + occurredAtUtc: e.Deadline.DueAtUtc, sourceOrigin: "DeadlineScheduler", evidence: evidence, payload: payload); diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/IDeadlineScheduler.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/IDeadlineScheduler.cs index 4d7d558e..394d081a 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/IDeadlineScheduler.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Orchestration/IDeadlineScheduler.cs @@ -39,7 +39,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration /// /// Wird vom Timer-Thread geraised, wenn ein Deadline fällig wird. Subscriber /// ist typischerweise der Orchestrator, der daraus ein synthetisches - /// DeadlineFired-Signal mit OccurredAtUtc = deadline.DueAtUtc erzeugt. + /// DeadlineFired-Signal mit OccurredAtUtc = deadline.DueAtUtc erzeugt; die + /// Fälligkeit reist zusätzlich im Payload (SignalPayloadKeys.DeadlineDueAtUtc). /// event EventHandler? Fired; diff --git a/src/Agent/AutopilotMonitor.DecisionCore.Tests/DeadlineFireTimeStampTests.cs b/src/Agent/AutopilotMonitor.DecisionCore.Tests/DeadlineFireTimeStampTests.cs index 2c3729e5..847e1a00 100644 --- a/src/Agent/AutopilotMonitor.DecisionCore.Tests/DeadlineFireTimeStampTests.cs +++ b/src/Agent/AutopilotMonitor.DecisionCore.Tests/DeadlineFireTimeStampTests.cs @@ -10,14 +10,12 @@ using Xunit; namespace AutopilotMonitor.DecisionCore.Tests { /// - /// A DeadlineFired signal is stamped with the wall-clock firing time, not the due - /// time: a deadline due during Modern Standby or a reboot fires only afterwards, and every - /// effect of the resulting step (phase_transition, enrollment_complete) inherits the signal - /// time — a due-time stamp would date the verdict into the outage (session ac5660b8, - /// "Completed" drawn inside the Asleep block). The due time travels in the payload under - /// for the stale-fire guards that identify - /// the deadline incarnation; without the key they fall back to the signal time (pre-key - /// signal logs, where the two were equal by contract). + /// The reducer identifies a deadline incarnation through the due time carried in the + /// payload (), never through the signal + /// time: the host stamps DeadlineFired with the due time (D-238), but the guards + /// must stay correct for any stamp — a late fire after Modern Standby or a restart, a + /// replayed signal, or a future switch to the firing clock. Without the key they fall back + /// to the signal time (pre-key signal logs, where the two were equal by contract). /// public sealed class DeadlineFireTimeStampTests { @@ -74,8 +72,9 @@ namespace AutopilotMonitor.DecisionCore.Tests { // Session ac5660b8 shape: ESP exits, the user leaves the device at the Hello prompt, it // enters Modern Standby, HelloSafety is due during the sleep and fires ~3 min late after - // wake. The Hello timeout fact, the Finalizing step and the FinalizingGrace due time must - // all sit at the firing clock — never inside the sleep window. + // wake. Fed with the firing clock as signal time, the reducer must stamp the Hello + // timeout fact, the Finalizing step and the FinalizingGrace due time from that time — + // the stamp policy is the host's choice (D-238), the reducer follows the signal. var engine = new DecisionEngine(); var state = DecisionState.CreateInitial("sess-standby", "tenant", T0); state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0)).NewState; diff --git a/src/Agent/AutopilotMonitor.DecisionCore.Tests/RealmJoinGateTests.cs b/src/Agent/AutopilotMonitor.DecisionCore.Tests/RealmJoinGateTests.cs index 73d0475e..2cea329c 100644 --- a/src/Agent/AutopilotMonitor.DecisionCore.Tests/RealmJoinGateTests.cs +++ b/src/Agent/AutopilotMonitor.DecisionCore.Tests/RealmJoinGateTests.cs @@ -706,7 +706,7 @@ namespace AutopilotMonitor.DecisionCore.Tests var deadline = Assert.Single(signalStep.NewState.Deadlines, d => d.Name == DeadlineNames.DeviceOnlyEspDetection); Assert.Equal(T0.AddMinutes(7), deadline.DueAtUtc); - // DeadlineFired (OccurredAtUtc = DueAtUtc per scheduler contract) → terminal. + // DeadlineFired at the due time (no payload due key → helper falls back to the signal time) → terminal. var step = engine.Reduce(signalStep.NewState, MakeSignal(3, DecisionSignalKind.DeadlineFired, T0.AddMinutes(7), new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.DeviceOnlyEspDetection })); diff --git a/src/Agent/AutopilotMonitor.DecisionCore.Tests/SelfDeployingDeadlineTerminalTests.cs b/src/Agent/AutopilotMonitor.DecisionCore.Tests/SelfDeployingDeadlineTerminalTests.cs index d13ce094..dc0b584b 100644 --- a/src/Agent/AutopilotMonitor.DecisionCore.Tests/SelfDeployingDeadlineTerminalTests.cs +++ b/src/Agent/AutopilotMonitor.DecisionCore.Tests/SelfDeployingDeadlineTerminalTests.cs @@ -443,8 +443,9 @@ namespace AutopilotMonitor.DecisionCore.Tests { // Cancel-then-rearm race: old deadline (DueAt=T+8) fires queued; before processing, // DeviceSetupProvisioningComplete arrives (signal at T+10) → cancel+rearm to DueAt=T+15. - // The queued OLD fire (OccurredAtUtc=T+8) arrives. Guard C must dead-end WITHOUT - // cancelling the new deadline. + // The queued OLD fire arrives carrying its due time T+8 (no payload key here, so the + // helper falls back to the signal time). Guard C must dead-end WITHOUT cancelling the + // new deadline. var engine = new DecisionEngine(); var state = PrimeDeviceSetup(engine, DecisionState.CreateInitial("sd-11", "t", T0)); @@ -467,7 +468,7 @@ namespace AutopilotMonitor.DecisionCore.Tests firesPayload: new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.DeviceOnlyEspDetection })); state = rearmedBuilder.Build(); - // OLD queued fire arrives with OccurredAtUtc=T+8 — mismatches new deadline at T+15. + // OLD queued fire arrives with due time T+8 — mismatches the new deadline at T+15. var step = engine.Reduce(state, MakeSignal(99, DecisionSignalKind.DeadlineFired, T0.AddMinutes(8), new Dictionary { [SignalPayloadKeys.Deadline] = DeadlineNames.DeviceOnlyEspDetection })); diff --git a/src/Web/autopilot-monitor-web/app/sessions/hooks/useSessionDerivedData.ts b/src/Web/autopilot-monitor-web/app/sessions/hooks/useSessionDerivedData.ts index fb7b9595..d8284e40 100644 --- a/src/Web/autopilot-monitor-web/app/sessions/hooks/useSessionDerivedData.ts +++ b/src/Web/autopilot-monitor-web/app/sessions/hooks/useSessionDerivedData.ts @@ -5,6 +5,7 @@ import { EnrollmentEvent, Session } from "@/types"; import { V1_PHASE_NAMES, V2_PHASE_NAMES, V1_PHASE_ORDER, V2_PHASE_ORDER } from "../utils/phaseConstants"; import { detectSkipUserStatusPage } from "../utils/espConfig"; import { computeWhiteGloveDurations, computeWhiteGloveSplitSequence, groupEventsByPhase } from "../utils/eventHelpers"; +import type { WhiteGloveDurations } from "../utils/eventHelpers"; import { sumStandbySeconds } from "@/lib/standby"; interface PhaseGrouping { @@ -36,11 +37,7 @@ export interface UseSessionDerivedDataReturn { whiteGloveSplitSequence: number; preProvEvents: EnrollmentEvent[]; userEnrollEvents: EnrollmentEvent[]; - whiteGloveDurations: { - preProvDuration: string | null; - userEnrollDuration: string | null; - combinedDuration: string | null; - }; + whiteGloveDurations: WhiteGloveDurations; eventsByPhase: Record; orderedPhases: string[]; preProvGrouped: PhaseGrouping; @@ -177,15 +174,6 @@ export function useSessionDerivedData( return max; }, [events, sessionLastEventAt]); - // Sleep/standby seconds inside the enrollment window above (system_sleep_episode ground - // truth). The wall-clock duration deliberately keeps the pause — this number tells the story - // next to it ("1h 20m, 56m of it standby") and is clipped to the same window so the two agree - // with the time-attribution chip; sleep after the verdict is not enrollment time. - const standbySeconds = useMemo( - () => sumStandbySeconds(events, enrollmentWindow?.startMs ?? null, enrollmentWindow?.endMs ?? null), - [events, enrollmentWindow], - ); - const phaseNamesMap = session?.enrollmentType === "v2" ? V2_PHASE_NAMES : V1_PHASE_NAMES; const phaseOrder = session?.enrollmentType === "v2" ? V2_PHASE_ORDER : V1_PHASE_ORDER; @@ -221,13 +209,26 @@ export function useSessionDerivedData( // Compute per-block durations for WhiteGlove sessions (using unfiltered events for accuracy). // Duration 1 = pre-provisioning, Duration 2 = user enrollment, combined = D1 + D2 (pause excluded). - const whiteGloveDurations = useMemo(() => { + const whiteGloveDurations = useMemo(() => { if (!isWhiteGloveSession) { - return { preProvDuration: null as string | null, userEnrollDuration: null as string | null, combinedDuration: null as string | null }; + return { preProvDuration: null, userEnrollDuration: null, combinedDuration: null, preProvWindowMs: null, userEnrollWindowMs: null }; } return computeWhiteGloveDurations(events, whiteGloveSplitSequence, session?.startedAt); }, [events, isWhiteGloveSession, whiteGloveSplitSequence, session?.startedAt]); + // Sleep/standby seconds inside the span(s) the Duration cell is measured over + // (system_sleep_episode ground truth): the two WhiteGlove parts when the card shows the + // combined WhiteGlove duration (the shelf pause between them contributes nothing), otherwise + // the enrollment window above. The wall-clock duration deliberately keeps the pause — this + // number tells the story next to it ("1h 20m, 56m of it standby") and, clipped to the same + // spans, agrees with the time-attribution chip; sleep after the verdict is not enrollment time. + const standbySeconds = useMemo(() => { + const windows = isWhiteGloveSession && whiteGloveDurations.combinedDuration + ? [whiteGloveDurations.preProvWindowMs, whiteGloveDurations.userEnrollWindowMs].filter((w): w is NonNullable => w !== null) + : enrollmentWindow ? [enrollmentWindow] : null; + return sumStandbySeconds(events, windows); + }, [events, enrollmentWindow, isWhiteGloveSession, whiteGloveDurations]); + // Group events by phase — single timeline for normal sessions, two groups for WhiteGlove const { eventsByPhase, orderedPhases } = useMemo(() => { if (isWhiteGloveSession) return { eventsByPhase: {} as Record, orderedPhases: [] as string[] }; diff --git a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/NetworkBand.tsx b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/NetworkBand.tsx index 6bb6da54..1e7f43d3 100644 --- a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/NetworkBand.tsx +++ b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/NetworkBand.tsx @@ -118,6 +118,14 @@ export default function NetworkBand({ model }: { model: NetworkModel }) { )} ))} + {lifeMarkers.some((m) => m.timeout) && ( + + + Verdict by timeout (a wait ran out; not an observed event) + + )} ✓ @@ -310,7 +318,12 @@ export default function NetworkBand({ model }: { model: NetworkModel }) { strokeWidth="1" className="text-gray-400" /> - + {m.timeout ? ( + // Hollow: a wait expired at this instant — nothing observed on the device. + + ) : ( + + )} {/* invisible enlarged hit target — the dot alone is hard to hover */} {showLabel && ( diff --git a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/__tests__/networkTimelineModel.test.ts b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/__tests__/networkTimelineModel.test.ts index 0c81e290..aef2f9b9 100644 --- a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/__tests__/networkTimelineModel.test.ts +++ b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/__tests__/networkTimelineModel.test.ts @@ -274,3 +274,49 @@ describe('location-gated WiFi payloads', () => { expect(withReading?.dataLimitedReason).toBeUndefined(); }); }); + +describe('timeout verdict markers', () => { + it('draws a Hello-timeout completion as a hollow timeout marker with a plain-language reason', () => { + // ac5660b8 shape: the completion is stamped at the instant the Hello wait ran out — a + // policy instant that fell into a sleep episode, not something the device did. + const events = [ + ethernetInfo(1, 0), + ev(2, 'system_sleep_episode', 12 * MIN, { + kind: 'modern_standby', + enteredAt: iso(7 * MIN), + exitedAt: iso(12 * MIN), + durationSeconds: 300, + }), + ev(3, 'enrollment_complete', 9 * MIN, { trigger: 'DeadlineFired:finalizing_grace', helloOutcome: 'Timeout' }), + ]; + const model = buildNetworkModel(session, events)!; + const marker = model.lifeMarkers.find((m) => m.label.startsWith('Completed')); + expect(marker?.label).toBe('Completed (timeout)'); + expect(marker?.timeout).toBe(true); + expect(marker?.detail).toContain('Windows Hello wait ran out'); + // The sleep block stays one segment — no wake is depicted at the marker. + expect(model.segments.filter((s) => s.kind === 'asleep')).toHaveLength(1); + }); + + it('keeps an observed completion as a plain marker even though the grace deadline delivered it', () => { + const events = [ + ethernetInfo(1, 0), + ev(2, 'enrollment_complete', 9 * MIN, { trigger: 'DeadlineFired:finalizing_grace', helloOutcome: 'Success' }), + ]; + const model = buildNetworkModel(session, events)!; + const marker = model.lifeMarkers.find((m) => m.label.startsWith('Completed')); + expect(marker?.label).toBe('Completed'); + expect(marker?.timeout).toBeUndefined(); + }); + + it('treats the device-only detection window as a timeout verdict', () => { + const events = [ + ethernetInfo(1, 0), + ev(2, 'enrollment_complete', 9 * MIN, { trigger: 'DeadlineFired:device_only_esp_detection' }), + ]; + const model = buildNetworkModel(session, events)!; + const marker = model.lifeMarkers.find((m) => m.label.startsWith('Completed')); + expect(marker?.label).toBe('Completed (timeout)'); + expect(marker?.detail).toContain('user phase'); + }); +}); diff --git a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/networkTimelineModel.ts b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/networkTimelineModel.ts index 08b025a3..1b97b1f3 100644 --- a/src/Web/autopilot-monitor-web/app/sessions/network-timeline/networkTimelineModel.ts +++ b/src/Web/autopilot-monitor-web/app/sessions/network-timeline/networkTimelineModel.ts @@ -79,6 +79,26 @@ export interface LifeMarker { label: string; /** Optional extra tooltip line (clock markers: old→new time, reason). */ detail?: string; + /** + * The verdict came from a wait that ran out (Hello wait, device-only detection), stamped at + * the wall-clock instant the wait expired — a policy instant, not something observed on the + * device, which may have been asleep. Drawn hollow so it never reads as an event. + */ + timeout?: boolean; +} + +/** Why a terminal verdict is a timeout verdict, in product words — or null when it was observed. */ +export function timeoutVerdictDetail(data: Record | undefined): string | null { + if (!data) return null; + const helloOutcome = typeof data.helloOutcome === 'string' ? data.helloOutcome.toLowerCase() : ''; + const trigger = typeof data.trigger === 'string' ? data.trigger : ''; + if (helloOutcome === 'timeout') { + return 'The Windows Hello wait ran out at this instant; nothing happened on the device here — the enrollment counted as complete from this moment.'; + } + if (trigger === 'DeadlineFired:device_only_esp_detection') { + return 'The wait for a user phase after device setup ran out at this instant; nothing happened on the device here — the enrollment counted as complete from this moment.'; + } + return null; } export interface NetworkModel { @@ -535,17 +555,14 @@ export function buildNetworkModel(session: Session, rawEvents: EnrollmentEvent[] .filter((e) => ['system_reboot_detected', 'desktop_arrived', 'enrollment_complete', 'enrollment_failed'].includes(e.eventType), ) - .map((e) => ({ - t: Date.parse(e.timestamp), - label: - e.eventType === 'system_reboot_detected' - ? 'Reboot' - : e.eventType === 'desktop_arrived' - ? 'Desktop' - : e.eventType === 'enrollment_complete' - ? 'Completed' - : 'Failed', - })) + .map((e): LifeMarker => { + const t = Date.parse(e.timestamp); + if (e.eventType === 'system_reboot_detected') return { t, label: 'Reboot' }; + if (e.eventType === 'desktop_arrived') return { t, label: 'Desktop' }; + const base = e.eventType === 'enrollment_complete' ? 'Completed' : 'Failed'; + const detail = timeoutVerdictDetail(e.data as Record | undefined); + return detail ? { t, label: `${base} (timeout)`, detail, timeout: true } : { t, label: base }; + }) .filter((m) => !isNaN(m.t)); // Clock-step markers: live steps sit at their corrected changepoint; diff --git a/src/Web/autopilot-monitor-web/app/sessions/utils/eventHelpers.ts b/src/Web/autopilot-monitor-web/app/sessions/utils/eventHelpers.ts index 9f49d1a0..68a88de2 100644 --- a/src/Web/autopilot-monitor-web/app/sessions/utils/eventHelpers.ts +++ b/src/Web/autopilot-monitor-web/app/sessions/utils/eventHelpers.ts @@ -83,10 +83,18 @@ export function computeWhiteGloveSplitSequence(events: EnrollmentEvent[]): numbe // Sequence is the canonical event order, so the block edges by sequence are the robust // span anchors. Part 1 additionally starts at session.startedAt (registration) when // provided — the same anchor the backend uses for DurationSeconds. +export interface TimeWindowMs { + startMs: number; + endMs: number; +} + export interface WhiteGloveDurations { preProvDuration: string | null; userEnrollDuration: string | null; combinedDuration: string | null; + /** The two spans the durations are measured over — the standby note clips to the same spans. */ + preProvWindowMs: TimeWindowMs | null; + userEnrollWindowMs: TimeWindowMs | null; } export function computeWhiteGloveDurations( @@ -97,8 +105,8 @@ export function computeWhiteGloveDurations( const preProvEvts = splitSequence < 0 ? events : events.filter(e => e.sequence <= splitSequence); const userEnrollEvts = splitSequence < 0 ? [] : events.filter(e => e.sequence > splitSequence); - const spanMs = (evts: EnrollmentEvent[], startOverrideMs?: number): number => { - if (evts.length === 0) return 0; + const span = (evts: EnrollmentEvent[], startOverrideMs?: number): TimeWindowMs | null => { + if (evts.length === 0) return null; let first = evts[0]; let last = evts[0]; for (const e of evts) { @@ -107,8 +115,9 @@ export function computeWhiteGloveDurations( } const start = startOverrideMs ?? new Date(first.timestamp).getTime(); const end = new Date(last.timestamp).getTime(); - return Math.max(0, end - start); + return { startMs: start, endMs: Math.max(start, end) }; }; + const spanMs = (w: TimeWindowMs | null): number => (w ? w.endMs - w.startMs : 0); const fmt = (ms: number): string | null => { const sec = Math.round(ms / 1000); @@ -119,13 +128,17 @@ export function computeWhiteGloveDurations( }; const startedAtMs = startedAt ? new Date(startedAt).getTime() : NaN; - const preProvMs = spanMs(preProvEvts, Number.isFinite(startedAtMs) ? startedAtMs : undefined); - const userEnrollMs = spanMs(userEnrollEvts); + const preProvWindowMs = span(preProvEvts, Number.isFinite(startedAtMs) ? startedAtMs : undefined); + const userEnrollWindowMs = span(userEnrollEvts); + const preProvMs = spanMs(preProvWindowMs); + const userEnrollMs = spanMs(userEnrollWindowMs); return { preProvDuration: fmt(preProvMs), userEnrollDuration: fmt(userEnrollMs), combinedDuration: fmt(preProvMs + userEnrollMs), + preProvWindowMs, + userEnrollWindowMs, }; } diff --git a/src/Web/autopilot-monitor-web/lib/__tests__/standby.test.ts b/src/Web/autopilot-monitor-web/lib/__tests__/standby.test.ts index 50d27356..2efc3e0d 100644 --- a/src/Web/autopilot-monitor-web/lib/__tests__/standby.test.ts +++ b/src/Web/autopilot-monitor-web/lib/__tests__/standby.test.ts @@ -4,14 +4,17 @@ import { sumStandbySeconds } from "../standby"; const T = (iso: string) => Date.parse(iso); -function sleepEpisode(seq: number, enteredAt: string, exitedAt: string, durationSeconds: number): EnrollmentEvent { +function sleepEpisode(seq: number, enteredAt: string | null, exitedAt: string | null, durationSeconds: number): EnrollmentEvent { + const data: Record = { kind: "modern_standby", durationSeconds }; + if (enteredAt) data.enteredAt = enteredAt; + if (exitedAt) data.exitedAt = exitedAt; return { eventType: "system_sleep_episode", source: "SystemTimelineWatcher", - timestamp: exitedAt, + timestamp: exitedAt ?? "2026-09-09T06:45:19Z", sequence: seq, message: "Device exited Modern Standby", - data: { kind: "modern_standby", enteredAt, exitedAt, durationSeconds }, + data, } as unknown as EnrollmentEvent; } @@ -20,42 +23,51 @@ describe("sumStandbySeconds", () => { const episode = sleepEpisode(163, "2026-09-09T06:40:28.6907161Z", "2026-09-09T06:45:19.0307161Z", 290); const windowStart = T("2026-09-09T06:32:46.772Z"); const completedAt = T("2026-09-09T06:42:55.2144855Z"); + const window = [{ startMs: windowStart, endMs: completedAt }]; it("clips an episode that straddles the end of the window", () => { - expect(sumStandbySeconds([episode], windowStart, completedAt)).toBe(147); + expect(sumStandbySeconds([episode], window)).toBe(147); }); it("counts the whole episode when it lies inside the window", () => { - expect(sumStandbySeconds([episode], windowStart, T("2026-09-09T06:45:49Z"))).toBe(290); + expect(sumStandbySeconds([episode], [{ startMs: windowStart, endMs: T("2026-09-09T06:45:49Z") }])).toBe(290); }); - it("counts the whole episode without a window", () => { - expect(sumStandbySeconds([episode], null, null)).toBe(290); + it("counts the whole episode without windows", () => { + expect(sumStandbySeconds([episode], null)).toBe(290); }); it("returns null for an episode entirely outside the window", () => { - expect(sumStandbySeconds([episode], windowStart, T("2026-09-09T06:40:00Z"))).toBeNull(); + expect(sumStandbySeconds([episode], [{ startMs: windowStart, endMs: T("2026-09-09T06:40:00Z") }])).toBeNull(); + }); + + it("sums only the in-window flanks across two WhiteGlove windows", () => { + // Episode 10:00–14:00; part 1 ends 10:30, part 2 runs 13:45–14:20 → 30 min + 15 min. + const shelf = sleepEpisode(9, "2026-09-09T10:00:00Z", "2026-09-09T14:00:00Z", 4 * 3600); + const windows = [ + { startMs: T("2026-09-09T09:40:00Z"), endMs: T("2026-09-09T10:30:00Z") }, + { startMs: T("2026-09-09T13:45:00Z"), endMs: T("2026-09-09T14:20:00Z") }, + ]; + expect(sumStandbySeconds([shelf], windows)).toBe(45 * 60); }); it("dedups the same episode observed twice", () => { const again = sleepEpisode(200, "2026-09-09T06:40:28.6907161Z", "2026-09-09T06:45:19.0307161Z", 290); - expect(sumStandbySeconds([episode, again], null, null)).toBe(290); + expect(sumStandbySeconds([episode, again], null)).toBe(290); + }); + + it("does not let an unusable observation shadow a later usable one", () => { + const broken = sleepEpisode(150, "2026-09-09T06:40:28.6907161Z", null, 0); + expect(sumStandbySeconds([broken, episode], null)).toBe(290); }); it("falls back to durationSeconds when the payload carries no instants", () => { - const legacy = { - eventType: "system_sleep_episode", - source: "SystemTimelineWatcher", - timestamp: "2026-09-09T06:45:19Z", - sequence: 5, - message: "", - data: { kind: "sleep", durationSeconds: 120 }, - } as unknown as EnrollmentEvent; - expect(sumStandbySeconds([legacy], windowStart, completedAt)).toBe(120); + const legacy = sleepEpisode(5, null, null, 120); + expect(sumStandbySeconds([legacy], window)).toBe(120); }); it("ignores other events and returns null when nothing slept", () => { const other = { ...episode, eventType: "performance_snapshot" } as EnrollmentEvent; - expect(sumStandbySeconds([other], null, null)).toBeNull(); + expect(sumStandbySeconds([other], null)).toBeNull(); }); }); diff --git a/src/Web/autopilot-monitor-web/lib/__tests__/whiteGloveDurations.test.ts b/src/Web/autopilot-monitor-web/lib/__tests__/whiteGloveDurations.test.ts index 5771d9c7..57b42f73 100644 --- a/src/Web/autopilot-monitor-web/lib/__tests__/whiteGloveDurations.test.ts +++ b/src/Web/autopilot-monitor-web/lib/__tests__/whiteGloveDurations.test.ts @@ -29,6 +29,9 @@ describe("computeWhiteGloveDurations", () => { expect(d.preProvDuration).toBe("57m 0s"); expect(d.userEnrollDuration).toBe("56m 0s"); expect(d.combinedDuration).toBe("1h 53m"); // pause 09:28→11:00 excluded + // The spans the durations are measured over — the standby note clips to exactly these. + expect(d.preProvWindowMs).toEqual({ startMs: Date.parse("2026-07-23T08:31:00Z"), endMs: Date.parse("2026-07-23T09:28:00Z") }); + expect(d.userEnrollWindowMs).toEqual({ startMs: Date.parse("2026-07-23T11:00:00Z"), endMs: Date.parse("2026-07-23T11:56:00Z") }); }); it("ignores a historical event time re-emitted into the user block (post-resume IME re-parse)", () => { diff --git a/src/Web/autopilot-monitor-web/lib/standby.ts b/src/Web/autopilot-monitor-web/lib/standby.ts index a96b1ddb..5c784634 100644 --- a/src/Web/autopilot-monitor-web/lib/standby.ts +++ b/src/Web/autopilot-monitor-web/lib/standby.ts @@ -1,19 +1,25 @@ import type { EnrollmentEvent } from "@/types"; +export interface StandbyWindow { + startMs: number; + endMs: number; +} + /** - * Seconds the device spent asleep inside a window, from `system_sleep_episode` ground truth. + * Seconds the device spent asleep inside the given windows, from `system_sleep_episode` + * ground truth. * * The payload's `enteredAt` / `exitedAt` are the authoritative instants (the event itself is - * stamped at wake). Each episode is clipped to `[windowStartMs, windowEndMs]` so the number sits - * next to a duration that covers the same window — an episode that straddles the end of the - * enrollment contributes only its in-window part, matching the backend's time-attribution - * `SleepSpans`. Episodes are dedup'd on `enteredAt`: an agent restart can re-backfill the same - * episode from a different event-log record. Returns null when nothing was asleep. + * stamped at wake). Each episode is clipped to the windows so the number sits next to a + * duration measured over the same spans — one span for a regular session, the two WhiteGlove + * parts for a pre-provisioned one (the shelf pause between them contributes nothing, as in the + * backend's time-attribution `SleepSpans`). `windows === null` means unclipped. Episodes are + * dedup'd on `enteredAt` once they contributed: an agent restart can re-backfill the same episode + * from a different event-log record. Returns null when nothing was asleep. */ export function sumStandbySeconds( events: EnrollmentEvent[], - windowStartMs: number | null, - windowEndMs: number | null, + windows: ReadonlyArray | null, ): number | null { const seen = new Set(); let totalMs = 0; @@ -23,19 +29,27 @@ export function sumStandbySeconds( const exitedRaw = typeof e.data.exitedAt === "string" ? e.data.exitedAt : null; const key = enteredRaw ?? `seq-${e.sequence}`; if (seen.has(key)) continue; - seen.add(key); - let start = enteredRaw ? Date.parse(enteredRaw) : NaN; - let end = exitedRaw ? Date.parse(exitedRaw) : NaN; + const start = enteredRaw ? Date.parse(enteredRaw) : NaN; + const end = exitedRaw ? Date.parse(exitedRaw) : NaN; if (!Number.isFinite(start) || !Number.isFinite(end)) { // No usable instants: fall back to the reported duration, unclipped. const duration = Number(e.data.durationSeconds); - if (Number.isFinite(duration) && duration > 0) totalMs += duration * 1000; + if (!Number.isFinite(duration) || duration <= 0) continue; + seen.add(key); + totalMs += duration * 1000; continue; } - if (windowStartMs !== null) start = Math.max(start, windowStartMs); - if (windowEndMs !== null) end = Math.min(end, windowEndMs); - if (end > start) totalMs += end - start; + seen.add(key); + if (windows === null) { + if (end > start) totalMs += end - start; + continue; + } + for (const w of windows) { + const s = Math.max(start, w.startMs); + const t = Math.min(end, w.endMs); + if (t > s) totalMs += t - s; + } } return totalMs > 0 ? Math.round(totalMs / 1000) : null; }