From b77da673802117b2a237359383714dd8dfe7d917 Mon Sep 17 00:00:00 2001 From: l0ng-ai <24760907+l0ng-ai@users.noreply.github.com> Date: Sun, 16 Aug 2026 07:06:29 +0800 Subject: [PATCH] fix(log): the timestamp is UTC and now says so MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Log lines read `23:00:24.563` on a machine whose clock said `07:00:24`. The stamp is seconds since the epoch folded into a day, so it is UTC, and nothing marked it — the line looked eight hours stale rather than eight hours offset, which is the wrong conclusion to reach while reading a log to work out when something happened. One `Z`. UTC is the right choice for a daemon that outlives sessions and can be read from anywhere; being unlabelled was the defect. Still no date, and now the comment says why: turning epoch seconds into a civil date is calendar arithmetic this crate would have to hand-roll, and getting that subtly wrong is worse than a reader taking the day from the file, whose path `server logs` prints directly above the lines. Verified against a running server: the line now reads `23:02:15.701Z` with `date -u` at `23:02:17`. Nothing else came out of this sweep, which is worth recording: the remaining `(s)` spellings are all either log lines or the *seconds* unit in `Keepalive interval (s)` — a blind pass over them would have been wrong. The daemon also survives malformed wire input intact (empty, garbage, a 4 GB length header, unknown kinds, a 100 KB burst, and 200 junk connections) and leaks no threads doing it. --- crates/tty7-core/src/core/logfile.rs | 27 ++++++++++++++++++++++++++- 1 file changed, 26 insertions(+), 1 deletion(-) diff --git a/crates/tty7-core/src/core/logfile.rs b/crates/tty7-core/src/core/logfile.rs index 5cdd776e..b39b7317 100644 --- a/crates/tty7-core/src/core/logfile.rs +++ b/crates/tty7-core/src/core/logfile.rs @@ -95,13 +95,26 @@ fn log_path() -> Option { crate::core::config::config_path("tty7.log") } +/// Time of day, UTC, and said so. +/// +/// The `Z` is the whole point of this being a function worth a comment: the +/// stamp is seconds since the epoch folded into a day, which is UTC, and a +/// reader east or west of it sees a number hours away from their own clock +/// with nothing to explain it. On this machine the log said 23:00 while the +/// clock said 07:00, and the line looked eight hours stale rather than +/// eight hours offset. +/// +/// No date, deliberately: turning epoch seconds into a civil date is calendar +/// arithmetic this crate would have to hand-roll, and the cost of getting it +/// subtly wrong is worse than the cost of a reader checking the file's mtime +/// for the day. `server logs` prints the path directly above the lines. fn timestamp() -> String { let now = std::time::SystemTime::now() .duration_since(std::time::UNIX_EPOCH) .unwrap_or_default(); let secs = now.as_secs() % 86_400; format!( - "{:02}:{:02}:{:02}.{:03}", + "{:02}:{:02}:{:02}.{:03}Z", secs / 3600, (secs % 3600) / 60, secs % 60, @@ -131,6 +144,18 @@ mod tests { assert_eq!(parse_level("TRACE"), LevelFilter::Trace); } + /// A stamp with no zone reads as local time, and this one is not. + #[test] + fn the_stamp_says_which_clock_it_is_on() { + let stamp = timestamp(); + assert!( + stamp.ends_with('Z'), + "a UTC time of day has to say so, or it reads as hours wrong: {stamp}" + ); + let hh: u32 = stamp[..2].parse().expect("hours lead the stamp"); + assert!(hh < 24, "{stamp}"); + } + #[test] fn the_file_is_rewritten_once_it_passes_the_cap() { let path = std::env::temp_dir().join(format!("tty7-logfile-{}.log", std::process::id()));