Field regression, session e9753578 (agent 2.0.1410, PST-defaulted device in DE).
Five script_started events resolved 9 h early while their script_completed
counterparts resolved correctly, inflating every platform-script duration to
~32,400 s. Reverts the application introduced in e9dba11b.
Root cause: calibration keeps ONE offset per log file, but a single file can hold
lines from two writer eras. IME restarting across a timezone change leaves older
lines in the old zone and newer ones in the new zone, in the same file. The anchor
is the newest line, so its offset was also applied to the older lines, for which
it does not hold. The class doc even claimed "self-healing on writer restart" —
that reasoning only ever covered FUTURE lines, never the ones already on disk.
The more expensive mistake was the second one: correcting ABSOLUTE timestamps
without checking what depends on their DIFFERENCES. Applying the reader zone
uniformly is wrong in absolute terms but self-consistent — both ends of a duration
are wrong by the same amount, so the duration is right. Correcting only some
timestamps produced a mixed frame inside one session, which is strictly worse than
being uniformly wrong. This is the same asymmetry the original analysis described
for AppInstallSummaries (68 min reported against 8 min real) and then reproduced.
What stays, deliberately:
- Bias-carrying lines still resolve via the writer-declared offset; that path was
never implicated.
- The measurement keeps running. It costs nothing, feeds the Info log, and is the
field data the era-aware fix has to be built on — the first anlauf got the era
question wrong from assumption rather than observation.
- Provenance now separates measured from applied (measuredWriterOffsetMinutes vs
sourceOffsetMinutes). The broken event was tagged "calibrated" while carrying an
offset that did not hold for its line; that confusion must not be expressible.
- The fallback path reports the offset it actually applied. An event stating no
offset cannot be recomputed later, which defeats the point of provenance.
Provenance earned its keep here: 57 events measured -420 (the PDT writer) against
5 at +120 made the diagnosis a two-minute query instead of median statistics over
a session.
Next: era-aware calibration keyed on the IME-STARTED marker, which we already
track, plus a test over a log file containing two writer eras — the case that was
missing.
Agent 2393 green against a verified-clean build.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Every IME-sourced event now states what the writer wrote, what offset was applied,
and how that offset was obtained:
sourceLocalTs raw local time, verbatim, NO zone suffix
sourceOffsetMinutes the offset subtracted
sourceOffsetOrigin bias | calibrated | reader-zone-fallback
Why: until now the only record of a conversion was the converted value, so a wrong
offset was indistinguishable from a right one. Proving the field defect needed the
diagnostics archive — and of the 5,386 sessions that went through a timezone
change, essentially none had one, so the analysis had to fall back to median
statistics across thousands of sessions to establish what one stored value makes
obvious per session. It also makes a stored timestamp recomputable after the fact,
without an agent release.
No zone suffix on sourceLocalTs on purpose: the value genuinely carries none, and
formatting one in would re-introduce the assumption this whole change removes.
sourceOffsetMinutes is normalised to one sense (local = UTC + offset) across both
origins. The wire bias uses the opposite GetTimeZoneInformation convention
(UTC = local + bias), so a "+480" line is reported as -480; without that the field
would flip sign depending on where the offset came from and be useless to compare.
Added centrally in TagDerivedTimestamp, which all 14 emit sites already call, so
this does not scatter through the adapter. DataJson only — no table schema change,
so no Store/Map/seed chain and no backend deploy needed to start collecting it.
Agent 2393 / backend 4313 green against a verified-clean build.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
ResolveOccurredAt rejected a source timestamp when ageHours < -1.0. That bound
could not fire for the single most common timezone error: with a one-hour offset
mistake the real value is parseLag - 3600 s, i.e. just ABOVE -1.0. It sat exactly
on the boundary of the case it was meant to catch, which is why every skewed
session sailed past it.
It was asymmetric too — a past-shifted error had to exceed 24 h before anything
noticed, while the measured field errors reached -17 h.
The bound is now derived rather than guessed: writer and reader share one system
clock, and the tracker only sees a line after it was written, so a correctly
converted source timestamp is always at or behind "now". Anything ahead means the
conversion was wrong. MaxFutureSourceSkew is 2 minutes of jitter tolerance —
deliberately far below the hour a timezone mistake produces.
The rejection log now names which bound tripped and by how much, instead of
printing a bare ageHours that reads the same for both directions.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This is the behaviour change the previous two commits prepared. ImeLogTracker no
longer substitutes its own timezone belief for the IME process's; it measures the
writer's offset from a freshly appended line and converts with that.
Freshness is stricter than "the file grew". GetSafePosition returns 0 for an
unknown file, so the first pass reads the whole file and its newest line may be
hours old — anchoring there would measure the line's age, not the writer's offset.
LogFilePositionTracker.HasSeen(), captured BEFORE GetSafePosition creates the
entry, gates calibration on growth against a size we had already observed.
Calibration runs at the END of a qualifying pass, so that pass still uses the
previously measured offset — at most one poll (100 ms) old, and an offset only
moves when a process restarts. Calibrating first would mean buffering the pass,
which is not viable: the first pass over AppWorkload.log can be hundreds of MB.
The cost is a warm-up of one growing pass, during which lines fall back to the
reader zone.
Bias-carrying lines are never used as anchors: they already state the writer's
offset, so they need no measurement and must not overwrite one.
CalibrateFrom logs at Info when the measured offset disagrees with this process's
own zone, naming the correction applied. That disagreement is precisely the
condition that silently corrupted every IME-derived timestamp until now; agreement
stays at Debug so the normal case does not add noise.
Tests are deliberately machine-independent: the assertion is always "a line
written at instant T resolves to T", asserted across writer beliefs of +2, +1, 0,
-7 and +10. That one property covers both field cases — the writer disagreeing
with us (the bug) and the writer agreeing with us (the majority of sessions, where
two stale beliefs cancel and which a fix to the agent's own cache would have
broken). Plus: no calibration on first sight, following a writer restart into a
new zone, and a declared bias honoured without being measured.
CheckLogFilesAsync is internal as a test seam — calibration depends on the pass
structure, which only a real read cycle exercises.
Agent 2390 / backend 4313 green against a verified-clean build.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Behaviour-neutral: 2381 agent and 4313 backend tests pass unchanged.
The parser resolved a bias-less line with DateTimeStyles.AssumeLocal followed by
ToUniversalTime(), i.e. with the READING process's cached zone. That silently
assumes reader and writer agree. They do not — each caches its zone at process
start and neither follows a later tzutil or Windows auto-timezone change — and the
assumption was buried inside a shared helper where no call site could see it.
CmTraceLogEntry now exposes what the line actually contains: LocalTimestamp
(Kind=Unspecified, because the value is meaningless without knowing the writer's
zone) and BiasMinutes. TimestampUtc is populated only when the writer declared its
bias, which is the one case where the offset is genuinely known. Timestamp is
removed rather than deprecated, so the compiler names every site that has to
decide — it immediately turned up ProcessLogMessageForTest, which grep had missed.
The defective path still exists, but now as one named function,
ResolveUtcAssumingReaderZone(), whose documentation states when it is wrong. All
three consumers call it and so keep their current behaviour exactly:
- ImeLogTracker routes every use through ResolveEntryUtc(), the single point where
the measured offset replaces the fallback in the follow-up change;
- StallProbeCollector and LogParserCollector read file snapshots rather than
tailing, so they cannot measure an offset and stay on the fallback for now.
The parser also no longer invents a timestamp. An unparseable time used to be
stamped DateTime.UtcNow inside the parser, making a fabricated value
indistinguishable from a real one downstream; it now reports HasTimestamp=false
and leaves the fallback to the caller, which alone knows what is safe in context
(StallProbeCollector still treats such a line as fresh — calling it stale would
hide progress).
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
A CMTrace line carries local time and no offset — IME 1.104 writes
DateTime.Now.TimeOfDay in both of its trace listeners. Converting it with the
agent's own TimeZoneInfo.Local assumes both processes agree on the zone. They do
not: each caches its zone at process start and neither follows a later tzutil or a
Windows auto-timezone change, so the error is Offset_writer - Offset_agent and is
zero only by coincidence.
Measured over 11,068 sessions: 26 carry a real zone-offset error, +1 h (GMT to
W. Europe, session bfff9b1c) through -17 h (a writer still on the Pacific OOBE
default while the agent had already moved to E. Australia). Note the sign — this
is why "make the agent's own clock honest" is the wrong fix: in the -17 h cases
the agent was correct and the writer was stale, and clearing the agent's cache
would have broken the majority of sessions where both are stale and the two errors
cancel.
The tracker tails at a 100 ms poll, so a line that appeared since the previous
pass was written essentially "now". That makes the writer's offset measurable:
round(lineLocal - agentUtcNow) onto the 15-minute grid every real UTC offset sits
on. Per source file, because IntuneManagementExtension.log and AppWorkload.log are
written by different processes; re-measured on every fresh anchor, so a writer
restart is picked up within one poll.
The freshness requirement is the load-bearing part and cannot be replaced by the
residual guard: a backlog line exactly 30 minutes old is itself a clean multiple
of the grid, rounds with zero residual, and would calibrate the offset half an
hour wrong. RejectsBacklogLine_EvenWhenItRoundsCleanly pins that the calibrator
cannot detect this on its own — only the caller's freshness rule prevents it.
Additive only; no call site uses it yet.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Sequence is a persisted, strictly monotonic per-session counter assigned at emit
time (EventSequenceCounter: locked, saved before return, survives restarts). It is
immune to every clock problem. Timestamp carries the device clock frame plus, for
CMTrace-derived events, the writing process's timezone belief.
EvaluateAppInstallDurationCondition and EvaluateEventCorrelationCondition both
ordered by Timestamp and expressed "A happened before B" as a timestamp
comparison. Both now order by Sequence and compare Sequence for ordering.
Timestamp deliberately stays where an actual ELAPSED DURATION is meant:
durationSeconds, the evidence fields, and TimeWindowSeconds.
Scope, honestly: this is hardening, not a live bug fix. BuiltInAnalyzeRules.cs
contains zero event_correlation conditions, so the cross-frame join can only be
reached by a self-authored rule. And the app-install duration evaluator pairs
app_install_started with app_install_completed — both IME-sourced, one frame — so
its arithmetic was already correct. (The measured 68-vs-8-minute inflation comes
from EventIngestProcessor.AppInstall, which folds DO-collector download_progress
together with IME app_install_completed; that is fixed at the root in the agent.)
The TimeWindowSeconds check stays exposed: the window IS a duration, so there is
no alternative to a timestamp there. A +1 h skew on B makes any window below
3600 s fail to match. Only the agent-side calibration closes that.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
LastEventAt is the maximum AGENT-supplied event timestamp and therefore lives in
the device clock frame. The silence sweep compared it against a server-derived
cutoff, mixing two frames.
Measured over 11,068 sessions: 26 carry a genuine CMTrace timezone skew on their
IME-derived events, from -17 h to +1 h (a further 27 carry plain device-clock
offsets). At -17 h a live agent looks silent the moment it starts and is marked
Stalled with a customer-visible "Agent silent for 1020min"; at +1 h the sweep is
blind for an hour.
Adds SessionSummary.LastIngestAt, stamped from the server clock in
IncrementSessionEventCountAsync — reaching that method IS contact from the agent,
so it is written unconditionally rather than gated on latestEventTimestamp.
The sweep's server-side filter now spans both frames (LastIngestAt lt X or
LastEventAt lt X): filtering on LastIngestAt alone would silently drop every row
written before the field existed, because Table Storage does not match a filter
against a missing property. The authoritative decision moves into
ServerFrameLastContact() (LastIngestAt ?? LastEventAt ?? StartedAt) and is applied
in both stages — before the Stalled marker and in the stage-2 alive guard.
Deliberately not mirrored into SessionsIndex: the sweep reads Sessions, and the
index manifest is pinned bidirectionally by tests.
shared-manifests.json + .generated.ts regenerated — SharedManifestParityTests is
the drift brake and correctly went red on the new field.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Section headings now reserve keep-with-next space (charts reserve their full
height), so a title never strands at a page bottom while its table starts on
the next page. Table cells wrap up to 4 lines instead of single-line ellipsis,
and the exit-code column carries the full error description (the 24-char slice
is gone) - that text is what the app owner acts on. Failure-code column widths
rebalanced (Code 42 / Description 62 / Exit 60 / Count 16).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The pipeline's AutomaticDecompression (GZip|Deflate) removes the response
Content-Length header on virtually every backend JSON response, so
net_total_bytes_down in agent_metrics_snapshot read 0 on healthy sessions.
When the header is absent, buffer the content (LoadIntoBufferAsync, 16 MB cap)
and record the DECOMPRESSED payload size — HttpClient buffers responses anyway
(default ResponseContentRead), so no extra memory cost. Fail-soft: a buffering
error keeps 0 and leaves the failure for the caller to observe.
AutomaticDecompression itself stays untouched (pinned by
MtlsHttpClientFactoryTests).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
IME 1.104 removed the [DO TEL] log line, leaving the agent's DO collector as
the only do_telemetry source — and its gate only fires when a 3s poll itself
observes the completed download. Fast, interrupted or between-poll-completed
downloads never emit one, so DoDownloadMode stayed -1 and DoAggregator dropped
the whole row: DO bytes read as "practically null" on 1.104 fleets even though
download_progress events carried the full do* set on every poll.
- Shared ApplyDoFields for both writers: download_progress folds byte counters
and file size via Math.Max (monotonic, replay-idempotent) and sets the mode
only when >= 0; do_telemetry stays authoritative (last-write-wins) but never
regresses DoDownloadMode to the -1 unset sentinel.
- DownloadBytes now prefers actually-transferred bytes over doFileSize (the
file size used to inflate the transfer measure).
Intended effect after deploy: DO aggregates count previously-invisible
incomplete downloads, so app counts/bytes rise. No backfill of historic rows.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- New GA-only tool get_agent_efficiency_metrics: near-pass-through of the
server-side per-version aggregation (120s timeout, default 500 sessions,
optional tenantId). Added to GA_FULL + PLATFORM_ONLY catalog snapshots.
- platformWindowEcho decides truncated on the backend's sessionsScanned
(sessions actually covered) and only falls back to the has-snapshots count
for old backends — the previous comparison read false even when the cap was
hit exactly, whenever some scanned sessions carried no snapshots.
- get_platform_metrics: 90s timeout (backend fans out one storage query per
session); spool block, crashRate, deliveryLatency, computedAt,
computeDurationMs and fromCache are no longer dropped on the MCP side;
description clarifies totalBytesDown is the agent's own HTTP traffic.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
- New GET /api/global/metrics/agent-efficiency (GlobalReadOrAdmin, ?tenantId=):
per-agent-version percentiles (CPU, working set, private bytes, threads,
handles, spool, API latency/requests), crash rates per version, top offender
sessions per dimension, 5-min cache keyed (days, limit, tenant). First
backend consumption of agent_thread_count/agent_handle_count.
- PlatformAgentMetricsResponse.SessionsScanned: sessions the scan actually
covered — the honest basis for the caller's truncated flag (Sessions.Count
only counts sessions WITH snapshots).
- Per-session fetch no longer drains the full Events partition: new
GetSessionEventsByTypesAsync (multi-type OData filter + column projection +
real maxResults enforcement); the 20 delivery-latency sample sessions keep
the full fetch so latency deltas stay computed over all events.
- Shared AgentMetricsAggregation (crash tally, payload getters, bounded
fan-out, metrics event types) so the two services cannot drift.
- GetAllSessionsPageAsync gains an optional select projection (default null,
existing callers unchanged), pinned by an equivalence test.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Adds an "Export PDF" button to the app detail page that renders the full
90/30/7-day install report (KPIs, both charts, failure codes, device model
correlation, version breakdown, detection-rule/regression callouts) as a
branded A4 PDF, drawn data-driven with jsPDF — no DOM capture, so the output
is light-palette and theme-independent. jsPDF stays out of the route bundle
via on-click dynamic import (verified: separate async chunk).
Sample messages and the affected-sessions list are deliberately excluded:
the PDF is meant to be emailed outside the org.
Tracks app_report_pdf_exported in Application Insights (windowDays, scope,
durationMs, pageCount, success/errorName — chunk-load failures included).
Generic chrome (header/footer/tables/KPI cells/callouts) lives in
utils/pdf/pdfPrimitives.ts for reuse by future report exports.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The five stuck sits-d Cloud PCs carried SkipUserStatusPage=True — verified
across three agent processes (10+ registry reads, True every time) and six
hours of live Shell-Core watching with zero 62407: Windows never rendered a
user ESP page, so no exit and no AccountSetup provisioning registry can ever
exist on this flow. Arm B of ShouldTransitionToAwaitingHello was open from
the bootstrap EspConfigDetected onward, but every evaluation site hangs off
a signal the flow cannot produce, and the AdvisoryCompletion backstop arms
exclusively from an EspExiting signal — an open gate nobody knocks on, six
hours to the max-lifetime watchdog. The earlier lost-exit-through-reboot
diagnosis is retired by the same evidence.
HandleImeUserSessionCompletedV1's completion attempt now accepts the
observed skip in place of IsPostAccountSetupFinalExit (anchor + genuine IME
user-session completion + real-user desktop stay mandatory; Device
Preparation excluded). The knock deliberately lives on the IME edge, not on
desktop arrival: Fix 10's AccountSetup bounce-back would undo a desktop-side
promotion two signals later, while the IME phase line always precedes the
user-session-complete line in log order, so a bounced promotion is
re-knocked by the very next re-emission — restart re-parse included.
Docs and comments no longer claim an ESP-exit recovery that does not exist
(stray duplicate summary in ShellCoreTracker, ImeLogHost restore-callback
comment); the OKF doc is reframed on the evidence and names the residual
SkipUser=false exit-in-downtime gap honestly.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Round-four review, confirmed — and the cause sits a layer below where I had been
fixing. The IsBackfill return added last round only guarded the coordinator's own
completion logic. Upstream of it, ShellCoreTracker still raised
FinalizingSetupPhaseTriggered, the coordinator still forwarded EspExited to the
adapter before that return, and the adapter discards the args entirely
(OnEspExited(...) => EmitEspExiting()). So a replayed exit still arrived at the
reducer as an ordinary, unmarked EspExiting.
There it is decisive: HandleEspExitingV1 passes espFinalExitInFlight: true for
every arriving exit, and IsPostAccountSetupFinalExit orders exits by ingest
ordinal rather than timestamp — so a historic exit replayed today reads as
post-AccountSetup by construction. With state restored from the snapshot
(AccountSetup entered, a genuine IME user session, desktop arrived) arm C of
ShouldTransitionToAwaitingHello opens on the Device→Account handoff. The reducer
is itself a completion gate and cannot tell the two apart, so the fix has to be
upstream.
The replay is therefore narrowed to what is provably safe: the Hello-wizard start
(62404). That fact is conservative — it vetoes a premature "Hello is disabled"
skip and can never by itself complete a session, so replaying it can only make the
agent wait longer. It is also the observation session 772fe502 wrote the replay
for. A 62407 is no longer raised at all, neither exit nor failure: the exit
because Windows writes the identical description for the intermediate and the
final one and nothing downstream can order it, the failure because re-injecting it
as fresh can fail a session that recovered on retry (ANALYZE-ESP-006). Skipped
records are reported once as an agent_trace with counts and bounds — silently
dropping evidence is how this class of bug survives.
The cross-layer proof is now a pair, as the review asked:
ClassicEspExitingOnRestoredStateTests pins that the reducer opens on any arriving
exit (including one with an hour-old source timestamp), and
ShellCoreTrackerReplayScopeTests pins that the replay never produces one.
Dead machinery removed with it: EspExitedEventArgs.IsBackfill, allowEspExit, the
newest-exit selection, the IsBackfill return. The method is now called
BackfillRecentHelloWizardStart.
One pre-existing integration test drove EspExited through HandleBackfillRecord
because the replay is easier to call than the event-log watcher, and its class doc
claimed that was the production path — it never was, the replay had no caller when
that test was written. Switched to the live path and the doc corrected.
Agent V2.Core 2361, DecisionCore 538, Backend 4287, all green.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Round-three review, confirmed. The previous round stopped a replayed exit from
arming the DEFERRED re-check but left the immediate synthesis attempt right below
it untouched. My justification for that — "pre-existing behaviour" — was simply
wrong: the immediate attempt on a replayed exit never existed, because the
backfill had no caller. I introduced it, and by moving the replay behind the IME
state restore I made the dangerous state reachable by design: if the newest 62407
in the window is only the intermediate DeviceSetup→AccountSetup exit while the
restored app states are already terminal, that attempt opens the strong
AccountSetup gate before the final exit has even happened. A test was pinning the
faulty assumption as expected behaviour.
A replayed exit now returns before touching completion at all — no deferred edge,
no immediate attempt. Nothing available to it can establish its position in time:
Shell-Core writes the identical description for both exits, and every probe that
could order it reads state as it is now rather than at the event's time. The
replay keeps the job it was written for in session 772fe502 — feeding EspExiting,
FinalizingSetup and the Hello wizard to the reducer for the window in which no
agent process was observing. Completion is the exclusive business of exits this
agent watched live.
With the synthesis attempt gone, the replay no longer needs restored app states,
so it moves back into EspAndHelloHost.Start(); that also keeps this host's startup
independent of the IME host's. ImeLogHost.onStateRestored goes back to doing just
the re-check, which is still needed for a live exit observed before the restore
finishes.
The test asserting the faulty assumption is inverted, plus coverage that the
replay is not neutered (EspExiting still forwards) and that a live exit following
a replayed one completes normally.
Agent V2.Core 2364, DecisionCore 533, Backend 4287, all green.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Round-two review, both findings confirmed against the code.
A replayed exit was being confirmed as post-AccountSetup by reading the registry
at replay time. That read reflects NOW, not the event's time, so an agent that was
down across the DeviceSetup→AccountSetup transition would confirm the stale
intermediate exit and, once the apps settled, synthesise a completion while the
AccountSetup page was still up. Windows offers no way to tell the two apart from
the event itself — Shell-Core writes the identical description
CommercialOOBE_ESPProgress_Page_Exiting for both. So the deferred edge is now
armed by LIVE exits only (EspExitedEventArgs.IsBackfill): only for those is the
continuous-observation argument valid. A replayed exit keeps the single immediate
synthesis attempt it always had.
For that attempt to be worth anything it must see real data, so the replay moved
out of EspAndHelloHost.Start() into ReplayEspExitBackfill(), invoked from
ImeLogHost.onStateRestored — after LoadState() has restored the package states.
That is what makes "the agent came back long after the ESP finished" recoverable.
The five-minute window for non-reboot restarts was unsound: the scheduled task
carries a BootTrigger only, with no restart-on-failure, so after an
exception_crash the agent does not return until the next boot — hours later, long
after Windows wrote the final exit. The window is now measured rather than
guessed: back to the last moment the previous run is known to have been alive,
taking the wider of the snapshot mtime (rewritten every decision step, available
for every exit type) and LastBootUtc. The five-minute default is the floor,
ClampLookbackMinutes the ceiling, and a future timestamp from clock skew is
ignored instead of producing a negative window.
Also switched the backfill tests to the real Shell-Core wording — the invented
string matched the regex but hid the fact that both exits look identical.
9 new tests. Agent V2.Core 2362, DecisionCore 533, Backend 4287, all green.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Follow-up to the review hardening: the replay ran on EVERY agent start with a
5-minute window, first run included. On a first run there is no gap to recover —
no earlier agent process existed — and a 62407 already sitting in the Shell-Core
log belongs to a phase transition this agent was never meant to observe. Replaying
it pushes an EspExiting into the reducer that the pre-fix agent never saw, i.e. a
happy-path behaviour change for no gain.
ResolveEspExitBackfillLookbackMinutes now keys the window to the previous exit
type: first_run (or unknown) disables the replay entirely, clean/hard_kill/
exception_crash keep the 5-minute default because the process is back within
seconds, and reboot_kill widens to "since LastBootUtc" because that gap spans the
forced restart until the post-reboot logon. The result is still clamped to
BackfillLookbackMaxMinutes, so policy and backstop together cannot build an
unbounded event-log query.
With this the happy path is byte-identical to pre-fix behaviour: on a first run
nothing replays, no edge is remembered, and the deferred re-check returns on a
volatile bool read.
No other backfill is affected — the Hello, MDM-reboot, Windows-Update and
ModernDeployment trackers each own a private backfill invoked from their own
Start(), none of which this change touches.
13 policy tests including clock skew across the reboot, a missing boot timestamp
and the clamp backstop. Agent V2.Core 2353, DecisionCore 533, Backend 4287.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
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>
Seven sits-d Cloud PCs enrolled the same day with identical configuration
(~138 required apps at the user-ESP gate, DeviceGuard/DmaGuard device-assigned).
The two that finished AccountSetup before the coalesced reboot landed succeeded;
the five the reboot killed in Stage=EspAccountSetup never derived a completion
again and ended Incomplete on healthy devices. Two defects behind that:
ShellCoreTracker.BackfillRecentEspExitEvents() has existed since session
772fe502 but no caller ever invoked it, so the Shell-Core watcher only saw
records written after Start(). Every agent restart silently dropped an ESP exit
(62407) or Hello-wizard start (62404) from its downtime. EspAndHelloHost.Start()
now calls it, and the fixed 5-minute window is sized to the actual downtime when
the previous run died to a reboot (LastBootUtc, clamped to 360 min).
The user-apps-settled synthesis ran only on the EspExited edge. When the ESP page
exits with apps still in flight the single attempt misses and nothing re-checks —
8110e262 and a89aac2d both reached 138/138 apps, 0 failed, and still never
completed. The exit edge is now recorded and the synthesis re-evaluated from
ImeLogTracker.OnAppStateChanged. No new completion path: the gate conditions are
unchanged, this only gives the existing conservative check a second look. The
fire-once claim moves to Interlocked (edge and re-check run on different threads)
and the re-check does not re-emit app_install_starved.
Rules: ANALYZE-ESP-005 gains on_event:session_stalled so a hung session produces
a finding at the 60-minute stall instead of staying finding-less for hours
(verified against 8110e262 — fired, confidence 95). New ANALYZE-APP-016 turns the
already-emitted app_install_starved events into a customer finding and, unlike
ANALYZE-APP-015, fires even on a succeeded session: 3b9291aa was recorded
Succeeded with 99 required apps that never started installing.
ANALYZE-APP-015 and ANALYZE-ESP-001 were considered for the stall trigger and
deliberately left alone — APP-015 is the documented worked example of the
terminal-precondition trap, and ESP-001's phase_duration gate on a still-open
phase is unverified mid-run.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The first CI run overwrote all four customer-facing scripts on the download
host and the legacy mirror with their own byte values as decimal text
(Install-AutopilotMonitor.ps1 went from 27331 to 95679 bytes).
PowerShell unrolls an array returned from a function into the output stream, so
the caller receives Object[] rather than byte[]. Invoke-RestMethod serialises an
Object[] body as space-separated decimals. Every hash check stayed green because
[byte[]] parameter coercion repairs the type everywhere except on the wire.
build-agent.yml's Send-Blob was never affected: it read the bytes inside the
function. Proven with a local HttpListener: the old shape puts 50 bytes starting
54,48,32,51,53 ("60 35 13 1...") on the wire where 17 bytes starting 60,35,13,10
("<#\r\n.SYN") are expected.
Fixes:
- ',' on both byte-array returns, plus an explicit [byte[]] at the upload site.
- Read each blob back from storage right after its PUT and abort before the
mirror and the remaining files. Verifying only at the end left every blob
corrupted.
- The version-bump guard tolerates an unparseable published copy with a warning
instead of throwing: that is the state a republish exists to repair, and a
guard that blocks the repair is worse than no guard.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Byte comparison made the guard fire on comment fixes, typos in comments and
reflow -- changes no consumer of the version can act on, so forcing a bump for
them is friction without a payoff.
The guard now compares a code fingerprint: the PowerShell token stream with
comments, newlines and line continuations removed. A behaviour change under an
unchanged $ScriptVersion still fails; comment and formatting changes publish
with a warning. That is also the rule the source file's own comment on
$ScriptVersion already states ("bump on meaningful changes").
Tokenising rather than regex-stripping keeps a '#' inside a string literal from
being mistaken for a comment.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The scripts behind download.autopilotmonitor.com/agent/ rotated only on a
publish_as_stable run of build-agent.yml, so a bootstrap fix sat unpublished
until the next agent cutover -- while the WDP bootstrap MSI downloads the
published copy on every enrolling device.
Publish-BootstrapScripts.ps1 becomes the single owner of the chain: dev render
with anchor check, $ScriptVersion bump guard, uploads (eu + fail-soft legacy
mirror, no-cache), the two version oracles, and verification through the alias.
publish-scripts.yml calls it on every push to main touching the sources; the
publish_as_stable branch of build-agent.yml calls the same code, so a release
still lands a consistent set.
Blobs are published in a deterministic CRLF/UTF-8-without-BOM form. Git
normalises line endings on checkout, so raw working-copy bytes would differ per
environment and make every byte comparison -- guard and verify alike -- depend
on where the workflow ran. The form reproduces the currently published bytes
exactly.
The Pester (PS 5.1) and ASCII gates move into the reusable
bootstrap-script-gates.yml and now block the upload; pester.yml keeps the
pull-request view and drops its push trigger. AdminConfiguration
.LatestBootstrapV2ScriptVersion gets exactly one writer.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Codex findings on d8c84f41/a369ff99: (1) MarkUploaded now recomputes
_pendingBytes from the pending list when accounting drifts negative or
stays non-zero on an empty list — a silent negative would disarm the
spool-pressure trigger. (2) New test covers the DevicePrepCompletion
handler''s AwaitingDesktop fallback (stale/replayed timer without a
desktop fact): synthetic Hello timeout, park, and completion on the
later real desktop arrival. Third finding (HashingCappedReadStream
maxBytes:0) refuted — the 0=uncapped contract is implemented in the
same class and exercised by the heal-path tests.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
99/100 spool_pressure_detected events in the field were file-size-only
triggers on a near-empty backlog (append-only spool.jsonl grows past 5 MB
in healthy long sessions). TelemetrySpool now tracks PendingBytes (exact
serialized size of the not-yet-uploaded tail, maintained on enqueue /
mark-uploaded / restart rehydrate) and the collector thresholds on that
instead of SpoolFileSizeBytes, which stays as an informational metric.
Snapshot gains spool_pending_bytes; pressure event data carries
pendingBytes + pendingBytesThreshold.
Also: startup recovery scan streams via File.ReadLines instead of
materializing the whole spool with File.ReadAllLines (corrupt-tail
break semantics unchanged).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Hero gets a quiet checkmark chip row (user-driven, pre-provisioning,
self-deploying, Device Preparation, Windows 365, Entra ID & Hybrid join);
about page deployment claim now includes the MSI LOB channel for WDP.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
afee7ae0 audit: WDP sessions ran the full Classic/ESP apparatus. Gates key on
the deterministic BootstrapperAgent ExecutionContext marker only (CloudAssigned*
fallbacks keep Classic behavior).
Paket A (event hygiene): no autopilot_profile/-missing + ZTD query/probe on WDP;
esp_config_detected null-gate (no more unknown/unknown); starved sweep skipped
on WDP (data stays in app_tracking_summary/final-status).
Paket B (resources): EspPolicyProviderStallHost + ProvisioningStatusTracker not
started on WDP; ModernDeployment noise IDs 100/417/418/1005 fully suppressed
(Critical always passes) + Autopilot error backfill skipped; StallProbe skips
ESP category scan and treats noise IDs as harmless.
Paket C (DecisionCore): enrollmentTypeDeterministic payload key seeds
DevicePreparation at High confidence (fallbacks stay Medium); completion_waiting
drops the unsatisfiable account_setup_provisioning_complete gate on WDP; arm D
promotes on real-user desktop; new device_prep_completion 30-min backstop closes
the park-until-watchdog hole; parked tripwire gets a WDP branch.
17 new tests; suites green (532/2307/4287). OKF doc agent/wdp-scenario-gates.md.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Session bc803955 (DevicePrep, Succeeded) rendered "No application data
available" although the M365 CSP package installed during prep and IME
delivered 12 required user apps 9 seconds after final-status was written.
- EnrollmentTerminationHandler: bounded settle wait (20s, 250ms poll) before
the dialog snapshot - DevicePreparation-only and only while the tracker has
zero packages, so Classic pays nothing. Root cause of the lost race is IME
AppWorkload.log flush latency (~10-20s), not the 100ms tracker poll.
Dialog, starved sweep and app_tracking_summary all see settled data.
- FinalStatusBuilder: synthetic "Microsoft 365 Apps" row from the Office C2R
detector's persisted lifecycle state (Office CSP installs never flow through
the IME Win32 pipeline). Prepended to the Device bucket, counted in
appSummary; Preinstalled state deliberately excluded. No SummaryDialog.exe
change needed - it renders packageStatesByPhase generically.
- OfficeInstallStateData: CompletedAtUtc + VersionReached stamped on terminal
persists (duration/version for the row); older state files load fail-soft.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Timeline rows render time-of-day only, so a large gap between adjacent
events (and the date change it implies) was invisible without expanding
event details. Rows following a gap >= 1h now show an amber chip
(e.g. "+3h" / "+19d"); hovering reveals the full date. Applies to both
the phase timeline and raw mode, using the same display timestamp as
the row (backfilled events keep their event-log time).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Session f475e697: a device re-enrolled without a wipe (IME log residue from a
previous enrollment) completes its pre-installed apps as instant detections,
pulling the phase anchors ~6.5 min ahead of the real ESP page — the breakdown
was mechanically exact but semantically wrong, and entered fleet stats as clean.
- New duration-critical flag PriorEnrollmentResidue, set on
historic_ime_replay_detected; excluded from fleet segment stats via the
existing DurationCriticalFlags mask. registry_app_baseline successes are
deliberately NOT a trigger (by-design normal for WDP Batch-1) — pinned by test.
- AttributionVersion 1 -> 2 so the maintenance sweep recomputes in-retention
breakdowns and flags old residue sessions retroactively (rule 8).
- Web: flag label in TimeAttributionLane; docs: quality-flags section.
- Stale comment fix: SaveWhiteGloveSuccessResult is NOT a WhiteGlove indicator
on Win11 25H2+ (validated 2026-08-18 against user-driven sessions) —
observability only, consumed nowhere for classification.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Daily-review finding: the MSI upload is write-once (If-None-Match:*), so a
first attempt that died between the MSI and the provenance upload funneled
every retry into the 409 short-circuit — which returned "Archived" without
ever writing provenance.json (permanently lost). The 409 path now checks for
the sidecar and, when missing, rehashes the ARCHIVED bytes and writes it;
heal failures ride the normal retryable ladder.
Also closes the review's test gaps: ImeMsiArchiveQueueWorker + producer
worker-level tests (internal QueueClient test ctors, SessionDeletionWorker
pattern), CorporateIdentifierValidator null/whitespace + OData special-char
+ page-cap-transient tests, registry observer helper tests
(TerminalOutcome/ChangedFields/ClassifyStatusServiceStatus).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Live findings from the first two 2.0.1402 sessions (Oliver, 2026-08-18):
1. "Failed to get AAD token" is logged routinely during the device phase
(no user token exists yet) - both test sessions raised the Warning
although nothing was wrong. The failure is now held pending: any
IME-TOKEN-SUCCESS match clears it (staleness-gated so a replayed
success from a previous enrollment cannot mask a current outage), and
ime_token_failure fires only when no success follows for the 30-min
grace window, then deduped per errorCode. Genuine auth outages run
long enough to hit the window; routine device-phase failures never do.
2. New one-shot registry_app_baseline event (Info, only when non-empty):
summary of the Win32Apps state that predates the agent run - counts
by enforcement class + capped 50-app typed payload incl.
LastUpdatedTimeUtc. On WDP the DPP-policy apps install in Batch 1
before the bootstrap-script agent exists; their outcomes live only in
this baseline, closing the pre-agent app gap without log backfill.
The diff rail stays silent on baseline state (anti-replay unchanged).
Event type dual-registered (Constants + MCP catalog + manifests regen).
Tests: grace-window cycle (resolved / unresolved / re-arm dedup),
baseline summary (counts, one-shot, empty). All suites green
(Agent 2274, Functions 4262, MCP 561, web 762), 0 warnings.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
WIX0103 on the first run: Invoke-BootstrapDownload.ps1 not found because
wix build resolves File/@Source relative to the working directory, not
the wxs location. Matches the local build documented in Package.wxs.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
workflow_dispatch-only, mirroring the agent release contract: validate
the runner script (PS parse + ASCII-only, it runs as SYSTEM on every
enrolling device), wix 5 build, upload versioned + stable blob names to
the agent container (no-cache, no legacy mirror - the MSI channel never
existed there), HEAD-verify the public alias serves the fresh bytes,
Sigstore provenance attestation. MSI version stays source-controlled in
Package.wxs - bumped to 1.0.2 (runner: encoding fix + bootstrap-msi.log
rename). Customer download:
https://download.autopilotmonitor.com/agent/AutopilotMonitor-Bootstrap.msi
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
The agent log directory mixed three conventions (agent_20260817.log,
bootstrap_agent.log, msi-bootstrap.log) while everything else in the
diagnostics ZIP is already kebab-case. All log files now follow
<component>-<content>.log:
agent.log (was agent_YYYYMMDD.log; segments agent-NNN.log)
bootstrap-script.log (was bootstrap_agent.log; script v2.4)
bootstrap-msi.log (was msi-bootstrap.log)
crash-<utc>.log (was crash_<utc>.log)
gather-rules-debug.log (was gather_rules_debug.log)
ime-pattern-matches.log (was ime_pattern_matches.log)
The date is dropped from the main log: the agent only lives for one
enrollment, and date rotation split the chronology at local midnight -
which can fall mid-enrollment while the clock is still on the OOBE
default timezone. The existing 50MB size rotation stays as the growth
bound. Legacy dated files are ignored by the rotation probe; crash
detection still picks up legacy crash_*.log once so an in-place
self-update cannot lose a pending crash classification.
Diag collectors glob *.log and need no change. MCP zip-map and docs
note the legacy names for archives from pre-rename agents. Settings UI
hint paths updated. MSI rebuild + bootstrap script publish (v2.4) +
MCP redeploy required to ship.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Intune LOB requires a higher ProductVersion to accept a re-upload. Also
includes the runner logging fix: PS 5.1 *>> redirection writes UTF-16LE
into the otherwise ANSI msi-bootstrap.log - route through Add-Content for
a single encoding.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Still needed: the skill extracts each MSI here (msiexec /a payload for grepping
in binaries); only decompilates go to the ime-decompiles repo and MSIs to the
ime-archive blob container.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
P2 of the 2026-08-17 IME code audit. IME log wording is an unstable
contract (audit found 9 silently dead patterns, reworded lines, quote
drift, [DO TEL] removal); the registry is IME's internal product
contract - the ESP page and Intune reporting consume it.
ImeRegistryAppStateObserver + ImeRegistryAppStateHost (always-on
observability, no DecisionEngine coupling):
- one recursive RegistryWatcher on HKLM\...\IntuneManagementExtension
covers Win32Apps (EnforcementStateMessage JSON, ExitCode, Intent),
EspTrackingWin32Apps and SideCarPolicies\StatusServiceReports;
2 s debounced snapshot-and-diff + 60 s periodic fallback tick
(poll-only degraded mode if the watcher fails to arm)
- silent startup baseline: Win32Apps keys survive re-enrollments,
pre-existing state never replays as fresh events
- registry_app_state (Info, state-change-only, 200/session cap with
one-shot cap notice)
- app_state_reconciliation (Warning, once per app, immediate upload):
a changed entry terminal for >= 90 s is compared against the
log-derived AppPackageState - divergence is the built-in
log-pattern drift alarm (registry = truth, logs = narrative)
Event types dual-registered (Constants + MCP resource-catalog + shared
manifests regenerated). OKF concept doc agent/registry-app-state-pillar.md
incl. WDP Paket-3 reuse notes. Tests: pure parse/diff/divergence logic +
tick flow via snapshot override (baseline silence, emission, dwell,
fire-once, cap). All suites green.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
P0b/P1 of the 2026-08-17 IME code audit (agent release required):
- Tail AppActionProcessor.log (+ rollover glob) in ImeLogTracker and the
--run-ime-matching CLI. IME routes every [Win32App][ActionProcessor]
line there (enforcement decision engine), so IME-NO-ACTION and
IME-NOT-TARGETED-1/2 could never fire before, and GRS skips were
invisible. Live session 0fe2c562 carried 16 no-action and 64
classification lines in that file.
- New patterns (wordings verified in decompiled IME 1.97 AND 1.104):
IME-GRS-SKIP ("is in GRS. The app will not be enforced." -> Postponed;
THE canonical silent non-install reason), IME-GRS-CLEARED (early
subgraph termination, retry next check-in -> Postponed),
IME-TOKEN-FAILURE ("Failed to get AAD token ... errorCode = N").
- New action imeTokenFailure -> ime_token_failure Warning event (new
EventType: Constants + MCP resource-catalog + shared manifests
regenerated). Tracker dedups per distinct errorCode; included in
the historic-replay guard so stale lines from a previous enrollment
cannot emit a misleading warning. Complements IME-TOKEN-SUCCESS:
an auth outage previously left check-ins silently doing nothing.
Tests: adapter emission + unknown-code + tracker dedup; known-actions
catalog extended; all suites green (Functions 4262, Agent 2252, web 762).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
IME 1.104 no longer logs the [DO TEL] line whose JSON carried the
DO-reported download duration - the Download Progress card lost all
times (per-app and total).
Durations now fall back to the observed event window (first download
event -> first completion-marking event) whenever the DO-reported value
is absent, and completed items show "in <duration>" inline. Works
retroactively for already-stored sessions, no agent release required;
the DO-reported value still wins when present (older IME versions).
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Oliver Kieselbach