Re: "(ada0:ahcich0:0:0:0): Periph destroyed", followed by panic
Date: Sat, 17 Jan 2026 17:29:44 UTC
On Sat, Jan 17, 2026 at 10:03 AM Fabian Keil <freebsd-listen@fabiankeil.de>
wrote:
> On an ElectroBSD system based on stable/14 215d16e4102b I got this panic:
>
> fk@elektrobier4 /dpool/crash $kgdb151 /boot/kernel/kernel vmcore.0
> [...]
> Reading symbols from /boot/kernel/kernel...
> Reading symbols from /usr/lib/debug//boot/kernel/kernel.debug...
>
> Unread portion of the kernel message buffer:
> ahcich0: Timeout on slot 13 port 0
> ahcich0: is 04000000 cs 00002000 ss 00000000 rs 00002000 tfd 451 serr
> 00400000 cmd 0000ed17
> (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 a8 7a d4 40 b9 00 00
> 08 00 00
> (ada0:ahcich0:0:0:0): CAM status: Auto-Sense Retrieval Failed
> (ada0:ahcich0:0:0:0): Error 5, Unretryable error
> GEOM_ELI: g_eli_write_done() failed (error=5)
> gpt/dpool-ada2.eli[WRITE(offset=1535927209984, length=1048576)]
> (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 a8 82 d4 40 b9 00 00
> 08 00 00
> (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
> (ada0:ahcich0:0:0:0): ATA status: 00 ()
> (ada0:ahcich0:0:0:0): RES: 00 00 00 00 00 00 00 00 00 00 00
> (ada0:ahcich0:0:0:0): Retrying command, 3 more tries remain
> (ada0:ahcich0:0:0:0): WRITE_FPDMA_QUEUED. ACB: 61 00 a8 8a d4 40 b9 00 00
> 08 00 00
> (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
> (ada0:ahcich0:0:0:0): ATA status: 00 ()
> (ada0:ahcich0:0:0:0): RES: 00 00 00 00 00 00 00 00 00 00 00
> (ada0:ahcich0:0:0:0): Retrying command, 3 more tries remain
> swap_pager: indefinite wait buffer: bufobj: 0, blkno: 14059, size: 65536
> swap_pager: indefinite wait buffer: bufobj: 0, blkno: 310, size: 4096
> (ada0:ahcich0:0:0:0): READ_DMA. ACB: c8 00 10 4a 06 47 00 00 00 00 10 00
> (ada0:ahcich0:0:0:0): CAM status: ATA Status Error
> (ada0:ahcich0:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 40 (UNC )
> (ada0:ahcich0:0:0:0): RES: 51 40 10 4a 06 47 07 00 00 10 00
> (ada0:ahcich0:0:0:0): Retrying command, 3 more tries remain
> GEOM_ELI: g_eli_write_done() failed (error=6)
> gpt/dpool-ada2.eli[WRITE(offset=1940057759744, length=8192)]
> GEOM_ELI: g_eli_write_done() failed (error=6)
> gpt/dpool-ada2.eli[WRITE(offset=1940058021888, length=8192)]
> (ada0:ahcich0:0:0:0): Periph destroyed
>
>
> Fatal trap 12: page fault while in kernel mode
> cpuid = 4; apic id = 04
> fault virtual address = 0x18
> fault code = supervisor write data, page not present
> instruction pointer = 0x20:0xffffffff8036c567
> stack pointer = 0x28:0xfffffe00c4d46e80
> frame pointer = 0x28:0xfffffe00c4d46ea0
> code segment = base 0x0, limit 0xfffff, type 0x1b
> = DPL 0, pres 1, long 1, def32 0, gran 1
> processor eflags = interrupt enabled, resume, IOPL = 0
> current process = 4 (doneq0)
> rdi: fffff800041d0dd0 rsi: 0000000000000000 rdx: 0000000000000000
> rcx: 0000000000000000 r8: fffff80003dbbc60 r9: fffffe00c4d47000
> rax: 0000000000000000 rbx: fffff800041d0dd0 rbp: fffffe00c4d46ea0
> r10: 0000000000000001 r11: 0000000000002af8 r12: 0000000000000000
> r13: fffffe00c4d46eb8 r14: 0000000000000000 r15: fffff80003dbb740
> trap number = 12
> panic: page fault
> cpuid = 4
> time = 1768657494
> KDB: stack backtrace:
> db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame
> 0xfffffe00c4d46bd0
> vpanic() at vpanic+0x161/frame 0xfffffe00c4d46d00
> panic() at panic+0x43/frame 0xfffffe00c4d46d60
> trap_pfault() at trap_pfault+0x3e0/frame 0xfffffe00c4d46db0
> calltrap() at calltrap+0x8/frame 0xfffffe00c4d46db0
> --- trap 0xc, rip = 0xffffffff8036c567, rsp = 0xfffffe00c4d46e80, rbp =
> 0xfffffe00c4d46ea0 ---
> xpt_done_process() at xpt_done_process+0x1f7/frame 0xfffffe00c4d46ea0
> xpt_done_td() at xpt_done_td+0xf5/frame 0xfffffe00c4d46ef0
> fork_exit() at fork_exit+0x81/frame 0xfffffe00c4d46f30
> fork_trampoline() at fork_trampoline+0xe/frame 0xfffffe00c4d46f30
> --- trap 0, rip = 0, rsp = 0, rbp = 0 ---
> Uptime: 1d12h54m14s
> Dumping 3625 out of 16313
> MB:..1%..11%..21%..31%..41%..51%..61%..71%..81%..91%
>
> Reading symbols from /boot/kernel/geom_eli.ko...
> [...]
> Reading symbols from /usr/lib/debug//boot/kernel/fdescfs.ko.debug...
> __curthread () at /usr/src/sys/amd64/include/pcpu_aux.h:57
> warning: Source file is more recent than executable.
> 57 __asm("movq %%gs:%P1,%0" : "=r" (td) : "n"
> (offsetof(struct pcpu,
> (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 0xffffffff80a201c0 in kern_reboot (howto=260) at
> /usr/src/sys/kern/kern_shutdown.c:523
> #3 0xffffffff80a206c9 in vpanic (fmt=0xffffffff80f8236f "%s", ap=ap@entry=0xfffffe00c4d46d40)
> at /usr/src/sys/kern/kern_shutdown.c:967
> #4 0xffffffff80a20503 in panic (fmt=<unavailable>) at
> /usr/src/sys/kern/kern_shutdown.c:891
> #5 0xffffffff80ec27c0 in trap_fatal (frame=<optimized out>,
> eva=<optimized out>) at /usr/src/sys/amd64/amd64/trap.c:1000
> #6 0xffffffff80ec27c0 in trap_pfault (frame=0xfffffe00c4d46dc0,
> usermode=false, signo=<optimized out>, ucode=<optimized out>)
> #7 <signal handler called>
> #8 0xffffffff8036c567 in atomic_fcmpset_long (src=18446735277681260352,
> dst=<optimized out>, expect=<optimized out>) at
> /usr/src/sys/amd64/include/atomic.h:184
> #9 xpt_done_process (ccb_h=0xfffff800041d0dd0) at
> /usr/src/sys/cam/cam_xpt.c:5331
> #10 0xffffffff8036e6e5 in xpt_done_td (arg=arg@entry=0xffffffff8157b240
> <cam_doneqs>) at /usr/src/sys/cam/cam_xpt.c:5434
> #11 0xffffffff809d7321 in fork_exit (callout=0xffffffff8036e5f0
> <xpt_done_td>, arg=0xffffffff8157b240 <cam_doneqs>,
> frame=0xfffffe00c4d46f40) at /usr/src/sys/kern/kern_fork.c:1153
> #12 <signal handler called>
> (kgdb) f 9
> #9 xpt_done_process (ccb_h=0xfffff800041d0dd0) at
> /usr/src/sys/cam/cam_xpt.c:5331
> warning: Source file is more recent than executable.
>
That's concerning...
> 5331 mtx_lock(&devq->send_mtx);
> (kgdb) l
> 5326 if (sim)
> 5327 devq = sim->devq;
> 5328 KASSERT(devq, ("Periph disappeared with CCB %p %s
> request pending.",
> 5329 ccb_h, xpt_action_name(ccb_h->func_code)));
>
so if devq is NULL here, it's quite likely there's corruption and/or the
sim has already been freed. That suggests that there's a "ref leak" bug
around tracking the lifetimes of the sim. If you can reproduce this, you
may be able to find where. They are tricky things to go after, though.
dtrace can help, but lately it's ability to track fbt stuff is wobbly due
to clang's aggressive inlining. The sim can be non-null here when multiple
different cam_path objects refer to the same path and one is released, and
the other isn't so we don't null out the bus, so sim is a stale value,
likely read from free'd memory. This can only happen, though, in the
ref-leak case where not enough refs are taken to the bus, IIRC.
This all happens after the periph is destroyed. generically, that's
perfectly fine (we have about 100 systems a week at work have this happen
due to drive failure in our population of tens of thousands of hard disks).
We don't use ahci, though, anymore (we have several sata SSDs in the fleet
still, though). ahci when we did use it did have a fair amount of problems.
I chased a lot of bugs there, though they were often that some part of ahci
decided the device was back, and we tried to create a new periph while the
old one was being destroyed and hit issues there. I fixed all the ones that
were hitting our fleet a few years ago.
5330
> 5331 mtx_lock(&devq->send_mtx);
> 5332 devq->send_active--;
> 5333 devq->send_openings++;
> 5334 cam_ccbq_ccb_done(&dev->ccbq, (union ccb *)ccb_h);
> 5335
> (kgdb) p devq
> $1 = (struct cam_devq *) 0x0
> (kgdb) p sim
> $2 = <optimized out>
> (kgdb) p ccb_h
> $3 = (struct ccb_hdr *) 0xfffff800041d0dd0
> (kgdb) p *ccb_h
> $4 = {pinfo = {priority = 1152, generation = 4539901, index = -3},
> xpt_links = {le = {le_next = 0x0, le_prev = 0x0}, sle = {sle_next = 0x0},
> tqe = {tqe_next = 0x0, tqe_prev = 0x0}, stqe = {stqe_next = 0x0}},
> sim_links = {
> le = {le_next = 0x0, le_prev = 0x0}, sle = {sle_next = 0x0}, tqe =
> {tqe_next = 0x0, tqe_prev = 0x0}, stqe = {stqe_next = 0x0}}, periph_links =
> {le = {le_next = 0x0, le_prev = 0x0}, sle = {sle_next = 0x0}, tqe = {
> tqe_next = 0x0, tqe_prev = 0x0}, stqe = {stqe_next = 0x0}},
> retry_count = 4, alloc_flags = 1, cbfcnp = 0xffffffff80395a10 <adadone>,
> func_code = XPT_ATA_IO, status = 1025, path = 0xfffff800041f8ee0, path_id =
> 0,
> target_id = 0, target_lun = 0, flags = 2147483776, xflags = 0,
> periph_priv = {entries = {{ptr = 0x3, field = 3, bytes =
> "\003\000\000\000\000\000\000"}, {ptr = 0xfffff800d148dbc0, field =
> 18446735281127742400,
> bytes = "\300\333H\321\000\370\377\377"}}, bytes =
> "\003\000\000\000\000\000\000\000\300\333H\321\000\370\377\377"}, sim_priv
> = {entries = {{ptr = 0x0, field = 0, bytes =
> "\000\000\000\000\000\000\000"}, {
> ptr = 0x0, field = 0, bytes = "\000\000\000\000\000\000\000"}},
> bytes = '\000' <repeats 15 times>}, qos = {etime = 0x0, sim_data = 0,
> periph_data = 17711719}, timeout = 30000, softtimeout = {tv_sec = 0,
> tv_usec = 0}}
> (kgdb) p *ccb_h->path
> $5 = {periph = 0xfffff80006001000, bus = 0x0, target = 0x0, device = 0x0}
> (kgdb) p *ccb_h->path->periph
> $6 = {periph_start = 0xffffffff80393950 <adastart>, periph_oninval =
> 0xffffffff803937f0 <adaoninvalidate>, periph_dtor = 0xffffffff80393830
> <adacleanup>, periph_name = 0xffffffff80fa966b "ada", path =
> 0xfffff800041f8ee0,
> softc = 0xfffffe00dc7f7000, sim = 0xfffff800040bbf00, unit_number = 0,
> type = CAM_PERIPH_BIO, flags = 384, scheduled_priority = 1152,
> immediate_priority = 4294967295, periph_allocating = 0, periph_allocated =
> 32,
> refcount = 0, ccb_list = {slh_first = 0x0}, periph_links = {sle_next =
> 0x0}, unit_links = {tqe_next = 0xfffff80006002e00, 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 = 0xffffffff803670f0
> <xpt_run_allocq_task>, ta_context = 0xfffff80006001000},
> ccb_zone = 0xfffff80003b31a00, periph_rootmount = {flags = 0, who =
> 0xffffffff80fa966b "ada", list = {tqe_next = 0xfffff80006002eb0, tqe_prev =
> 0xfffff80003c798b0}}}
>
> The kernel has been built without "options INVARIANTS"
> which explains why the KASSERT wasn't triggered.
>
> gpt/dpool-ada2.eli is actually located on ada0.
>
> I'm aware that ada0 is flaky but still think the system should
> keep going after the disk loss as it's using mirrored ZFS pools
> and the other disk seems fine.
>
> I have a couple of local patches including one in sys/cam/cam_xpt.c [0].
>
> I'm currently trying to reproduce the problem.
>
> Fabian
>
> [0] <
> https://www.fabiankeil.de/sourcecode/electrobsd/ElectroBSD-20220822-d9391cfeef5b/0183-cam-Fix-nullpointer-dereference.diff
You should never pass NULL as the path to xpt_async(). It's a required
element of the call: the path you are sending the async event to. And the
path must have either a device or a bus, which that traceback didn't have.
Now, how did it come to pass that the bus and/or device was NULL here?
That's where the bug is... xpt_create_path always fills in the bus (via
xpt_compile_path). One common way for it to become NULL like this is
xpt_release_path is called on it. Maybe you can use dtrace to find where
that's coming to pass? I'm not seeing anything super quick in the code, but
I'm just doing a quick analysis to answer this email + past experience...
So I hope that helps get to the next level of 'hey, this is wrong' but I
know climbing that hill is hard. I'll help when I can, but at this stage I
can only offer generic advice that I'm not feeling is very helpful.
Warner