mirror of
https://github.com/okieselbach/AutopilotMonitor.git
synced 2026-10-24 12:42:38 +00:00
fix(agent,engine,web): a deadline decision is stamped with the firing clock, never the due time (D-238)
A HelloSafety deadline due during Modern Standby fired after wake but was stamped with its due time, so enrollment_complete and CompletedAt landed inside the sleep window: the Network Timeline drew "Completed" in the middle of the Asleep block and three views named three different standby durations. - OnDeadlineFired posts OccurredAtUtc = FiredAtUtc and carries the due time under SignalPayloadKeys.DeadlineDueAtUtc; the stale-fire guards (RealmJoin re-arm, SelfDeploying guard C) identify the incarnation via DecisionEngine.DeadlineDueAtUtc, which falls back to the signal time for pre-key signal logs. - SignalSerializer renders Date-tokenized payload strings as ISO-8601 round-trip text instead of the culture-formatted JValue.ToString() (a replayed deadlineDueAtUtc came back as "4/20/2026 9:55:00 AM"). - Web: the Session Info standby note is clipped to the same window as the duration next to it (lib/standby.ts) and printed with seconds, matching the attribution chip. Tests: DeadlineFireTimeStampTests (late HelloSafety fire, guard C, RealmJoin re-arm, helper fallback), SerializationTests date-like payload round-trip, EnrollmentOrchestratorTests late fire, lib/__tests__/standby.test.ts. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
This commit is contained in:
+1
-1
Submodule internal updated: 2f4d12b8df...aecb8467c4
+36
@@ -265,6 +265,42 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
|
||||
sut.Stop();
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void Deadline_fired_late_is_stamped_with_the_firing_clock_and_carries_its_due_time()
|
||||
{
|
||||
// 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.
|
||||
using var rig = new EnrollmentOrchestratorRig(At);
|
||||
var sut = rig.Build();
|
||||
sut.Start();
|
||||
|
||||
var dueAt = At.AddMinutes(-5);
|
||||
var scheduler = GetScheduler(sut);
|
||||
scheduler.Schedule(new ActiveDeadline(
|
||||
name: "hello_safety",
|
||||
dueAtUtc: dueAt,
|
||||
firesSignalKind: DecisionSignalKind.DeadlineFired,
|
||||
firesPayload: new Dictionary<string, string> { [SignalPayloadKeys.Deadline] = "hello_safety" }));
|
||||
|
||||
var signalLog = GetSignalLog(sut);
|
||||
Assert.True(SpinWait.SpinUntil(() => ContainsDeadlineFired(signalLog), 3000));
|
||||
|
||||
DecisionSignal? fired = null;
|
||||
foreach (var sig in signalLog.ReadAll())
|
||||
{
|
||||
if (sig.Kind == DecisionSignalKind.DeadlineFired) { fired = sig; break; }
|
||||
}
|
||||
Assert.NotNull(fired);
|
||||
Assert.Equal(At, fired!.OccurredAtUtc);
|
||||
Assert.NotNull(fired.Payload);
|
||||
Assert.Equal("hello_safety", fired.Payload![SignalPayloadKeys.Deadline]);
|
||||
Assert.Equal(dueAt.ToString("O"), fired.Payload[SignalPayloadKeys.DeadlineDueAtUtc]);
|
||||
|
||||
sut.Stop();
|
||||
}
|
||||
|
||||
// ========================================================================= Quarantine
|
||||
|
||||
[Fact]
|
||||
|
||||
@@ -9,9 +9,10 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
|
||||
/// <para>
|
||||
/// The orchestrator consumes this event and translates it into a synthetic
|
||||
/// <c>DeadlineFired</c>-<see cref="AutopilotMonitor.DecisionCore.Signals.DecisionSignal"/>
|
||||
/// whose <c>OccurredAtUtc</c> equals the deadline's <see cref="ActiveDeadline.DueAtUtc"/>,
|
||||
/// not the wall-clock firing time — so replay stays deterministic even if the agent
|
||||
/// restarts long after the deadline has passed.
|
||||
/// whose <c>OccurredAtUtc</c> is <see cref="FiredAtUtc"/> — the moment the agent actually
|
||||
/// decided — and whose payload carries the deadline's <see cref="ActiveDeadline.DueAtUtc"/>.
|
||||
/// 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.
|
||||
/// </para>
|
||||
/// </summary>
|
||||
public sealed class DeadlineFiredEventArgs : EventArgs
|
||||
@@ -24,7 +25,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
|
||||
|
||||
public ActiveDeadline Deadline { get; }
|
||||
|
||||
/// <summary>Wall-clock time the event was raised. For observability; does NOT influence the signal's OccurredAtUtc.</summary>
|
||||
/// <summary>Wall-clock time the timer fired; becomes the signal's OccurredAtUtc.</summary>
|
||||
public DateTime FiredAtUtc { get; }
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,6 +1,7 @@
|
||||
#nullable enable
|
||||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Globalization;
|
||||
using System.IO;
|
||||
using System.Threading;
|
||||
using System.Threading.Tasks;
|
||||
@@ -1159,7 +1160,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
|
||||
var evidence = new Evidence(
|
||||
kind: EvidenceKind.Synthetic,
|
||||
identifier: e.Deadline.Name,
|
||||
summary: $"deadline '{e.Deadline.Name}' fired at {e.Deadline.DueAtUtc:O}");
|
||||
summary: $"deadline '{e.Deadline.Name}' due {e.Deadline.DueAtUtc:O} fired at {e.FiredAtUtc:O}");
|
||||
|
||||
// The reducer reads the deadline name under SignalPayloadKeys.Deadline
|
||||
// (see HandleDeadlineFiredV1 in DecisionEngine.Shared). Forward the
|
||||
@@ -1180,10 +1181,15 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
|
||||
payload[SignalPayloadKeys.Deadline] = e.Deadline.Name;
|
||||
}
|
||||
|
||||
// OccurredAtUtc = DueAtUtc (not firedAt) — replay-determinism per DeadlineFiredEventArgs doc.
|
||||
// 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.
|
||||
payload[SignalPayloadKeys.DeadlineDueAtUtc] = e.Deadline.DueAtUtc.ToString("O", CultureInfo.InvariantCulture);
|
||||
|
||||
_ingress.Post(
|
||||
kind: DecisionSignalKind.DeadlineFired,
|
||||
occurredAtUtc: e.Deadline.DueAtUtc,
|
||||
occurredAtUtc: e.FiredAtUtc,
|
||||
sourceOrigin: "DeadlineScheduler",
|
||||
evidence: evidence,
|
||||
payload: payload);
|
||||
|
||||
@@ -0,0 +1,192 @@
|
||||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Globalization;
|
||||
using System.Linq;
|
||||
using AutopilotMonitor.DecisionCore.Engine;
|
||||
using AutopilotMonitor.DecisionCore.Signals;
|
||||
using AutopilotMonitor.DecisionCore.State;
|
||||
using Xunit;
|
||||
|
||||
namespace AutopilotMonitor.DecisionCore.Tests
|
||||
{
|
||||
/// <summary>
|
||||
/// A <c>DeadlineFired</c> 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
|
||||
/// <see cref="SignalPayloadKeys.DeadlineDueAtUtc"/> 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).
|
||||
/// </summary>
|
||||
public sealed class DeadlineFireTimeStampTests
|
||||
{
|
||||
private static readonly DateTime T0 = new DateTime(2026, 9, 9, 6, 31, 0, DateTimeKind.Utc);
|
||||
|
||||
private static DecisionSignal MakeSignal(
|
||||
long ordinal,
|
||||
DecisionSignalKind kind,
|
||||
DateTime occurredAtUtc,
|
||||
IReadOnlyDictionary<string, string>? payload = null) =>
|
||||
new DecisionSignal(
|
||||
sessionSignalOrdinal: ordinal,
|
||||
sessionTraceOrdinal: ordinal,
|
||||
kind: kind,
|
||||
kindSchemaVersion: 1,
|
||||
occurredAtUtc: occurredAtUtc,
|
||||
sourceOrigin: "test",
|
||||
evidence: new Evidence(EvidenceKind.Synthetic, $"t-{kind}-{ordinal}", $"synthetic {kind}"),
|
||||
payload: payload);
|
||||
|
||||
/// <summary>What the host posts: name plus due time, OccurredAtUtc = firing clock.</summary>
|
||||
private static Dictionary<string, string> FiredPayload(string deadlineName, DateTime dueAtUtc) =>
|
||||
new Dictionary<string, string>
|
||||
{
|
||||
[SignalPayloadKeys.Deadline] = deadlineName,
|
||||
[SignalPayloadKeys.DeadlineDueAtUtc] = dueAtUtc.ToString("O", CultureInfo.InvariantCulture),
|
||||
};
|
||||
|
||||
// ============================================================== helper
|
||||
|
||||
[Fact]
|
||||
public void DeadlineDueAtUtc_reads_the_payload_and_falls_back_to_the_signal_time()
|
||||
{
|
||||
var due = T0.AddMinutes(5);
|
||||
var fired = T0.AddMinutes(9);
|
||||
|
||||
var withKey = MakeSignal(1, DecisionSignalKind.DeadlineFired, fired, FiredPayload(DeadlineNames.HelloSafety, due));
|
||||
Assert.Equal(due, DecisionEngine.DeadlineDueAtUtc(withKey));
|
||||
Assert.Equal(DateTimeKind.Utc, DecisionEngine.DeadlineDueAtUtc(withKey).Kind);
|
||||
|
||||
var withoutKey = MakeSignal(2, DecisionSignalKind.DeadlineFired, fired,
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.Deadline] = DeadlineNames.HelloSafety });
|
||||
Assert.Equal(fired, DecisionEngine.DeadlineDueAtUtc(withoutKey));
|
||||
|
||||
var garbage = MakeSignal(3, DecisionSignalKind.DeadlineFired, fired,
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.DeadlineDueAtUtc] = "not-a-time" });
|
||||
Assert.Equal(fired, DecisionEngine.DeadlineDueAtUtc(garbage));
|
||||
}
|
||||
|
||||
// ============================================================== Classic: standby at the Hello prompt
|
||||
|
||||
[Fact]
|
||||
public void Late_HelloSafety_fire_stamps_the_resolution_and_the_grace_window_from_the_firing_clock()
|
||||
{
|
||||
// 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.
|
||||
var engine = new DecisionEngine();
|
||||
var state = DecisionState.CreateInitial("sess-standby", "tenant", T0);
|
||||
state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0)).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(1, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(1),
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(2, DecisionSignalKind.AccountSetupProvisioningComplete, T0.AddMinutes(2))).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(3, DecisionSignalKind.DesktopArrived, T0.AddMinutes(3))).NewState;
|
||||
|
||||
var espExit = T0.AddMinutes(6).AddSeconds(50.2144855);
|
||||
state = engine.Reduce(state, MakeSignal(4, DecisionSignalKind.EspExiting, espExit)).NewState;
|
||||
var helloSafety = Assert.Single(state.Deadlines, d => d.Name == DeadlineNames.HelloSafety);
|
||||
Assert.Equal(espExit.AddSeconds(300), helloSafety.DueAtUtc);
|
||||
|
||||
// Timer fires after wake, 2m 54s past due.
|
||||
var firedAt = helloSafety.DueAtUtc.AddSeconds(174);
|
||||
var finalizing = engine.Reduce(state, MakeSignal(5, DecisionSignalKind.DeadlineFired, firedAt,
|
||||
FiredPayload(DeadlineNames.HelloSafety, helloSafety.DueAtUtc)));
|
||||
|
||||
Assert.True(finalizing.Transition.Taken);
|
||||
Assert.Equal(SessionStage.Finalizing, finalizing.NewState.Stage);
|
||||
Assert.Equal("Timeout", finalizing.NewState.HelloOutcome!.Value);
|
||||
Assert.Equal(firedAt, finalizing.NewState.HelloResolvedUtc!.Value);
|
||||
|
||||
var grace = Assert.Single(finalizing.NewState.Deadlines, d => d.Name == DeadlineNames.FinalizingGrace);
|
||||
Assert.Equal(firedAt.AddSeconds(5), grace.DueAtUtc);
|
||||
|
||||
// The chained grace fires on time and completes; nothing carries the old due time.
|
||||
var completed = engine.Reduce(finalizing.NewState, MakeSignal(6, DecisionSignalKind.DeadlineFired, grace.DueAtUtc,
|
||||
FiredPayload(DeadlineNames.FinalizingGrace, grace.DueAtUtc)));
|
||||
Assert.Equal(SessionStage.Completed, completed.NewState.Stage);
|
||||
Assert.Equal(SessionOutcome.EnrollmentComplete, completed.NewState.Outcome);
|
||||
Assert.Contains(completed.Effects, e =>
|
||||
e.Kind == DecisionEffectKind.EmitEventTimelineEntry
|
||||
&& e.Parameters != null
|
||||
&& e.Parameters.TryGetValue("eventType", out var et) && et == "enrollment_complete");
|
||||
}
|
||||
|
||||
// ============================================================== SelfDeploying guard C
|
||||
|
||||
[Fact]
|
||||
public void SelfDeploying_guard_C_matches_the_incarnation_by_payload_due_time_not_by_firing_clock()
|
||||
{
|
||||
var engine = new DecisionEngine();
|
||||
var state = DecisionState.CreateInitial("sd-late", "t", T0);
|
||||
state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0)).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(1, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(1),
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "DeviceSetup" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(2, DecisionSignalKind.DeviceSetupProvisioningComplete, T0.AddMinutes(3))).NewState;
|
||||
var armed = Assert.Single(state.Deadlines, d => d.Name == DeadlineNames.DeviceOnlyEspDetection);
|
||||
Assert.Equal(T0.AddMinutes(8), armed.DueAtUtc);
|
||||
|
||||
// A stale fire of an OLDER incarnation (due T+5) arriving late: dead-end, deadline kept.
|
||||
var stale = engine.Reduce(state, MakeSignal(3, DecisionSignalKind.DeadlineFired, T0.AddMinutes(12),
|
||||
FiredPayload(DeadlineNames.DeviceOnlyEspDetection, T0.AddMinutes(5))));
|
||||
Assert.False(stale.Transition.Taken);
|
||||
Assert.Equal("device_only_esp_detection_stale_due_at_mismatch", stale.Transition.DeadEndReason);
|
||||
Assert.Single(stale.NewState.Deadlines, d => d.Name == DeadlineNames.DeviceOnlyEspDetection);
|
||||
|
||||
// The real fire, 4 min late (standby), carries the armed due time: terminal.
|
||||
var real = engine.Reduce(stale.NewState, MakeSignal(4, DecisionSignalKind.DeadlineFired, T0.AddMinutes(12),
|
||||
FiredPayload(DeadlineNames.DeviceOnlyEspDetection, armed.DueAtUtc)));
|
||||
Assert.True(real.Transition.Taken);
|
||||
Assert.Equal(SessionStage.Completed, real.NewState.Stage);
|
||||
}
|
||||
|
||||
// ============================================================== RealmJoin re-arm guard
|
||||
|
||||
[Fact]
|
||||
public void RealmJoin_rearm_guard_compares_the_payload_due_time_not_the_firing_clock()
|
||||
{
|
||||
var engine = new DecisionEngine();
|
||||
var state = DecisionState.CreateInitial("rj-late", "t", T0);
|
||||
state = engine.Reduce(state, MakeSignal(0, DecisionSignalKind.SessionStarted, T0)).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(1, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(1),
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "DeviceSetup" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(2, DecisionSignalKind.EspPhaseChanged, T0.AddMinutes(2),
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.EspPhase] = "AccountSetup" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(3, DecisionSignalKind.EspExiting, T0.AddMinutes(3))).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(4, DecisionSignalKind.HelloResolved, T0.AddMinutes(4),
|
||||
new Dictionary<string, string> { [SignalPayloadKeys.HelloOutcome] = "Success" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(5, DecisionSignalKind.RealmJoinDetected, T0.AddMinutes(5),
|
||||
new Dictionary<string, string> { [DecisionEngine.RealmJoinPayloadKeys.DeploymentPhase] = "100" })).NewState;
|
||||
state = engine.Reduce(state, MakeSignal(6, DecisionSignalKind.DesktopArrived, T0.AddMinutes(6))).NewState;
|
||||
var first = Assert.Single(state.Deadlines, d => d.Name == DeadlineNames.RealmJoinTimeout);
|
||||
|
||||
// Simulate the activity-based re-arm: the armed incarnation is now due later.
|
||||
var rearmedDue = first.DueAtUtc.AddMinutes(25);
|
||||
var rearmed = state.ToBuilder()
|
||||
.CancelDeadline(DeadlineNames.RealmJoinTimeout)
|
||||
.AddDeadline(new ActiveDeadline(
|
||||
name: DeadlineNames.RealmJoinTimeout,
|
||||
dueAtUtc: rearmedDue,
|
||||
firesSignalKind: DecisionSignalKind.DeadlineFired,
|
||||
firesPayload: new Dictionary<string, string> { [SignalPayloadKeys.Deadline] = DeadlineNames.RealmJoinTimeout }))
|
||||
.Build();
|
||||
|
||||
// The OLD incarnation's fire arrives late — after the re-armed due time on the clock.
|
||||
// Only the payload due time identifies it as superseded.
|
||||
var firedAt = rearmedDue.AddMinutes(1);
|
||||
var stale = engine.Reduce(rearmed, MakeSignal(7, DecisionSignalKind.DeadlineFired, firedAt,
|
||||
FiredPayload(DeadlineNames.RealmJoinTimeout, first.DueAtUtc)));
|
||||
Assert.False(stale.Transition.Taken);
|
||||
Assert.Equal("realmjoin_timeout_stale_superseded_by_rearm", stale.Transition.DeadEndReason);
|
||||
Assert.Null(stale.NewState.RealmJoinFacts.Outcome);
|
||||
|
||||
// The re-armed incarnation's own fire, same firing clock: timeout is applied.
|
||||
var real = engine.Reduce(stale.NewState, MakeSignal(8, DecisionSignalKind.DeadlineFired, firedAt,
|
||||
FiredPayload(DeadlineNames.RealmJoinTimeout, rearmedDue)));
|
||||
Assert.True(real.Transition.Taken);
|
||||
Assert.Equal("Timeout", real.NewState.RealmJoinFacts.Outcome!.Value);
|
||||
Assert.Equal(SessionStage.Finalizing, real.NewState.Stage);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -54,6 +54,37 @@ namespace AutopilotMonitor.DecisionCore.Tests
|
||||
Assert.Equal("AccountSetup", roundtripped.Payload!["phase"]);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void SignalSerializer_roundtrip_keeps_date_like_payload_strings_verbatim()
|
||||
{
|
||||
// The shared reader tokenizes ISO-8601 strings as dates; the string dictionaries must
|
||||
// still come back as the round-trip text the writer produced, never culture-formatted
|
||||
// (the DeadlineFired due time is parsed back with the "o" format on replay).
|
||||
var due = new DateTime(2026, 4, 20, 9, 55, 0, DateTimeKind.Utc);
|
||||
var original = new DecisionSignal(
|
||||
sessionSignalOrdinal: 7,
|
||||
sessionTraceOrdinal: 7,
|
||||
kind: DecisionSignalKind.DeadlineFired,
|
||||
kindSchemaVersion: 1,
|
||||
occurredAtUtc: due.AddMinutes(5),
|
||||
sourceOrigin: "DeadlineScheduler",
|
||||
evidence: new Evidence(
|
||||
kind: EvidenceKind.Synthetic,
|
||||
identifier: "hello_safety",
|
||||
summary: "deadline fired",
|
||||
derivationInputs: new Dictionary<string, string> { ["armedAt"] = "2026-04-20T09:50:00.0000000Z" }),
|
||||
payload: new Dictionary<string, string>
|
||||
{
|
||||
["deadline"] = "hello_safety",
|
||||
["deadlineDueAtUtc"] = due.ToString("O"),
|
||||
});
|
||||
|
||||
var roundtripped = SignalSerializer.Deserialize(SignalSerializer.Serialize(original));
|
||||
|
||||
Assert.Equal("2026-04-20T09:55:00.0000000Z", roundtripped.Payload!["deadlineDueAtUtc"]);
|
||||
Assert.Equal("2026-04-20T09:50:00.0000000Z", roundtripped.Evidence.DerivationInputs!["armedAt"]);
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public void SignalSerializer_Deserialize_MissingEvidence_throws()
|
||||
{
|
||||
|
||||
@@ -86,6 +86,15 @@ namespace AutopilotMonitor.DecisionCore.Engine
|
||||
/// <summary>On <c>DeadlineFired</c>: the deadline name from <see cref="DeadlineNames"/>.</summary>
|
||||
public const string Deadline = "deadline";
|
||||
|
||||
/// <summary>
|
||||
/// On <c>DeadlineFired</c>: the deadline's <see cref="State.ActiveDeadline.DueAtUtc"/> as an
|
||||
/// ISO-8601 round-trip string. The signal's <c>OccurredAtUtc</c> is the time the timer
|
||||
/// actually fired (which trails the due time after standby or an agent restart); stale-fire
|
||||
/// guards that must identify the deadline incarnation read this key via
|
||||
/// <c>DecisionEngine.DeadlineDueAtUtc</c>.
|
||||
/// </summary>
|
||||
public const string DeadlineDueAtUtc = "deadlineDueAtUtc";
|
||||
|
||||
/// <summary>On <c>EspPhaseChanged</c>: the raw phase name as observed by the collector.</summary>
|
||||
public const string EspPhase = "phase";
|
||||
|
||||
|
||||
@@ -252,10 +252,11 @@ namespace AutopilotMonitor.DecisionCore.Engine
|
||||
|
||||
// Third staleness shape (introduced with the activity-based extension): the fire
|
||||
// belongs to an OLDER deadline incarnation that a re-arm has since replaced —
|
||||
// recognizable because the armed deadline is due LATER than this fire
|
||||
// (OccurredAtUtc = DueAtUtc per the scheduler contract). Without this guard the
|
||||
// recognizable because the armed deadline is due LATER than the due time this fire
|
||||
// belongs to (payload, see DeadlineDueAtUtc — never the signal time, which is the
|
||||
// firing clock and trails the due time after standby). Without this guard the
|
||||
// stale fire would evaluate the timeout/extension decision ahead of schedule.
|
||||
var supersededByRearm = armedDeadline != null && armedDeadline.DueAtUtc > signal.OccurredAtUtc;
|
||||
var supersededByRearm = armedDeadline != null && armedDeadline.DueAtUtc > DeadlineDueAtUtc(signal);
|
||||
|
||||
if (alreadyResolvedOrTimedOut || armedDeadline == null || supersededByRearm)
|
||||
{
|
||||
|
||||
@@ -255,10 +255,11 @@ namespace AutopilotMonitor.DecisionCore.Engine
|
||||
// --- Stale-fire guard C: DueAtUtc mismatch ---
|
||||
// Cancel-then-rearm race: an old DeadlineFired (from a deadline incarnation that was
|
||||
// replaced by a later HandleDeviceSetupProvisioningCompleteV1 arming) is processed
|
||||
// after the rearm. DeadlineScheduler posts OccurredAtUtc == deadline.DueAtUtc, so the
|
||||
// OLD fire carries the OLD DueAtUtc. Dead-end WITHOUT cancelling the active deadline
|
||||
// (the whole point is to keep the new one for its real fire).
|
||||
if (activeDeadline.DueAtUtc != signal.OccurredAtUtc)
|
||||
// after the rearm. The fire carries the due time of the incarnation it belongs to
|
||||
// (payload, see DeadlineDueAtUtc), so the OLD fire carries the OLD DueAtUtc. Dead-end
|
||||
// WITHOUT cancelling the active deadline (the whole point is to keep the new one for
|
||||
// its real fire).
|
||||
if (activeDeadline.DueAtUtc != DeadlineDueAtUtc(signal))
|
||||
{
|
||||
var bookkept = BumpStepBookkeeping(state, signal);
|
||||
var transition = BuildDeadEndTransition(
|
||||
|
||||
@@ -1013,6 +1013,27 @@ namespace AutopilotMonitor.DecisionCore.Engine
|
||||
return signal.OccurredAtUtc;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// The due time of the deadline a <c>DeadlineFired</c> signal belongs to. The host stamps the
|
||||
/// signal with the wall-clock firing time (after Modern Standby or an agent restart that
|
||||
/// trails the due time by minutes) and carries the due time under
|
||||
/// <see cref="SignalPayloadKeys.DeadlineDueAtUtc"/>; stale-fire guards compare THIS against
|
||||
/// the armed <see cref="ActiveDeadline.DueAtUtc"/>, never the signal time. Falls back to
|
||||
/// <c>signal.OccurredAtUtc</c> for signal logs written before the key existed, where the
|
||||
/// two were equal by contract.
|
||||
/// </summary>
|
||||
internal static DateTime DeadlineDueAtUtc(DecisionSignal signal)
|
||||
{
|
||||
if (signal.Payload != null
|
||||
&& signal.Payload.TryGetValue(SignalPayloadKeys.DeadlineDueAtUtc, out var raw)
|
||||
&& DateTime.TryParseExact(raw, "o", System.Globalization.CultureInfo.InvariantCulture,
|
||||
System.Globalization.DateTimeStyles.RoundtripKind, out var due))
|
||||
{
|
||||
return due.Kind == DateTimeKind.Utc ? due : due.ToUniversalTime();
|
||||
}
|
||||
return signal.OccurredAtUtc;
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Determine the user-visible enrollment phase implied by an ESP phase-change signal.
|
||||
/// Plan §2.3 phase-fact mapping. Populated in M3.1 as Classic handlers come online.
|
||||
|
||||
@@ -282,11 +282,9 @@ namespace AutopilotMonitor.DecisionCore.Engine
|
||||
|
||||
if (!reachedTerminal)
|
||||
{
|
||||
// The DeadlineFired signal carries DueAtUtc as OccurredAtUtc, so for a tick
|
||||
// armed in the current run this is already current-clock-equivalent. The
|
||||
// EffectiveDeadlineBase guard still fires correctly across restart, where
|
||||
// a stale DueAtUtc from the prior run could otherwise re-arm the next tick
|
||||
// in the past.
|
||||
// The DeadlineFired signal carries the wall-clock firing time, so the next tick
|
||||
// is armed relative to now — also after a late fire (standby). The
|
||||
// EffectiveDeadlineBase guard still floors a replayed fire at boot.
|
||||
var rearm = BuildClassifierTickDeadline(EffectiveDeadlineBase(state, signal));
|
||||
builder.AddDeadline(rearm);
|
||||
effects.Add(new DecisionEffect(DecisionEffectKind.ScheduleDeadline, deadline: rearm));
|
||||
|
||||
@@ -1,5 +1,6 @@
|
||||
using System;
|
||||
using System.Collections.Generic;
|
||||
using System.Globalization;
|
||||
using AutopilotMonitor.DecisionCore.Signals;
|
||||
using Newtonsoft.Json;
|
||||
using Newtonsoft.Json.Linq;
|
||||
@@ -46,7 +47,7 @@ namespace AutopilotMonitor.DecisionCore.Serialization
|
||||
var d = new Dictionary<string, string>();
|
||||
foreach (var prop in diObj.Properties())
|
||||
{
|
||||
d[prop.Name] = prop.Value?.ToString() ?? string.Empty;
|
||||
d[prop.Name] = StringValue(prop.Value);
|
||||
}
|
||||
derivationInputs = d;
|
||||
}
|
||||
@@ -64,7 +65,7 @@ namespace AutopilotMonitor.DecisionCore.Serialization
|
||||
var p = new Dictionary<string, string>();
|
||||
foreach (var prop in payloadObj.Properties())
|
||||
{
|
||||
p[prop.Name] = prop.Value?.ToString() ?? string.Empty;
|
||||
p[prop.Name] = StringValue(prop.Value);
|
||||
}
|
||||
payload = p;
|
||||
}
|
||||
@@ -112,6 +113,23 @@ namespace AutopilotMonitor.DecisionCore.Serialization
|
||||
typedPayload: typedPayload);
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// String-dictionary values (Payload, DerivationInputs) verbatim. The shared reader
|
||||
/// tokenizes an ISO-8601 string as a Date (<c>DateParseHandling.DateTime</c>), and
|
||||
/// <c>JValue.ToString()</c> would then render it in the current culture — a replayed
|
||||
/// <c>deadlineDueAtUtc</c> came back as "4/20/2026 9:55:00 AM". Render a Date token as
|
||||
/// the round-trip text the writer produced.
|
||||
/// </summary>
|
||||
private static string StringValue(JToken? token)
|
||||
{
|
||||
if (token is JValue jv && jv.Type == JTokenType.Date && jv.Value is DateTime dt)
|
||||
{
|
||||
var utc = dt.Kind == DateTimeKind.Local ? dt.ToUniversalTime() : DateTime.SpecifyKind(dt, DateTimeKind.Utc);
|
||||
return utc.ToString("O", CultureInfo.InvariantCulture);
|
||||
}
|
||||
return token?.ToString() ?? string.Empty;
|
||||
}
|
||||
|
||||
private static T ParseEnum<T>(string? raw, T fallback) where T : struct, Enum
|
||||
{
|
||||
if (string.IsNullOrEmpty(raw)) return fallback;
|
||||
|
||||
@@ -4,6 +4,7 @@ import { useState } from "react";
|
||||
import { Session } from "@/types";
|
||||
import { SessionStatusBadge } from "@/components/SessionStatusBadge";
|
||||
import FailureSnapshotBlock from "./FailureSnapshotBlock";
|
||||
import { formatDuration } from "@/lib/formatting";
|
||||
|
||||
interface SessionInfoCardProps {
|
||||
session: Session;
|
||||
@@ -12,16 +13,10 @@ interface SessionInfoCardProps {
|
||||
isGatherRulesSession: boolean;
|
||||
ntpOffset?: { offsetSeconds: number; ntpServer?: string } | null;
|
||||
configMgrDetected?: { ccmVersion?: string; ccmServiceState?: string; siteCode?: string; confidenceScore?: number } | null;
|
||||
/** Total observed sleep/standby seconds (system_sleep_episode ground truth) — explains an inflated wall-clock duration. */
|
||||
/** Sleep/standby seconds inside the enrollment window (system_sleep_episode ground truth) — explains an inflated wall-clock duration. */
|
||||
standbySeconds?: number | null;
|
||||
}
|
||||
|
||||
// Compact duration for the standby note: "56m", "1h 2m".
|
||||
function formatStandby(seconds: number): string {
|
||||
if (seconds >= 3600) return `${Math.floor(seconds / 3600)}h ${Math.floor((seconds % 3600) / 60)}m`;
|
||||
return `${Math.max(1, Math.round(seconds / 60))}m`;
|
||||
}
|
||||
|
||||
export default function SessionInfoCard({ session, enrollmentDuration, displayStatus, isGatherRulesSession, ntpOffset, configMgrDetected, standbySeconds }: SessionInfoCardProps) {
|
||||
const lastContactTooltip = session.lastEventAt
|
||||
? `Last contact: ${new Date(session.lastEventAt).toLocaleString([], { dateStyle: "short", timeStyle: "medium" })}`
|
||||
@@ -72,9 +67,9 @@ export default function SessionInfoCard({ session, enrollmentDuration, displaySt
|
||||
{enrollmentDuration ?? `${Math.round((session.durationSeconds ?? 0) / 60)} min`}
|
||||
<span
|
||||
className="text-indigo-600 font-normal"
|
||||
title={`The device spent ${formatStandby(standbySeconds)} asleep (standby/hibernate) during this window — the wall-clock duration includes that pause. Subtract it for the active enrollment time.`}
|
||||
title={`The device spent ${formatDuration(standbySeconds)} asleep (standby/hibernate) during this window — the wall-clock duration includes that pause. Subtract it for the active enrollment time.`}
|
||||
>
|
||||
{" "}· 🌙 {formatStandby(standbySeconds)} standby
|
||||
{" "}· 🌙 {formatDuration(standbySeconds)} standby
|
||||
</span>
|
||||
</span>
|
||||
) : (
|
||||
|
||||
@@ -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 { sumStandbySeconds } from "@/lib/standby";
|
||||
|
||||
interface PhaseGrouping {
|
||||
eventsByPhase: Record<string, EnrollmentEvent[]>;
|
||||
@@ -138,7 +139,7 @@ export function useSessionDerivedData(
|
||||
// agent started — environment observation, not enrollment activity — and would drag the
|
||||
// start toward pre-enrollment OOBE idle time (mirrors the backend anchor eligibility;
|
||||
// field case d0c5b672).
|
||||
const enrollmentDurationFromEvents = useMemo(() => {
|
||||
const enrollmentWindow = useMemo(() => {
|
||||
const activityEvents = events.filter(e => e.source !== "SystemTimelineWatcher");
|
||||
if (activityEvents.length === 0) return null;
|
||||
const timestamps = activityEvents.map(e => new Date(e.timestamp).getTime());
|
||||
@@ -147,11 +148,16 @@ export function useSessionDerivedData(
|
||||
const endTime = completeEvent
|
||||
? new Date(completeEvent.timestamp).getTime()
|
||||
: Math.max(...timestamps);
|
||||
const durationSec = Math.round((endTime - firstEventTime) / 1000);
|
||||
return { startMs: firstEventTime, endMs: endTime };
|
||||
}, [events]);
|
||||
|
||||
const enrollmentDurationFromEvents = useMemo(() => {
|
||||
if (!enrollmentWindow) return null;
|
||||
const durationSec = Math.round((enrollmentWindow.endMs - enrollmentWindow.startMs) / 1000);
|
||||
if (durationSec < 60) return `${durationSec}s`;
|
||||
if (durationSec < 3600) return `${Math.floor(durationSec / 60)}m ${durationSec % 60}s`;
|
||||
return `${Math.floor(durationSec / 3600)}h ${Math.floor((durationSec % 3600) / 60)}m`;
|
||||
}, [events]);
|
||||
}, [enrollmentWindow]);
|
||||
|
||||
// Last moment the agent reported anything — the end of the observation window, in the
|
||||
// device clock frame the event timestamps share. Deliberately NOT the enrollment duration
|
||||
@@ -171,24 +177,14 @@ export function useSessionDerivedData(
|
||||
return max;
|
||||
}, [events, sessionLastEventAt]);
|
||||
|
||||
// Total observed sleep/standby seconds (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"). Dedup on enteredAt: the same episode can be observed twice (agent
|
||||
// restart re-backfills it from a different event-log record).
|
||||
const standbySeconds = useMemo(() => {
|
||||
const seenEpisodes = new Set<string>();
|
||||
let total = 0;
|
||||
for (const e of events) {
|
||||
if (e.eventType !== "system_sleep_episode" || !e.data) continue;
|
||||
const duration = Number(e.data.durationSeconds);
|
||||
if (!Number.isFinite(duration) || duration <= 0) continue;
|
||||
const enteredAt = typeof e.data.enteredAt === "string" ? e.data.enteredAt : `seq-${e.sequence}`;
|
||||
if (seenEpisodes.has(enteredAt)) continue;
|
||||
seenEpisodes.add(enteredAt);
|
||||
total += duration;
|
||||
}
|
||||
return total > 0 ? Math.round(total) : null;
|
||||
}, [events]);
|
||||
// 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;
|
||||
|
||||
@@ -0,0 +1,61 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import type { EnrollmentEvent } from "@/types";
|
||||
import { sumStandbySeconds } from "../standby";
|
||||
|
||||
const T = (iso: string) => Date.parse(iso);
|
||||
|
||||
function sleepEpisode(seq: number, enteredAt: string, exitedAt: string, durationSeconds: number): EnrollmentEvent {
|
||||
return {
|
||||
eventType: "system_sleep_episode",
|
||||
source: "SystemTimelineWatcher",
|
||||
timestamp: exitedAt,
|
||||
sequence: seq,
|
||||
message: "Device exited Modern Standby",
|
||||
data: { kind: "modern_standby", enteredAt, exitedAt, durationSeconds },
|
||||
} as unknown as EnrollmentEvent;
|
||||
}
|
||||
|
||||
describe("sumStandbySeconds", () => {
|
||||
// Session ac5660b8: asleep 06:40:28.69–06:45:19.03 (290 s), enrollment window ends 06:42:55.21.
|
||||
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");
|
||||
|
||||
it("clips an episode that straddles the end of the window", () => {
|
||||
expect(sumStandbySeconds([episode], windowStart, completedAt)).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);
|
||||
});
|
||||
|
||||
it("counts the whole episode without a window", () => {
|
||||
expect(sumStandbySeconds([episode], null, null)).toBe(290);
|
||||
});
|
||||
|
||||
it("returns null for an episode entirely outside the window", () => {
|
||||
expect(sumStandbySeconds([episode], windowStart, T("2026-09-09T06:40:00Z"))).toBeNull();
|
||||
});
|
||||
|
||||
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);
|
||||
});
|
||||
|
||||
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);
|
||||
});
|
||||
|
||||
it("ignores other events and returns null when nothing slept", () => {
|
||||
const other = { ...episode, eventType: "performance_snapshot" } as EnrollmentEvent;
|
||||
expect(sumStandbySeconds([other], null, null)).toBeNull();
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,41 @@
|
||||
import type { EnrollmentEvent } from "@/types";
|
||||
|
||||
/**
|
||||
* Seconds the device spent asleep inside a window, 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.
|
||||
*/
|
||||
export function sumStandbySeconds(
|
||||
events: EnrollmentEvent[],
|
||||
windowStartMs: number | null,
|
||||
windowEndMs: number | null,
|
||||
): number | null {
|
||||
const seen = new Set<string>();
|
||||
let totalMs = 0;
|
||||
for (const e of events) {
|
||||
if (e.eventType !== "system_sleep_episode" || !e.data) continue;
|
||||
const enteredRaw = typeof e.data.enteredAt === "string" ? e.data.enteredAt : null;
|
||||
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;
|
||||
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;
|
||||
continue;
|
||||
}
|
||||
if (windowStartMs !== null) start = Math.max(start, windowStartMs);
|
||||
if (windowEndMs !== null) end = Math.min(end, windowEndMs);
|
||||
if (end > start) totalMs += end - start;
|
||||
}
|
||||
return totalMs > 0 ? Math.round(totalMs / 1000) : null;
|
||||
}
|
||||
Reference in New Issue
Block a user