mirror of
https://github.com/okieselbach/AutopilotMonitor.git
synced 2026-10-24 20:53:06 +00:00
fix(sessions): backfilled system-timeline events no longer anchor StartedAt/duration
Field case d0c5b672: a pre-agent system_clock_changed event (backfilled from the Windows event log with its original timestamp, ~14min before the first real activity) became the partition's earliest row and re-anchored the session's StartedAt, inflating the duration toward pre-enrollment OOBE idle time. With the watcher's 24h backfill lookback, the 2h backward-shift guard only caps this effect, it does not prevent it. SystemTimelineWatcher rows (clock steps, sleep episodes) are environment observation, not enrollment activity, and are now excluded from all three anchor derivations: the Events-table earliest-row probe (new IsSessionAnchorEligible, probe scans past ineligible rows), the ingest batch's EarliestEventTimestamp fold, and the web's client-side enrollment-duration derivation. The events themselves stay on the timeline unchanged. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
+50
-4
@@ -101,6 +101,52 @@ public class SessionStartedAtBackwardShiftGuardTests
|
||||
Assert.Equal((int)(lastEvent - earliest).TotalSeconds, harness.Written!.GetInt32("DurationSeconds"));
|
||||
}
|
||||
|
||||
// =========================== system-timeline rows are not session anchors ====
|
||||
|
||||
[Fact]
|
||||
public void IsSessionAnchorEligible_excludes_system_timeline_watcher_rows()
|
||||
{
|
||||
Assert.False(TableStorageService.IsSessionAnchorEligible(
|
||||
new TableEntity("p", "r") { ["Source"] = "SystemTimelineWatcher" }));
|
||||
Assert.True(TableStorageService.IsSessionAnchorEligible(
|
||||
new TableEntity("p", "r") { ["Source"] = "ImeLogTracker" }));
|
||||
Assert.True(TableStorageService.IsSessionAnchorEligible(
|
||||
new TableEntity("p", "r"))); // legacy row without Source projection
|
||||
}
|
||||
|
||||
[Fact]
|
||||
public async Task Pending_duration_skips_backfilled_system_timeline_row_and_anchors_on_activity()
|
||||
{
|
||||
// Field case d0c5b672: a pre-agent system_clock_changed event (backfilled from the
|
||||
// Windows event log, original timestamp ~14min before the first real activity) was
|
||||
// the partition's earliest row and re-anchored StartedAt. The probe must skip
|
||||
// SystemTimelineWatcher rows and anchor on the first activity event instead —
|
||||
// even when the watcher row sits well inside the 2h plausibility window.
|
||||
var clockEventAt = StartedAt.AddMinutes(-90);
|
||||
var firstActivity = StartedAt.AddMinutes(-5);
|
||||
var lastEvent = StartedAt.AddMinutes(70);
|
||||
var harness = new Harness(SessionRow(), eventRows: new[]
|
||||
{
|
||||
EventRow(clockEventAt, sequence: 18, source: "SystemTimelineWatcher"),
|
||||
EventRow(firstActivity, sequence: 2, source: "ImeLogTracker"),
|
||||
});
|
||||
|
||||
var ok = await harness.Sut.UpdateSessionStatusAsync(
|
||||
TenantId, SessionId, SessionStatus.Pending,
|
||||
latestEventTimestamp: lastEvent);
|
||||
|
||||
Assert.True(ok);
|
||||
Assert.NotNull(harness.Written);
|
||||
Assert.Equal((int)(lastEvent - firstActivity).TotalSeconds, harness.Written!.GetInt32("DurationSeconds"));
|
||||
}
|
||||
|
||||
private static TableEntity EventRow(DateTime occurredUtc, int sequence, string source) =>
|
||||
new($"{TenantId}_{SessionId}", $"{occurredUtc:yyyyMMddHHmmssfff}_{sequence:D10}")
|
||||
{
|
||||
["OccurredUtc"] = new DateTimeOffset(occurredUtc),
|
||||
["Source"] = source,
|
||||
};
|
||||
|
||||
// ============================================================ Harness ====
|
||||
|
||||
private static TableEntity SessionRow()
|
||||
@@ -126,7 +172,7 @@ public class SessionStartedAtBackwardShiftGuardTests
|
||||
public TableStorageService Sut { get; }
|
||||
public TableEntity? Written { get; private set; }
|
||||
|
||||
public Harness(TableEntity existing, DateTime? earliestStoredEvent = null)
|
||||
public Harness(TableEntity existing, DateTime? earliestStoredEvent = null, TableEntity[]? eventRows = null)
|
||||
{
|
||||
var sessions = new Mock<TableClient>();
|
||||
|
||||
@@ -150,7 +196,7 @@ public class SessionStartedAtBackwardShiftGuardTests
|
||||
});
|
||||
|
||||
var events = new Mock<TableClient>();
|
||||
var eventRows = earliestStoredEvent.HasValue
|
||||
var servedRows = eventRows ?? (earliestStoredEvent.HasValue
|
||||
? new[]
|
||||
{
|
||||
new TableEntity($"{TenantId}_{SessionId}", $"{earliestStoredEvent.Value:yyyyMMddHHmmssfff}_0000000001")
|
||||
@@ -158,12 +204,12 @@ public class SessionStartedAtBackwardShiftGuardTests
|
||||
["OccurredUtc"] = new DateTimeOffset(earliestStoredEvent.Value),
|
||||
},
|
||||
}
|
||||
: Array.Empty<TableEntity>();
|
||||
: Array.Empty<TableEntity>());
|
||||
events.Setup(t => t.QueryAsync<TableEntity>(
|
||||
It.IsAny<string>(), It.IsAny<int?>(), It.IsAny<IEnumerable<string>>(), It.IsAny<CancellationToken>()))
|
||||
.Returns(AsyncPageable<TableEntity>.FromPages(new[]
|
||||
{
|
||||
Page<TableEntity>.FromValues(eventRows, null, new Mock<Response>().Object),
|
||||
Page<TableEntity>.FromValues(servedRows, null, new Mock<Response>().Object),
|
||||
}));
|
||||
|
||||
var serviceClient = new Mock<TableServiceClient>();
|
||||
|
||||
+9
-1
@@ -14,7 +14,15 @@ namespace AutopilotMonitor.Functions.Services
|
||||
|
||||
foreach (var evt in storedEvents)
|
||||
{
|
||||
if (!classification.EarliestEventTimestamp.HasValue || evt.Timestamp < classification.EarliestEventTimestamp.Value)
|
||||
// System-timeline-watcher rows (clock steps, sleep episodes) are backfilled
|
||||
// from the Windows event log with original timestamps up to 24h before the
|
||||
// agent started — environment observation, not enrollment activity. They must
|
||||
// not pull the session anchor toward pre-enrollment OOBE idle time (mirrors
|
||||
// TableStorageService.IsSessionAnchorEligible on the Events-table probe;
|
||||
// field case d0c5b672).
|
||||
var anchorEligible = evt.Source != "SystemTimelineWatcher";
|
||||
if (anchorEligible &&
|
||||
(!classification.EarliestEventTimestamp.HasValue || evt.Timestamp < classification.EarliestEventTimestamp.Value))
|
||||
classification.EarliestEventTimestamp = evt.Timestamp;
|
||||
if (!classification.LatestEventTimestamp.HasValue || evt.Timestamp > classification.LatestEventTimestamp.Value)
|
||||
classification.LatestEventTimestamp = evt.Timestamp;
|
||||
|
||||
@@ -3250,12 +3250,27 @@ namespace AutopilotMonitor.Functions.Services
|
||||
}
|
||||
|
||||
/// <summary>
|
||||
/// Returns the earliest event timestamp persisted for a session, if any.
|
||||
/// Events are written with RowKey "{Timestamp}_{Sequence}", so querying the partition
|
||||
/// and taking the first row yields the earliest event. Resolution must NOT rely on
|
||||
/// the system Timestamp: it is reset by storage migrations, and this value feeds the
|
||||
/// StartedAt/Duration reconciliation — a migration-reset read would rewrite those
|
||||
/// session fields with the migration date.
|
||||
/// Event sources whose rows never anchor the session. The system timeline watcher
|
||||
/// backfills environment observations (clock steps, sleep episodes) from the Windows
|
||||
/// event log with their ORIGINAL timestamps — up to 24h before the agent started.
|
||||
/// They belong on the timeline, but they are not enrollment activity: anchoring on
|
||||
/// them silently stretches StartedAt/DurationSeconds toward pre-enrollment OOBE idle
|
||||
/// time (field case d0c5b672: a pre-agent clock correction pulled StartedAt ~14min
|
||||
/// before the first real activity; the 2h backward-shift guard only caps, not
|
||||
/// prevents, this). User decision 2026-08-21: the session anchor stays on real
|
||||
/// enrollment activity.
|
||||
/// </summary>
|
||||
internal static bool IsSessionAnchorEligible(TableEntity eventRow)
|
||||
=> eventRow.GetString("Source") != "SystemTimelineWatcher";
|
||||
|
||||
/// <summary>
|
||||
/// Returns the earliest ANCHOR-ELIGIBLE event timestamp persisted for a session, if
|
||||
/// any. Events are written with RowKey "{Timestamp}_{Sequence}", so scanning the
|
||||
/// partition in order and taking the first eligible row (see
|
||||
/// <see cref="IsSessionAnchorEligible"/>) yields the earliest activity event.
|
||||
/// Resolution must NOT rely on the system Timestamp: it is reset by storage
|
||||
/// migrations, and this value feeds the StartedAt/Duration reconciliation — a
|
||||
/// migration-reset read would rewrite those session fields with the migration date.
|
||||
/// </summary>
|
||||
private async Task<DateTime?> GetEarliestSessionEventTimestampAsync(string tenantId, string sessionId)
|
||||
{
|
||||
@@ -3265,12 +3280,15 @@ namespace AutopilotMonitor.Functions.Services
|
||||
var partitionKey = $"{tenantId}_{sessionId}";
|
||||
var query = tableClient.QueryAsync<TableEntity>(
|
||||
filter: $"PartitionKey eq '{partitionKey}'",
|
||||
maxPerPage: 1,
|
||||
select: new[] { "RowKey", BusinessTimestamp.OccurredUtcColumn, "Timestamp" }
|
||||
maxPerPage: 25,
|
||||
select: new[] { "RowKey", BusinessTimestamp.OccurredUtcColumn, "Timestamp", "Source" }
|
||||
);
|
||||
|
||||
await foreach (var entity in query)
|
||||
{
|
||||
if (!IsSessionAnchorEligible(entity))
|
||||
continue; // environment observation, not enrollment activity — keep scanning
|
||||
|
||||
return ResolveEventTimestampOrNull(entity);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -124,12 +124,18 @@ export function useSessionDerivedData(
|
||||
const displayStatus = gatherRulesSucceeded ? "Succeeded" : (session?.status ?? "");
|
||||
|
||||
// Calculate enrollment duration from events (first event → enrollment_complete or last event)
|
||||
// More accurate than session.durationSeconds which is based on registration StartedAt
|
||||
// More accurate than session.durationSeconds which is based on registration StartedAt.
|
||||
// System-timeline-watcher rows (clock steps, sleep episodes) are excluded: they are
|
||||
// backfilled from the Windows event log with original timestamps up to 24h before the
|
||||
// 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(() => {
|
||||
if (events.length === 0) return null;
|
||||
const timestamps = events.map(e => new Date(e.timestamp).getTime());
|
||||
const activityEvents = events.filter(e => e.source !== "SystemTimelineWatcher");
|
||||
if (activityEvents.length === 0) return null;
|
||||
const timestamps = activityEvents.map(e => new Date(e.timestamp).getTime());
|
||||
const firstEventTime = Math.min(...timestamps);
|
||||
const completeEvent = events.find(e => e.eventType === "enrollment_complete");
|
||||
const completeEvent = activityEvents.find(e => e.eventType === "enrollment_complete");
|
||||
const endTime = completeEvent
|
||||
? new Date(completeEvent.timestamp).getTime()
|
||||
: Math.max(...timestamps);
|
||||
|
||||
Reference in New Issue
Block a user