Re: "(ada0:ahcich0:0:0:0): Periph destroyed", followed by panic

In reply to: Fabian Keil : "Re: "(ada0:ahcich0:0:0:0): Periph destroyed", followed by panic"
Go to: [ bottom of page ] [ top of archives ] [ this month ]
From: Fabian Keil <freebsd-listen_at_fabiankeil.de>
Date: Sun, 18 Jan 2026 17:48:29 UTC
Fabian Keil <freebsd-listen@fabiankeil.de> wrote on 2026-01-18 at 15:47:53:

> Fabian Keil <freebsd-listen@fabiankeil.de> wrote on 2026-01-18 at 12:20:05:

> > Running ahcich0-detacher.sh:
> > 
> > | #!/bin/sh
> > |
> > | main() {
> > |     while true; do
> > |         date
> > |         echo "Detaching ahcich0"
> > |         sudo devctl detach ahcich0
> > |         echo "Attaching ahcich0"
> > |         sudo devctl attach ahcich0
> > |         sleep 0.1
> > |         sudo dd if=/dev/random bs=1m of=/dev/ada0 &
> > |         sleep 0.1
> > |     done
> > | }
> > | 
> > | main
> > 
> > in two terminals at the same time within seconds reliably results in:
> > 
> > fk@test-vm ~ $kgdb151 /boot/kernel/kernel /var/crash/vmcore.3
> > GNU gdb (GDB) 15.1 [GDB v15.1 for FreeBSD]
> > [...]
> > Reading symbols from /boot/kernel/kernel...
> > Reading symbols from /usr/lib/debug//boot/kernel/kernel.debug...
> > 
> > Unread portion of the kernel message buffer:
> > trap number             = 12
> > panic: page fault
> [...]

> Doing the same with a kernel that includes "options CAMDEBUG" and
> "options DEBUG_MEMGUARD" after enabling CAM debug messages with:
> camcontrol debug -T -I -P -S -X 0:0:0
> results in:

With "camcontrol debug -I -P -T -S -X -c -p all" the script
triggered additional panics:

