DF-3717 / run.log
DF-3717 run transcript (DragonFly 6.5-DEVELOPMENT x86_64, hz=100, guest "dfbsd")
======================================================================
Sources: serial console via `vm.sh log`, live sessions via `vm.sh run_root`.
Full command sequences in run.sh. Two earlier harness iterations (v1/v2)
are included at the end for the honesty record.
======================================================================
--- presence probe (run_root) ---------------------------------------
DragonFly dfbsd 6.5-DEVELOPMENT DragonFly 6.5-DEVELOPMENT #0: Thu Jul 2 06:02:54 UTC 2026 root@dfbsd:/usr/obj/usr/src/sys/X86_64_GENERIC x86_64
NO_MYRICOM_PCI
MXGE_NOT_LOADED
/boot/kernel/if_mxge.ko (module file exists; cannot bind: no device)
--- source parity probe (run_root) ----------------------------------
MD5 (/usr/src/sys/kern/kern_timeout.c) = 4512d1eb3b4cd8e241c2c9787723bf28
920: ssleep(c, &c->spin, 0, "costp", 0);
4468: callout_stop(&sc->co_hdl); [if_mxge.c]
--- build (final replica, busy-wait observer) -----------------------
see build.log; module: mxge_callout_replica.ko (BUILD_RC=0)
--- decisive run (serial console, `vm.sh log`) -----------------------
mxge_callout_replica: loaded (hz=100)
mxge_replica: armed FIX-test tick (hz/4)
mxge_replica[fix]: tick parked (started=9 ran=8); callout_stop_async + release + callout_terminate
mxge_replica[fix]: returned; pending=0 ran=9 (0 == cleanly stopped, NO deadlock)
mxge_replica: armed STOP-test tick (hz/4)
mxge_replica[stop]: tick BLOCKED on our serializer (started=9 ran=8) - entering callout_stop() :4468
mxge_replica[stop]: IF THIS IS THE LAST mxge_replica LINE, THE mxge_detach AB-BA DEADLOCK IS PROVEN
<<< callout_stop() never returned; no further module output ever >>>
--- fix-shape return confirmation (run_root, same session) -----------
kern.mxgereplica.armfix: 0 -> 0
=== FIX-SHAPE (stop_async under + terminate outside) ===
kern.mxgereplica.fix: 0 -> 0
FIX_RC=0
--- wedge state observed from a second session (run_root) -----------
$ ps -ax -o pid,stat,wchan,command | grep -E "mxgereplica.stop|softclock" | grep -v grep
-1 B2 slize (softclock 2)
-1 B3 - (softclock 3)
-1 B4 - (softclock 4)
-1 B5 - (softclock 5)
-1 B0 - (softclock 0)
-1 B1 - (softclock 1)
859 D1 costp sysctl kern.mxgereplica.stop=1
B2 slize = softclock thread of CPU 2 parked INSIDE lwkt_serialize_enter
(the mxge_tick half, if_mxge.c:3720)
D1 costp = the "detaching" thread stuck INSIDE callout_stop's sync wait
(kern_timeout.c:920) while HOLDING the serializer
(the mxge_detach half, if_mxge.c:4463-4468)
--- recovery ---------------------------------------------------------
vm.sh reset with-src (guest clean afterwards)
======================================================================
HONESTY RECORD — earlier harness iterations (superseded, kept for the log)
======================================================================
[v1] re-armed a callout_terminate()d callout (mxge never does this):
mxge_replica[fix]: returned; pending=0 ran=9 (0 == cleanly stopped, NO deadlock) <- fix result already valid
panic: assertion "cc->flags & CALLOUT_DID_INIT" failed in callout_reset at /usr/src/sys/kern/kern_timeout.c:804
callout_reset() at callout_reset+0x7f0
arm_sysctl() at arm_sysctl+0x78
sysctl_root.isra.5() ...
<<< harness bug (terminate is terminal); does not touch the tested protocol >>>
[v2] polled for the parked callback with tsleep(timeout=2); poll froze:
$ ps -ax -o pid,stat,wchan,command | grep -E "sysctl|make" | grep -v grep
970 I1 pause timeout 20 sysctl kern.mxgereplica.fix=1
971 D2 mxgw sysctl kern.mxgereplica.fix=1
$ ps -ax ... | grep softclock
-1 B2 slize (softclock 2)
<<< the tick HAD fired and parked (B2 slize); the observer's tsleep timeout
is itself a callout serviced by that same parked softclock, so the
observer never woke. Incidental proof that a parked softclock freezes
all tsleep timeouts on its CPU. v3 (final) uses a bounded busy-wait. >>>