panic: device_unbusy: called for non-busy device iichid0

[David Wolfskill]

This was on the new(er) laptop with which I have been experimenting; it
uses iichid to controll/access the built-in mouse/touchpad.

The machine was running:

FreeBSD g1-48.catwhisker.org 14.0-CURRENT FreeBSD 14.0-CURRENT #252 main-n246951-38e7025a60b2: Wed May 26 04:56:25 PDT 2021 ***@g1-48.catwhisker.org:/common/S4/obj/usr/src/amd64.amd64/sys/CANARY amd64 1400017 1400017

at the time. Note that the reboot after building the above (yesterday)
was without issue, and the reboot after the panic was also without issue
-- so this would seem to have elements of timing/racing involved. (And
it's likely to be distinctly unpleasant to debug, as it seems that
reproduction may be rather "iffy.")

I took a photo of the displayed backtrace; it's at
Loading Image...

Here's a slightly-abbreviated hand-transcribed version:

panic: device_unbusy: called for non-busy device iichid0
cpuid = 8
time = 1622113818
KDB: stack backtrace:
db_trace_self_wrapper()
vpanic()
panic()
device_unbusy()
iicbus_release_bus()
iichid_intr()
ithread-loop()
fork_exit()
fork_trampoline()
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
KDB: enter: panic
[ thread pid 12 tid 100170 ]
Stopped at 0xffffffff80c36867 = kdb_enter+ 0x37: $0,0x12a0b9e(%rip)
db>


Peace,
david

[Vladimir Kondratyev]

Post by David Wolfskill
This was on the new(er) laptop with which I have been experimenting; it
uses iichid to controll/access the built-in mouse/touchpad.
at the time. Note that the reboot after building the above (yesterday)
was without issue, and the reboot after the panic was also without issue
-- so this would seem to have elements of timing/racing involved. (And
it's likely to be distinctly unpleasant to debug, as it seems that
reproduction may be rather "iffy.")
I took a photo of the displayed backtrace; it's at
https://www.catwhisker.org/~david/FreeBSD/head/n246951/device_unbusy.jpg
panic: device_unbusy: called for non-busy device iichid0
cpuid = 8
time = 1622113818
db_trace_self_wrapper()
vpanic()
panic()
device_unbusy()
iicbus_release_bus()
iichid_intr()
ithread-loop()
fork_exit()
fork_trampoline()
--- trap 0, rip = 0, rsp = 0, rbp = 0 ---
KDB: enter: panic
[ thread pid 12 tid 100170 ]
Stopped at 0xffffffff80c36867 = kdb_enter+ 0x37: $0,0x12a0b9e(%rip)
db>

It looks like iicbus issue.

It was very easy reproducible with iichid when latter had a bug
triggering interrupt storm on device_attach:

https://github.com/wulf7/iichid/issues/22

It was caused by unlocked calls to device_busy() and device_unbusy() in
iicbus_request_bus() routine. These unlocked calls resulted in races
with parallel device attachment process.

CC-ed ian@