Unread portion of the kernel message buffer:
(noperiph:ahcich0:0:-1:ffffffff): xpt_async(AC_PATH_DEREGISTERED)
cam_debug: xpt_run_devq
cam_debug: running device 0xfffff80010078800
(ada0:ahcich0:0:0:0): xpt_freeze_devq(1)
(noperiph:ahcich0:0:0:0): xpt_freeze_devq_device(1) 0->1
(ada0:ahcich0:0:0:0): SETFEATURES ENABLE RCACHE. ACB: ef aa 00 00 00 40 00 00 00 00 00 00
(ada0:ahcich0:0:0:0): ahciaction func_code=918
(ada0:ahcich0:0:0:0): xpt_done_direct: status 0x1
cam_debug: xpt_run_devq
(ada0:ahcich0:0:0:0): adadone
cam_debug: xpt_release_ccb
cam_debug: xpt_run_allocq(0xfffff80005f76500)
(ada0:ahcich0:0:0:0): xpt_schedule
cam_debug: xpt_run_allocq(0xfffff80005f76500)
(ada0:ahcich0:0:0:0): xpt_setup_ccb
cam_debug: calling periph_start()
(ada0:ahcich0:0:0:0): adastart
(ada0:ahcich0:0:0:0): xpt_action: func 0x918 XPT_ATA_IO
(ada0:ahcich0:0:0:0): xpt_action_default: func 0x918 XPT_ATA_IO
(ada0:ahcich0:0:0:0): xpt_action_default: func= 0x918 XPT_ATA_IO status 0
(ada0:ahcich0:0:0:0): cam_release_devq(0, 0, 0, 0)
(ada0:ahcich0:0:0:0): xpt_setup_ccb
(ada0:ahcich0:0:0:0): xpt_action: func 0x5 XPT_REL_SIMQ
(ada0:ahcich0:0:0:0): xpt_action_default: func 0x5 XPT_REL_SIMQ
(ada0:ahcich0:0:0:0): xpt_release_devq(1, 1)
(noperiph:ahcich0:0:0:0): xpt_release_devq_device(1, 1) 1->0
cam_debug: xpt_schedule_dev
cam_debug: Inserting onto queue
cam_debug: xpt_run_devq
(ada0:ahcich0:0:0:0): xpt_action_default: func= 0x5 XPT_REL_SIMQ status 0x1
cam_debug: running device 0xfffff80010078800
(ada0:ahcich0:0:0:0): xpt_freeze_devq(1)
(noperiph:ahcich0:0:0:0): xpt_freeze_devq_device(1) 0->1
(ada0:ahcich0:0:0:0): SETFEATURES ENABLE WCACHE. ACB: ef 02 00 00 00 40 00 00 00 00 00 00
(ada0:ahcich0:0:0:0): ahciaction func_code=918
(ada0:ahcich0:0:0:0): (noperiph:ahcich0:0:-1:ffffffff): xpt_done_direct: status 0x1
cam_debug: xpt_run_devq
(ada0:ahcich0:0:0:0): adadone
(ada0:ahcich0:0:0:0): cam_release_devq(0, 0, 0, 0)
(ada0:ahcich0:0:0:0): xpt_setup_ccb
(ada0:ahcich0:0:0:0): xpt_action: func 0x5 XPT_REL_SIMQ
(ada0:ahcich0:0:0:0): xpt_action_default: func 0x5 XPT_REL_SIMQ
(ada0:ahcich0:0:0:0): xpt_release_devq(1, 1)
(noperiph:ahcich0:0:0:0): xpt_release_devq_device(1, 1) 1->0
cam_debug: xpt_run_devq
(ada0:ahcich0:0:0:0): xpt_action_default: func= 0x5 XPT_REL_SIMQ status 0x1
cam_debug: xpt_release_ccb
cam_debug: xpt_run_allocq(0xfffff80005f76500)
panic: sleepq_add: td 0xfffff80005ffd740 to sleep on wchan 0xffffffff82680385 with sleeping prohibited
[...]
(kgdb) where
#0  __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57
#1  doadump (textdump=textdump@entry=1) at /usr/src/sys/kern/kern_shutdown.c:405
#2  0xffffffff80a26e10 in kern_reboot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:523
#3  0xffffffff80a27329 in vpanic (fmt=0xffffffff81092912 "%s: td %p to sleep on wchan %p with sleeping prohibited", ap=ap@entry=0xfffffe056b713660) at /usr/src/sys/kern/kern_shutdown.c:967
#4  0xffffffff80a270b3 in panic (fmt=<unavailable>) at /usr/src/sys/kern/kern_shutdown.c:891
#5  0xffffffff80a87b58 in sleepq_add (wchan=wchan@entry=0xffffffff82680385, lock=lock@entry=0xffffffff82680300, wmesg=0xffffffff810419b8 "codrain", flags=flags@entry=0, queue=queue@entry=0)
    at /usr/src/sys/kern/subr_sleepqueue.c:326
