DF-2712 / df2712_rig.c
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 | /* * df2712_rig.c -- kernel-compiled hard-IRQ watchdog rig for DF-2712 * verification (usched_bsd4 kick-under-spinlock liveloop wedge). * * Compiled INTO the guest kernel (runtime kldload GPFs on this guest). * The rig does NOT modify any scheduler code path; it only observes: * * - one 1 Hz periodic systimer per cpu, armed at boot (mirrors * initclocks_usched's lwkt_setcpu_self loop, kern_clock.c:465). * Each tick runs in HARD-INTERRUPT context on its cpu and: * . increments beats[cpu] (cpu alive & taking timers) * . samples this cpu's OUTGOING ipiq FIFO depths (per-target * FIFOs gd->gd_ipiq[n], the exact FIFOs whose >128 fill makes * lwkt_send_ipiq3 liveloop, lwkt_ipiq.c:225/232/244) * . samples gd_spinlocks / td_critcount * * - cpu0's tick additionally watches every cpu's beats. A cpu that * stays inside a critical section (e.g. spinning on bsd4_spin in * _spin_lock_contested, or livelooping in lwkt_send_ipiq3 which * crit_enter()s at lwkt_ipiq.c:197) cannot deliver its systimers, * so its beats freeze. >=5 consecutive frozen beats on any cpu * prints "DF2712-WEDGE-MARKER" -- that is the wedge marker. * * sysctls (root): * debug.df2712.verbose 0/1 heartbeat snapshot lines every ivl ticks * debug.df2712.ivl n heartbeat interval in ticks (default 5) * debug.df2712.dump (write anything) print full snapshot once * * Racy cross-cpu reads are diagnostic-only (values are frozen anyway * in the wedge state we are capturing). */ #include <sys/param.h> #include <sys/kernel.h> #include <sys/systm.h> #include <sys/sysctl.h> #include <sys/globaldata.h> #include <sys/systimer.h> #include <sys/thread.h> #include <machine/smp.h> static struct systimer df2712_wd[MAXCPU]; static volatile long df2712_beats[MAXCPU]; static volatile int df2712_maxd[MAXCPU]; /* max outgoing FIFO depth */ static volatile int df2712_spin[MAXCPU]; /* last gd_spinlocks sample */ static volatile int df2712_crit[MAXCPU]; /* last td_critcount sample */ static long df2712_lastb[MAXCPU]; /* cpu0-side frozen detection */ static int df2712_frozen[MAXCPU]; static long df2712_wmark_cnt; static int df2712_verbose; static int df2712_ivl = 5; static int df2712_armed; static int df2712_dump_sysctl(SYSCTL_HANDLER_ARGS); SYSCTL_NODE(_debug, OID_AUTO, df2712, CTLFLAG_RW, 0, "DF-2712 watchdog rig"); SYSCTL_INT(_debug_df2712, OID_AUTO, verbose, CTLFLAG_RW, &df2712_verbose, 0, "print heartbeat snapshots"); SYSCTL_INT(_debug_df2712, OID_AUTO, ivl, CTLFLAG_RW, &df2712_ivl, 0, "heartbeat interval in ticks"); SYSCTL_INT(_debug_df2712, OID_AUTO, armed, CTLFLAG_RD, &df2712_armed, 0, "watchdog armed"); SYSCTL_LONG(_debug_df2712, OID_AUTO, wmarks, CTLFLAG_RD, &df2712_wmark_cnt, 0, "wedge markers printed"); SYSCTL_PROC(_debug_df2712, OID_AUTO, dump, CTLTYPE_INT | CTLFLAG_RW, NULL, 0, df2712_dump_sysctl, "I", "write to print a full snapshot"); static void df2712_print_snap(const char *tag) { long beats[MAXCPU]; int spin[MAXCPU], crit[MAXCPU], maxd[MAXCPU]; int c; for (c = 0; c < ncpus; ++c) { beats[c] = df2712_beats[c]; spin[c] = df2712_spin[c]; crit[c] = df2712_crit[c]; maxd[c] = df2712_maxd[c]; } kprintf("[df2712] %s t=%ld:", tag, (long)df2712_beats[0]); for (c = 0; c < ncpus; ++c) { kprintf(" c%d:b%ld,s%d,k%d,d%d", c, beats[c], spin[c], crit[c], maxd[c]); } kprintf("\n"); } /* * cpu0 only: frozen-beat detection across all cpus. */ static void df2712_master_tick(void) { int c, wedged = 0; for (c = 0; c < ncpus; ++c) { long b = df2712_beats[c]; if (b == df2712_lastb[c]) ++df2712_frozen[c]; else df2712_frozen[c] = 0; df2712_lastb[c] = b; if (df2712_frozen[c] >= 5) wedged = 1; } if (wedged && (df2712_beats[0] % 5) == 0) { ++df2712_wmark_cnt; df2712_print_snap("DF2712-WEDGE-MARKER (cpu systimer frozen >=5s)"); } else if (df2712_verbose && (df2712_beats[0] % df2712_ivl) == 0) { df2712_print_snap("hb"); } } /* * Per-cpu 1 Hz hard-interrupt tick. */ static void df2712_tick(systimer_t st __unused, int in_ipi __unused, struct intrframe *frame __unused) { globaldata_t gd = mycpu; int cpu = gd->gd_cpuid; int t, d, maxd = 0; for (t = 0; t < ncpus; ++t) { d = gd->gd_ipiq[t].ip_windex - gd->gd_ipiq[t].ip_rindex; if (d > maxd) maxd = d; } if (maxd > df2712_maxd[cpu]) df2712_maxd[cpu] = maxd; df2712_spin[cpu] = gd->gd_spinlocks; df2712_crit[cpu] = gd->gd_curthread->td_critcount; ++df2712_beats[cpu]; if (cpu == 0) df2712_master_tick(); } static int df2712_dump_sysctl(SYSCTL_HANDLER_ARGS) { int error, v = 0; error = sysctl_handle_int(oidp, &v, 0, req); if (error || req->newptr == NULL) return (error); df2712_print_snap("dump"); return (0); } static void df2712_init(void *x __unused) { struct globaldata *ogd = mycpu; int n; for (n = 0; n < ncpus; ++n) { lwkt_setcpu_self(globaldata_find(n)); systimer_init_periodic(&df2712_wd[n], df2712_tick, NULL, 1); } lwkt_setcpu_self(ogd); df2712_armed = 1; kprintf("[df2712] hard-IRQ watchdog armed on %d cpus (1 Hz)\n", ncpus); } SYSINIT(df2712wd, SI_BOOT2_USCHED, SI_ORDER_ANY, df2712_init, NULL); |