fix(agent): harden post-reboot completion recovery after review

Three real regressions, all confirmed against the code before touching it — two of
them introduced by the recovery itself.

The remembered exit edge was unqualified. Shell-Core raises 62407 at every ESP
phase transition, so OnEspExited also latched the DeviceSetup→AccountSetup one;
the deferred re-check would then open the strong AccountSetup gate as soon as the
last user app settled, while the AccountSetup page was still up and its other
subcategories still running. IsConfirmedPostAccountSetupExit() now demands
positive evidence (AccountSetup activity observed, or SkipUser == true) and is
deliberately stricter than the existing IsIntermediateDeviceEspExit() forward
guard: an unknown SkipUser counts as not confirmed. Erring strict costs the
pre-fix stall; erring loose costs a premature Succeeded. The immediate on-edge
synthesis keeps its previous behaviour verbatim.

The replay picked the oldest exit, not the final one. The reader walks
oldest-first and the exit branch is fire-once, so the widened downtime window —
which routinely holds both the intermediate and the final exit — handed over the
intermediate one and the fire-once guard swallowed the exit that matters.
ReplayBackfillRecords buffers the batch and lets only the newest exit-matching
record through; ESP failures and the Hello-wizard rail keep replaying
chronologically.

The replay ran before the IME state restore. ImeLogTracker.Start() restores the
persisted package states via LoadState() without raising OnAppStateChanged, and
ImeLogHost starts after EspAndHelloHost, so the replay evaluated an empty app
list — leaving the sharpest case unfixed: apps already terminal before the
reboot, only the final exit lost to the downtime. ImeLogHost gained an
onStateRestored callback wired to the re-check, and the host order is now pinned
by DefaultComponentFactoryOrderingTests so a reshuffle fails loudly.

