fs: timestamps come from the clock, and /proc/fsstat says how full the tables are

Everything created after boot was stamped 1970. know() in SchFS and now_sec() in
the v1 filesystem both returned uptime(), under comments saying the kernel had no
wall clock -- which stopped being true when time_init() started reading the RTC.
The comments outlived the condition they described.

Two errors, and the second is the less obvious: uptime() counts 10 ms *ticks* and
they were being used as *seconds*, so a node created 0.6 s into boot read back as
00:01:00 and the clocks ran a hundred times too fast. Both now go through
wallclock(), which exists precisely so nothing can disagree with gettimeofday
about the time. Confirmed against the RTC line from the same boot.

The occupancy counters are the instrumentation docs/plan/roadmap.md asked for
while hunting the ls -lR hang: inode, file and pinned-buffer counts with a
high-water mark each, maintained at the 0->1 and 1->0 transitions rather than by
scanning, so they cost one increment on a path that already holds the table's
lock.

The peaks are the diagnostic. A live count only describes the moment you looked,
and a reference leak is invisible in it right up until the table is full -- at
which point iget() panics and filealloc() returns 0, which is where the trail
used to go cold.

What they measured: across ten iterations of ls -lR with writes interleaved, 33
execs and 13378 tree descents, inode_peak stayed at 9/200, file_peak at 9/512 and
buf_pinned_peak at 1/256, with the SchFS bracket unlocked throughout. That
eliminates the roadmap's own hypothesis -- "a lock or reference-count leak
somewhere in the *at() paths" -- and the hang did not reproduce. It is very
likely fixed in passing by the *at() dirfd rewrite, the getdents cookie rewrite
or SchFS becoming the root, all of which landed after it was reported.

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

include/fsstat.h

@@ -41,6 +41,31 @@ struct fsstat {
   // exec(2), which on this system means reading an 800 KB multicall binary.
   uint64 exec_calls;
   uint64 exec_cycles;
+
+  // ---------------------------------------------------------------------
+  // Table occupancy, for finding leaks.
+  //
+  // `_used` is the live count; `_peak` is the high-water mark, and the peak is
+  // the number that answers the question. A live count only tells you about the
+  // moment you looked, and a reference leak is invisible in it right up until
+  // the table is full -- at which point iget() panics and filealloc() returns
+  // 0, which is where the trail goes cold.
+  //
+  // Maintained at the 0->1 and 1->0 transitions rather than by scanning, so
+  // they cost one increment on a path that already holds the relevant lock.
+  //
+  // What to watch: run a long ls-heavy session and read /proc/fsstat between
+  // commands. A peak that climbs and never comes back down after the commands
+  // finish is the leak, and which of the three it is says where to look.
+  uint64 inode_used,  inode_peak;
+  uint64 file_used,   file_peak;
+  uint64 buf_pinned,  buf_pinned_peak;
 };
 
+// Bump a (used, peak) pair. Callers hold the table's own lock already.
+#define FSSTAT_TAKE(used, peak) \
+    do { if (++(used) > (peak)) (peak) = (used); } while (0)
+#define FSSTAT_DROP(used)       \
+    do { if ((used) > 0) (used)--; } while (0)
+
 extern struct fsstat fsstat;

kernel/dev/bio.c

