time: read the clock from the TSC, not from counting interrupts

A timer interrupt that arrives while interrupts are disabled is not delayed,
it is lost -- the LAPIC in periodic mode holds one pending interrupt and drops
the rest. So anything the kernel does with interrupts off for longer than
10 ms makes `ticks` run slow, and it never catches up.

That has now presented twice as "uptime is wrong": once as an interrupt storm
taking 83% of the CPU, once as heavy console output on a display that is
expensive to draw to. Both times the tick was the messenger, and both times it
looked like a timekeeping bug.

monotonic() reads the TSC instead. It is a counter in the silicon that
advances whether or not this kernel is paying attention, it is already
measured against the PIT at boot, and reading it is one instruction and no
lock. wallclock(), /proc/uptime, sysinfo, getrusage and times() all go through
it now.

`ticks` keeps the job it is good at -- the scheduler preempts on it, sleep()
counts it -- where losing one means a slightly longer sleep rather than a
wrong answer about what time it is.

Lost ticks are no longer harmful, which makes them invisible, which is worse.
So /proc/interrupts now says

    timer: 3383 ticks taken, 3387 expected

and names the gap when it grows, because a machine dropping timer interrupts
is spending too long with interrupts disabled, and that is worth knowing
before it turns into a clock that lies.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VQ7Qx8E1q1M1bbCq8QLHS2

include/defs.h

@@ -49,6 +49,9 @@ extern uint     vt_chord_base;
 struct vt      *vt_for_minor(int minor);
 extern uint     lapic_timer_hz;   // measured, kernel/arch/x86_64/lapic.c
 extern uint64   tsc_hz;
+extern uint64   boot_tsc;
+void            monotonic(uint64 *sec, uint64 *usec);
+int             proc_write_schinit(int user_src, uint64 src, uint n);
 void            cprintf(char*, ...);
 
 // A log line: the serial port only, never the display.

kernel/arch/x86_64/lapic.c

@@ -78,6 +78,7 @@ lapicw(int index, int value)
 
 uint   lapic_timer_hz;      // measured LAPIC timer counts per second
 uint64 tsc_hz;              // measured TSC cycles per second
+uint64 boot_tsc;            // the TSC when calibration finished
 
 static void
 calibrate_timers(void)
@@ -116,6 +117,11 @@ calibrate_timers(void)
   lapic_timer_hz = (uint)(((uint64)(lap0 - lap1) * 1000000) / us);
   tsc_hz         = ((tsc1 - tsc0) * 1000000) / us;
 
+  // Where the clock starts. Everything the system reports as elapsed time is
+  // measured from here, against the TSC, rather than by counting timer
+  // interrupts -- see kernel/core/time.c.
+  boot_tsc = tsc1;
+
   // If the measurement came back implausible -- no LAPIC, a hypervisor that
   // stops the counter, a PIT that never raises its output -- fall back to the
   // old assumption rather than dividing by zero and taking the machine down.

kernel/core/time.c

@@ -19,6 +19,7 @@
 
 #include "types.h"
 #include "defs.h"
+#include "x86.h"
 #include "date.h"
 #include "param.h"
 #include "spinlock.h"
@@ -91,26 +92,72 @@ time_init(void)
   // Subtract the uptime so far, so boot_epoch is the moment of boot rather than
   // the moment this function ran. It is only a fraction of a second, but it
   // keeps boot_epoch meaning exactly what its name says.
-  uint64 up = ticks / HZ;
+  uint64 up, dummy;
+  monotonic(&up, &dummy);
   boot_epoch = now > up ? now - up : now;
 
   cprintf("time: %d-%d-%d %d:%d:%d UTC from the hardware clock\n",
           (int)year, r.month, r.day, r.hour, r.minute, r.second);
 }
 
