Re: "(ada0:ahcich0:0:0:0): Periph destroyed", followed by panic
- In reply to: Warner Losh : "Re: "(ada0:ahcich0:0:0:0): Periph destroyed", followed by panic"
- Go to: [ bottom of page ] [ top of archives ] [ this month ]
Date: Tue, 20 Jan 2026 12:10:29 UTC
On Tue, Jan 20, 2026 at 5:05 AM Warner Losh <imp@bsdimp.com> wrote:
>
>
> On Mon, Jan 19, 2026 at 10:52 AM Fabian Keil <freebsd-listen@fabiankeil.de>
> wrote:
>
>> Fabian Keil <freebsd-listen@fabiankeil.de> wrote on 2026-01-18 at
>> 12:20:05:
>>
>> > Warner Losh <imp@bsdimp.com> wrote on 2026-01-17 at 10:29:44:
>>
>> > > 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...
>>
>> > While I have not yet been able to reproduce the exact same panic on the
>> > same system, I ran into a related issue while trying to reproduce the
>> > problem in a byhve vm.
>> >
>> > Running ahcich0-detacher.sh:
>> [...]
>> > in two terminals at the same time within seconds reliably results in:
>> [...]
>> > (kgdb) f 8
>> > #8 0xffffffff80369a66 in xpt_async (async_code=256,
>> path=0xfffff8000606eb60, async_arg=0x0) at /usr/src/sys/cam/cam_xpt.c:4321
>> > 4321 xpt_freeze_simq(path->bus->sim, 1);
>> [...]
>> > (kgdb) p *path
>> > $1 = {periph = 0x0, bus = 0x0, target = 0x0, device = 0x0}
>>
>> I've come up with a patch that seems to prevent the problem [0].
>>
>
> I'd use a bool for that patch, not an int. How often do you see 'not
> detaching detached device?' It seems like a reasonable roadblock in the
> surface... especially since it looks like it can only be true when we
> succeed in attach.
>
>
>> > I also once managed to get devctl sleeping "forever" by running only
>> > one ahcich0-detacher.sh instance, but haven't been able to reproduce
>> > this yet.
>>
>> Now that the panic is prevented this issue can be reliably triggered
>> by running ahcich0-detacher.sh in parallel for a while.
>>
>> (kgdb) where
>> #0 sched_switch (td=td@entry=0xfffff8010a749740, flags=flags@entry=259)
>> at /usr/src/sys/kern/sched_ule.c:2437
>> #1 0xffffffff80a34da3 in mi_switch (flags=flags@entry=259) at
>> /usr/src/sys/kern/kern_synch.c:548
>> #2 0xffffffff80a88233 in sleepq_switch (wchan=0xfffff80006256380,
>> pri=<optimized out>) at /usr/src/sys/kern/subr_sleepqueue.c:608
>> #3 0xffffffff80a880fc in sleepq_wait (wchan=<unavailable>,
>> pri=<unavailable>) at /usr/src/sys/kern/subr_sleepqueue.c:659
>> #4 0xffffffff80a34311 in _sleep (ident=ident@entry=0xfffff80006256380,
>> lock=lock@entry=0xfffffe058a9f9400, priority=priority@entry=43,
>> wmesg=0xffffffff8105a969 "simfree", sbt=sbt@entry=0, pr=pr@entry=0,
>> flags=256)
>> at /usr/src/sys/kern/kern_synch.c:223
>> #5 0xffffffff803676c0 in cam_sim_free (sim=0xfffff80006256380,
>> free_devq=free_devq@entry=1) at /usr/src/sys/cam/cam_sim.c:157
>> #6 0xffffffff804bc6cd in ahci_ch_detach (dev=0xfffff800060a2800,
>> dev@entry=<error reading variable: value is not available>) at
>> /usr/src/sys/dev/ahci/ahci.c:969
>> #7 0xffffffff80a63404 in DEVICE_DETACH (dev=0xfffff800060a2800) at
>> ./device_if.h:234
>> #8 device_detach (dev=dev@entry=0xfffff800060a2800) at
>> /usr/src/sys/kern/subr_bus.c:2712
>> #9 0xffffffff80a6b307 in devctl2_ioctl (cdev=<optimized out>,
>> cmd=<unavailable>, cmd@entry=<error reading variable: value is not
>> available>, data=0xfffff8010a7e1400 "ahcich0",
>> data@entry=<error reading variable: value is not available>,
>> fflag=<optimized out>, td=0xfffff8010a749740, td@entry=<error reading
>> variable: value is not available>) at /usr/src/sys/kern/subr_bus.c:5843
>> #10 0xffffffff808d3da1 in devfs_ioctl (ap=0xfffffe058835bc58) at
>> /usr/src/sys/fs/devfs/devfs_vnops.c:963
>> #11 0xffffffff80f4a9ed in VOP_IOCTL_APV (vop=0xffffffff8149bd28
>> <devfs_specops>, a=a@entry=0xfffffe058835bc58) at vnode_if.c:1229
>> #12 0xffffffff80b3b030 in VOP_IOCTL (vp=<optimized out>,
>> command=<optimized out>, data=<optimized out>, fflag=<optimized out>,
>> cred=<optimized out>, td=<optimized out>) at ./vnode_if.h:637
>> #13 0xffffffff80b3b030 in vn_ioctl (fp=<optimized out>, com=<optimized
>> out>, data=<unavailable>, active_cred=<unavailable>, td=<unavailable>)
>> #14 0xffffffff808d446e in devfs_ioctl_f (fp=<unavailable>, fp@entry=<error
>> reading variable: value is not available>, com=<unavailable>, com@entry=<error
>> reading variable: value is not available>, data=<unavailable>,
>> data@entry=<error reading variable: value is not available>,
>> cred=<unavailable>, cred@entry=<error reading variable: value is not
>> available>, td=<unavailable>, td@entry=<error reading variable: value is
>> not available>)
>> at /usr/src/sys/fs/devfs/devfs_vnops.c:894
>> #15 0xffffffff80aa1ef1 in fo_ioctl (fp=0xfffff8000fccadc0,
>> com=2157462530, data=0xfffff8010a7e1400, active_cred=<unavailable>,
>> td=0xfffff8010a749740) at /usr/src/sys/sys/file.h:379
>> #16 kern_ioctl (td=td@entry=0xfffff8010a749740, fd=<optimized out>,
>> com=com@entry=2157462530, data=data@entry=0xfffff8010a7e1400 "ahcich0")
>> at /usr/src/sys/kern/sys_generic.c:810
>> #17 0xffffffff80aa1be3 in sys_ioctl (td=0xfffff8010a749740,
>> uap=0xfffff8010a749b40) at /usr/src/sys/kern/sys_generic.c:715
>> #18 0xffffffff80ef6d9a in syscallenter (td=0xfffff8010a749740) at
>> /usr/src/sys/amd64/amd64/../../kern/subr_syscall.c:193
>> #19 amd64_syscall (td=0xfffff8010a749740, traced=0) at
>> /usr/src/sys/amd64/amd64/trap.c:1241
>> #20 <signal handler called>
>> #21 0x0000225fa814557a in ?? ()
>> Backtrace stopped: Cannot access memory at address 0x225fa68c9038
>> (kgdb) f 5
>> #5 0xffffffff803676c0 in cam_sim_free (sim=0xfffff80006256380,
>> free_devq=free_devq@entry=1) at /usr/src/sys/cam/cam_sim.c:157
>> 157 error = msleep(sim, mtx, PRIBIO, "simfree", 0);
>> (kgdb) p *sim
>> $1 = {sim_action = 0xffffffff804bcc80 <ahciaction>, sim_poll =
>> 0xffffffff804bd360 <ahcipoll>, sim_name = 0xffffffff8104741f "ahcich",
>> softc = 0xfffffe058a9f8000, mtx = 0xfffffe058a9f9400, links = {tqe_next =
>> 0x0,
>> tqe_prev = 0x0}, path_id = 0, unit_number = 0, bus_id = 0,
>> max_tagged_dev_openings = 32, max_dev_openings = 2, flags = 0, devq =
>> 0xfffff80005d94880, refcount = 1}
>>
>
> refcount=1 means that a reference to the sim wasn't properly released.
> We're sleeping here waiting for that to happen. You'll need to find that
> ref leak.
>
>
>> (kgdb) p *mtx
>> $2 = {lock_object = {lo_name = 0xffffffff81070545 "AHCI channel lock",
>> lo_flags = 16973824, lo_data = 0, lo_witness = 0xfffff802bfd7f700},
>> mtx_lock = 0}
>> (kgdb) l
>> 152 mtx_assert(mtx, MA_OWNED);
>> 153 }
>> 154 KASSERT(sim->refcount >= 1, ("sim->refcount >= 1"));
>> 155 sim->refcount--;
>> 156 if (sim->refcount > 0) {
>> 157 error = msleep(sim, mtx, PRIBIO, "simfree", 0);
>> 158 KASSERT(error == 0, ("invalid error value for
>> msleep(9)"));
>> 159 }
>> 160 KASSERT(sim->refcount == 0, ("sim->refcount == 0"));
>> 161 if (mtx == &cam_sim_free_mtx) /* sim->mtx == NULL */
>>
>> I'm not sure what to do about this.
>>
>
> Sadly, you have to find the leak, or what's holding onto the sim. You will
> have to track, likely with dtrace since I don't see any cam debug in it,
> calls to cam_sim_hold and cam_sim_release. They are mismatched for some
> reason, and you'll have to hunt that down. It looks like they are called
> from only one place, though, and that's xpt_bus_register and
> xpt_release_bus respectively. You'll need to see what path can cause
> xpt_bus_register to be called, but then fail to call the matching
> xpt_release_bus. It doesn't look like an error in ahci_ch_attach (it calls
> xpt_bus_deregister which drops the reference with a call to
> xpt_release_bus). But it looks like if you are putting the NULL chek and
> short circuit, you might have two threads racing:
> (1) creation path creating the device and it's past xpt_bus_register, but
> not yet to ahci_attached -- there's no giant dropping sleeps here
> (2) in the detach path *somehow* that gets to ahci_ch_detach in this
> window, maybe because the locking of the channel and updating the channel
> are with different mutexes, allowing the race.
> This also suggests that the multiple different locks may not be held long
> enough.
>
> Now in theory we take out Giant in the newbus code to prevent this.
> However, we drop Giant sometimes when we sleep which can lead to races (the
> race is already lost before we get into simfree sleep though). If the above
> is the confirmed race you are provoking in your testing (which arguably is
> a bit artificial, but maybe not SO artificial). It might also be the
> absence of a bus_topo_lock() in one of these paths.
>
> Hopefully that will give you more to chew on and hopefully find the next
> layer or two of this onion.
>
Maybe add a panic() to the case where the channel is NULL. There you know
you are actively racing, if that theory holds. Then you can see what other
thread is in the attach path and that might help chase it one step further.
Warner
> Warner
>
>
>> Fabian
>>
>> [0] <
>> https://www.fabiankeil.de/sourcecode/electrobsd/sys-dev-ahci-Don-t-try-to-detach-an-already-detached-device-20260119.diff
>> >
>>
>>