fix(log): the timestamp is UTC and now says so

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.
This commit is contained in:
l0ng-ai
2026-08-16 07:06:29 +08:00
parent 3c495e03af
commit b77da67380
+26 -1
View File
@@ -95,13 +95,26 @@ fn log_path() -> Option<PathBuf> {
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()));