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

Reply: Fabian Keil : "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 ]
From: Fabian Keil <freebsd-listen_at_fabiankeil.de>
Date: Wed, 21 Jan 2026 14:02:30 UTC
Warner Losh <imp@bsdimp.com> wrote on 2026-01-20 at 05:05:46:

> 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:

> > > (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 will update the patch to use a bool and will try to upstream it shortly.

When running ahcich0-detacher.sh in two terminals the message
appears frequently but that seems to be expected.

> > > 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) 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.

Using dtrace indicates that cam_sim_free() is always called with a
refcount of 2, but usually cam_sim_release() is then called through
geom which lets cam_sim_free() return.

The following dtrace output doesn't explicitly show this because
fbt:kernel:cam_sim_free:return seems to be optimised away:

2026 Jan 21 14:07:40.061: 1 100400 ahci_ch_attach:entry
2026 Jan 21 14:07:40.061: 1 100400 cam_sim_hold:entry Sim: ahcich 0:0 Refcount: 1

              kernel`xpt_bus_register+0xf9
              kernel`ahci_ch_attach+0x709
              kernel`device_attach+0x43d
              kernel`devctl2_ioctl+0x144
              kernel`devfs_ioctl+0xcb
              kernel`vn_ioctl+0xc8
              kernel`devfs_ioctl_f+0x1e
              kernel`kern_ioctl+0x286
              kernel`sys_ioctl+0x117
              kernel`amd64_syscall+0x117
              kernel`0xffffffff80e981bb
2026 Jan 21 14:07:40.061: 1 100400 cam_sim_hold:return Sim: ahcich 0:0 Refcount: 2
2026 Jan 21 14:07:40.061: 1 100400 ahci_ch_attach:return
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: ada0
2026 Jan 21 14:07:40.151: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: ada0
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: ada0
2026 Jan 21 14:07:40.151: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: label:taste
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.151: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.161: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.161: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.161: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.161: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.161: 0 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.161: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.161: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0001, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.161: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.161: 0 100034 g_destroy_geom:entry : geom->flags: 0x0001, geom->name: ada0
2026 Jan 21 14:07:40.161: 0 100034 g_wither_washer:return
2026 Jan 21 14:07:40.161: 0 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.161: 0 100034 g_wither_washer:return
2026 Jan 21 14:07:40.201: 0 100388 ahci_ch_detach:entry
2026 Jan 21 14:07:40.201: 0 100388 cam_sim_free:entry Sim: ahcich 0:0 Refcount: 2

              kernel`ahci_ch_detach+0xb1
              kernel`device_detach+0x180
              kernel`devctl2_ioctl+0x412
              kernel`devfs_ioctl+0xcb
              kernel`vn_ioctl+0xc8
              kernel`devfs_ioctl_f+0x1e
              kernel`kern_ioctl+0x286
              kernel`sys_ioctl+0x117
              kernel`amd64_syscall+0x117
              kernel`0xffffffff80e981bb
2026 Jan 21 14:07:40.211: 0 100044 g_orphan_provider:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: ada0
2026 Jan 21 14:07:40.211: 0 100034 g_orphan_provider:entry : access: r0w0e0, geom->flags: 0x0001, geom->name: ada0, provider->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0001, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_wither_washer:return
2026 Jan 21 14:07:40.211: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: ada0
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: ada0
2026 Jan 21 14:07:40.211: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.211: 0 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_provider:entry : access: r0w0e0, geom->flags: 0x0001, geom->name: ada0, provider->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.211: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_geom:entry : geom->flags: 0x0001, geom->name: ada0
2026 Jan 21 14:07:40.211: 0 100034 g_destroy_provider:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: ada0
2026 Jan 21 14:07:40.211: 0 100034 g_disk_providergone:entry dp->d_gone: set
2026 Jan 21 14:07:40.222: 0 100034 cam_sim_release:entry Sim: ahcich 0:0 Refcount: 1

              kernel`xpt_release_bus+0xde
              kernel`xpt_free_path+0x43
              kernel`cam_periph_release_locked_buses+0x239
              kernel`cam_periph_release+0x47
              kernel`g_disk_providergone+0x27
              kernel`g_destroy_provider+0x4c
              kernel`g_wither_washer+0x7e
              kernel`g_run_events+0x388
              kernel`fork_exit+0x81
              kernel`0xffffffff80e988ee
2026 Jan 21 14:07:40.222: 0 100034 cam_sim_release:return Sim: ahcich 0:0 Refcount: 0
2026 Jan 21 14:07:40.222: 0 100034 g_wither_washer:return
2026 Jan 21 14:07:40.222: 0 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.222: 0 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.222: 0 100034 g_destroy_geom:entry : geom->flags: 0x0001, geom->name: ada0
2026 Jan 21 14:07:40.222: 0 100034 g_wither_washer:return
2026 Jan 21 14:07:40.231: 1 100388 ahci_ch_detach:return

When the problem does occur, cam_sim_release() isn't called at all
and it looks like geom only starts to process the attached device
after the detaching is already in progress:

2026 Jan 21 14:07:40.271: 0 100406 ahci_ch_attach:entry
2026 Jan 21 14:07:40.271: 0 100406 cam_sim_hold:entry Sim: ahcich 0:0 Refcount: 1

              kernel`xpt_bus_register+0xf9
              kernel`ahci_ch_attach+0x709
              kernel`device_attach+0x43d
              kernel`devctl2_ioctl+0x144
              kernel`devfs_ioctl+0xcb
              kernel`vn_ioctl+0xc8
              kernel`devfs_ioctl_f+0x1e
              kernel`kern_ioctl+0x286
              kernel`sys_ioctl+0x117
              kernel`amd64_syscall+0x117
              kernel`0xffffffff80e981bb