@@ -116,7 +116,8 @@ bget(uint dev, uint64 blockno)
   // Is the block already cached?
   for(b = bcache.head.next; b != &bcache.head; b = b->next){
     if(b->dev == dev && b->blockno == blockno){
-      b->refcnt++;
+      if(b->refcnt++ == 0)
+        FSSTAT_TAKE(fsstat.buf_pinned, fsstat.buf_pinned_peak);
       release(&bcache.lock);
       acquiresleep(&b->lock);
       return b;
@@ -132,6 +133,7 @@ bget(uint dev, uint64 blockno)
       b->blockno = blockno;
       b->flags = 0;
       b->refcnt = 1;
+      FSSTAT_TAKE(fsstat.buf_pinned, fsstat.buf_pinned_peak);
       release(&bcache.lock);
       acquiresleep(&b->lock);
       return b;
@@ -154,6 +156,7 @@ bget(uint dev, uint64 blockno)
     if(b->refcnt == 0){
       fsstat.bget_evict_dirty++;
       b->refcnt++;              // claim it, so nobody else recycles it either
+      FSSTAT_TAKE(fsstat.buf_pinned, fsstat.buf_pinned_peak);
       release(&bcache.lock);
       acquiresleep(&b->lock);
 
@@ -167,6 +170,7 @@ bget(uint dev, uint64 blockno)
       acquire(&bcache.lock);
       if(b->refcnt != 1){
         b->refcnt--;
+        FSSTAT_DROP(fsstat.buf_pinned);
         release(&bcache.lock);
         releasesleep(&b->lock);
         goto retry;
@@ -273,6 +277,7 @@ brelse(struct buf *b)
   acquire(&bcache.lock);
   b->refcnt--;
   if (b->refcnt == 0) {
+    FSSTAT_DROP(fsstat.buf_pinned);
     // no one is waiting for it.
     b->next->prev = b->prev;
     b->prev->next = b->next;

kernel/dev/procfs.c

@@ -33,6 +33,7 @@
 #include "uaccess.h"
 #include "errno.h"
 #include "fsstat.h"
+#include "schfs.h"
 
 #define PROC_BUFSZ 2048
 
@@ -199,7 +200,7 @@ gen_cpuinfo(struct sbuf *sb)
   if (ncpu_online < ncpu) {
     sb_kv(sb, "cpus present\t: ", ncpu, 0);
     sb_puts(sb, "note\t\t: additional processors are enumerated but not "
-                "started; see docs/roadmap.md\n");
+                "started; see docs/plan/roadmap.md\n");
   }
 }
 
@@ -338,6 +339,33 @@ gen_fsstat(struct sbuf *sb)
   sb_puts(sb, "\ndescents         "); sb_putu(sb, fsstat.descents);
   sb_puts(sb, "\nexec_calls       "); sb_putu(sb, fsstat.exec_calls);
   sb_puts(sb, "\nexec_kcycles     "); sb_putu(sb, fsstat.exec_cycles / 1000);
+
+  // Occupancy. The peaks are the diagnostic: a peak that climbs across a
+  // session and never falls back after the commands finish is a reference
+  // leak, and which line it is on says where to look.
+  sb_puts(sb, "\ninode_used       "); sb_putu(sb, fsstat.inode_used);
+  sb_puts(sb, "\ninode_peak       "); sb_putu(sb, fsstat.inode_peak);
+  sb_puts(sb, " / "); sb_putu(sb, NINODE);
+  sb_puts(sb, "\nfile_used        "); sb_putu(sb, fsstat.file_used);
+  sb_puts(sb, "\nfile_peak        "); sb_putu(sb, fsstat.file_peak);
+  sb_puts(sb, " / "); sb_putu(sb, NFILE);
+  sb_puts(sb, "\nbuf_pinned       "); sb_putu(sb, fsstat.buf_pinned);
+  sb_puts(sb, "\nbuf_pinned_peak  "); sb_putu(sb, fsstat.buf_pinned_peak);
+  sb_puts(sb, " / "); sb_putu(sb, NBUF);
+
+  // The SchFS bracket. `locked 1` with `owner 0` is the wedge: the volume lock
+  // is held by something that is not in a transaction, so nothing will ever
+  // release it and every later filesystem call sleeps in acquiresleep.
+  for (int i = 0; i < SCHFS_VOL_SLOTS; i++) {
+    int locked, owner, depth;
+    schfs_lockinfo(i, &locked, &owner, &depth);
+    if (locked < 0)
+      continue;
+    sb_puts(sb, "\nschfs"); sb_putu(sb, (uint64)i);
+    sb_puts(sb, "  locked "); sb_putu(sb, (uint64)locked);
+    sb_puts(sb, "  tx_owner_pid "); sb_putu(sb, (uint64)owner);
+    sb_puts(sb, "  tx_depth "); sb_putu(sb, (uint64)depth);
+  }
   sb_puts(sb, "\n");
 }
 

kernel/fs/file.c

@@ -6,6 +6,7 @@
 #include "spinlock.h"
 #include "sleeplock.h"
 #include "file.h"
+#include "fsstat.h"
 #include "posix.h"
 #include "errno.h"
 
@@ -31,6 +32,7 @@ filealloc(void)
   for(f = ftable.file; f < ftable.file + NFILE; f++){
     if(f->ref == 0){
       f->ref = 1;
+      FSSTAT_TAKE(fsstat.file_used, fsstat.file_peak);   // 0 -> 1
       // Cleared here rather than left to the caller: every creator sets
       // readable/writable/off, but only open() sets nonblock, so a struct file
       // recycled from a non-blocking device would hand its flag to the next
@@ -70,6 +72,7 @@ fileclose(struct file *f)
   ff = *f;
   f->ref = 0;
   f->type = FD_NONE;
+  FSSTAT_DROP(fsstat.file_used);                          // 1 -> 0
   release(&ftable.lock);
 
   if(ff.type == FD_PIPE)

kernel/fs/fs.c

@@ -41,6 +41,7 @@
 #include "sleeplock.h"
 #include "fs.h"
 #include "buf.h"
+#include "fsstat.h"
 #include "file.h"
 
 extern uint uptime(void);
@@ -356,12 +357,20 @@ ifree(int dev, int inum)
 // Timestamp helper
 // ===========================================================================
 
-// Returns the current time in seconds.  uptime() is assumed to return ticks;
-// replace with a real wall-clock source if your kernel has one.
+// Returns the current time in seconds since the epoch.
+//
+// It used to return uptime() under a comment saying to replace it with a real
+// wall-clock source "if your kernel has one". It has one -- see wallclock() in
+// kernel/core/time.c -- and the same fix went into SchFS's know(), where the
+// symptom was visible: every file created after boot was stamped 1970, and the
+// timestamps advanced a hundred times too fast because uptime() counts 10 ms
+// ticks and they were being read as seconds.
 static uint
 now_sec(void)
 {
-  return (uint)uptime();
+  uint64 sec;
+  wallclock(&sec, 0);
+  return (uint)sec;
 }
 
 // ===========================================================================
@@ -450,6 +459,7 @@ iget(uint dev, uint64 inum)
   ip->dev   = dev;
   ip->inum  = inum;
   ip->ref   = 1;
+  FSSTAT_TAKE(fsstat.inode_used, fsstat.inode_peak);   // 0 -> 1
   ip->valid = 0;
   ip->ops   = ops_for(dev);
   release(&itable.lock);
@@ -534,7 +544,8 @@ iput(struct inode *ip)
     acquire(&itable.lock);
   }
 
-  ip->ref--;
+  if (--ip->ref == 0)
+    FSSTAT_DROP(fsstat.inode_used);
   release(&itable.lock);
 }