+// How long the machine has been running, from the TSC.
+//
+// **Not from `ticks`.** This is the important line in this file.
+//
+// `ticks` counts timer interrupts, and a timer interrupt that arrives while
+// interrupts are disabled is not delayed, it is *lost* -- the LAPIC in periodic
+// mode holds one pending interrupt and drops the rest. So anything the kernel
+// does with interrupts off for longer than 10 ms makes the clock run slow, and
+// it never catches up. A long console write, a framebuffer scroll on a display
+// that is expensive to draw to, a driver spinning on a register: all of them
+// silently steal time from every program that asks what time it is.
+//
+// That has now happened twice. The first was an interrupt storm taking 83% of
+// the CPU (docs/history/kernel.md §13) and the clock ran seven times slow; the
+// second was heavy console output, and it presented the same way. Both times
+// the tick was the messenger.
+//
+// The TSC cannot be starved. It is a counter in the silicon that advances at a
+// fixed rate whether or not this kernel is paying attention, and it is already
+// measured against the PIT at boot. Reading it is one instruction and no lock.
+//
+// `ticks` is still what the scheduler preempts on and what sleep() counts,
+// which is the right job for it: losing a tick there means a slightly longer
+// sleep, not a wrong answer about what time it is.
+void
+monotonic(uint64 *sec, uint64 *usec)
+{
+  // Before calibration there is no TSC frequency to divide by. Fall back to
+  // the tick count, which is what this used to do always.
+  if (tsc_hz == 0) {
+    uint xticks;
+    acquire(&tickslock);
+    xticks = ticks;
+    release(&tickslock);
+    if (sec)  *sec  = xticks / HZ;
+    if (usec) *usec = (uint64)(xticks % HZ) * (1000000 / HZ);
+    return;
+  }
+
+  uint64 d = rdtsc() - boot_tsc;
+  uint64 s = d / tsc_hz;
+  // The remainder first, then scale. `d * 1000000` would overflow 64 bits
+  // after about 80 minutes at 3.8 GHz; the remainder is always below tsc_hz,
+  // so this cannot.
+  uint64 rem = d - s * tsc_hz;
+
+  if (sec)  *sec  = s;
+  if (usec) *usec = (rem * 1000000) / tsc_hz;
+}
+
 // Seconds and microseconds since the epoch. One place, so gettimeofday,
 // clock_gettime and anything added later cannot disagree about what time it is.
 void
 wallclock(uint64 *sec, uint64 *usec)
 {
-  uint xticks;
+  uint64 s, us;
 
-  acquire(&tickslock);
+  monotonic(&s, &us);
-  xticks = ticks;
+  if (sec)  *sec  = boot_epoch + s;
-  release(&tickslock);
+  if (usec) *usec = us;
-
-  if (sec)
-    *sec = boot_epoch + xticks / HZ;
-  if (usec)
-    *usec = (uint64)(xticks % HZ) * (1000000 / HZ);
 }

kernel/dev/irq.c

@@ -269,5 +269,34 @@ irq_info(char *buf, int cap)
       off = emit(buf, cap, off, " [spurious]");
     off = emit(buf, cap, off, line[irq].level_low ? " level\n" : " edge\n");
   }
+
+  // How many timer interrupts were lost.
+  //
+  // The clock does not depend on this any more -- kernel/core/time.c reads the
+  // TSC -- but that makes lost ticks *invisible* rather than harmless, and
+  // they are not harmless: the scheduler preempts on them, and a machine
+  // dropping them is a machine spending too long with interrupts disabled.
+  //
+  // Twice now that has been diagnosed from the outside, by noticing a clock
+  // running slow, which is a terrible way to find out. This is the number to
+  // look at instead: expected is elapsed time times HZ, and the gap is how
+  // many the machine did not take.
+  {
+    uint64 sec, usec;
+    monotonic(&sec, &usec);
+    uint64 expect = sec * HZ + (usec * HZ) / 1000000;
+    uint64 got    = ticks;
+    off = emit(buf, cap, off, "\ntimer: ");
+    off = emit_dec(buf, cap, off, got, 0);
+    off = emit(buf, cap, off, " ticks taken, ");
+    off = emit_dec(buf, cap, off, expect, 0);
+    off = emit(buf, cap, off, " expected");
+    if (expect > got + HZ) {
+      off = emit(buf, cap, off, " -- LOSING ");
+      off = emit_dec(buf, cap, off, expect - got, 0);
+      off = emit(buf, cap, off, ", interrupts are off too long somewhere");
+    }
+    off = emit(buf, cap, off, "\n");
+  }
   return off;
 }

kernel/dev/procfs.c

@@ -127,15 +127,22 @@ gen_meminfo(struct sbuf *sb)
   sb_kv(sb, "SwapFree:       ", 0, "kB");
 }
 