#6  0xffffffff80a46baa in _callout_stop_safe (c=c@entry=0xfffff80006088428, flags=flags@entry=1, drain=drain@entry=0x0) at /usr/src/sys/kern/kern_timeout.c:1218
#7  0xffffffff803614db in cam_iosched_fini (isc=0xfffff80006088000) at /usr/src/sys/cam/cam_iosched.c:1237
#8  0xffffffff80395b36 in adacleanup (periph=0xfffff80005f76500, periph@entry=<error reading variable: value is not available>) at /usr/src/sys/cam/ata/ata_da.c:1285
#9  0xffffffff8036457f in camperiphfree (periph=0xfffff80005f76500) at /usr/src/sys/cam/cam_periph.c:750
#10 cam_periph_release_locked_buses (periph=periph@entry=0xfffff80005f76500) at /usr/src/sys/cam/cam_periph.c:448
#11 0xffffffff803647cb in cam_periph_release_locked (periph=0xfffff80005f76500) at /usr/src/sys/cam/cam_periph.c:459
#12 0xffffffff8036f224 in xpt_done_process (ccb_h=ccb_h@entry=0xfffff8000620e220) at /usr/src/sys/cam/cam_xpt.c:5379
#13 0xffffffff8036ee9e in xpt_done_direct (done_ccb=0xfffff8000620e220) at /usr/src/sys/cam/cam_xpt.c:4531
#14 0xffffffff804bcb55 in ahci_ch_intr_direct (arg=0xfffffe058a7e5000, arg@entry=<error reading variable: value is not available>) at /usr/src/sys/dev/ahci/ahci.c:1352
#15 0xffffffff804bb54e in ahci_intr_one (data=<optimized out>) at /usr/src/sys/dev/ahci/ahci.c:555
#16 0xffffffff809ddf86 in intr_event_execute_handlers (ie=0xfffff80006092800, p=<optimized out>) at /usr/src/sys/kern/kern_intr.c:1183
#17 ithread_execute_handlers (ie=0xfffff80006092800, p=<optimized out>) at /usr/src/sys/kern/kern_intr.c:1196
#18 ithread_loop (arg=arg@entry=0xfffff800060b2020) at /usr/src/sys/kern/kern_intr.c:1289
#19 0xffffffff809da302 in fork_exit (callout=0xffffffff809ddd20 <ithread_loop>, arg=0xfffff800060b2020, frame=0xfffffe056b713f40) at /usr/src/sys/kern/kern_fork.c:1153
#20 <signal handler called>

And:

Unread portion of the kernel message buffer:
(noperiph:ahcich0:0:0:0): xpt_async: func 0x70f XPT_ASYNC aync_code 256 AC_LOST_DEVICE
(ada0:ahcich0:0:0:0): xpt_freeze_devq(1)
(noperiph:ahcich0:0:0:0): xpt_freeze_devq_device(1) 0->1
(noperiph:ahcich0:0:0:0): xpt_action: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:0:0): xpt_action_default: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:0:0): xpt_action_default: func= 0x70f XPT_ASYNC status 0x1
(noperiph:ahcich0:0:0:0): (ada0:ahcich0:0:0:0): xpt_free_path
(ada0:ahcich0:0:0:0): xpt_release_path
(noperiph:ahcich0:0:-1:ffffffff): 

Fatal trap 18: integer divide fault while in kernel mode
[...]
(kgdb) where
#0  __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57
#1  doadump (textdump=textdump@entry=1) at /usr/src/sys/kern/kern_shutdown.c:405
#2  0xffffffff80a26e10 in kern_reboot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:523
#3  0xffffffff80a27329 in vpanic (fmt=0xffffffff80fd76ff "%s", ap=ap@entry=0xfffffe04e91a3cc0) at /usr/src/sys/kern/kern_shutdown.c:967
#4  0xffffffff80a270b3 in panic (fmt=<unavailable>) at /usr/src/sys/kern/kern_shutdown.c:891
#5  0xffffffff80ef5f48 in trap_fatal (frame=0xfffffe04e91a3d10, eva=<optimized out>) at /usr/src/sys/amd64/amd64/trap.c:1000
#6  <signal handler called>
#7  0xffffffff80361391 in cam_iosched_ticker (arg=0xfffff80006291800) at /usr/src/sys/cam/cam_iosched.c:665
#8  0xffffffff80a45e97 in softclock_call_cc (c=0xfffff80006291c28, cc=cc@entry=0xffffffff82680300, direct=direct@entry=0) at /usr/src/sys/kern/kern_timeout.c:719
#9  0xffffffff80a475c7 in softclock_thread (arg=arg@entry=0xffffffff82680300) at /usr/src/sys/kern/kern_timeout.c:858
#10 0xffffffff809da302 in fork_exit (callout=0xffffffff80a47510 <softclock_thread>, arg=0xffffffff82680300, frame=0xfffffe04e91a3f40) at /usr/src/sys/kern/kern_fork.c:1153
#11 <signal handler called>
(kgdb) f 7
#7  0xffffffff80361391 in cam_iosched_ticker (arg=0xfffff80006291800) at /usr/src/sys/cam/cam_iosched.c:665
665             pending /= isc->periph->path->device->ccbq.total_openings;
(kgdb) p isc->periph->path->device->ccbq.total_openings
$1 = 0
(kgdb) p isc->periph->path->device->ccbq
$2 = {queue = {queue_array = 0x0, array_size = 0, entries = 0, generation = 0, qfrozen_cnt = 0}, queue_extra_head = {tqh_first = 0x0, tqh_last = 0x0}, queue_extra_entries = 0, total_openings = 0, allocated = 0, 
  dev_openings = 0, dev_active = 25165824}