11 new tests. Agent V2.Core 2340, DecisionCore 533, Backend 4287, all green.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Oliver Kieselbach
2026-08-19 17:27:29 +02:00
parent e1b03de5b3
commit b61d7023bc
10 changed files with 423 additions and 18 deletions
+35 -3
View File
@@ -56,6 +56,14 @@ and the lookback becomes "everything since the boot that killed us", clamped to
`ShellCoreTracker.BackfillLookbackMaxMinutes` (360 — the agent's max lifetime). Every other
exit type keeps the 5-minute default.
**Newest exit wins.** Widening the window changes what the replay contains. The reader walks
oldest-first and the exit branch is fire-once, so a naive record-by-record replay hands over
the *first* match — with a downtime-sized window that is the intermediate
DeviceSetup→AccountSetup exit, and the final post-AccountSetup exit is then swallowed by the
fire-once guard. `ReplayBackfillRecords` therefore buffers the batch and lets only the newest
exit-matching record through the exit branch; ESP failures and the Hello-wizard rail keep
replaying chronologically, exactly as before.
## Defect 2 — the synthesis was edge-triggered
`MaybeSynthesizeAccountSetupCompleteFromSettledUserApps()` ran **only** from `OnEspExited`.
@@ -72,11 +80,35 @@ uses). Every terminal app transition gives the synthesis another look.
This adds **no new completion path**. The gate conditions are unchanged — real ESP exit,
every required user-ESP app terminal, zero failures. The re-check only grants the existing,
deliberately conservative check a second opportunity. Two guards keep it cheap and safe:
deliberately conservative check a second opportunity. Three guards keep it cheap and safe:
the fire-once claim is an `Interlocked.CompareExchange` (the re-check runs on the IME log
thread, the edge on the Shell-Core watcher thread), and the re-check path suppresses
thread, the edge on the Shell-Core watcher thread); the re-check path suppresses
`app_install_starved` emission so the one-shot warning does not become a per-transition
stream.
stream; and the edge itself is gated.
**Only a confirmed post-AccountSetup exit may be remembered.** Shell-Core raises 62407 at
every ESP phase transition. Remembering the DeviceSetup→AccountSetup one would let the
deferred re-check open the strong AccountSetup gate the moment the last user app settles —
while the AccountSetup page is still up and its other subcategories are still running, i.e.
a premature success. `IsConfirmedPostAccountSetupExit()` demands positive evidence and is
deliberately stricter than the existing `IsIntermediateDeviceEspExit()` forward guard:
| Evidence | Meaning |
|---|---|
| provisioning tracker reports AccountSetup activity | the page that just tore down is the AccountSetup one |
| `SkipUser == true` | the profile has no user ESP; the Device-ESP exit **is** the final one |
Anything else — including an unknown `SkipUser` — counts as *not confirmed*. The asymmetry is
intentional: erring strict costs at worst the pre-fix behaviour (the session stalls), while
erring loose costs a premature `Succeeded`, which nothing downstream can take back.
**The re-check must also run after the IME state restore.** `ImeLogTracker.Start()` restores
the persisted package states via `LoadState()` and raises no `OnAppStateChanged` for them, and
`ImeLogHost` starts *after* `EspAndHelloHost` (pinned by
`DefaultComponentFactoryOrderingTests`). So on a restart the ESP-exit replay runs against an
empty app list. `ImeLogHost` takes an `onStateRestored` callback — wired in the factory to the
re-check — which covers the sharpest case of all: apps already terminal *before* the reboot,
with only the final exit lost to the downtime.
# Examples
+1 -1
View File
@@ -2,7 +2,7 @@
## 2026-08-19
* **New**: `agent/post-reboot-completion-recovery.md` — a forced mid-ESP reboot (DeviceGuard/DmaGuard) used to cost the session its AccountSetup completion permanently. Two defects: `ShellCoreTracker.BackfillRecentEspExitEvents()` existed but had no caller, so every agent restart dropped an ESP exit (62407) written while it was down; and the user-apps-settled synthesis was edge-triggered on `EspExited` only, so apps settling afterwards never re-opened the gate. `EspAndHelloHost.Start()` now backfills with a lookback sized to the downtime (`previousExit=reboot_kill` → since `LastBootUtc`, clamped to 360 min), and `ReevaluateUserAppsSettledSynthesis()` is chained into `ImeLogTracker.OnAppStateChanged`. No new completion path — the gate conditions are unchanged. Evidence: sits-d Cloud PCs, five `Incomplete` sessions on healthy devices, two of them at `138/138 apps, 0 failed`.
* **New**: `agent/post-reboot-completion-recovery.md` — a forced mid-ESP reboot (DeviceGuard/DmaGuard) used to cost the session its AccountSetup completion permanently. Two defects: `ShellCoreTracker.BackfillRecentEspExitEvents()` existed but had no caller, so every agent restart dropped an ESP exit (62407) written while it was down; and the user-apps-settled synthesis was edge-triggered on `EspExited` only, so apps settling afterwards never re-opened the gate. `EspAndHelloHost.Start()` now backfills with a lookback sized to the downtime (`previousExit=reboot_kill` → since `LastBootUtc`, clamped to 360 min), and `ReevaluateUserAppsSettledSynthesis()` is chained into `ImeLogTracker.OnAppStateChanged`. No new completion path — the gate conditions are unchanged. Evidence: sits-d Cloud PCs, five `Incomplete` sessions on healthy devices, two of them at `138/138 apps, 0 failed`. Hardened after review: only a **confirmed** post-AccountSetup exit may be remembered as the edge (`IsConfirmedPostAccountSetupExit` — AccountSetup activity seen, or `SkipUser == true`; unknown counts as not confirmed), the replay hands over the **newest** exit rather than the oldest (the widened window holds the intermediate one too), and `ImeLogHost` re-triggers the check after its silent `LoadState()` because it starts after `EspAndHelloHost`.
* **Update**: `rules/analyze-rule-triggers.md` — `on_event:session_stalled` documented as an established interim trigger for the never-terminal stuck session (one emission per session, no throttle needed). `ANALYZE-ESP-005` carries it: both its conditions are monotonic and it has no terminal precondition, and it fires at confidence 95 on the sits-d stalled stream. `ANALYZE-APP-015` deliberately does NOT — it is the worked example of the terminal-precondition trap (lint 1) — and `ANALYZE-ESP-001` does not either, because its `phase_duration` gate on a still-open phase is unverified mid-run. New `ANALYZE-APP-016` ("Required Apps Never Started — ESP Apps Gate Starved") turns the existing `app_install_starved` events into a customer-facing finding and, unlike `ANALYZE-APP-015`, fires even when the session succeeded — session `3b9291aa` was recorded `Succeeded` with 99 required apps that never started installing.
@@ -35,14 +35,25 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring
public Fixture() { Logger = new AgentLogger(Tmp.Path, AgentLogLevel.Debug); }
public EspAndHelloTracker BuildCoordinator(Func<bool> settledProbe)
=> BuildCoordinator(settledProbe, accountSetupActivityProbe: () => true, skipUserEsp: false);
/// <summary>
/// Codex review P1 (2026-08-19): the remembered exit edge is gated on positive evidence
/// that the exit is post-AccountSetup, so these two probes decide whether the deferred
/// re-check may fire at all.
/// </summary>
public EspAndHelloTracker BuildCoordinator(
Func<bool> settledProbe,
Func<bool> accountSetupActivityProbe,
bool? skipUserEsp)
{
return new EspAndHelloTracker(
sessionId: "S1",
tenantId: "T1",
post: new InformationalEventPost(TrackerPostSink, Clock),
logger: Logger,
skipConfigProbe: () => ((bool?)false, (bool?)false),
accountSetupActivityProbe: () => true,
skipConfigProbe: () => (skipUserEsp, (bool?)false),
accountSetupActivityProbe: accountSetupActivityProbe,
userEspAppsSettledProbe: settledProbe);
}
@@ -224,6 +235,90 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring
Assert.Single(f.TrackerPostSink.Posted);
}
// ------------------------------------------------------------------------------
// Codex review P1 (2026-08-19): Shell-Core raises 62407 at EVERY ESP phase transition.
// Remembering the intermediate DeviceSetup→AccountSetup exit would let the deferred
// re-check open the strong AccountSetup gate as soon as the last user app settles —
// while the AccountSetup page is still up and its other subcategories still running.
// ------------------------------------------------------------------------------
[Fact]
public void Intermediate_device_exit_is_not_remembered_as_the_edge()
{
using var f = new Fixture();
var settled = false;
// Classic user-driven enrollment (SkipUser=false) that has NOT reached AccountSetup:
// this 62407 is the DeviceSetup→AccountSetup transition, not the final exit.
using var coordinator = f.BuildCoordinator(
() => settled, accountSetupActivityProbe: () => false, skipUserEsp: false);
using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock);
coordinator.TriggerEspExitedForTest(Fixed);
// Apps settle afterwards — the level is reached, but the edge was never a valid one.
settled = true;
for (var i = 0; i < 10; i++) coordinator.ReevaluateUserAppsSettledSynthesis();
Assert.DoesNotContain(f.Ingress.Posted, p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete);
Assert.False(coordinator.UserAppsSettledSynthesisFiredForTest);
Assert.Empty(f.TrackerPostSink.Posted);
}
[Fact]
public void Unknown_skip_user_is_treated_as_unconfirmed()
{
// Erring strict costs at worst today's stall; erring loose costs a premature Succeeded.
using var f = new Fixture();
var settled = false;
using var coordinator = f.BuildCoordinator(
() => settled, accountSetupActivityProbe: () => false, skipUserEsp: null);
using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock);
coordinator.TriggerEspExitedForTest(Fixed);
settled = true;
coordinator.ReevaluateUserAppsSettledSynthesis();
Assert.False(coordinator.UserAppsSettledSynthesisFiredForTest);
}
[Fact]
public void Skip_user_profile_confirms_the_device_exit_as_final()
{
// SkipUser=true means there is no user ESP at all — the Device-ESP exit IS the final
// one and no second exit is coming, so the edge is legitimately remembered.
using var f = new Fixture();
var settled = false;
using var coordinator = f.BuildCoordinator(
() => settled, accountSetupActivityProbe: () => false, skipUserEsp: true);
using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock);
coordinator.TriggerEspExitedForTest(Fixed);
settled = true;
coordinator.ReevaluateUserAppsSettledSynthesis();
Assert.Equal(1, f.Ingress.Posted.Count(p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete));
}
[Fact]
public void Account_setup_activity_confirms_the_edge_for_the_deferred_recheck()
{
// The real reboot shape: AccountSetup activity is visible in the registry, the final
// exit lands, the apps settle a moment later.
using var f = new Fixture();
var settled = false;
using var coordinator = f.BuildCoordinator(
() => settled, accountSetupActivityProbe: () => true, skipUserEsp: false);
using var adapter = new EspAndHelloTrackerAdapter(coordinator, f.Ingress, f.Clock);
coordinator.TriggerEspExitedForTest(Fixed);
Assert.DoesNotContain(f.Ingress.Posted, p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete);
settled = true;
coordinator.ReevaluateUserAppsSettledSynthesis();
Assert.Equal(1, f.Ingress.Posted.Count(p => p.Kind == DecisionSignalKind.AccountSetupProvisioningComplete));
}
[Fact]
public void Reevaluate_stays_silent_while_apps_are_still_unsettled()
{
@@ -163,6 +163,93 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring
Assert.Equal(0, exits);
}
// ------------------------------------------------------------------------------
// Codex review P1 (2026-08-19): the reader walks oldest-first and the exit branch is
// fire-once, so a naive replay hands over the FIRST match. With the downtime-sized
// lookback the window routinely holds the intermediate DeviceSetup→AccountSetup exit
// AND the final one — and the first match is the wrong edge, with the right one
// swallowed by the fire-once guard.
// ------------------------------------------------------------------------------
[Fact]
public void Replay_hands_over_the_newest_esp_exit_not_the_oldest()
{
using var tmp = new TempDirectory();
using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow));
var exits = new List<DateTime>();
tracker.EspExited += (_, args) => exits.Add(args.OccurredAtUtc);
var intermediate = ClockNow.AddMinutes(-40); // DeviceSetup → AccountSetup
var final = ClockNow.AddMinutes(-9); // AccountSetup → End (the one we need)
tracker.ReplayBackfillRecords(new List<(int, string, DateTime)>
{
(ShellCoreTracker.EventId_ShellCore_WebAppEvent, EspExitDescription, intermediate),
(ShellCoreTracker.EventId_ShellCore_WebAppEvent, EspExitDescription, final),
});
var raised = Assert.Single(exits);
Assert.Equal(final, raised);
}
[Fact]
public void Replay_keeps_chronological_order_for_non_exit_records()
{
// Only the exit branch is newest-wins; the Hello-wizard rail and ESP failures must
// keep replaying exactly as before, oldest-first.
using var tmp = new TempDirectory();
using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow));
var order = new List<string>();
tracker.HelloWizardStarted += (_, args) => order.Add($"wizard:{args.OccurredAtUtc:HH:mm}");
tracker.EspExited += (_, args) => order.Add($"exit:{args.OccurredAtUtc:HH:mm}");
const string aadHello = "CloudExperienceHost web app activity started. CXID: 'AADHello'.";
tracker.ReplayBackfillRecords(new List<(int, string, DateTime)>
{
(ShellCoreTracker.EventId_ShellCore_WebAppEvent, EspExitDescription, ClockNow.AddMinutes(-40)),
(ShellCoreTracker.EventId_ShellCore_WebAppStarted, aadHello, ClockNow.AddMinutes(-20)),
(ShellCoreTracker.EventId_ShellCore_WebAppEvent, EspExitDescription, ClockNow.AddMinutes(-9)),
});
// Wizard replays at its own position; the exit fires once, for the newest record.
Assert.Equal(new[] { "wizard:" + ClockNow.AddMinutes(-20).ToString("HH:mm"),
"exit:" + ClockNow.AddMinutes(-9).ToString("HH:mm") }, order);
}
[Fact]
public void Replay_of_a_single_exit_is_unchanged()
{
using var tmp = new TempDirectory();
using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow));
var exits = new List<DateTime>();
tracker.EspExited += (_, args) => exits.Add(args.OccurredAtUtc);
var only = ClockNow.AddMinutes(-11);
tracker.ReplayBackfillRecords(new List<(int, string, DateTime)>
{
(ShellCoreTracker.EventId_ShellCore_WebAppEvent, EspExitDescription, only),
});
Assert.Equal(only, Assert.Single(exits));
}
[Fact]
public void Replay_of_an_empty_batch_is_a_no_op()
{
using var tmp = new TempDirectory();
using var tracker = MakeTracker(tmp, new VirtualClock(ClockNow));
var exits = 0;
tracker.EspExited += (_, __) => exits++;
tracker.ReplayBackfillRecords(new List<(int, string, DateTime)>());
Assert.Equal(0, exits);
}
[Theory]
[InlineData(0, 1)]
[InlineData(-42, 1)]
@@ -118,6 +118,16 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
hosts,
"AadJoinHost wires its onRealUserJoined callback to the already-constructed DesktopArrivalHost.");
// Codex review P2 (2026-08-19): EspAndHelloHost.Start() replays the Shell-Core
// ESP exit, but ImeLogTracker only restores its persisted app states in its own
// Start() — which happens later. Pin the order that makes ImeLogHost's
// onStateRestored nudge necessary, so a future reshuffle either keeps the nudge
// meaningful or fails here loudly.
AssertBefore<EspAndHelloHost, ImeLogHost>(
hosts,
"the ESP-exit replay runs before the IME app-state restore, which is why " +
"ImeLogHost re-triggers the user-apps-settled synthesis after LoadState.");
// Closure-latch sanity (factory lines ~139/297): the EspAndHelloHost probes close
// over the ImeLogHost reference, which is assigned during the same factory call —
// the host must therefore exist in the returned list.
@@ -0,0 +1,72 @@
#nullable enable
using System;
using AutopilotMonitor.Agent.V2.Core.Logging;
using AutopilotMonitor.Agent.V2.Core.Orchestration;
using AutopilotMonitor.Agent.V2.Core.Tests.Harness;
using Xunit;
namespace AutopilotMonitor.Agent.V2.Core.Tests.Orchestration
{
/// <summary>
/// Codex review P2 (2026-08-19) — <see cref="ImeLogHost"/> starts AFTER <c>EspAndHelloHost</c>,
/// and <c>ImeLogTracker.Start()</c> restores the persisted package states silently (LoadState
/// raises no <c>OnAppStateChanged</c>). On an agent restart the Shell-Core ESP-exit replay
/// therefore runs against an empty app list. Without the post-restore nudge the exact reboot
/// case the completion recovery exists for — apps already terminal BEFORE the reboot, only the
/// final exit lost to the downtime — would still never complete.
/// </summary>
public sealed class ImeLogHostStateRestoredCallbackTests : IDisposable
{
private readonly TempDirectory _tmp = new TempDirectory();
public void Dispose() => _tmp.Dispose();
private ImeLogHost CreateHost(Action? onStateRestored)
=> new ImeLogHost(
sessionId: "s",
tenantId: "t",
logger: new AgentLogger(_tmp.Path, AgentLogLevel.Info),
ingress: new FakeSignalIngressSink(),
clock: new VirtualClock(new DateTime(2026, 8, 19, 8, 43, 16, DateTimeKind.Utc)),
imeLogPathOverride: _tmp.Path,
imeMatchLogPath: null,
imePatterns: null,
stateDirectory: _tmp.Path,
whiteGloveSealingPatternIds: null,
onStateRestored: onStateRestored);
[Fact]
public void Start_invokes_the_state_restored_callback_exactly_once()
{
var calls = 0;
using var host = CreateHost(() => calls++);
host.Start();
try { Assert.Equal(1, calls); }
finally { host.Stop(); }
}
[Fact]
public void A_throwing_callback_does_not_break_host_start()
{
// Fail-soft like every other co-wired callback in the orchestration layer: a broken
// re-check must never take the IME log host — the session's primary signal source —
// down with it.
using var host = CreateHost(() => throw new InvalidOperationException("recheck boom"));
var ex = Record.Exception(() => host.Start());
try { Assert.Null(ex); }
finally { host.Stop(); }
}
[Fact]
public void No_callback_is_a_valid_configuration()
{
using var host = CreateHost(null);
var ex = Record.Exception(() => host.Start());
try { Assert.Null(ex); }
finally { host.Stop(); }
}
}
}
@@ -52,11 +52,18 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// guard concurrently (Shell-Core watcher thread + IME log thread).
private int _userAppsSettledSynthesisFired;
// sits-d Cloud-PC fix (2026-08-19) — set once a Shell-Core normal ESP exit has been
// observed (live OR backfill). The synthesis needs two facts: the ESP exit is an EDGE
// that happens once, the settled user-ESP apps are a LEVEL that may only be reached
// minutes later. Recording the edge lets ReevaluateUserAppsSettledSynthesis re-check
// the level afterwards instead of losing the completion for the rest of the session.
// sits-d Cloud-PC fix (2026-08-19) — set once a CONFIRMED post-AccountSetup Shell-Core
// exit has been observed (live OR backfill). The synthesis needs two facts: the ESP exit
// is an EDGE that happens once, the settled user-ESP apps are a LEVEL that may only be
// reached minutes later. Recording the edge lets ReevaluateUserAppsSettledSynthesis
// re-check the level afterwards instead of losing the completion for the rest of the
// session.
//
// Codex review P1 (2026-08-19): "confirmed" is load-bearing. Shell-Core raises 62407 at
// EVERY ESP phase transition, DeviceSetup→AccountSetup included. Remembering that
// intermediate exit would let the deferred re-check open the strong AccountSetup gate the
// moment the last user app settles — while the AccountSetup page is still up and its other
// subcategories are still running. See IsConfirmedPostAccountSetupExit.
private volatile bool _espExitObserved;
// Liveness plan PR3 — one-shot-per-appId dedupe for app_install_starved emissions.
@@ -578,6 +585,40 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
return skipUser == false;
}
/// <summary>
/// Codex review P1 (2026-08-19) — may THIS <c>esp_exiting</c> be remembered as the edge the
/// deferred user-apps-settled re-check builds on?
/// <para>
/// Deliberately STRICTER than <c>!IsIntermediateDeviceEspExit()</c>: that helper forwards
/// on an unknown SkipUser (forwarding a signal early is cheap), whereas remembering the
/// wrong edge here can open a completion gate minutes later with no second chance to take
/// it back. So this one demands positive evidence and treats "unknown" as "not confirmed":
/// </para>
/// <list type="bullet">
/// <item>the provisioning tracker has seen AccountSetup activity — the page that just
/// tore down is demonstrably the AccountSetup one; or</item>
/// <item>SkipUser is explicitly <c>true</c> — the profile has no user ESP at all, so the
/// Device-ESP exit IS the final one and no second exit is coming.</item>
/// </list>
/// <para>
/// Erring strict costs at worst today's behaviour (the session stalls as it did before the
/// fix); erring loose costs a premature Succeeded, which is unrecoverable.
/// </para>
/// </summary>
private bool IsConfirmedPostAccountSetupExit()
{
bool accountSetupSeen;
try { accountSetupSeen = _accountSetupActivityProbe(); }
catch (Exception ex)
{
_logger.Debug($"EspAndHelloTracker: account-setup-activity probe threw: {ex.Message}");
accountSetupSeen = false;
}
if (accountSetupSeen) return true;
return GetSkipUserEspCached() == true;
}
private bool? GetSkipUserEspCached()
{
lock (_skipConfigLock)
@@ -718,8 +759,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
catch (Exception ex) { _logger.Error("Error forwarding EspExited", ex); }
// Record the edge BEFORE the synthesis attempt so a later app-state change can
// re-run it even when the apps are not settled yet at this instant.
_espExitObserved = true;
// re-run it even when the apps are not settled yet at this instant — but ONLY for
// an exit we can positively place after AccountSetup. The immediate attempt below
// is deliberately left ungated: it keeps its pre-existing behaviour exactly.
if (IsConfirmedPostAccountSetupExit())
_espExitObserved = true;
// Session caa6cf50 gate-starvation fix: a Shell-Core normal exit while IME's
// user-ESP app tracking is fully settled is alternative evidence that
@@ -391,6 +391,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
PathType.LogName,
$"*[System[(EventID=62404 or EventID=62407) and TimeCreated[timediff(@SystemTime) <= {lookbackMs}]]]");
var records = new List<(int Id, string Description, DateTime OccurredAtUtc)>();
using (var reader = new EventLogReader(query))
{
for (EventRecord record = reader.ReadEvent(); record != null; record = reader.ReadEvent())
@@ -402,10 +403,12 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
// (EspAndHelloTrackerAdapter) can stamp signals with the source time
// rather than collapsing to wall-clock-now.
var timestamp = (record.TimeCreated ?? DateTime.UtcNow).ToUniversalTime();
HandleBackfillRecord(record.Id, description, timestamp);
records.Add((record.Id, description, timestamp));
}
}
}
ReplayBackfillRecords(records);
}
catch (Exception ex)
{
@@ -413,6 +416,44 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
}
}
/// <summary>
/// Codex review P1 (2026-08-19) — replays a chronological batch of Shell-Core records.
/// <para>
/// The reader walks oldest-first and the ESP-exit branch is fire-once, so a naive
/// record-by-record replay hands the FIRST match downstream. With the downtime-sized
/// lookback the window routinely holds both the intermediate DeviceSetup→AccountSetup exit
/// and the final post-AccountSetup one — and the first match is the intermediate one, i.e.
/// exactly the wrong edge, with the right one swallowed by the fire-once guard.
/// </para>
/// <para>
/// So: everything is replayed in chronological order (ESP failures and the Hello-wizard
/// rail keep their existing semantics verbatim), but only the NEWEST exit-matching record
/// is allowed through the exit branch. Internal for direct testing without an event log.
/// </para>
/// </summary>
internal void ReplayBackfillRecords(
IReadOnlyList<(int Id, string Description, DateTime OccurredAtUtc)> records)
{
if (records == null || records.Count == 0) return;
var lastExitIndex = -1;
for (var i = 0; i < records.Count; i++)
{
if (EspExitingPattern.IsMatch(records[i].Description ?? ""))
lastExitIndex = i;
}
for (var i = 0; i < records.Count; i++)
{
var record = records[i];
HandleBackfillRecord(
record.Id,
record.Description ?? "",
record.OccurredAtUtc,
allowEspExit: i == lastExitIndex);
}
}
/// <summary>
/// Internal backfill record handler — extracted for testability and to keep the
/// backfill loop free of direct event-processing logic. The
@@ -420,7 +461,8 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
/// (<c>record.TimeCreated</c>); subscribers read it via
/// <see cref="LastEventOccurredAtUtc"/> during their synchronous event handler.
/// </summary>
internal void HandleBackfillRecord(int eventId, string description, DateTime occurredAtUtc)
internal void HandleBackfillRecord(
int eventId, string description, DateTime occurredAtUtc, bool allowEspExit = true)
{
if (eventId == EventId_ShellCore_WebAppStarted)
{
@@ -452,7 +494,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.SystemSignals
return;
}
if (EspExitingPattern.IsMatch(description))
if (allowEspExit && EspExitingPattern.IsMatch(description))
{
bool shouldNotify = false;
lock (_stateLock)
@@ -339,7 +339,14 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
stateDirectory: _stateDirectory,
whiteGloveSealingPatternIds: whiteGloveSealingPatternIds,
simulationMode: simulationMode,
simulationSpeedFactor: _agentConfig.ReplaySpeedFactor);
simulationSpeedFactor: _agentConfig.ReplaySpeedFactor,
// Codex review P2 (2026-08-19): the IME tracker restores its persisted app states
// inside Start(), silently (LoadState raises no OnAppStateChanged). This host starts
// AFTER EspAndHelloHost, so the Shell-Core ESP-exit replay has already run against
// an empty app list. Nudge the synthesis once the restored level is in place —
// otherwise the exact reboot case (apps terminal BEFORE the reboot, only the final
// exit lost to the downtime) still never completes.
onStateRestored: () => espAndHelloHost.ReevaluateUserAppsSettledSynthesis());
hosts.Add(imeLogHost);
imeLogHostRef = imeLogHost;
@@ -18,6 +18,7 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
private readonly ImeLogTracker _tracker;
private readonly ImeProcessWatcher _processWatcher;
private readonly Action? _onStateRestored;
private readonly ImeLogTrackerAdapter _adapter;
private readonly AgentLogger _logger;
private int _disposed;
@@ -96,9 +97,11 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
string stateDirectory,
IReadOnlyCollection<string>? whiteGloveSealingPatternIds,
bool simulationMode = false,
double simulationSpeedFactor = 50)
double simulationSpeedFactor = 50,
Action? onStateRestored = null)
{
_logger = logger;
_onStateRestored = onStateRestored;
var logFolder = string.IsNullOrEmpty(imeLogPathOverride) ? DefaultImeLogFolder : imeLogPathOverride!;
var expandedMatchLogPath = string.IsNullOrEmpty(imeMatchLogPath)
? null
@@ -128,10 +131,23 @@ namespace AutopilotMonitor.Agent.V2.Core.Orchestration
_processWatcher = new ImeProcessWatcher(sessionId, tenantId, processWatcherPost, logger);
}
/// <summary>
/// Codex review P2 (2026-08-19) — <see cref="ImeLogTracker.Start"/> restores the persisted
/// package states (LoadState) and does NOT raise <c>OnAppStateChanged</c> for them. This
/// host is started AFTER <c>EspAndHelloHost</c>, so on an agent restart the Shell-Core
/// ESP-exit replay runs against an empty app list and synthesises nothing — and without a
/// nudge here nothing would ever re-check, which is precisely the reboot case the
/// completion recovery exists for (apps already terminal before the reboot, only the final
/// exit lost to the downtime). <paramref name="onStateRestored"/> fires once, after the
/// restore, so the deferred synthesis gets its look at the restored level.
/// </summary>
public void Start()
{
_tracker.Start();
_processWatcher.Start();
try { _onStateRestored?.Invoke(); }
catch (Exception ex) { _logger.Warning($"ImeLogHost: onStateRestored callback threw: {ex.Message}"); }
}
public void Stop()