2026 Jan 21 14:07:40.271: 0 100406 cam_sim_hold:return Sim: ahcich 0:0 Refcount: 2
2026 Jan 21 14:07:40.271: 0 100406 ahci_ch_attach:return
2026 Jan 21 14:07:40.271: 1 100400 ahci_ch_detach:entry
2026 Jan 21 14:07:40.271: 1 100400 cam_sim_free:entry Sim: ahcich 0:0 Refcount: 2

              kernel`ahci_ch_detach+0xb1
              kernel`device_detach+0x180
              kernel`devctl2_ioctl+0x412
              kernel`devfs_ioctl+0xcb
              kernel`vn_ioctl+0xc8
              kernel`devfs_ioctl_f+0x1e
              kernel`kern_ioctl+0x286
              kernel`sys_ioctl+0x117
              kernel`amd64_syscall+0x117
              kernel`0xffffffff80e981bb
2026 Jan 21 14:07:40.361: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.361: 0 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: ada0
2026 Jan 21 14:07:40.361: 0 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.361: 0 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: ada0
2026 Jan 21 14:07:40.361: 0 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: ada0
2026 Jan 21 14:07:40.391: 1 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: label:taste, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: label:taste
2026 Jan 21 14:07:40.391: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.391: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.391: 1 100034 g_detach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.401: 1 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.401: 1 100034 g_destroy_geom:entry : geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C
2026 Jan 21 14:07:40.401: 1 100034 g_attach:entry : access: r0w0e0, geom->flags: 0x0000, geom->name: diskid/DISK-BHYVE-38D3-F1E6-DA3C, provider->name: No provider
2026 Jan 21 14:07:40.401: 1 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.401: 1 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.401: 1 100034 g_destroy_consumer:entry : access: r0w0e0, geom->flags: 0x0001, geom->name: ada0, provider->name: No provider
2026 Jan 21 14:07:40.401: 1 100034 g_do_wither:entry 
2026 Jan 21 14:07:40.401: 1 100034 g_destroy_geom:entry : geom->flags: 0x0001, geom->name: ada0
2026 Jan 21 14:07:40.401: 1 100034 g_wither_washer:return
2026 Jan 21 14:07:40.401: 1 100034 g_wither_washer:entry 
2026 Jan 21 14:07:40.401: 1 100034 g_wither_washer:return
2026 Jan 21 14:07:40.411: 1 100407 ahci_ch_detach:entry
2026 Jan 21 14:07:40.411: 1 100407 ahci_ch_detach:return
2026 Jan 21 14:07:40.481: 0 100386 ahci_ch_detach:entry
2026 Jan 21 14:07:40.493: 0 100386 ahci_ch_detach:return

Setting kern.cam.iosched.dynamic=0 makes the problem a lot
harder to trigger.

In the meantime the system with the real flaky disk (elektrobier4)
panicked again in xpt_done_process() and I noticed that a similar
problem has been reported in PR/277499 "panic in doneq0 xpt_done_td
xpt_done_process after HDD falling off the bus (Periph destroyed)" [0]
which references PR 263704 "Panic because device went away with
XPT_ATA_IO pending" [1]. Both are "Closed FIXED" at the moment.

For now I've set kern.cam.iosched.dynamic=0 on elektrobier4 as well
to see how the behaviour differs when ada0 acts up again which
I expect to happen within days.

Fabian

[0] <https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=263703>
[1] <https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=263704>