I have local patches in cam_iosched.c but think they are unrelated.

Finally I got:

Unread portion of the kernel message buffer:
(noperiph:ahcich0:0:0:0): xpt_async: func 0x70f XPT_ASYNC aync_code 256 AC_LOST_DEVICE
(ada0:ahcich0:0:0:0): xpt_freeze_devq(1)
(noperiph:ahcich0:0:0:0): xpt_freeze_devq_device(1) 0->1
(noperiph:ahcich0:0:0:0): xpt_action: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:0:0): xpt_action_default: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:0:0): (noperiph:ahcich0:0:0:0): xpt_action_default: func= 0x70f XPT_ASYNC status 0x1
(ada0:ahcich0:0:0:0): xpt_free_path
(ada0:ahcich0:0:0:0): xpt_release_path
(noperiph:ahcich0:0:-1:ffffffff): xpt_compile_path
(noperiph:ahcich0:0:-1:ffffffff): xpt_async: func 0x70f XPT_ASYNC aync_code 256 AC_LOST_DEVICE
(noperiph:ahcich0:0:-1:ffffffff): xpt_action: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:-1:ffffffff): xpt_action_default: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:-1:ffffffff): xpt_action_default: func= 0x70f XPT_ASYNC status 0x1
(noperiph:ahcich0:0:-1:ffffffff): xpt_async: func 0x70f XPT_ASYNC aync_code 64 AC_PATH_DEREGISTERED
(noperiph:ahcich0:0:-1:ffffffff): xpt_action: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:-1:ffffffff): xpt_action_default: func 0x70f XPT_ASYNC
(noperiph:ahcich0:0:-1:ffffffff): xpt_action_default: func= 0x70f XPT_ASYNC status 0x1
(noperiph:ahcich0:0:-1:ffffffff): xpt_release_path
ahcich0: detached
xpt_async(AC_LOST_DEVICE)
panic: mutex CAM device lock not owned at /usr/src/sys/cam/cam_periph.c:671
[...]
(kgdb) where
#0  __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57
#1  doadump (textdump=textdump@entry=1) at /usr/src/sys/kern/kern_shutdown.c:405
#2  0xffffffff80a26e10 in kern_reboot (howto=260) at /usr/src/sys/kern/kern_shutdown.c:523
#3  0xffffffff80a27329 in vpanic (fmt=0xffffffff80ff020a "mutex %s not owned at %s:%d", ap=ap@entry=0xfffffe056b6965f0) at /usr/src/sys/kern/kern_shutdown.c:967
#4  0xffffffff80a270b3 in panic (fmt=<unavailable>) at /usr/src/sys/kern/kern_shutdown.c:891
#5  0xffffffff80a0116f in __mtx_assert (c=<optimized out>, what=what@entry=4, file=<unavailable>, line=<unavailable>, line@entry=671) at /usr/src/sys/kern/kern_mutex.c:1092
#6  0xffffffff80364a2f in cam_periph_invalidate (periph=0xfffff80005f76400) at /usr/src/sys/cam/cam_periph.c:671
#7  0xffffffff803659a2 in cam_periph_async (periph=<unavailable>, code=<unavailable>, path=<unavailable>, arg=<unavailable>) at /usr/src/sys/cam/cam_periph.c:1496
#8  0xffffffff80395352 in adaasync (callback_arg=<optimized out>, code=<optimized out>, path=<optimized out>, arg=<optimized out>) at /usr/src/sys/cam/ata/ata_da.c:1414
#9  0xffffffff80372ec1 in xpt_async_bcast (async_head=0xfffff80010dc0078, async_code=256, path=0xfffff800090eaf20, async_arg=0x0) at /usr/src/sys/cam/cam_xpt.c:4260
#10 xpt_async_process_dev (device=device@entry=0xfffff80010dc0000, arg=arg@entry=0xfffff80031066800) at /usr/src/sys/cam/cam_xpt.c:4167
#11 0xffffffff80371d7c in xptdevicetraverse (target=<unavailable>, target@entry=<error reading variable: value is not available>, start_device=<unavailable>, 
    start_device@entry=<error reading variable: value is not available>, tr_func=0xffffffff80372d70 <xpt_async_process_dev>, tr_func@entry=<error reading variable: value is not available>, arg=0xfffff80031066800, 
    arg@entry=<error reading variable: value is not available>) at /usr/src/sys/cam/cam_xpt.c:2225
