klog: [ssss.mmm] millisecond timestamps from the PIT

- interrupts::uptime_ms(): monotonic ms since boot — the 100 Hz PIT
  tick (10 ms) plus interpolation from the PIT's live 1.19 MHz
  down-counter (read twice around the tick load; a count jump means a
  tick fired between reads) for true sub-ms resolution.  TICKS widened
  AtomicU16 -> AtomicU64 (u16 wrapped after ~11 min).
- PIT_READY gates interpolation until interrupts::init configures the
  timer, so early-boot lines are deterministically [0000.000] instead
  of uninitialised-PIT noise; klog clamps timestamps monotonic.
- The CMOS RTC cannot provide milliseconds (1 Hz BCD device, seconds
  only) — millis come from the PIT.
- klog stores ms per line at append time; dump format is now
  '[0000.123] 000000  === rsnix boot ===' (user-specified format).

Verified in QEMU: first line [0000.000], Phase-2 lines show real
monotonic ms (fs: vfs ready at [0000.519], self-test [0000.524]),
per-dump monotonicity, boot.log persists timestamps, test-disk round
trip fsck-clean.

1 files changed, 56 insertions, 8 deletions

diff --git a/rsnix/src/interrupts.rs b/rsnix/src/interrupts.rs
index 2b82a3d..c176276 100644
--- a/rsnix/src/interrupts.rs
+++ b/rsnix/src/interrupts.rs
@@ -2,7 +2,7 @@
 // Interrupt handling: IDT, PIC remap, ISR dispatch.
 // ---------------------------------------------------------------------------
 use core::arch::asm;
-use core::sync::atomic::{AtomicU16, Ordering};
+use core::sync::atomic::{AtomicBool, AtomicU16, AtomicU64, Ordering};
 
 // ---------------------------------------------------------------------------
 // IDT entry and table
@@ -91,11 +91,17 @@ fn eoi(irq: u8) {
 
 const PIT_CMD: u16 = 0x43;
 const PIT_CH0: u16 = 0x40;
-const PIT_FREQ: u64 = 1_193_182;
+const PIT_FREQ: u64 = 1_193_182; // PIT clock: 1.193182 MHz
+const PIT_HZ: u64 = 100;
 
-/// Set up PIT channel 0 in mode 2 (rate generator) at `hz` (1–1000ish).
-fn pit_set_rate(hz: u64) {
-    let divisor = (PIT_FREQ / hz) as u16;
+/// Counter divisor loaded for the ~100 Hz tick (matches `pit_set_rate`).
+pub const PIT_DIVISOR: u16 = (PIT_FREQ / PIT_HZ) as u16;
+
+/// Set up PIT channel 0 in mode 2 (rate generator) at the fixed 100 Hz
+/// tick rate — the divisor must stay `PIT_DIVISOR`, which `uptime_ms`
+/// relies on for interpolation.
+fn pit_set_rate() {
+    let divisor = PIT_DIVISOR;
     unsafe {
         // Mode 2, channel 0, lobyte/hibyte, binary
         asm!("out dx, al", in("dx") PIT_CMD,  in("al") 0b0011_0100u8,
@@ -107,6 +113,45 @@ fn pit_set_rate(hz: u64) {
     }
 }
 
+/// Latch and read the PIT channel 0 down-counter (0..=PIT_DIVISOR).
+/// In mode 2 the counter counts down and reloads on reaching 0, so it
+/// only ever jumps *up* when a tick fires.
+fn pit_count() -> u16 {
+    unsafe {
+        asm!("out dx, al", in("dx") PIT_CMD, in("al") 0x00u8,
+            options(nomem, nostack, preserves_flags));
+        let lo: u8;
+        let hi: u8;
+        asm!("in al, dx", out("al") lo, in("dx") PIT_CH0,
+            options(nomem, nostack, preserves_flags));
+        asm!("in al, dx", out("al") hi, in("dx") PIT_CH0,
+            options(nomem, nostack, preserves_flags));
+        u16::from_le_bytes([lo, hi])
+    }
+}
+
+/// True once the PIT tick is configured (`interrupts::init`).  Before
+/// that the PIT counter is uninitialised, so `uptime_ms` reports 0
+/// (early-boot messages are all at [0000.000], which is truthful — the
+/// clock hasn't started).
+static PIT_READY: AtomicBool = AtomicBool::new(false);
+
+/// Monotonic milliseconds since boot: the 100 Hz tick (10 ms each) plus
+/// interpolation from the PIT's live 1.19 MHz down-counter for the
+/// sub-10 ms fraction.  The countdown is read twice around the tick
+/// load: if it jumped up, a tick fired between the reads.
+pub fn uptime_ms() -> u64 {
+    if !PIT_READY.load(Ordering::Relaxed) {
+        return 0;
+    }
+    let c1 = pit_count();
+    let ticks = TICKS.load(Ordering::Relaxed);
+    let c2 = pit_count();
+    let ticks = if c2 > c1 { ticks + 1 } else { ticks };
+    let c = u64::from(c2.min(PIT_DIVISOR));
+    ticks * (1000 / PIT_HZ) + (u64::from(PIT_DIVISOR) - c) * 1000 / PIT_FREQ
+}
+
 // ---------------------------------------------------------------------------
 // Lock-free SPSC ring buffer for keyboard scancodes
 // ---------------------------------------------------------------------------
@@ -286,8 +331,10 @@ pub fn read_scancode() -> Option<u8> {
     KEYBUF.pop()
 }
 
-/// Global tick counter (incremented by timer IRQ, ~100 Hz).
-pub static TICKS: AtomicU16 = AtomicU16::new(0);
+/// Global tick counter (incremented by timer IRQ, ~100 Hz).  u64 so
+/// uptime never wraps; `uptime_ms` interpolates the PIT counter for the
+/// sub-tick fraction.
+pub static TICKS: AtomicU64 = AtomicU64::new(0);
 
 /// Initialise the IDT, remap the PIC, set up the PIT, and enable interrupts.
 pub fn init() {
@@ -326,7 +373,8 @@ pub fn init() {
         remap_pic();
 
         // Set up PIT timer at ~100 Hz.
-        pit_set_rate(100);
+        pit_set_rate();
+        PIT_READY.store(true, Ordering::Relaxed);
 
         // Unmask timer (IRQ0 → bit 0) and keyboard (IRQ1 → bit 1) on master.
         let mut mask: u8;