DF-3715 / run.log
# Session 1 (pre-reset guest instance, fresh boot after vm.sh reset with-src): # build: cc -O2 ... -c callout_replica.c ; ld -r -o callout_replica.ko (build.log has full output) # load: kldload /root/kmod/callout_replica.ko -> KLD_OK # sysctl kern.emreplica.arm -> 0 (module live) # # Test 1 - arm both replica callouts (gc = try-based em_txgc_timer shape, # blk = blocking em_timer shape): root# sysctl kern.emreplica.arm=1 kern.emreplica.arm: 0 -> 0 # dmesg: callout_replica: loaded (hz=100) # replica: armed (gc every tick, blk every hz/4) # Test 2 - em_stop vs try-based gc timer (negative control for the # DF-3669/DF-3681 "re-arm survives callout_stop" premise): root# sysctl kern.emreplica.stop_gc=1 kern.emreplica.stop_gc: 0 -> 0 GC_TEST_RC=0 # dmesg: replica[gc]: stop while INPROG (fired=300 ran=300) # replica[gc]: callout_stop returned, pending=0 # replica[gc]: RESULT pending=0 (0 == re-arm did NOT survive callout_stop; # DF-3681 premise false for try-based handler here) # -> on this kern_timeout.c, callout_stop() unloads a racing self-re-arm: # the em_txgc_timer cannot survive em_stop(). # Test 3 - em_stop vs blocking timer (em_timer shape): AB-BA root# (sysctl kern.emreplica.stop_blk=1 > /root/blk.log 2>&1) & # ... 12+ seconds later, from a second session: root# cat /root/blk.log kern.emreplica.stop_blk: 0 # dmesg (final lines - note the absent "callout_stop returned (NO deadlock)"): # replica[blk]: handler BLOCKED on our serializer (fired=91 ran=90) - entering callout_stop() # replica[blk]: IF THIS IS THE LAST replica LINE, AB-BA DEADLOCK IS PROVEN # # wedged-thread evidence (second session, ps): root# ps -o pid,stat,wchan,command -ax | grep stop_blk 1051 D3 costp sysctl kern.emreplica.stop_blk=1 # # ^ D-state (uninterruptible) with wait-channel "costp" == the ssleep label # inside _callout_cancel_or_stop() sys/kern/kern_timeout.c:923 - the caller # is permanently stuck inside callout_stop() holding the serializer, while # the replica handler (softclock thread) is blocked in lwkt_serialize_enter() # on that very serializer. The sysctl thread never returns; the softclock # thread of the armed CPU never processes another callout. Guest was reset # afterwards (vm.sh reset with-src). # ---- RAW CAPTURES (pre-reset instance, session output) ---- # dmesg | grep replica | tail -4: callout_replica: loaded (hz=100) replica: armed (gc every tick, blk every hz/4) replica[gc]: stop while INPROG (fired=300 ran=300) replica[gc]: callout_stop returned, pending=0 replica[gc]: RESULT pending=0 (0 == re-arm did NOT survive callout_stop; DF-3681 premise false for try-based handler here) replica[blk]: handler BLOCKED on our serializer (fired=91 ran=90) - entering callout_stop() replica[blk]: IF THIS IS THE LAST replica LINE, AB-BA DEADLOCK IS PROVEN # ^ "replica[blk]: callout_stop returned (NO deadlock)" NEVER printed. # ps -o pid,stat,wchan,command -ax | grep stop_blk (second session, guest wedged): 1051 D3 costp sysctl kern.emreplica.stop_blk=1 # ^ D3 = uninterruptible; wchan "costp" = ssleep label in # sys/kern/kern_timeout.c:923 inside _callout_cancel_or_stop() -> the # caller is permanently stuck INSIDE callout_stop() holding the replica # serializer while the em_timer-shaped callback is blocked acquiring it. # softclock threads at capture time (one of them is the wedged callback): root -1 0.0 0.0 0 0 ?? B0..B5 (softclock 0..5 present, 6 cpus)