diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/Ime/ImeLogTrackerOffsetCalibrationTests.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/Ime/ImeLogTrackerOffsetCalibrationTests.cs index 39f074cf..a3f2414e 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/Ime/ImeLogTrackerOffsetCalibrationTests.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core.Tests/Monitoring/Ime/ImeLogTrackerOffsetCalibrationTests.cs @@ -202,5 +202,71 @@ namespace AutopilotMonitor.Agent.V2.Core.Tests.Monitoring.Ime TimeSpan ignored; Assert.False(h.Tracker.OffsetCalibrator.TryGetOffset(LogFileName, out ignored)); } + + [Fact] + public async Task RecordsProvenance_ForACalibratedLine() + { + // P8: what the writer wrote, what we subtracted, and how we knew — the evidence that + // makes a stored timestamp recomputable without the diagnostics archive. + using var h = new Harness(); + var writerOffset = TimeSpan.FromHours(-7); // PST/PDT, the OOBE default + + h.Append(Line("marker 1", h.Now, writerOffset)); + await h.Pass(); + + h.Now = T0.AddSeconds(10); + h.Append(Line("marker 2", h.Now, writerOffset)); + await h.Pass(); + + h.Now = T0.AddSeconds(20); + var writtenAt = h.Now; + h.Append(Line("marker 3", writtenAt, writerOffset)); + await h.Pass(); + + Assert.Equal(CmTraceOffsetOrigin.Calibrated, h.Tracker.LastMatchedSourceOffsetOrigin); + Assert.Equal(-420, h.Tracker.LastMatchedSourceOffsetMinutes); + Assert.True(h.Tracker.LastMatchedSourceLocalTimestamp.HasValue); + + // The raw local value is kept verbatim, with no zone attached — attaching one would + // re-introduce exactly the assumption this change removes. + Assert.Equal(writtenAt + writerOffset, h.Tracker.LastMatchedSourceLocalTimestamp.Value); + Assert.Equal(DateTimeKind.Unspecified, h.Tracker.LastMatchedSourceLocalTimestamp.Value.Kind); + } + + [Fact] + public async Task RecordsProvenance_AsFallback_BeforeAnyCalibration() + { + // The warm-up pass: the offset is not measured yet, so the reader zone is assumed and + // the event has to say so rather than look source-grounded. + using var h = new Harness(); + + h.Append(Line("marker 1", h.Now, TimeSpan.FromHours(2))); + await h.Pass(); + + Assert.Equal(CmTraceOffsetOrigin.None, h.Tracker.LastMatchedSourceOffsetOrigin); + Assert.Null(h.Tracker.LastMatchedSourceOffsetMinutes); + Assert.True(h.Tracker.LastMatchedSourceLocalTimestamp.HasValue); + } + + [Fact] + public async Task RecordsProvenance_ForADeclaredBias() + { + using var h = new Harness(); + + h.Append(Line("marker 1", h.Now, TimeSpan.FromHours(2))); + await h.Pass(); + + h.Now = T0.AddSeconds(10); + var local = h.Now + TimeSpan.FromHours(-8); + h.Append($""); + await h.Pass(); + + Assert.Equal(CmTraceOffsetOrigin.Bias, h.Tracker.LastMatchedSourceOffsetOrigin); + // Reported in the same sense as a measured offset (local = UTC + offset), so the two + // origins are directly comparable; the wire bias uses the opposite convention. + Assert.Equal(-480, h.Tracker.LastMatchedSourceOffsetMinutes); + } + } } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.LogProcessing.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.LogProcessing.cs index 2b888d79..d2f4404c 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.LogProcessing.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.LogProcessing.cs @@ -248,7 +248,22 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime private void HandlePatternMatch(CompiledPattern pattern, Match match, string message, CmTraceLogEntry entry) { LastMatchedPatternId = pattern.PatternId; - LastMatchedLogTimestamp = entry == null ? (DateTime?)null : ResolveEntryUtc(entry); + if (entry == null) + { + LastMatchedLogTimestamp = null; + LastMatchedSourceLocalTimestamp = null; + LastMatchedSourceOffsetMinutes = null; + LastMatchedSourceOffsetOrigin = CmTraceOffsetOrigin.None; + } + else + { + CmTraceOffsetOrigin origin; + int? offsetMinutes; + LastMatchedLogTimestamp = ResolveEntryUtc(entry, out origin, out offsetMinutes); + LastMatchedSourceLocalTimestamp = entry.HasTimestamp ? entry.LocalTimestamp : (DateTime?)null; + LastMatchedSourceOffsetMinutes = offsetMinutes; + LastMatchedSourceOffsetOrigin = origin; + } // Generic pattern-match hook (M4.4.4). Invoked before action-specific callbacks so // subscribers (e.g. ImeLogTrackerAdapter emitting WhiteGloveSealingPatternDetected) @@ -597,24 +612,49 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime /// private DateTime ResolveEntryUtc(CmTraceLogEntry entry) { + CmTraceOffsetOrigin origin; + int? offsetMinutes; + return ResolveEntryUtc(entry, out origin, out offsetMinutes); + } + + /// + /// Resolve a parsed entry to UTC and report HOW the offset was obtained, so the emitting + /// side can attach the evidence (P8). See . + /// + private DateTime ResolveEntryUtc(CmTraceLogEntry entry, out CmTraceOffsetOrigin origin, out int? offsetMinutes) + { + origin = CmTraceOffsetOrigin.None; + offsetMinutes = null; + if (entry == null) return UtcNowProvider(); // Writer declared its own offset — nothing left to measure. - if (entry.TimestampUtc.HasValue) return entry.TimestampUtc.Value; + if (entry.TimestampUtc.HasValue) + { + origin = CmTraceOffsetOrigin.Bias; + // Bias uses the GetTimeZoneInformation convention (UTC = local + bias); report the + // value in the same sense as a measured offset (local = UTC + offset). + offsetMinutes = entry.BiasMinutes.HasValue ? -entry.BiasMinutes.Value : (int?)null; + return entry.TimestampUtc.Value; + } if (!entry.HasTimestamp) return UtcNowProvider(); // Measured offset of the process that wrote this file. + TimeSpan measured; DateTime calibrated; if (_currentSourceFileName != null + && OffsetCalibrator.TryGetOffset(_currentSourceFileName, out measured) && OffsetCalibrator.TryResolveUtc(_currentSourceFileName, entry.LocalTimestamp, out calibrated)) { + origin = CmTraceOffsetOrigin.Calibrated; + offsetMinutes = (int)measured.TotalMinutes; return calibrated; } // Not calibrated yet (first growing pass, or a file that never grows while we watch). // Falls back to this process's zone, which is right only if the writer happens to - // share our belief. Emissions built on this are flagged as not source-grounded. + // share our belief. Origin stays None so the emitted event says so. return CmTraceLogParser.ResolveUtcAssumingReaderZone(entry.LocalTimestamp); } diff --git a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs index 0c2499e8..3064ec52 100644 --- a/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs +++ b/src/Agent/AutopilotMonitor.Agent.V2.Core/Monitoring/Enrollment/Ime/ImeLogTracker.cs @@ -209,6 +209,25 @@ namespace AutopilotMonitor.Agent.V2.Core.Monitoring.Enrollment.Ime public string LastMatchedPatternId { get; internal set; } public DateTime? LastMatchedLogTimestamp { get; internal set; } + /// + /// Raw local time of the last matched line, exactly as the writer wrote it — no zone + /// attached, because the line carries none. + /// + /// Recorded so an emitted event can carry the evidence for its own timestamp. Without it + /// a conversion error is only provable from the diagnostics archive, and of the 5,386 + /// sessions that went through a timezone change essentially none had one — the field + /// analysis had to fall back to median statistics over thousands of sessions to show + /// what one stored value would have made obvious per session. + /// + /// + public DateTime? LastMatchedSourceLocalTimestamp { get; internal set; } + + /// Offset applied to , in minutes. + public int? LastMatchedSourceOffsetMinutes { get; internal set; } + + /// How that offset was arrived at — declared, measured, or neither. + public CmTraceOffsetOrigin LastMatchedSourceOffsetOrigin { get; internal set; } + // Callbacks to EnrollmentTracker public Action OnEspPhaseChanged { get; set; } public Action OnImeAgentVersion { get; set; }