#12 0xffffffff80371b24 in xpttargettraverse (bus=bus@entry=0xfffff80009df5380, start_target=start_target@entry=0x0, tr_func=<optimized out>, arg=arg@entry=0xfffff80031066800) at /usr/src/sys/cam/cam_xpt.c:2186
#13 0xffffffff8036e84e in xpt_async_process (periph=<optimized out>, ccb=0xfffff80031066800) at /usr/src/sys/cam/cam_xpt.c:4216
#14 0xffffffff8036f224 in xpt_done_process (ccb_h=0xfffff80031066800) at /usr/src/sys/cam/cam_xpt.c:5379
#15 0xffffffff80371245 in xpt_async_td (arg=arg@entry=0xffffffff8157d1c0 <cam_async>) at /usr/src/sys/cam/cam_xpt.c:5405
#16 0xffffffff809da302 in fork_exit (callout=0xffffffff80371160 <xpt_async_td>, arg=0xffffffff8157d1c0 <cam_async>, frame=0xfffffe056b696f40) at /usr/src/sys/kern/kern_fork.c:1153
#17 <signal handler called>
(kgdb) f 6
#6  0xffffffff80364a2f in cam_periph_invalidate (periph=0xfffff80005f76400) at /usr/src/sys/cam/cam_periph.c:671
671             cam_periph_assert(periph, MA_OWNED);
(kgdb) p *periph
$1 = {periph_start = 0xffffffff80395bc0 <adastart>, periph_oninval = 0xffffffff80395ac0 <adaoninvalidate>, periph_dtor = 0xffffffff80395b00 <adacleanup>, periph_name = 0xffffffff8100959d "ada", path = 0xfffff80005891f80, 
  softc = 0xfffffe057ae4f000, sim = 0xfffff8000607b080, unit_number = 0, type = CAM_PERIPH_BIO, flags = 256, scheduled_priority = 4294967295, immediate_priority = 4294967295, periph_allocating = 0, periph_allocated = 0, 
  refcount = 2, ccb_list = {slh_first = 0x0}, periph_links = {sle_next = 0xfffff80005f76500}, unit_links = {tqe_next = 0x0, tqe_prev = 0xffffffff814101b0 <adadriver+16>}, deferred_callback = 0x0, deferred_ac = 0, 
  periph_run_task = {ta_link = {stqe_next = 0x0}, ta_pending = 0, ta_priority = 0 '\000', ta_flags = 0 '\000', ta_func = 0xffffffff80368370 <xpt_run_allocq_task>, ta_context = 0xfffff80005f76400}, 
  ccb_zone = 0xfffff80006222c00, periph_rootmount = {flags = 0, who = 0xffffffff8100959d "ada", list = {tqe_next = 0x0, tqe_prev = 0xffffffff814dd480 <root_holds>}}}
(kgdb) p *periph->path
$2 = {periph = 0x0, bus = 0xfffff80009df5380, target = 0xfffff801cbda1980, device = 0xfffff80031065000}
(kgdb) p periph->path->device.device_mtx 
$3 = {lock_object = {lo_name = 0xffffffff8103bd18 "CAM device lock", lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffff802bfd7ef80}, mtx_lock = 0}

Fabian