diff --git a/include/fsstat.h b/include/fsstat.h index 04bb756..aa252f2 100644 --- a/include/fsstat.h +++ b/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; diff --git a/kernel/dev/bio.c b/kernel/dev/bio.c index 08b49be..924d1fe 100644 --- a/kernel/dev/bio.c +++ b/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; diff --git a/kernel/dev/procfs.c b/kernel/dev/procfs.c index 18039b9..cf4ac7f 100644 --- a/kernel/dev/procfs.c +++ b/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"); } diff --git a/kernel/fs/file.c b/kernel/fs/file.c index 5eb2dca..0ce123a 100644 --- a/kernel/fs/file.c +++ b/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) diff --git a/kernel/fs/fs.c b/kernel/fs/fs.c index 479a1d9..cf374e1 100644 --- a/kernel/fs/fs.c +++ b/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); }