diff --git a/README.md b/README.md index 4239eff..ec9f29a 100644 --- a/README.md +++ b/README.md @@ -51,7 +51,9 @@ The reader includes Security events 4778/4779 from the same auditing subcategory Shutdown, restart and boot do not produce lock/unlock events, so the reader also includes the user's Security events 4647 (user-initiated sign-out, also written when shutting down or restarting from Start) and 4624 interactive, remote-interactive and cached-interactive sign-ins (logon types 2, 10 and 11). Windows also writes a short cached-interactive logon while checking credentials at each unlock; such a 4624 is ignored unless the same logon ID later appears in that user's lock, unlock, connection or sign-out events, or it is the logon session the app is running in, which covers today's sign-in before the first lock. A sign-in starts work and a sign-out ends it. A real lock/unlock or session transition within five seconds takes precedence, and, as with disconnects, a sign-out from an already locked or disconnected session does not end work again. A restart creates a new logon session: sessions that follow each other, each ending with a lock, disconnect or sign-out before the next begins, form one day, and the sign-out-to-sign-in gap is an ordinary break pair, so it splits sections only when longer than the threshold and can be selected as lunch or meeting. Interleaved sessions still require review. These events come from the Logon and Logoff audit subcategories, which Windows enables by default. -Sleep, crashes and shutdowns without a sign-out are read from the System log, which ordinary users can read; if it is unavailable, the Security events still work. A Power-Troubleshooter 1 record, written on wake, gives the exact UTC start and end of a sleep or hibernation; overlapping periods, such as sleep followed by hibernation, merge into one. EventLog 6008, written at the next boot after a crash or power loss, supplies the system's last-alive time from its binary data, so that end is an estimate. Kernel-General 13 marks an orderly OS shutdown. These machine-wide records count only while the user's session is open, taking over that session's identity: a sleep after a lock, a crash while locked or a shutdown after a sign-out is ignored and hidden from the event list. Sleeping while signed in is an ordinary break pair, so it can be lunch or split sections. When the wake shows the lock screen, work restarts at the real unlock, and a lock recorded within 60 seconds of resuming repeats the sleep's end. After a crash, the next sign-in continues the day. Modern Standby without a lock is not interpreted. +Sleep, crashes and shutdowns without a sign-out are read from the System log, which ordinary users can read; if it is unavailable, the Security events still work. A Power-Troubleshooter 1 record, written on wake, gives the exact UTC start and end of a sleep or hibernation; overlapping periods, such as sleep followed by hibernation, merge into one. EventLog 6008, written at the next boot after a crash or power loss, supplies the system's last-alive time from its binary data, so that end is an estimate. Kernel-General 13 marks an orderly OS shutdown. These machine-wide records count only while the user's session is open, taking over that session's identity: a sleep after a lock, a crash while locked or a shutdown after a sign-out is hidden from the event list. Sleeping while signed in is an ordinary break pair, so it can be lunch or split sections. After a crash, the next sign-in continues the day. Modern Standby without a lock is not interpreted. + +Sleep context is retained for the associated session even when it was already locked. A native lock, disconnect or sign-out within five seconds after suspend replaces the synthetic sleep close, preserving its exact timestamp and saved break-pair choices. A lock-screen notification from five seconds before through 60 seconds after wake repeats that close, regardless of the order of Security and System record IDs. Work restarts at the real unlock/reconnect when one is present; a native close prevents wake alone from reopening the session. A real unlock/reconnect ends this duplicate suppression immediately. Without native closing or reopening evidence, wake remains the inferred work start. Native events remain visible in the log, and unexplained repeated transitions or events from other sessions still require review. Breaks strictly longer than the split threshold are excluded and split work rows. Shorter ordinary breaks count as work. The selected lunch break is always excluded, including a short manual lunch. Calculations use the original instants, not formatted display text. Workday grouping uses the local Windows time zone and handles daylight-saving boundaries. diff --git a/src/CompUsage.Core/SessionEvents.cs b/src/CompUsage.Core/SessionEvents.cs index 191c243..e7250d9 100644 --- a/src/CompUsage.Core/SessionEvents.cs +++ b/src/CompUsage.Core/SessionEvents.cs @@ -59,28 +59,47 @@ public static IReadOnlyList WorkTransitions(IEnumerable ev var list = events.OrderBy(e => e.Timestamp).ThenBy(e => e.RecordId).ToArray(); var result = new List(); var closed = new Dictionary(); + var sleeps = new Dictionary(); for (var i = 0; i < list.Length; i++) { var entry = list[i]; var previous = result.Count > 0 ? result[^1] : null; if (entry.IsSystemEvent) { - // Machine-wide events matter only while the user's session is open (sleep, crash, shutdown), - // or for the wake that ends a sleep kept here. They take over that session's identity. - if (previous is null || (entry.IsLock ? previous.IsLock : previous.EventId != LockEvent.Sleep)) continue; - var adopted = entry with { UserSid = previous.UserSid, UserName = previous.UserName, Domain = previous.Domain, - SessionId = previous.SessionId, LogonId = previous.LogonId }; - result.Add(adopted); closed[adopted.SessionKey] = adopted.IsLock; + if (entry.EventId == LockEvent.Wake) + { + var sleeping = sleeps.Values.FirstOrDefault(s => s.Wake == entry); + if (sleeping is null) continue; + if (previous?.SessionKey != sleeping.Sleep.SessionKey) + { + sleeps.Remove(sleeping.Sleep.SessionKey); + continue; + } + // A wake is only a provisional work start when there is no native closing record. + // Keep the sleep context even when its synthetic close was replaced or never emitted. + if (!sleeping.RequiresUnlock && previous == sleeping.Sleep) + { + var wake = Adopt(entry, sleeping.Sleep); + sleeping.ProvisionalWake = wake; + result.Add(wake); closed[wake.SessionKey] = false; + } + continue; + } + // A new machine power transition ends any previous resume window. Shutdowns never reopen sessions. + sleeps.Clear(); + if (previous is null) continue; + var adopted = Adopt(entry, previous); + if (entry.EventId == LockEvent.Sleep) + { + // MergeSleeps supplies non-overlapping periods. Looking ahead to the next power event also + // recognizes resume locks timestamped just before Wake, independently of cross-log record IDs. + var nextPower = list.Skip(i + 1).FirstOrDefault(e => e.IsSystemEvent); + sleeps[adopted.SessionKey] = new(adopted, nextPower?.EventId == LockEvent.Wake ? nextPower : null, previous.IsLock); + } + if (previous.IsLock) continue; + result.Add(adopted); closed[adopted.SessionKey] = true; continue; } - if (previous?.EventId == LockEvent.Wake && previous.SessionKey == entry.SessionKey - && (!entry.IsLock || entry.Timestamp - previous.Timestamp <= TimeSpan.FromSeconds(60))) - { - // The wake showed the lock screen: work restarts at the real unlock, and a lock recorded - // while resuming repeats the sleep's end. - result.RemoveAt(result.Count - 1); closed[entry.SessionKey] = true; - if (entry.IsLock) continue; - } var duplicate = false; if (Rank(entry) > 0 && HasLogon(entry)) { @@ -100,15 +119,61 @@ public static IReadOnlyList WorkTransitions(IEnumerable ev if (duplicate) break; } } - // Disconnecting, signing out or shutting down an already locked or disconnected session does not end work again. - if (entry.EventId is 4647 or 4779 && closed.GetValueOrDefault(entry.SessionKey)) duplicate = true; if (duplicate) continue; + if (sleeps.TryGetValue(entry.SessionKey, out var sleep)) + { + if (!entry.IsLock) + { + // The real unlock/reconnect wins over an inferred wake and ends duplicate suppression. + if (sleep.ProvisionalWake is { } wake) result.Remove(wake); + sleeps.Remove(entry.SessionKey); + } + else if (entry.EventId is 4800 or 4779 or 4647) + { + if (previous == sleep.Sleep && entry.Timestamp - sleep.Sleep.Timestamp <= TimeSpan.FromSeconds(5) + && (sleep.Wake is null || entry.Timestamp < sleep.Wake.Timestamp)) + { + // Prefer the native suspend close: its exact time and record ID keep saved break choices valid. + result[^1] = entry; + sleep.RequiresUnlock = true; + closed[entry.SessionKey] = true; + continue; + } + if (sleep.Wake is { } resumed && entry.Timestamp >= resumed.Timestamp.AddSeconds(-5) + && entry.Timestamp <= resumed.Timestamp.AddSeconds(60)) + { + // Wake can precede or follow the lock-screen notification. Neither starts or ends work again. + if (sleep.ProvisionalWake is { } wake) result.Remove(wake); + sleep.ProvisionalWake = null; + sleep.RequiresUnlock = true; + closed[entry.SessionKey] = true; + continue; + } + if (sleep.Wake is { } ended && entry.Timestamp > ended.Timestamp) sleeps.Remove(entry.SessionKey); + } + } + // Disconnecting, signing out or shutting down an already locked or disconnected session does not end work again. + if (entry.EventId is 4647 or 4779 && closed.GetValueOrDefault(entry.SessionKey)) continue; result.Add(entry); closed[entry.SessionKey] = entry.IsLock; } return result; } + private sealed class SleepState(LockEvent sleep, LockEvent? wake, bool requiresUnlock) + { + public LockEvent Sleep { get; } = sleep; + public LockEvent? Wake { get; } = wake; + public bool RequiresUnlock { get; set; } = requiresUnlock; + public LockEvent? ProvisionalWake { get; set; } + } + + private static LockEvent Adopt(LockEvent entry, LockEvent session) => entry with + { + UserSid = session.UserSid, UserName = session.UserName, Domain = session.Domain, + SessionId = session.SessionId, LogonId = session.LogonId + }; + public static bool Sequential(IReadOnlyList events) { // A sign-out, restart and new sign-in create a new logon session. Sessions that follow each other, diff --git a/tests/CompUsage.Checks/Program.cs b/tests/CompUsage.Checks/Program.cs index 3ffd33a..9ff2bae 100644 --- a/tests/CompUsage.Checks/Program.cs +++ b/tests/CompUsage.Checks/Program.cs @@ -199,6 +199,42 @@ List Day(int day, string from = "08:02:14", string until = "16:48:09" Equal(4801, day.Pairs[0].Unlock.EventId); Equal(At(16,"12:55"), day.Sections[1].From); } }); +Check("Suspend just before a native close preserves the native timestamp and manual lunch pair", () => +{ + foreach (var closeId in new[] { 4800, 4779, 4647 }) + { + var locked = Event(16,"12:00:00.550",true) with { EventId = closeId }; + var unlocked = Event(16,"12:40",false); + LockEvent[] native = [Event(16,"08:00",false), locked, unlocked, Event(16,"17:00",true)]; + var before = Report(native); lunches["2026-10-16"] = before.Pairs[0].Id; + var day = Report(native.Concat(SleepPeriod(16,"12:00","12:01"))); + True(!day.Incomplete); Equal(before.Pairs[0].Id, day.Lunch!.Id); + Equal(locked.Timestamp, day.Sections[0].To); Equal(unlocked.Timestamp, day.Sections[1].From); + Equal(2, day.Sections.Count); lunches.Clear(); + } +}); +Check("Suspend, disconnect and lock within one second close work only once, including at day end", () => +{ + var locked = Event(16,"17:00:00.550",true); + var day = Report([Event(16,"08:00",false), ..SleepPeriod(16,"17:00","17:01"), + locked with {RecordId=id++,EventId=4779,Timestamp=At(16,"17:00:00.160"),SessionId=""}, locked]); + True(!day.Incomplete); Equal(locked.RecordId, day.Last!.RecordId); + Equal(locked.Timestamp, day.Sections.Single().To); +}); +Check("Suspend coalescing does not hide distant locks, other sessions or intervening unlocks", () => +{ + LockEvent[] entries = [Event(16,"08:00",false), ..SleepPeriod(16,"12:00","12:40"), + Event(16,"12:00:06",true), Event(16,"12:55",false), Event(16,"17:00",true)]; + True(Report(entries).Incomplete); + entries[3] = Event(16,"12:00:00.550",true,"2"); + True(Report(entries).Incomplete); + entries[3] = Event(16,"12:00:00.550",true) with {LogonId="0x2"}; + True(Report(entries).Incomplete); + var transitions = SessionEvents.WorkTransitions([Event(16,"08:00",false), + SystemEvent(16,"12:00",LockEvent.Sleep), Event(16,"12:00:00.250",false), Event(16,"12:00:00.550",true)]); + Equal(4, transitions.Count); Equal(LockEvent.Sleep, transitions[1].EventId); +}); +SessionEventChecks.Run(Check); Check("An unexpected shutdown ends work at the last-alive time and the next sign-in continues the day", () => { var day = Report([Event(16,"08:00",false), SystemEvent(16,"15:31:19",LockEvent.UnexpectedShutdown), diff --git a/tests/CompUsage.Checks/SessionEventChecks.cs b/tests/CompUsage.Checks/SessionEventChecks.cs new file mode 100644 index 0000000..0453e81 --- /dev/null +++ b/tests/CompUsage.Checks/SessionEventChecks.cs @@ -0,0 +1,156 @@ +using System.Globalization; +using CompUsage.Core; + +internal static class SessionEventChecks +{ + private static readonly TimeZoneInfo Zone = TimeZoneInfo.FindSystemTimeZoneById("Central Europe Standard Time"); + private static readonly AppSettings Settings = new(); + private static DateTimeOffset At(string time) => WorkDayClock.At(new(2026, 10, 16), TimeOnly.Parse(time, CultureInfo.InvariantCulture), Zone); + private static LockEvent User(long id, string time, int eventId) => new(id, At(time), eventId, "sid", "Test", "LOCAL", "1", "0x1"); + private static LockEvent[] Sleep(long id = 100, string from = "12:00", string to = "12:40") => + [new(id, At(from), LockEvent.Sleep, "", "", "", "", ""), new(id, At(to), LockEvent.Wake, "", "", "", "", "")]; + private static WorkReport Report(IEnumerable events) => WorkReports.Build(events, Settings, + new Dictionary(), At("23:00").AddDays(1), Zone).Single(); + private static void Require(bool condition, string context) + { + if (!condition) throw new Exception(context); + } + + public static void Run(Action check) + { + check("Suspend and native closes preserve exact endpoints and saved lunch choices in either order", () => + { + foreach (var closeId in new[] { 4800, 4779, 4647 }) + foreach (var offset in new[] { -5L * TimeSpan.TicksPerSecond, -5_500_000L, 0L, 5_500_000L, 5L * TimeSpan.TicksPerSecond }) + foreach (var record in new[] { 2L, 100L, 102L }) + { + var locked = User(record, "12:00", closeId) with { Timestamp = At("12:00").AddTicks(offset) }; + var unlocked = User(4, "12:55", 4801); + LockEvent[] native = [User(1, "08:00", 4801), locked, unlocked, User(5, "17:00", 4800)]; + var choice = Report(native).Pairs.Single().Id; + LockEvent[] entries = [..native, ..Sleep()]; + var day = WorkReports.Build(entries, Settings, new Dictionary { ["2026-10-16"] = choice }, + At("23:00").AddDays(1), Zone).Single(); + Require(!day.Incomplete && day.Sections.Count == 2, $"close={closeId}, suspend offset={offset}: incomplete day"); + Require(day.Lunch?.Id == choice && day.ManualLunch, "The native break-pair ID changed"); + Require(day.Sections[0].To == locked.Timestamp && day.Sections[1].From == unlocked.Timestamp, "Native endpoint precision was lost"); + Require(Presentation.CopyRow(day.Sections[0], Zone) == Presentation.CopyRow(Report(native).Sections[0], Zone), "Clipboard endpoint changed"); + } + }); + check("Resume notifications do not repeat a native close before or after suspend", () => + { + foreach (var closeId in new[] { 4800, 4779, 4647 }) + foreach (var initialOffset in new[] { -TimeSpan.TicksPerMinute, -5_500_000L, 0L, 5_500_000L }) + foreach (var resumeId in new[] { 4800, 4779, 4647 }) + foreach (var resumeOffset in new[] { -5L * TimeSpan.TicksPerSecond, -5_000_000L, 0L, 2L * TimeSpan.TicksPerSecond, TimeSpan.TicksPerMinute }) + { + var locked = User(2, "12:00", closeId) with { Timestamp = At("12:00").AddTicks(initialOffset) }; + var resume = User(3, "12:40", resumeId) with { Timestamp = At("12:40").AddTicks(resumeOffset) }; + LockEvent[] entries = [User(1, "08:00", 4801), locked, ..Sleep(), resume, User(4, "12:55", 4801), User(5, "17:00", 4800)]; + var day = Report(entries); + Require(!day.Incomplete && day.Sections.Count == 2, + $"close={closeId}@{initialOffset}, resume={resumeId}@{resumeOffset}: false incomplete day"); + Require(day.Pairs.Single().Lock == locked && day.Sections[1].From == At("12:55"), "Resume changed the break endpoints"); + Require(day.Events.Contains(resume), "A native event disappeared from the visible log"); + } + }); + check("A resume lock before or simultaneous with wake works without a native suspend close", () => + { + foreach (var record in new[] { 3L, 100L, 103L }) + foreach (var ticks in new[] { -5L * TimeSpan.TicksPerSecond, -1L, 0L, 1L, TimeSpan.TicksPerMinute }) + { + var resume = User(record, "12:40", 4800) with { Timestamp = At("12:40").AddTicks(ticks) }; + LockEvent[] events = [User(1, "08:00", 4801), ..Sleep(), resume, User(104, "12:55", 4801), User(105, "17:00", 4800)]; + foreach (var ordered in new[] { events, events.Reverse().ToArray() }) + { + var day = Report(ordered); + Require(!day.Incomplete && day.Sections.Count == 2, $"Resume order changed the day: id={record}, ticks={ticks}"); + Require(day.Sections[0].To == At("12:00") && day.Sections[1].From == At("12:55"), "Wake counted lock-screen time as work"); + } + } + }); + check("Suspend coalescing honors the five-second limit and preserves genuine repeated locks", () => + { + foreach (var time in new[] { "12:00:05.0000001", "12:01", "12:39:54.9999999", "12:41:00.0000001" }) + { + LockEvent[] entries = [User(1, "08:00", 4801), User(2, "11:59:59", 4800), ..Sleep(), + User(3, time, 4800), User(4, "12:55", 4801), User(5, "17:00", 4800)]; + Require(Report(entries).Incomplete, $"Unexplained repeated lock at {time} was hidden"); + } + var afterSuspend = Report([User(1, "08:00", 4801), ..Sleep(), User(2, "12:00:05.0000001", 4800), + User(4, "12:55", 4801), User(5, "17:00", 4800)]); + Require(afterSuspend.Incomplete, "A late suspend lock was coalesced outside the five-second window"); + }); + check("A real unlock ends resume suppression, including immediately before wake", () => + { + foreach (var unlockTime in new[] { "12:39:59", "12:40", "12:40:01" }) + foreach (var initialClose in new[] { false, true }) + { + List entries = [User(1, "08:00", 4801), ..Sleep(), User(3, unlockTime, 4801), + User(4, "12:40:02", 4800), User(5, "12:55", 4801), User(6, "17:00", 4800)]; + if (initialClose) entries.Add(User(2, "12:00:00.550", 4800)); + var day = Report(entries); + Require(!day.Incomplete && day.Sections.Count == 3, $"Real post-unlock work lost: {unlockTime}, initial close={initialClose}"); + Require(day.Sections[1].From == At(unlockTime) && day.Sections[1].To == At("12:40:02"), "Real lock was treated as a resume duplicate"); + } + }); + check("Suspend-disconnect-lock chains keep the native lock and subsequent resume duplicates stay suppressed", () => + { + var locked = User(4, "12:00:00.550", 4800); + var day = Report([User(1, "08:00", 4801), ..Sleep(), User(2, "12:00:00.100", 4779), + User(3, "12:00:00.200", 4647), locked, User(5, "12:39:59.500", 4779), + User(6, "12:40:02", 4800), User(7, "12:40:03", 4800), User(8, "12:55", 4801), User(9, "17:00", 4800)]); + Require(!day.Incomplete && day.Pairs.Single().Lock == locked, "The native close chain lost its original endpoint"); + }); + check("Sleep context never coalesces events from another session, logon or account", () => + { + foreach (var time in new[] { "12:00:00.550", "12:39:59.500", "12:40:02" }) + foreach (var foreign in new[] { User(3, time, 4800) with { SessionId = "2" }, + User(3, time, 4800) with { LogonId = "0x2" }, User(3, time, 4800) with { UserSid = "other" } }) + { + LockEvent[] events = [User(1, "08:00", 4801), ..Sleep(), foreign, User(4, "12:55", 4801), User(5, "17:00", 4800)]; + Require(Report(events).Incomplete, "Cross-session ambiguity was hidden"); + Require(SessionEvents.WorkTransitions(events).Contains(foreign), "Another session's lock was removed"); + } + }); + check("Wake alone opens an unlocked session, but never reopens a natively closed session", () => + { + var plain = Report([User(1, "08:00", 4801), ..Sleep(), User(5, "17:00", 4800)]); + Require(!plain.Incomplete && plain.Sections[1].From == At("12:40"), "A wake without lock-screen evidence did not resume work"); + var lateLock = Report([User(1, "08:00", 4801), ..Sleep(), User(3, "12:41:00.0000001", 4800), + User(4, "12:55", 4801), User(5, "17:00", 4800)]); + Require(!lateLock.Incomplete && lateLock.Sections.Count == 3, "A real lock beyond the resume window was suppressed"); + foreach (var time in new[] { "11:59:59", "12:00:00.550" }) + { + var closed = Report([User(1, "08:00", 4801), User(2, time, 4800), ..Sleep()]); + Require(!closed.Incomplete && closed.Sections.Count == 1 && closed.Last?.Timestamp == At(time), "Wake reopened a locked session"); + } + }); + check("Separate sleep cycles and merged hibernation retain their own resume context", () => + { + var day = Report([User(1, "08:00", 4801), ..Sleep(100, "10:00", "10:20"), User(2, "10:00:00.550", 4800), + User(3, "10:20:02", 4800), User(4, "10:30", 4801), ..Sleep(101, "12:00", "12:10"), ..Sleep(102), + User(5, "12:00:00.550", 4779), User(6, "12:39:59.500", 4800), User(7, "12:55", 4801), User(8, "17:00", 4800)]); + Require(!day.Incomplete && day.Sections.Count == 3, "Power-cycle context leaked between periods"); + Require(day.Sections[1].From == At("10:30") && day.Sections[1].To == At("12:00:00.550"), "Merged sleep changed native endpoints"); + }); + check("Shutdown invalidates pending resume context before a new logon", () => + { + var stop = new LockEvent(101, At("12:30"), LockEvent.SystemShutdown, "", "", "", "", ""); + var connected = User(4, "12:40", 4624) with { SessionId = "2", LogonId = "0x2" }; + var locked = connected with { RecordId = 5, Timestamp = At("17:00"), EventId = 4800 }; + var day = Report([User(1, "08:00", 4801), ..Sleep(), User(2, "12:00:00.550", 4800), stop, connected, locked]); + Require(!day.Incomplete && day.Sections.Count == 2 && day.Sections[1].From == connected.Timestamp, "Shutdown left a stale resume context"); + }); + check("Monitor-recovered locks and last-input endpoints survive suspend normalization", () => + { + var close = At("12:00:00.550"); var input = At("11:59:50"); + var day = WorkReports.Build([User(1, "08:00", 4801), ..Sleep(), User(3, "12:40:02", 4800), + User(4, "12:55", 4801), User(5, "17:00", 4800)], Settings with { LockTimeSource = "activity" }, + new Dictionary(), At("23:00").AddDays(1), Zone, + activity: [new(close, input, At("12:00"), "1")], breaks: [new(close, At("12:55"), BreakReasons.Lunch)]).Single(); + Require(!day.Incomplete && day.Sections.Count == 2, "A recovered suspend lock made the day incomplete"); + Require(day.Sections[0].To == input && day.Pairs.Single().Lock.Timestamp == close, "The monitor's exact endpoint was lost"); + }); + } +}