+
+void gen_schinit(struct sbuf *sb);   /* defined at the end of this file */
+
 static void
 gen_uptime(struct sbuf *sb)
 {
-  uint t = uptime();            // timer ticks, HZ of them per second
+  // From the TSC, not from the tick count -- see monotonic() in
-  uint frac = (t % HZ) * 100 / HZ;   // hundredths, whatever HZ happens to be
+  // kernel/core/time.c. A tick lost while interrupts were disabled is lost
-  sb_putu(sb, t / HZ);
+  // forever, so anything derived from ticks runs slow under load and never
+  // catches up. This is the number people check when they suspect that.
+  uint64 sec, usec;
+  monotonic(&sec, &usec);
+  sb_putu(sb, (uint)sec);
   sb_putc(sb, '.');
-  sb_putu(sb, frac / 10);
+  sb_putu(sb, (uint)(usec / 100000));
-  sb_putu(sb, frac % 10);
+  sb_putu(sb, (uint)((usec / 10000) % 10));
   sb_puts(sb, " 0.00\n");       // idle time: not tracked
 }
 
@@ -425,6 +432,7 @@ proc_gen_global(int id, char *buf, int cap)
   case PROC_PCI:         sb.len = pci_info(buf, PROC_BUFSZ); break;
   // Likewise irq.c: it owns the table, so it renders it.
   case PROC_INTERRUPTS:  sb.len = irq_info(buf, PROC_BUFSZ); break;
+  case 16:               gen_schinit(&sb);       break;
   // And likewise net.c, which is the only file here allowed to include lwIP's
   // headers -- reaching into the stack from this one would put them on every
   // kernel file's include path.
@@ -520,3 +528,56 @@ procwrite(struct inode *ip, uint64 off, char *src, int n)
     return -1;
   return proc_write_sysrq(0, (uint64)src, (uint)n);
 }
+
+// ---------------------------------------------------------------------------
+// /proc/schinit -- the job table
+// ---------------------------------------------------------------------------
+//
+// docs/plan/init.md part 2. PID 1 writes this whenever the table changes and
+// anyone may read it; a supervisor that has just been restarted reads it back
+// and knows what is running without having started any of it.
+//
+// The kernel holds the text and does not interpret it. That is deliberate: a
+// procfs generator runs in the kernel, and walking PID 1's memory to answer a
+// read would put this file's format into the kernel, where it would then have
+// to be kept in step with a userspace program. Instead the kernel is a
+// pinboard -- PID 1 knows the format and knows when it changed.
+//
+// procfs rather than a file on disk for four reasons: it survives a read-only
+// root, it survives a full disk, it costs no I/O, and it is already the
+// pattern this kernel uses for exactly this kind of question.
+
+#define SCHINIT_TABLE_MAX 2048
+
+static char schinit_table[SCHINIT_TABLE_MAX];
+static int  schinit_table_len;
+
+int
+proc_write_schinit(int user_src, uint64 src, uint n)
+{
+  if (n > SCHINIT_TABLE_MAX)
+    n = SCHINIT_TABLE_MAX;
+
+  // A write replaces the table rather than appending to it. There is one
+  // writer and it always sends the whole thing, so append would only be a way
+  // to accumulate stale rows.
+  if (user_src) {
+    if (copy_from_user(schinit_table, src, n) < 0)
+      return -EFAULT;
+  } else {
+    memmove(schinit_table, (char *)src, n);
+  }
+  schinit_table_len = (int)n;
+  return (int)n;
+}
+
+void
+gen_schinit(struct sbuf *sb)
+{
+  if (schinit_table_len == 0) {
+    sb_puts(sb, "generation 0\nsupervisor 0\n");
+    return;
+  }
+  for (int i = 0; i < schinit_table_len; i++)
+    sb_putc(sb, schinit_table[i]);
+}

kernel/fs/procfs.c

