SchOS/kernel/dev/irq.c
Nexoniarz bbc512a51c 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
2026-09-13 13:57:26 +02:00

302 lines
9 KiB
C

// Hardware interrupt registration. See include/irq.h for why this exists.
#include "types.h"
#include "defs.h"
#include "param.h"
#include "traps.h"
#include "spinlock.h"
#include "irq.h"
#include "x86.h"
struct irq_action {
irq_handler_t fn;
void *arg;
const char *name;
uint64 count;
};
static struct {
struct irq_action act[NCHAIN];
int n; // handlers installed; only ever grows during boot
int enabled;
int level_low;
uint64 unhandled;
} line[NIRQ];
// Guards registration against itself. The *dispatch* path deliberately does
// not take it: an interrupt handler that blocked on a lock held by whoever
// was registering would deadlock the CPU it fired on. Instead registration
// publishes an entry by writing all of its fields, issuing a barrier, and
// only then incrementing n -- so a concurrent dispatcher either does not see
// the entry at all or sees it complete.
//
// Removal is the harder direction, because compacting the array *does* move
// entries a dispatcher may be walking. irq_unregister therefore masks the
// line first and only re-routes it once the chain has been rewritten: with
// the line masked no new interrupt can arrive, and any handler already
// running holds no reference past its own return.
static struct spinlock irqlock;
void
irq_init(void)
{
initlock(&irqlock, "irq");
}
// IRQ_ERROR and IRQ_SPURIOUS are not IOAPIC pins -- they are local APIC
// vectors that xv6 numbered as though they were, so T_IRQ0+19 and T_IRQ0+31
// are already spoken for. A PCI device routed to pin 19 would deliver on the
// same vector as the LAPIC error interrupt. Refuse it here rather than let it
// be debugged later.
static int
reserved(int irq)
{
return irq == IRQ_ERROR || irq == IRQ_SPURIOUS || irq == IRQ_TIMER;
}
int
irq_register(int irq, irq_handler_t fn, void *arg, const char *name,
int level_low)
{
struct irq_action *a;
if(irq < 0 || irq >= NIRQ || fn == 0)
return -1;
if(reserved(irq)){
cprintf("irq_register: %s wants irq %d, which is reserved\n", name, irq);
return -1;
}
acquire(&irqlock);
if(line[irq].n >= NCHAIN){
release(&irqlock);
cprintf("irq_register: irq %d chain full, %s not attached\n", irq, name);
return -1;
}
// Two devices sharing a line must agree on how it is signalled; they
// physically cannot be wired both ways.
if(line[irq].n > 0 && line[irq].level_low != level_low){
release(&irqlock);
cprintf("irq_register: irq %d shared with conflicting trigger mode "
"(%s)\n", irq, name);
return -1;
}
a = &line[irq].act[line[irq].n];
a->fn = fn;
a->arg = arg;
a->name = name;
a->count = 0;
__sync_synchronize(); // publish the entry before it is reachable
line[irq].n++;
if(!line[irq].enabled){
line[irq].level_low = level_low;
ioapicroute(irq, 0, level_low);
line[irq].enabled = 1;
}
release(&irqlock);
return 0;
}
void
irq_unregister(int irq, irq_handler_t fn, void *arg)
{
int i, j;
if(irq < 0 || irq >= NIRQ)
return;
acquire(&irqlock);
for(i = 0; i < line[irq].n; i++){
if(line[irq].act[i].fn == fn && line[irq].act[i].arg == arg){
// Mask before touching the chain, always -- not only when this is the
// last handler. Compacting the array moves entries that a dispatcher on
// another CPU may be walking, so the line has to be quiet for the
// duration, and then brought back only if anything is left on it.
ioapicmask(irq);
line[irq].enabled = 0;
for(j = i; j + 1 < line[irq].n; j++)
line[irq].act[j] = line[irq].act[j+1];
line[irq].n--;
__sync_synchronize();
if(line[irq].n > 0){
ioapicroute(irq, 0, line[irq].level_low);
line[irq].enabled = 1;
}
break;
}
}
release(&irqlock);
}
// Notice a line that is firing far faster than any real device would, and say
// so once.
//
// A level-triggered PCI interrupt that nobody acknowledges re-fires the instant
// EOI is signalled, so the line runs at whatever rate the CPU can take traps --
// tens of thousands per second. That starves everything else on the machine,
// and it does so silently: the symptom appears wherever the missing CPU time
// hurts first, which is nowhere near the device at fault.
//
// It cost a long afternoon to find one of these. virtio-gpu shared IRQ 11 with
// the e1000 and registered no handler, so the line storm at ~72 kHz and took
// 83% of CPU0. What that looked like from userspace was a clock running seven
// times slow -- uptime, `time`, and ping's interval all wrong together, which
// reads as a timekeeping bug and sends you into the timer code. The timer was
// fine the whole time. This is the message that would have said so.
//
// The rate is measured against the TSC, deliberately: `ticks` is the first
// casualty of a storm, so a storm detector that counted ticks would go quiet
// exactly when it was needed.
#define STORM_SAMPLE 4096 // dispatches between rate checks
#define STORM_HZ 20000 // per second; no real device sustains this
static void
storm_check(int irq)
{
static uint64 sample_tsc[NIRQ];
static uint sample_n[NIRQ];
static uchar reported[NIRQ];
if(reported[irq] || !tsc_hz)
return;
if(++sample_n[irq] < STORM_SAMPLE)
return;
uint64 now = rdtsc(), prev = sample_tsc[irq];
sample_n[irq] = 0;
sample_tsc[irq] = now;
if(!prev)
return; // first sample: no interval to divide by
uint64 elapsed = now - prev;
if(elapsed == 0)
return;
uint64 rate = (uint64)STORM_SAMPLE * tsc_hz / elapsed;
if(rate < STORM_HZ)
return;
reported[irq] = 1;
cprintf("irq %d: %d interrupts/second -- a device on this line is not "
"acknowledging it.\n", irq, (int)rate);
for(int i = 0; i < line[irq].n; i++)
cprintf("irq %d: handler '%s' is attached\n", irq, line[irq].act[i].name);
if(line[irq].n == 0)
cprintf("irq %d: no handler is attached at all\n", irq);
}
void
irq_dispatch(int irq)
{
int i, n;
if(irq < 0 || irq >= NIRQ)
return;
n = line[irq].n;
if(n == 0){
line[irq].unhandled++;
storm_check(irq);
return;
}
// Every handler on a shared line is offered the interrupt; each one is
// responsible for recognising that its device is idle and returning.
for(i = 0; i < n; i++){
line[irq].act[i].count++;
line[irq].act[i].fn(line[irq].act[i].arg);
}
storm_check(irq);
}
// ---------------------------------------------------------------------------
// /proc/interrupts
// ---------------------------------------------------------------------------
static int
emit(char *buf, int cap, int off, const char *s)
{
while(*s && off < cap)
buf[off++] = *s++;
return off;
}
static int
emit_dec(char *buf, int cap, int off, uint64 v, int width)
{
char tmp[24];
int n = 0, i;
if(v == 0)
tmp[n++] = '0';
while(v > 0){
tmp[n++] = '0' + (v % 10);
v /= 10;
}
for(i = n; i < width && off < cap; i++)
buf[off++] = ' ';
while(n > 0 && off < cap)
buf[off++] = tmp[--n];
return off;
}
int
irq_info(char *buf, int cap)
{
int irq, i, off = 0;
for(irq = 0; irq < NIRQ; irq++){
if(line[irq].n == 0 && line[irq].unhandled == 0)
continue;
off = emit_dec(buf, cap, off, irq, 4);
off = emit(buf, cap, off, ": ");
for(i = 0; i < line[irq].n; i++){
off = emit_dec(buf, cap, off, line[irq].act[i].count, 10);
off = emit(buf, cap, off, " ");
off = emit(buf, cap, off,
line[irq].act[i].name ? line[irq].act[i].name : "?");
off = emit(buf, cap, off, i + 1 < line[irq].n ? ", " : "");
}
if(line[irq].n == 0)
off = emit(buf, cap, off, "(unhandled)");
if(line[irq].unhandled)
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;
}