diff --git a/docs/architecture/kernel.md b/docs/architecture/kernel.md index 2f64b84..4af344e 100644 --- a/docs/architecture/kernel.md +++ b/docs/architecture/kernel.md @@ -237,6 +237,14 @@ allocation over 8 MB mapped straight into a neighbouring live mapping. ## What it does not do +- **`ru_stime` is effectively always zero.** CPU time is sampled at the timer + tick and split on the interrupted privilege level, but `MSR_SFMASK` includes + `FL_IF`, so `SYSCALL` clears interrupts and no tick can land while a process + is inside a syscall. User time is real and discriminates properly — a busy + loop reports 97%, `sleep 2` reports 0% — but kernel time needs TSC deltas + closed and reopened around every `sched()`, which is scheduler accounting + rather than sampling, and is not written. + - **No slab allocator.** One page at a time, and every subsystem's fixed-size table is a consequence. This is the single change that would most improve the rest of the kernel. diff --git a/docs/plan/1.0.md b/docs/plan/1.0.md index 203b513..d6491a1 100644 --- a/docs/plan/1.0.md +++ b/docs/plan/1.0.md @@ -215,12 +215,33 @@ right then. cross-compile cache. Autoconf's own default for that check is `yes`; omitting the line would have been right. See [../history/kernel.md](../history/kernel.md), section 7. -- [ ] **`getrusage` does not distinguish `RUSAGE_CHILDREN`** from `RUSAGE_SELF`. -- [ ] **`/proc//exe` is a regular file, not a symlink**, so `readlink()` - fails and `ps -o comm` prints `[init]`. Symlinks themselves now work — - `open()` and `stat()` follow them, which they never did — so what is left - is procfs growing a symlink node type, not symlink support. -- [ ] **OVMF memory reporting**, if the region-list fix did not fully close it. +- [x] ~~**`getrusage` does not distinguish `RUSAGE_CHILDREN`** from + `RUSAGE_SELF`.~~ It did not distinguish anything: it ignored `who` and + reported the machine's *uptime* as the caller's user time, so every + process of every age answered with the same number. Per-process CPU time + is sampled at the timer tick now, children's time is rolled up on reap, + and `wait4()`'s fourth argument — a `struct rusage *` that was read off + the stack and thrown away — is filled. That last one is why zsh's `time` + reported `16777216.01s user` for everything: 2^24 seconds is + uninitialised memory, and it never varied because it was never written. + `time` now says 97% cpu for a busy loop and 0% for `sleep 2`. + `ru_stime` is a known zero; see + [../architecture/kernel.md](../architecture/kernel.md). +- [x] ~~**`/proc//exe` is a regular file, not a symlink.**~~ + `lrwxrwxrwx ... exe -> /bin/schinit`, and `readlink` returns it. It also + needed a real `st_size`, which every other procfs file deliberately + reports as zero: `readlink(2)` bounds its copy by it, so a symlink of + size 0 resolves to the empty string — which looks like it worked and is + worse than the regular file was. +- [x] ~~**OVMF memory reporting.**~~ The region-list fix did close it. 1 GB + reports 1017 MB usable, 2 GB reports 2041 MB, which is the right shape: + the firmware keeps about 7 MB either way. +- [x] ~~**`ps` printed a header and nothing else.**~~ Found while checking the + `exe` fix. `ps` with no arguments shows only processes on *this* + terminal, and `/proc//stat` hardcoded `tty_nr` to 0, so nothing + could ever match — `ps -e` always worked, which is what hid it. Fields + 14-17 (utime/stime/cutime/cstime) were hardcoded zero too, so `TIME` was + `00:00:00` for everything however long it had run. **Work already done and not connected:** diff --git a/include/defs.h b/include/defs.h index 889d683..5dcb799 100644 --- a/include/defs.h +++ b/include/defs.h @@ -536,7 +536,7 @@ void scheduler(void) __attribute__((noreturn)); void sched(void); void sleep(void*, struct spinlock*); int wait(void); -int waitpid(int, int*, int); +int waitpid(int, int*, int, uint64*, uint64*); void wakeup(void*); void yield(void); void sinit(void); diff --git a/include/proc.h b/include/proc.h index 7a5ffdf..79edd50 100644 --- a/include/proc.h +++ b/include/proc.h @@ -166,6 +166,9 @@ struct procinfo { int state; // enum procstate uint64 sz; int killed; + int ctty; // controlling terminal, 1-based; 0 = none + uint64 utime, stime; // CPU time in ticks, this process + uint64 cutime, cstime; // and its reaped children char name[16]; char exe[64]; // full path, for /proc//exe }; @@ -213,6 +216,16 @@ struct proc { struct ioport_range ioport[NIOPORT]; int nioport; + // CPU time, in timer ticks, charged by trap() at each tick to whoever was + // running. utime/stime split on the interrupted privilege level -- cs & 3 -- + // which is the only information the tick carries about what it interrupted. + // + // cutime/cstime accumulate *reaped* children, and only reaped ones: that is + // what RUSAGE_CHILDREN means, and it is why they are rolled up in wait() + // rather than in exit(). A child still running has not contributed yet. + uint64 utime, stime; + uint64 cutime, cstime; + uint64 signal_mask; uint64 pending_signals; int alarm_ticks; diff --git a/kernel/arch/x86_64/trap.c b/kernel/arch/x86_64/trap.c index 98a28e2..6622b49 100644 --- a/kernel/arch/x86_64/trap.c +++ b/kernel/arch/x86_64/trap.c @@ -90,6 +90,26 @@ trap(struct trapframe *tf) wakeup(&ticks); release(&tickslock); } + // Charge the tick to whoever it interrupted. Every CPU does this, not just + // CPU 0 -- the global clock advances once, but the *work* happened on + // whichever processor was running that process. + // + // The split is by the interrupted privilege level, because that is the + // only thing the tick knows about what it interrupted. It is sampling, not + // measurement, which is what Linux does too and why these are ticks rather + // than microseconds. + // + // **stime is therefore almost always zero here, and that is structural.** + // MSR_SFMASK includes FL_IF (see syscallinit), so SYSCALL clears interrupts + // and nothing re-enables them for the duration -- a timer tick cannot land + // while a process is executing a syscall. The only ticks that ever reach + // the `else` are ones that arrive in a nested trap. Charging real system + // time needs TSC deltas closed and reopened around every sched(), which is + // scheduler accounting rather than sampling, and is not written. + if(myproc()){ + if((tf->cs & 3) == DPL_USER) myproc()->utime++; + else myproc()->stime++; + } // Debug registers are per-CPU, and there is no general IPI here, so this // is how a watchpoint armed on one processor reaches the others: each // notices the table's generation has moved and reloads. One comparison diff --git a/kernel/fs/procfs.c b/kernel/fs/procfs.c index 67f5e5a..7cd5f22 100644 --- a/kernel/fs/procfs.c +++ b/kernel/fs/procfs.c @@ -175,15 +175,29 @@ gen_pid_stat(struct sb *s, const struct procinfo *pi) sbputi(s, pi->pgid); // 5 pgrp sbputc(s, ' '); sbputi(s, pi->sid); // 6 session - sbputs(s, " 0 -1 0"); // 7 tty_nr, 8 tpgid, 9 flags + // 7 tty_nr. Linux's dev_t: major 12 bits above minor's 8. /dev/ttyN is + // major 1, minor 10+N in devfs, so a process whose ctty is 1 reports + // (1 << 8) | 11. This was hardcoded 0, and that is why plain `ps` printed a + // header and nothing else: ps with no arguments shows only the processes on + // *this* terminal, and nothing could ever match. `ps -e` always worked. + sbputc(s, ' '); + sbputi(s, pi->ctty ? ((1 << 8) | (10 + pi->ctty)) : 0); + sbputs(s, " -1 0"); // 8 tpgid, 9 flags - // 10..17: minflt cminflt majflt cmajflt utime stime cutime cstime. - // No per-process accounting yet, so these are honestly zero rather than - // invented -- a fabricated CPU time is worse than none, because top would - // draw a plausible graph of a number nobody measured. - for (i = 0; i < 8; i++) + // 10..13: minflt cminflt majflt cmajflt. There is no fault accounting, and + // a fabricated number is worse than none -- top would draw a plausible graph + // of something nobody measured. + for (i = 0; i < 4; i++) sbputs(s, " 0"); + // 14..17: utime stime cutime cstime, in ticks, which is the unit the field + // is defined in. These were zero too, which is why `ps` and `top` showed + // 00:00:00 for everything no matter how long it had been running. + sbputc(s, ' '); sbputi(s, (int64)pi->utime); + sbputc(s, ' '); sbputi(s, (int64)pi->stime); + sbputc(s, ' '); sbputi(s, (int64)pi->cutime); + sbputc(s, ' '); sbputi(s, (int64)pi->cstime); + sbputs(s, " 20 0 1 0 0 "); // priority nice num_threads itrealvalue starttime sbputi(s, (int64)pi->sz); // 23 vsize, in bytes sbputc(s, ' '); @@ -278,6 +292,27 @@ procfs_iload(struct inode *ip) return; } + // /proc//exe is a symlink, as it is on Linux. + // + // It was a regular file holding the path as text, which reads the same from + // `cat` and is wrong to everything that matters: readlink() refused it with + // EINVAL, and `ps -o comm` -- which readlinks it -- fell back to the process + // name in brackets and printed `[init]` for everything. + // + // This one file has to report a real size, and every other procfs file + // deliberately reports zero. readlink(2) bounds its copy by ip->size, so a + // symlink whose size is 0 resolves to the empty string -- which is worse + // than the regular file was, because it looks like it worked. Generating it + // here costs one small render per stat() of one file. + if (!INO_IS_GLOBAL(ino) && INO_FILE(ino) == PF_EXE) { + char path[64]; + int len = gen_file(ino, path, sizeof(path)); + ip->type = T_SYMLINK; + ip->size = len > 0 ? (uint64)len : 0; + ip->nlink = 1; + return; + } + ip->type = T_FILE; // Size is reported as zero. // diff --git a/kernel/proc/proc.c b/kernel/proc/proc.c index fdfd974..3d91ad6 100644 --- a/kernel/proc/proc.c +++ b/kernel/proc/proc.c @@ -310,6 +310,7 @@ found: memset(p->sig_handler, 0, sizeof(p->sig_handler)); memset(p->sig_restorer, 0, sizeof(p->sig_restorer)); p->pending_signals = 0; + p->utime = p->stime = p->cutime = p->cstime = 0; p->signal_mask = 0; p->in_signal = 0; p->sigsusp_oldmask = 0; @@ -659,7 +660,7 @@ exit(int status) int wait(void) { - return waitpid(-1, 0, 0); + return waitpid(-1, 0, 0, 0, 0); } // waitpid(2)/wait4(2) proper: a specific pid (-1 = any child, matching @@ -676,7 +677,7 @@ wait(void) // this kernel can't wake for a real SIGCHLD (no signal delivery), so it // silently retried forever: a real, low-CPU hang with no error printed. int -waitpid(int pid, int *status, int options) +waitpid(int pid, int *status, int options, uint64 *ut, uint64 *st) { struct proc *p; int havekids; @@ -699,6 +700,16 @@ waitpid(int pid, int *status, int options) if(p->state == ZOMBIE){ int rpid = p->pid; int rstatus = p->xstate; // copy out before the slot is recycled + // RUSAGE_CHILDREN: the child's own time *and* whatever it had already + // reaped, which is what makes the total transitive down a whole tree + // of processes rather than one generation deep. + myproc()->cutime += p->utime + p->cutime; + myproc()->cstime += p->stime + p->cstime; + // wait4()'s fourth argument wants the *child's* usage, not the + // parent's running total, so it has to be read here -- three lines + // further down the slot is UNUSED and these are zero. + if (ut) *ut = p->utime + p->cutime; + if (st) *st = p->stime + p->cstime; p->kstack = 0; // the slot keeps its stack; see kstacks[] // Give back anything shared before freevm() decides it owns the // pages. See proc_release_shared() in kernel/sys/sys_mem.c. @@ -1317,6 +1328,11 @@ proc_snapshot(int idx, struct procinfo *out) out->state = p->state; out->sz = p->sz; out->killed = p->killed; + out->ctty = p->ctty; + out->utime = p->utime; + out->stime = p->stime; + out->cutime = p->cutime; + out->cstime = p->cstime; safestrcpy(out->name, p->name, sizeof(out->name)); safestrcpy(out->exe, p->exe, sizeof(out->exe)); release(&ptable.lock); diff --git a/kernel/sys/sys_proc.c b/kernel/sys/sys_proc.c index dc20e21..92ee72b 100644 --- a/kernel/sys/sys_proc.c +++ b/kernel/sys/sys_proc.c @@ -52,6 +52,9 @@ sys_kill(void) return sigsend(pid, sig) < 0 ? -ESRCH : 0; } +// Defined with getrusage() further down; wait4() needs it too. +static void rusage_fill(struct rusage *ru, uint64 ut, uint64 st); + addr_t sys_getpid(void) { return myproc()->pid; } addr_t sys_getppid(void) { return myproc()->parent ? myproc()->parent->pid : 1; } addr_t sys_gettid(void) { return myproc()->pid; } // single-threaded: tid == pid @@ -67,26 +70,45 @@ sys_waitpid(void) if (argint(0, &pid) < 0 || argaddr(1, &statusp) < 0 || argint(2, &options) < 0) return -1; int status; - int wpid = waitpid(pid, &status, options); + int wpid = waitpid(pid, &status, options, 0, 0); if (wpid > 0 && statusp) put_user(status, statusp); return wpid; } +// wait4(2) -- and its fourth argument is a `struct rusage *`. +// +// It was read off the stack and thrown away. So a caller that passed a buffer +// got it back untouched, and read whatever had been there before: zsh's +// `time` reported 16777216.01s user for every command, which is 2^24 seconds, +// which is uninitialised memory that happened to look like a number. The +// figure did not vary with the workload because it was never written. +// +// wait3() is the same syscall with pid -1, and it is the one shells actually +// call, so this is the path every `time` goes through. addr_t sys_wait4(void) { int pid, options; - addr_t statusp; + addr_t statusp, rup; + uint64 ut = 0, st = 0; + argint(0, &pid); argaddr(1, &statusp); argint(2, &options); + argaddr(3, &rup); + int status; - int wpid = waitpid(pid, &status, options); + int wpid = waitpid(pid, &status, options, &ut, &st); if (wpid <= 0) return wpid; if (statusp) put_user(status, statusp); + if (rup) { + struct rusage *ru = (struct rusage*)user_ptr(rup, sizeof(*ru)); + if (ru) + rusage_fill(ru, ut, st); + } return wpid; } @@ -385,27 +407,65 @@ addr_t sys_pause(void) return -EINTR; } +// getrusage(2). +// +// This used to ignore `who` entirely and report the machine's *uptime* as the +// caller's user time. Every process of every age answered with the same +// number, and RUSAGE_CHILDREN answered with it too -- so a shell timing a +// command got the age of the machine, and `time` on a pipeline was +// meaningless rather than merely imprecise. +// +// Ticks, converted at the boundary. The kernel counts whole timer ticks +// because that is what the sampling gives it; microseconds are what the +// interface asks for, so the multiply happens here rather than pretending to a +// resolution the counter does not have. +static void +rusage_fill(struct rusage *ru, uint64 ut, uint64 st) +{ + memset(ru, 0, sizeof(*ru)); + ru->ru_utime.tv_sec = (long)(ut / HZ); + ru->ru_utime.tv_usec = (long)((ut % HZ) * (1000000 / HZ)); + ru->ru_stime.tv_sec = (long)(st / HZ); + ru->ru_stime.tv_usec = (long)((st % HZ) * (1000000 / HZ)); +} + addr_t sys_getrusage(void) { int who; struct rusage *ru; argint(0, &who); - if (argptr(1, (char**)&ru, sizeof(*ru)) < 0) return -1; - memset(ru, 0, sizeof(*ru)); - uint64 rsec, rusec; - monotonic(&rsec, &rusec); - ru->ru_utime.tv_sec = (long)rsec; - ru->ru_utime.tv_usec = (long)rusec; - return 0; + if (argptr(1, (char**)&ru, sizeof(*ru)) < 0) return -EFAULT; + + switch (who) { + case RUSAGE_SELF: + rusage_fill(ru, myproc()->utime, myproc()->stime); + return 0; + case RUSAGE_CHILDREN: + rusage_fill(ru, myproc()->cutime, myproc()->cstime); + return 0; + default: + // RUSAGE_THREAD is -1 and would be RUSAGE_SELF here, since a process + // has exactly one thread. It is refused rather than aliased: answering + // it would imply threads exist. + return -EINVAL; + } } addr_t sys_times(void) { addr_t bufaddr; argaddr(0, &bufaddr); + // The tms fields are in clock ticks, which is what the kernel counts, so + // this one needs no conversion -- USER_HZ and HZ are both 100. They used + // to be memset to zero, which is why `times()` agreed with nothing. if (bufaddr) { struct tms *t = (struct tms*)user_ptr(bufaddr, sizeof(*t)); - if (t) memset(t, 0, sizeof(*t)); + if (t) { + t->tms_utime = (long)myproc()->utime; + t->tms_stime = (long)myproc()->stime; + t->tms_cutime = (long)myproc()->cutime; + t->tms_cstime = (long)myproc()->cstime; + } } // USER_HZ units, measured from the TSC. //