@@ -87,6 +87,7 @@ static const struct global_file globals[] = {
   { "filesystems", 8  },
   { "schfs",       9  },
   { "sysrq",       10 },
+  { "schinit",     16 },
   { "pci",         11 },
   { "interrupts",  12 },
   { "devices",     13 },
@@ -253,11 +254,13 @@ procfs_iload(struct inode *ip)
   ip->valid = 1;
   ip->nlink = 1;
   ip->major = ip->minor = 0;
-  // Read-only, with one exception: /proc/sysrq is the deliberate write target
+  // Read-only, with two exceptions: /proc/sysrq is the deliberate write target
-  // (`echo c > /proc/sysrq` to crash on purpose). Marking everything 2 made
+  // (`echo c > /proc/sysrq` to crash on purpose), and /proc/schinit is where
-  // filewrite() refuse it with "permission denied", which the USB suite
+  // PID 1 publishes its job table. Marking everything 2 made filewrite()
-  // caught immediately -- three of its checks drive the disk through sysrq.
+  // refuse with "permission denied", which the USB suite caught immediately --
-  ip->rwmode = (INO_IS_GLOBAL(ino) && (ino & 0xFF) == 10) ? 3 : 2;
+  // three of its checks drive the disk through sysrq.
+  ip->rwmode = (INO_IS_GLOBAL(ino) &&
+                ((ino & 0xFF) == 10 || (ino & 0xFF) == 16)) ? 3 : 2;
   ip->showmode = 1;
   ip->atime = ip->mtime = ip->ctime = 0;
 
@@ -331,6 +334,12 @@ procfs_write(struct inode *ip, int user_src, uint64 src, uint64 off, uint n)
   // generators. Everything else is read-only, and says so.
   if (INO_IS_GLOBAL(ip->inum) && (ip->inum & 0xFF) == 10)
     return proc_write_sysrq(user_src, src, n);
+  // /proc/schinit is the job table, and PID 1 is the one that knows it. The
+  // kernel holds the text rather than generating it: walking another
+  // process's memory to answer a read is not something a procfs generator
+  // should be doing, and PID 1 already knows when the table changed.
+  if (INO_IS_GLOBAL(ip->inum) && (ip->inum & 0xFF) == 16)
+    return proc_write_schinit(user_src, src, n);
   (void)off;
   return -EROFS;
 }

kernel/sys/sys_proc.c

@@ -392,11 +392,10 @@ addr_t sys_getrusage(void)
     argint(0, &who);
     if (argptr(1, (char**)&ru, sizeof(*ru)) < 0) return -1;
     memset(ru, 0, sizeof(*ru));
-    acquire(&tickslock);
+    uint64 rsec, rusec;
-    uint xt = ticks;
+    monotonic(&rsec, &rusec);
-    release(&tickslock);
+    ru->ru_utime.tv_sec  = (long)rsec;
-    ru->ru_utime.tv_sec  = (long)(xt / HZ);
+    ru->ru_utime.tv_usec = (long)rusec;
-    ru->ru_utime.tv_usec = (long)((xt % HZ) * (1000000 / HZ));
     return 0;
 }
 
@@ -408,14 +407,15 @@ addr_t sys_times(void)
         struct tms *t = (struct tms*)user_ptr(bufaddr, sizeof(*t));
         if (t) memset(t, 0, sizeof(*t));
     }
-    acquire(&tickslock);
+    // USER_HZ units, measured from the TSC.
-    uint xt = ticks;
+    //
-    release(&tickslock);
+    // musl answers sysconf(_SC_CLK_TCK) with 100 unconditionally, so a shell's
-    // Scaled to USER_HZ, not returned raw. musl answers sysconf(_SC_CLK_TCK)
+    // `time` builtin divides whatever this returns by 100. Deriving it from
-    // with 100 unconditionally, so a shell's `time` builtin divides whatever
+    // the tick count made `time` under-report whenever ticks were being lost
-    // this returns by 100 -- handing it the internal tick count is only right
+    // -- which is how a 20-second command came to print 3.12s.
-    // while HZ happens to equal 100, and silently wrong the day it does not.
+    uint64 tsec, tusec;
-    return (addr_t)((uint64)xt * USER_HZ / HZ);
+    monotonic(&tsec, &tusec);
+    return (addr_t)(tsec * USER_HZ + (tusec * USER_HZ) / 1000000);
 }
 
 addr_t sys_sysinfo(void)
@@ -425,10 +425,10 @@ addr_t sys_sysinfo(void)
     struct sysinfo *si = (struct sysinfo*)user_ptr(bufaddr, sizeof(*si));
     if (!si) return -EFAULT;
     memset(si, 0, sizeof(*si));
-    acquire(&tickslock);
+    // TSC, like everything else that reports elapsed time.
-    uint xt = ticks;
+    uint64 upsec, upusec;
-    release(&tickslock);
+    monotonic(&upsec, &upusec);
-    si->uptime    = (long)(xt / HZ);
+    si->uptime    = (long)upsec;
     // Real values: PHYSTOP is the top of usable physical memory and the page
     // allocator knows exactly how much of it is still on the free list. These
     // used to be the constants 256MB/128MB, invented and always wrong.