[Bug 275255] iwlwifi: panic after iwlwifi0: lkpi_iv_newstate: error -5 during state transition 5 (RUN) -> 0 (INIT) (8xxx/9xxx chipsets)
Date: Mon, 22 Apr 2024 17:27:55 UTC
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=275255
ml@netfence.it changed:
What |Removed |Added
----------------------------------------------------------------------------
CC| |ml@netfence.it
--- Comment #14 from ml@netfence.it ---
I'm seeing very frequent (i.e. several times per day) panics after upgrading
from 13.2R to 13.3R and possibly they are related to this bug.
I'm not able to get a proper core on this machine (and I still can't understand
why), but in the logs I find:
Apr 18 15:00:25 hector kernel: iwlwifi0: linuxkpi_ieee80211_beacon_loss: vif
0xfffffe00ac5b1e80 vap 0xfffffe00ac5b1010 state RUN
Apr 18 15:00:28 hector syslogd: last message repeated 1 times
Apr 18 15:00:29 hector kernel: ipfw: 9999 Deny UDP 192.168.113.82:137
192.168.113.255:137 in via wlan0
Apr 18 15:00:29 hector wpa_supplicant[93738]: wlan0: CTRL-EVENT-DISCONNECTED
bssid=fc:f5:28:ca:f1:12 reason=0
Apr 18 15:00:29 hector kernel: iwlwifi0: linuxkpi_ieee80211_connection_loss:
vif 0xfffffe00ac5b1e80 vap 0xfffffe00ac5b1010 state RUN
Apr 18 15:00:29 hector kernel: wlan0: link state changed to DOWN
Apr 18 15:00:29 hector wpa_supplicant[93738]: BSSID fc:f5:28:ca:f1:12 ignore
list count incremented to 2, ignoring for 10 seconds
Apr 18 15:00:29 hector wpa_supplicant[93738]: ioctl[SIOCS80211, op=20, val=0,
arg_len=7]: Can't assign requested address
Apr 18 15:00:29 hector dhclient[97089]: wlan0 link state up -> down
Apr 18 15:00:29 hector devd[99040]: Processing event '!system=IFNET
subsystem=wlan0 type=LINK_DOWN'
Apr 18 15:00:29 hector devd[99040]: Pushing table
Apr 18 15:00:29 hector devd[99040]: Processing notify event
Apr 18 15:00:29 hector devd[99040]: Popping table
Apr 18 15:00:29 hector dbus-daemon[3053]: [system] Activating service
name='org.freedesktop.ConsoleKit' requested by ':1.2' (uid=0 pid=24346 comm="")
(using servicehelper)
Apr 18 15:00:29 hector kernel: iwlwifi0: Couldn't drain frames for staid 0,
status 0x8
Apr 18 15:00:29 hector kernel: iwlwifi0: lkpi_sta_run_to_init:2173:
mo_sta_state(NOTEXIST) failed: -5
Apr 18 15:00:29 hector kernel: iwlwifi0: lkpi_iv_newstate: error -5 during
state transition 5 (RUN) -> 0 (INIT)
Apr 18 15:00:29 hector dbus-daemon[3053]: [system] Activating service
name='org.freedesktop.PolicyKit1' requested by ':1.3' (uid=0 pid=24293 comm="")
(using servicehelper)
Apr 18 15:00:29 hector dbus-daemon[3053]: [system] Successfully activated
service 'org.freedesktop.ConsoleKit'
Apr 18 15:00:29 hector polkitd[24756]: Started polkitd version 124
Apr 18 15:00:29 hector polkitd[24756]: Loading rules from directory
/usr/local/etc/polkit-1/rules.d
Apr 18 15:00:29 hector polkitd[24756]: Loading rules from directory
/usr/local/share/polkit-1/rules.d
Apr 18 15:00:29 hector polkitd[24756]: Finished loading, compiling and
executing 1 rules
Apr 18 15:00:29 hector dbus-daemon[3053]: [system] Successfully activated
service 'org.freedesktop.PolicyKit1'
Apr 18 15:00:29 hector polkitd[24756]: Acquired the name
org.freedesktop.PolicyKit1 on the system bus
Apr 18 15:00:29 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Activating service name='org.a11y.Bus' requested by ':1.0' (uid=1001 pid=25777
comm="")
Apr 18 15:00:29 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Successfully activated service 'org.a11y.Bus'
Apr 18 15:00:29 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Activating service name='org.xfce.Xfconf' requested by ':1.2' (uid=1001
pid=25777 comm="")
Apr 18 15:00:29 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Successfully activated service 'org.xfce.Xfconf'
Apr 18 15:00:30 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Activating service name='org.gtk.vfs.Daemon' requested by ':1.6' (uid=1001
pid=36842 comm="")
Apr 18 15:00:30 hector dbus-daemon[29677]: [session uid=1001 pid=28981]
Successfully activated service 'org.gtk.vfs.Daemon'
Apr 18 15:00:30 hector dbus-daemon[3053]: [system] Activating service
name='org.freedesktop.UPower' requested by ':1.6' (uid=1001 pid=40674 comm="")
(using servicehelper)
Apr 18 15:00:30 hector dbus-daemon[3053]: [system] Successfully activated
service 'org.freedesktop.UPower'
Apr 18 15:00:30 hector wpa_supplicant[93738]: wlan0: Trying to associate with
fc:f5:28:ca:f1:13 (SSID='CCBiesse' freq=5180 MHz)
Apr 18 15:00:30 hector kernel: iwlwifi0: lkpi_sta_scan_to_auth:1033: lvif
0xfffffe00ac5b1000 vap 0xfffffe00ac5b1010 iv_bss 0xfffffe00adb4c000 lvif_bss
0xfffff8000565a000 lvif_bss->ni 0xfffffe00aed99000 synched 0
Apr 18 15:00:30 hector kernel: iwlwifi0: lkpi_iv_newstate: error 16 during
state transition 1 (SCAN) -> 2 (AUTH)
Apr 18 15:01:09 hector syslogd: restart
Apr 18 15:01:09 hector syslogd: kernel boot file is /boot/kernel/kernel
Apr 18 15:01:09 hector kernel: Sleeping thread (tid 100785, pid 0) owns a
non-sleepable lock
Apr 18 15:01:09 hector kernel: KDB: stack backtrace of thread 100785:
Apr 18 15:01:09 hector kernel: sched_switch() at sched_switch+0x7d1/frame
0xfffffe00ab30fe20
Apr 18 15:01:09 hector kernel: mi_switch() at mi_switch+0xbf/frame
0xfffffe00ab30fe40
Apr 18 15:01:09 hector kernel: _sleep() at _sleep+0x1f0/frame
0xfffffe00ab30fec0
Apr 18 15:01:09 hector kernel: taskqueue_thread_loop() at
taskqueue_thread_loop+0xb1/frame 0xfffffe00ab30fef0
Apr 18 15:01:09 hector kernel: fork_exit() at fork_exit+0x7d/frame
0xfffffe00ab30ff30
Apr 18 15:01:09 hector kernel: fork_trampoline() at fork_trampoline+0xe/frame
0xfffffe00ab30ff30
Apr 18 15:01:09 hector kernel: --- trap 0xc, rip = 0x63639d6e3da, rsp =
0x6364d128f48, rbp = 0x6364d128f60 ---
Apr 18 15:01:09 hector kernel: panic: sleeping thread
Apr 18 15:01:09 hector kernel: cpuid = 2
Apr 18 15:01:09 hector kernel: time = 1713445230
Apr 18 15:01:09 hector kernel: KDB: stack backtrace:
Apr 18 15:01:09 hector kernel: db_trace_self_wrapper() at
db_trace_self_wrapper+0x2b/frame 0xfffffe00ab2ba960
Apr 18 15:01:09 hector kernel: vpanic() at vpanic+0x152/frame
0xfffffe00ab2ba9b0
Apr 18 15:01:09 hector kernel: panic() at panic+0x43/frame 0xfffffe00ab2baa10
Apr 18 15:01:09 hector kernel: propagate_priority() at
propagate_priority+0x293/frame 0xfffffe00ab2baa50
Apr 18 15:01:09 hector kernel: turnstile_wait() at turnstile_wait+0x314/frame
0xfffffe00ab2baaa0
Apr 18 15:01:09 hector kernel: __mtx_lock_sleep() at
__mtx_lock_sleep+0x17b/frame 0xfffffe00ab2bab30
Apr 18 15:01:09 hector kernel: linuxkpi_ieee80211_find_sta() at
linuxkpi_ieee80211_find_sta+0xd0/frame 0xfffffe00ab2bab70
Apr 18 15:01:09 hector kernel: linuxkpi_ieee80211_find_sta_by_ifaddr() at
linuxkpi_ieee80211_find_sta_by_ifaddr+0x7f/frame 0xfffffe00ab2babc0
Apr 18 15:01:09 hector kernel: iwl_mvm_rx_mpdu_mq() at
iwl_mvm_rx_mpdu_mq+0x420/frame 0xfffffe00ab2bacd0
Apr 18 15:01:09 hector kernel: iwl_pcie_rx_handle() at
iwl_pcie_rx_handle+0x444/frame 0xfffffe00ab2badd0
Apr 18 15:01:09 hector kernel: iwl_pcie_napi_poll_msix() at
iwl_pcie_napi_poll_msix+0x30/frame 0xfffffe00ab2bae20
Apr 18 15:01:09 hector kernel: lkpi_napi_task() at lkpi_napi_task+0xf/frame
0xfffffe00ab2bae40
Apr 18 15:01:09 hector kernel: taskqueue_run_locked() at
taskqueue_run_locked+0x182/frame 0xfffffe00ab2baec0
Apr 18 15:01:09 hector kernel: taskqueue_thread_loop() at
taskqueue_thread_loop+0xc2/frame 0xfffffe00ab2baef0
Apr 18 15:01:09 hector kernel: fork_exit() at fork_exit+0x7d/frame
0xfffffe00ab2baf30
Apr 18 15:01:09 hector kernel: fork_trampoline() at fork_trampoline+0xe/frame
0xfffffe00ab2baf30
Apr 18 15:01:09 hector kernel: --- trap 0xc, rip = 0x63639d6e3da, rsp =
0x63644046f48, rbp = 0x63644046f60 ---
Apr 18 15:01:09 hector kernel: Uptime: 33s
Another:
Apr 18 15:05:32 hector wpa_supplicant[21281]: wlan0: CTRL-EVENT-DISCONNECTED
bssid=fc:f5:28:ca:f1:13 reason=0
Apr 18 15:05:32 hector kernel: iwlwifi0: linuxkpi_ieee80211_beacon_loss: vif
0xfffffe00abd8de80 vap 0xfffffe00abd8d010 state RUN
Apr 18 15:05:32 hector syslogd: last message repeated 1 times
Apr 18 15:05:32 hector kernel: wlan0: link state changed to DOWN
Apr 18 15:05:32 hector devd[76299]: Processing event '!system=IFNET
subsystem=wlan0 type=LINK_DOWN'
Apr 18 15:05:32 hector dhclient[22403]: wlan0 link state up -> down
Apr 18 15:05:32 hector devd[76299]: Pushing table
Apr 18 15:05:32 hector devd[76299]: Processing notify event
Apr 18 15:05:32 hector kernel: iwlwifi0: Couldn't drain frames for staid 0,
status 0x8
Apr 18 15:05:32 hector kernel: iwlwifi0: lkpi_sta_run_to_init:2173:
mo_sta_state(NOTEXIST) failed: -5
Apr 18 15:05:32 hector kernel: iwlwifi0: lkpi_iv_newstate: error -5 during
state transition 5 (RUN) -> 1 (SCAN)
Apr 18 15:05:32 hector devd[76299]: Popping table
Apr 18 15:05:33 hector wpa_supplicant[21281]: wlan0: Trying to associate with
fc:f5:28:ca:f1:13 (SSID='CCBiesse' freq=5180 MHz)
Apr 18 15:05:33 hector kernel: iwlwifi0: lkpi_sta_scan_to_auth:1033: lvif
0xfffffe00abd8d000 vap 0xfffffe00abd8d010 iv_bss 0xfffffe00ade45000 lvif_bss
0xfffff80005c8f800 lvif_bss->ni 0xfffffe00ac03c000 synched 0
Apr 18 15:05:33 hector kernel: iwlwifi0: lkpi_iv_newstate: error 16 during
state transition 1 (SCAN) -> 2 (AUTH)
Apr 18 15:05:33 hector kernel: Sleeping thread (tid 100787, pid 0) owns a
non-sleepable lock
Apr 18 15:05:33 hector kernel: KDB: stack backtrace of thread 100787:
Apr 18 15:05:33 hector kernel: sched_switch() at sched_switch+0x7d1/frame
0xfffffe00b0d0ae20
Apr 18 15:05:33 hector kernel: mi_switch() at mi_switch+0xbf/frame
0xfffffe00b0d0ae40
Apr 18 15:05:33 hector kernel: _sleep() at _sleep+0x1f0/frame
0xfffffe00b0d0aec0
Apr 18 15:06:26 hector syslogd: restart
Apr 18 15:06:26 hector syslogd: kernel boot file is /boot/kernel/kernel
Apr 18 15:06:26 hector kernel: fork_exit() at fork_exit+0x7d/frame
0xfffffe00b0d0af30
Apr 18 15:06:26 hector kernel: fork_trampoline() at fork_trampoline+0xe/frame
0xfffffe00b0d0af30
Apr 18 15:06:26 hector kernel: --- trap 0xfc9226bb, rip = 0x9e2138e7aa6c807d,
rsp = 0xce04afe17783e5b4, rbp = 0x7adcc9aeee864891 ---
Apr 18 15:06:26 hector kernel: panic: sleeping thread
Apr 18 15:06:26 hector kernel: cpuid = 3
Apr 18 15:06:26 hector kernel: time = 1713445533
Apr 18 15:06:26 hector kernel: KDB: stack backtrace:
Apr 18 15:06:26 hector kernel: db_trace_self_wrapper() at
db_trace_self_wrapper+0x2b/frame 0xfffffe00b0dbc960
Apr 18 15:06:26 hector kernel: vpanic() at vpanic+0x152/frame
0xfffffe00b0dbc9b0
Apr 18 15:06:26 hector kernel: panic() at panic+0x43/frame 0xfffffe00b0dbca10
Apr 18 15:06:26 hector kernel: propagate_priority() at
propagate_priority+0x293/frame 0xfffffe00b0dbca50
Apr 18 15:06:26 hector kernel: turnstile_wait() at turnstile_wait+0x314/frame
0xfffffe00b0dbcaa0
Apr 18 15:06:26 hector kernel: __mtx_lock_sleep() at
__mtx_lock_sleep+0x17b/frame 0xfffffe00b0dbcb30
Apr 18 15:06:26 hector kernel: linuxkpi_ieee80211_find_sta() at
linuxkpi_ieee80211_find_sta+0xd0/frame 0xfffffe00b0dbcb70
Apr 18 15:06:26 hector kernel: linuxkpi_ieee80211_find_sta_by_ifaddr() at
linuxkpi_ieee80211_find_sta_by_ifaddr+0x7f/frame 0xfffffe00b0dbcbc0
Apr 18 15:06:26 hector kernel: iwl_mvm_rx_mpdu_mq() at
iwl_mvm_rx_mpdu_mq+0x420/frame 0xfffffe00b0dbccd0
Apr 18 15:06:26 hector kernel: iwl_pcie_rx_handle() at
iwl_pcie_rx_handle+0x444/frame 0xfffffe00b0dbcdd0
Apr 18 15:06:26 hector kernel: iwl_pcie_napi_poll_msix() at
iwl_pcie_napi_poll_msix+0x30/frame 0xfffffe00b0dbce20
Apr 18 15:06:26 hector kernel: lkpi_napi_task() at lkpi_napi_task+0xf/frame
0xfffffe00b0dbce40
Apr 18 15:06:26 hector kernel: taskqueue_run_locked() at
taskqueue_run_locked+0x182/frame 0xfffffe00b0dbcec0
Apr 18 15:06:26 hector kernel: taskqueue_thread_loop() at
taskqueue_thread_loop+0xc2/frame 0xfffffe00b0dbcef0
Apr 18 15:06:26 hector kernel: fork_exit() at fork_exit+0x7d/frame
0xfffffe00b0dbcf30
Apr 18 15:06:26 hector kernel: fork_trampoline() at fork_trampoline+0xe/frame
0xfffffe00b0dbcf30
Apr 18 15:06:26 hector kernel: --- trap 0, rip = 0, rsp = 0, rbp = 0 ---
Apr 18 15:06:26 hector kernel: Uptime: 4m36s
I've got several others.
Once I also entered a loop where the laptop would panic and reboot before I
reached the prompt.
Luckily entering single-user mode, starting network from there and then moving
to multi-user mode solved.
# pciconf -lv iwlwifi0
iwlwifi0@pci0:0:12:0: class=0x028000 rev=0x06 hdr=0x00 vendor=0x8086
device=0x31dc subvendor=0x8086 subdevice=0x0264
vendor = 'Intel Corporation'
device = 'Gemini Lake PCH CNVi WiFi'
class = network
(should be Intel 9461).
--
You are receiving this mail because:
You are on the CC list for the bug.