[Bug 281994] iwm: firmware crash
- In reply to: bugzilla-noreply_a_freebsd.org: "[Bug 281994] iwm: firmware crash"
- Go to: [ bottom of page ] [ top of archives ] [ this month ]
Date: Sun, 22 Dec 2024 20:07:00 UTC
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=281994 --- Comment #6 from Bill Blake <billblake2018@gmail.com> --- (In reply to Bjoern A. Zeeb from comment #4) Some points about my setup and an overview of what I did: My laptop runs FreeBSD 14.1 and connects to the net via the hotspot on MyPhone, an Android phone which normally uses the 5 GHz band for its hotspot. Generally speaking, my laptop is always connected to MyPhone, except when I leave and take MyPhone with me. When I return, it is not uncommon to have reconnection difficulties. If I use MyPhone's wifi (thus switching off the hotspot) while I'm out, it basically never reconnects; I have to restart the network. So my general rule is, if I return and the connection doesn't come up after a minute or two after I've turned my hotspot back on, I "wpa_cli reassoc" and/or just restart my network and that usually fixes things. I don't use the standard network scripts. "netop" is the script that devd calls to handle network related events. One important aspect of my setup is that wpa_supplicant is not called until *after* an "ifconfig wlan0 [list] scan" returns one of the known networks. All of the iwm panics happen after a known network has been seen and wpa_supplicant started. I'll start with an iwm panic from two months ago. That panic looks closer to yours than my recent ones do. However, after that panic, my laptop successfully connected to MyPhone. Three days ago, I took MyPhone with me, and the reconnect was normal. I didn't take MyPhone out again until yesterday. When I returned yesterday, it didn't reconnect. After reboots and power cycles, it still didn't connect. Mostly, there were iwm panics. There were a few other oddities, which I'll detail. Aside from the iwm panics, the most notable thing in the log of the recent events is that wpa_supplicant reported the wrong band when it tried to associate. When netop was called after wlan0 was created, it first looked for a known AP and found MyPhone, then it started wpa_supplicant. Wpa_supplicant then tried to associate with MyPhone on the 2.4 GHz band even though MyPhone was using 5 GHz. Things only started working normally when I switched MyPhone to 2.4 GHz. And they continued working normally when I switched it back to 5 GHz. Anyway, here's a more detailed analysis of what I found. 2024-10-18 using the generic kernel: For reasons I don't recall, I booted into the generic kernel. MyPhone was found and an attempt was made to connect to it. That timed out. There are messages from iwm after the timeout which appear to be common to every connection failure. The netop lines beginning "count:" are from checking the output of ifconfig wlan0 list scan, with a periodic ifconfig wlan0 scan thrown in. 07:11:25.908224 devd 1441 - - Executing '/home/admin/libexec/netop $'IFNET' $'wlan0' $'ATTACH' $''' 07:11:26.020727 netop 1584 - - call: IFNET wlan0 ATTACH 07:11:26.044030 netop 1584 - - run: daemon -cf /home/admin/libexec/netop daemon wlan0 wpastart 07:11:26.048701 devd 1441 - - Processing event '!system=ETHERNET subsystem=wlan0 type=IFATTACH' 07:11:26.075833 netop 1598 - - call: daemon wlan0 wpastart - 07:11:26.098293 netop 1598 - - run: ifconfig wlan0 up 07:11:26.333287 netop 1598 - - count: 0, networks: 07:11:27.408988 netop 1598 - - count: 0, networks: 07:11:28.438501 netop 1598 - - count: 1, networks: MyPhone, -50 07:11:28.440461 netop 1598 - - run: /usr/sbin/wpa_supplicant -d -d -s -B -i wlan0 -c /home/admin/etc/wpa_supplicant.conf -D bsd -P /var/run/wpa_supplicant/wlan0.pid 07:11:28.584498 wpa_supplicant 1633 - - Successfully initialized wpa_supplicant 07:11:28.652878 wpa_supplicant 1633 - - ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument 07:11:28.652885 wpa_supplicant 1633 - - ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument 07:11:30.259515 wpa_supplicant 1634 - - wlan0: Trying to associate with da:28:8d:0f:bc:b5 (SSID='MyPhone' freq=5180 MHz) 07:11:40.319564 wpa_supplicant 1634 - - wlan0: Authentication with da:28:8d:0f:bc:b5 timed out. 07:11:40.319771 kernel - - - iwm0: Failed to send binding (action:1): 35 07:11:40.319845 kernel - - - iwm0: iwm_auth: binding update cmd 07:11:40.319912 kernel - - - iwm0: iwm_newstate: could not move to auth state: 35 07:11:40.319759 wpa_supplicant 1634 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=da:28:8d:0f:bc:b5 reason=3 locally_generated=1 07:11:40.319827 wpa_supplicant 1634 - - BSSID da:28:8d:0f:bc:b5 ignore list count incremented to 2, ignoring for 10 seconds 07:11:40.319987 wpa_supplicant 1634 - - wlan0: CTRL-EVENT-DSCP-POLICY clear_all wpa_supplicant tried again and the controller panicked. 07:11:41.197630 wpa_supplicant 1634 - - wlan0: Trying to associate with da:28:8d:0f:bc:b5 (SSID='MyPhone' freq=5180 MHz) 07:11:41.202101 kernel - - - iwm0: dumping device error log 07:11:41.202137 kernel - - - iwm0: Start Error Log Dump: 07:11:41.202160 kernel - - - iwm0: Status: 0x3, count: 6 07:11:41.202182 kernel - - - iwm0: 0x00003001 | ADVANCED_SYSASSERT 07:11:41.202206 kernel - - - iwm0: 000022F0 | trm_hw_status0 07:11:41.202230 kernel - - - iwm0: 00000000 | trm_hw_status1 07:11:41.202255 kernel - - - iwm0: 00456D06 | branchlink2 07:11:41.202285 kernel - - - iwm0: 0046064A | interruptlink1 07:11:41.202312 kernel - - - iwm0: 00000000 | interruptlink2 07:11:41.202341 kernel - - - iwm0: 00000001 | data1 07:11:41.202371 kernel - - - iwm0: 00000000 | data2 07:11:41.202402 kernel - - - iwm0: DEADBEEF | data3 07:11:41.202434 kernel - - - iwm0: 001FDB16 | beacon time 07:11:41.202468 kernel - - - iwm0: 00BB55C6 | tsf low 07:11:41.202502 kernel - - - iwm0: 00000000 | tsf hi 07:11:41.202538 kernel - - - iwm0: 00000000 | time gp1 07:11:41.202574 kernel - - - iwm0: 00BB55C8 | time gp2 07:11:41.202612 kernel - - - iwm0: 00000001 | uCode revision type 07:11:41.202651 kernel - - - iwm0: 00000022 | uCode version major 07:11:41.202691 kernel - - - iwm0: BA501B11 | uCode version minor 07:11:41.202733 kernel - - - iwm0: 00000312 | hw version 07:11:41.202775 kernel - - - iwm0: 0080FF0F | board version 07:11:41.202819 kernel - - - iwm0: 0929002B | hcmd 07:11:41.202864 kernel - - - iwm0: 00022080 | isr0 07:11:41.202910 kernel - - - iwm0: 00000000 | isr1 07:11:41.202957 kernel - - - iwm0: 08201802 | isr2 07:11:41.203006 kernel - - - iwm0: 00400080 | isr3 07:11:41.203055 kernel - - - iwm0: 00000000 | isr4 07:11:41.203105 kernel - - - iwm0: 09280008 | last cmd Id 07:11:41.203157 kernel - - - iwm0: 00000000 | wait_event 07:11:41.203209 kernel - - - iwm0: 00000000 | l2p_control 07:11:41.203263 kernel - - - iwm0: 00000000 | l2p_duration 07:11:41.203321 kernel - - - iwm0: 00000000 | l2p_mhvalid 07:11:41.203377 kernel - - - iwm0: 00000000 | l2p_addr_match 07:11:41.203434 kernel - - - iwm0: 0000008F | lmpm_pmg_sel 07:11:41.203492 kernel - - - iwm0: 28020233 | timestamp 07:11:41.203552 kernel - - - iwm0: 00003838 | flow_handler 07:11:41.203613 kernel - - - iwm0: Start UMAC Error Log Dump: 07:11:41.203675 kernel - - - iwm0: Status: 0x3, count: 7 07:11:41.203738 kernel - - - iwm0: 0x00000070 | ADVANCED_SYSASSERT 07:11:41.203803 kernel - - - iwm0: 0x00000000 | umac branchlink1 07:11:41.203869 kernel - - - iwm0: 0xC0087D08 | umac branchlink2 07:11:41.203936 kernel - - - iwm0: 0xC008F006 | umac interruptlink1 07:11:41.204004 kernel - - - iwm0: 0xC0083A08 | umac interruptlink2 07:11:41.204074 kernel - - - iwm0: 0x00000800 | umac data1 07:11:41.204145 kernel - - - iwm0: 0xC0083A08 | umac data2 07:11:41.204217 kernel - - - iwm0: 0xDEADBEEF | umac data3 07:11:41.204308 kernel - - - iwm0: 0x00000022 | umac major 07:11:41.204329 kernel - - - iwm0: 0xBA501B11 | umac minor 07:11:41.204350 kernel - - - iwm0: 0xC088628C | frame pointer 07:11:41.204372 kernel - - - iwm0: 0xC088628C | stack pointer 07:11:41.204395 kernel - - - iwm0: 0x0929002B | last host cmd 07:11:41.204419 kernel - - - iwm0: 0x00000000 | isr status reg 07:11:41.204444 kernel - - - iwm0: driver status: 07:11:41.204471 kernel - - - iwm0: tx ring 0: qid=0 cur=0 queued=0 07:11:41.204499 kernel - - - iwm0: tx ring 1: qid=1 cur=0 queued=0 07:11:41.204528 kernel - - - iwm0: tx ring 2: qid=2 cur=0 queued=0 07:11:41.204559 kernel - - - iwm0: tx ring 3: qid=3 cur=0 queued=0 07:11:41.204591 kernel - - - iwm0: tx ring 4: qid=4 cur=0 queued=0 07:11:41.204625 kernel - - - iwm0: tx ring 5: qid=5 cur=0 queued=0 07:11:41.204660 kernel - - - iwm0: tx ring 6: qid=6 cur=0 queued=0 07:11:41.204699 kernel - - - iwm0: tx ring 7: qid=7 cur=0 queued=0 07:11:41.204736 kernel - - - iwm0: tx ring 8: qid=8 cur=0 queued=0 07:11:41.204776 kernel - - - iwm0: tx ring 9: qid=9 cur=42 queued=1 07:11:41.204816 kernel - - - iwm0: tx ring 10: qid=10 cur=0 queued=0 07:11:41.204858 kernel - - - iwm0: tx ring 11: qid=11 cur=0 queued=0 07:11:41.204901 kernel - - - iwm0: tx ring 12: qid=12 cur=0 queued=0 07:11:41.204946 kernel - - - iwm0: tx ring 13: qid=13 cur=0 queued=0 07:11:41.204995 kernel - - - iwm0: tx ring 14: qid=14 cur=0 queued=0 07:11:41.205042 kernel - - - iwm0: tx ring 15: qid=15 cur=0 queued=0 07:11:41.205091 kernel - - - iwm0: tx ring 16: qid=16 cur=0 queued=0 07:11:41.205141 kernel - - - iwm0: tx ring 17: qid=17 cur=0 queued=0 07:11:41.205192 kernel - - - iwm0: tx ring 18: qid=18 cur=0 queued=0 07:11:41.205245 kernel - - - iwm0: tx ring 19: qid=19 cur=0 queued=0 07:11:41.205302 kernel - - - iwm0: tx ring 20: qid=20 cur=0 queued=0 07:11:41.205358 kernel - - - iwm0: tx ring 21: qid=21 cur=0 queued=0 07:11:41.205415 kernel - - - iwm0: tx ring 22: qid=22 cur=0 queued=0 07:11:41.205473 kernel - - - iwm0: tx ring 23: qid=23 cur=0 queued=0 07:11:41.205533 kernel - - - iwm0: tx ring 24: qid=24 cur=0 queued=0 07:11:41.205594 kernel - - - iwm0: tx ring 25: qid=25 cur=0 queued=0 07:11:41.205656 kernel - - - iwm0: tx ring 26: qid=26 cur=0 queued=0 07:11:41.205720 kernel - - - iwm0: tx ring 27: qid=27 cur=0 queued=0 07:11:41.205785 kernel - - - iwm0: tx ring 28: qid=28 cur=0 queued=0 07:11:41.205852 kernel - - - iwm0: tx ring 29: qid=29 cur=0 queued=0 07:11:41.205920 kernel - - - iwm0: tx ring 30: qid=30 cur=0 queued=0 07:11:41.205990 kernel - - - iwm0: rx ring: cur=62 07:11:41.206060 kernel - - - iwm0: 802.11 state 1 07:11:41.206132 kernel - - - iwm0: iwm_intr: controller panicked, iv_state = 1; restarting 07:11:41.202092 wpa_supplicant 1634 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=da:28:8d:0f:bc:b5 reason=3 locally_generated=1 07:11:42.268272 kernel - - - iwm0: Failed to send binding (action:1): 35 07:11:42.268287 kernel - - - iwm0: iwm_auth: binding update cmd 07:11:42.268294 kernel - - - iwm0: iwm_newstate: could not move to auth state: 35 Third time was the charm; the connection worked. 07:11:43.771810 wpa_supplicant 1634 - - wlan0: Trying to associate with da:28:8d:0f:bc:b5 (SSID='MyPhone' freq=5180 MHz) 07:11:43.823014 kernel - - - wlan0: link state changed to UP 07:11:43.822999 wpa_supplicant 1634 - - wlan0: Associated with da:28:8d:0f:bc:b5 07:11:45.972310 wpa_supplicant 1634 - - wlan0: WPA: Key negotiation completed with da:28:8d:0f:bc:b5 [PTK=CCMP GTK=CCMP] 07:11:45.972376 wpa_supplicant 1634 - - wlan0: CTRL-EVENT-CONNECTED - Connection to da:28:8d:0f:bc:b5 completed [id=0 id_str=] 2024-12-19, using my custom kernel: I went out, taking MyPhone with me. The reconnect was normal: 17:55:26.636988 wpa_supplicant 88544 - - wlan0: Trying to associate with 16:84:2d:61:a5:c0 (SSID='MyPhone' freq=5180 MHz) 17:55:26.649910 kernel - - - [2507467] wlan0: link state changed to UP 17:55:26.649913 wpa_supplicant 88544 - - wlan0: Associated with 16:84:2d:61:a5:c0 17:55:26.670894 wpa_supplicant 88544 - - wlan0: WPA: Key negotiation completed with 16:84:2d:61:a5:c0 [PTK=CCMP GTK=CCMP] 17:55:26.670969 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-CONNECTED - Connection to 16:84:2d:61:a5:c0 completed [id=0 id_str=] 2024-12-21, again using my custom kernel: This is the next time I went out with MyPhone. I returned home and opened the laptop's lid at 17:26:40. By then it should have already connected but it hadn't. So I did a "wpa_reassoc" to see if that would get my connection working. When it didn't, I stopped the network. Note that wpa_supplicant is still trying on 5 GHz. 17:27:10.153020 wpa_supplicant 88544 - - wlan0: Trying to associate with 16:84:2d:61:a5:c0 (SSID='MyPhone' freq=5180 MHz) 17:27:10.153977 kernel - - - wlan0: link state changed to DOWN 17:27:10.153944 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=16:84:2d:61:a5:c0 reason=0 17:27:10.260066 wpa_supplicant 88544 - - wlan0: Trying to associate with 16:84:2d:61:a5:c0 (SSID='MyPhone' freq=5180 MHz) 17:27:20.261243 wpa_supplicant 88544 - - wlan0: Authentication with 16:84:2d:61:a5:c0 timed out. 17:27:20.261287 wpa_supplicant 88544 - - BSSID 16:84:2d:61:a5:c0 ignore list count incremented to 2, ignoring for 10 seconds 17:27:20.261443 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=16:84:2d:61:a5:c0 reason=3 locally_generated=1 17:27:20.261511 wpa_supplicant 88544 - - BSSID 16:84:2d:61:a5:c0 ignore list count incremented to 3, ignoring for 60 seconds 17:27:20.261663 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-DSCP-POLICY clear_all 17:28:35.410460 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-DSCP-POLICY clear_all 17:28:35.410600 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-DSCP-POLICY clear_all 17:28:35.421765 wpa_supplicant 88544 - - ioctl[SIOCS80211, op=95, val=208, arg_len=0]: Device not configured 17:28:35.421768 wpa_supplicant 88544 - - ioctl[SIOCS80211, op=17, val=0, arg_len=0]: Device not configured 17:28:35.421771 wpa_supplicant 88544 - - ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Device not configured 17:28:35.421774 wpa_supplicant 88544 - - ioctl[SIOCS80211, op=16, val=1, arg_len=0]: Device not configured 17:28:35.421852 devd 1589 - - Processing event '!system=IFNET subsystem=wlan0 type=DETACH' 17:28:35.421896 devd 1589 - - Executing '/home/admin/libexec/netop $'IFNET' $'wlan0' $'DETACH' $''' 17:28:35.421783 wpa_supplicant 88544 - - wlan0: CTRL-EVENT-TERMINATING 17:28:35.431024 netop 38414 - - call: IFNET wlan0 DETACH 17:28:35.435874 netop 38414 - - run: pkill -F /var/run/wpa_supplicant/wlan0.pid -x wpa_supplicant I restarted the network. Notice that wpa_supplicant is now trying to connect on 2.4 GHz. And it panics. At that time MyPhone's hotspot was still running on 5 GHz, so I have no idea why wpa_supplicant tried to use the wrong band. 17:28:40.504580 wpa_supplicant 38474 - - wlan0: Trying to associate with 16:84:2d:61:a5:c0 (SSID='MyPhone' freq=2412 MHz) 17:28:40.571791 kernel - - - iwm0: iwm_rate2ridx: WARNING: device rate for 0 not found! 17:28:40.571869 kernel - - - iwm0: iwm_rate2ridx: WARNING: device rate for 0 not found! 17:28:40.571907 kernel - - - iwm0: iwm_rate2ridx: WARNING: device rate for 0 not found! 17:28:40.571944 kernel - - - iwm0: iwm_rate2ridx: WARNING: device rate for 0 not found! 17:28:40.571981 kernel - - - iwm0: dumping device error log 17:28:40.572020 kernel - - - iwm0: Start Error Log Dump: 17:28:40.572059 kernel - - - iwm0: Status: 0x83, count: 6 17:28:40.572100 kernel - - - iwm0: 0x00002078 | ADVANCED_SYSASSERT 17:28:40.572142 kernel - - - iwm0: 000022F0 | trm_hw_status0 17:28:40.572186 kernel - - - iwm0: 00000000 | trm_hw_status1 17:28:40.572231 kernel - - - iwm0: 00456D06 | branchlink2 17:28:40.572277 kernel - - - iwm0: 0046064A | interruptlink1 17:28:40.572324 kernel - - - iwm0: 00000000 | interruptlink2 17:28:40.572376 kernel - - - iwm0: 00000000 | data1 17:28:40.572426 kernel - - - iwm0: 00000000 | data2 17:28:40.572477 kernel - - - iwm0: DEADBEEF | data3 17:28:40.572530 kernel - - - iwm0: 002A97C3 | beacon time 17:28:40.572584 kernel - - - iwm0: 40625E76 | tsf low 17:28:40.572639 kernel - - - iwm0: 00000029 | tsf hi 17:28:40.572695 kernel - - - iwm0: 00000000 | time gp1 17:28:40.572753 kernel - - - iwm0: 00156DA5 | time gp2 17:28:40.572814 kernel - - - iwm0: 00000001 | uCode revision type 17:28:40.572875 kernel - - - iwm0: 00000022 | uCode version major 17:28:40.572936 kernel - - - iwm0: BA501B11 | uCode version minor 17:28:40.572999 kernel - - - iwm0: 00000312 | hw version 17:28:40.573064 kernel - - - iwm0: 0080FF0F | board version 17:28:40.573129 kernel - - - iwm0: 092E004E | hcmd 17:28:40.573196 kernel - - - iwm0: 00022080 | isr0 17:28:40.573263 kernel - - - iwm0: 00000080 | isr1 17:28:40.573332 kernel - - - iwm0: 08201802 | isr2 17:28:40.573402 kernel - - - iwm0: 004118C0 | isr3 17:28:40.573474 kernel - - - iwm0: 00000000 | isr4 17:28:40.573546 kernel - - - iwm0: 092D002C | last cmd Id 17:28:40.573626 kernel - - - iwm0: 00000000 | wait_event 17:28:40.573647 kernel - - - iwm0: 00000010 | l2p_control 17:28:40.573669 kernel - - - iwm0: 00000020 | l2p_duration 17:28:40.573692 kernel - - - iwm0: 0000003F | l2p_mhvalid 17:28:40.573716 kernel - - - iwm0: 000000CF | l2p_addr_match 17:28:40.573742 kernel - - - iwm0: 0000000D | lmpm_pmg_sel 17:28:40.573769 kernel - - - iwm0: 28020233 | timestamp 17:28:40.573799 kernel - - - iwm0: 00004040 | flow_handler 17:28:40.573829 kernel - - - iwm0: Start UMAC Error Log Dump: 17:28:40.573860 kernel - - - iwm0: Status: 0x83, count: 7 17:28:40.573892 kernel - - - iwm0: 0x00000070 | ADVANCED_SYSASSERT 17:28:40.573925 kernel - - - iwm0: 0x00000000 | umac branchlink1 17:28:40.573960 kernel - - - iwm0: 0xC0087D08 | umac branchlink2 17:28:40.573997 kernel - - - iwm0: 0x010248A0 | umac interruptlink1 17:28:40.574035 kernel - - - iwm0: 0x01028718 | umac interruptlink2 17:28:40.574074 kernel - - - iwm0: 0x00000800 | umac data1 17:28:40.574114 kernel - - - iwm0: 0x01028718 | umac data2 17:28:40.574156 kernel - - - iwm0: 0xDEADBEEF | umac data3 17:28:40.574200 kernel - - - iwm0: 0x00000022 | umac major 17:28:40.574244 kernel - - - iwm0: 0xBA501B11 | umac minor 17:28:40.574290 kernel - - - iwm0: 0xC08875A8 | frame pointer 17:28:40.574337 kernel - - - iwm0: 0xC08875A8 | stack pointer 17:28:40.574386 kernel - - - iwm0: 0x092E004E | last host cmd 17:28:40.574436 kernel - - - iwm0: 0x00000000 | isr status reg 17:28:40.574487 kernel - - - iwm0: driver status: 17:28:40.574540 kernel - - - iwm0: tx ring 0: qid=0 cur=2 queued=0 17:28:40.574594 kernel - - - iwm0: tx ring 1: qid=1 cur=0 queued=0 17:28:40.574649 kernel - - - iwm0: tx ring 2: qid=2 cur=0 queued=0 17:28:40.574706 kernel - - - iwm0: tx ring 3: qid=3 cur=0 queued=0 17:28:40.574765 kernel - - - iwm0: tx ring 4: qid=4 cur=0 queued=0 17:28:40.574828 kernel - - - iwm0: tx ring 5: qid=5 cur=0 queued=0 17:28:40.574889 kernel - - - iwm0: tx ring 6: qid=6 cur=0 queued=0 17:28:40.574952 kernel - - - iwm0: tx ring 7: qid=7 cur=0 queued=0 17:28:40.575017 kernel - - - iwm0: tx ring 8: qid=8 cur=0 queued=0 17:28:40.575083 kernel - - - iwm0: tx ring 9: qid=9 cur=47 queued=1 17:28:40.575150 kernel - - - iwm0: tx ring 10: qid=10 cur=0 queued=0 17:28:40.575219 kernel - - - iwm0: tx ring 11: qid=11 cur=0 queued=0 17:28:40.575290 kernel - - - iwm0: tx ring 12: qid=12 cur=0 queued=0 17:28:40.575362 kernel - - - iwm0: tx ring 13: qid=13 cur=0 queued=0 17:28:40.575436 kernel - - - iwm0: tx ring 14: qid=14 cur=0 queued=0 17:28:40.575516 kernel - - - iwm0: tx ring 15: qid=15 cur=0 queued=0 17:28:40.575538 kernel - - - iwm0: tx ring 16: qid=16 cur=0 queued=0 17:28:40.575562 kernel - - - iwm0: tx ring 17: qid=17 cur=0 queued=0 17:28:40.575586 kernel - - - iwm0: tx ring 18: qid=18 cur=0 queued=0 17:28:40.575613 kernel - - - iwm0: tx ring 19: qid=19 cur=0 queued=0 17:28:40.575641 kernel - - - iwm0: tx ring 20: qid=20 cur=0 queued=0 17:28:40.575670 kernel - - - iwm0: tx ring 21: qid=21 cur=0 queued=0 17:28:40.575701 kernel - - - iwm0: tx ring 22: qid=22 cur=0 queued=0 17:28:40.575733 kernel - - - iwm0: tx ring 23: qid=23 cur=0 queued=0 17:28:40.575767 kernel - - - iwm0: tx ring 24: qid=24 cur=0 queued=0 17:28:40.575805 kernel - - - iwm0: tx ring 25: qid=25 cur=0 queued=0 17:28:40.575842 kernel - - - iwm0: tx ring 26: qid=26 cur=0 queued=0 17:28:40.575881 kernel - - - iwm0: tx ring 27: qid=27 cur=0 queued=0 17:28:40.575921 kernel - - - iwm0: tx ring 28: qid=28 cur=0 queued=0 17:28:40.575963 kernel - - - iwm0: tx ring 29: qid=29 cur=0 queued=0 17:28:40.576006 kernel - - - iwm0: tx ring 30: qid=30 cur=0 queued=0 17:28:40.576051 kernel - - - iwm0: rx ring: cur=66 17:28:40.576097 kernel - - - iwm0: 802.11 state 3 17:28:40.576145 kernel - - - iwm0: iwm_intr: controller panicked, iv_state = 3; restarting 17:28:40.570951 wpa_supplicant 38474 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=16:84:2d:61:a5:c0 reason=3 locally_generated=1 17:28:41.581325 kernel - - - iwm0: iwm_newstate: IWM_LQ_CMD failed: 35 I have a total of 67 of such panics. Each has 93 iwm0: lines and 25 of them vary in those 65 panics. And I don't know the driver, so there's no reasonable way I can analyze them. I'll include them (including the one above) in an attachment. Including the iwm panic I just showed, I got 9 panics. The "Trying to associate" timestamps are: 17:28:40.504580 17:28:45.150464 17:28:49.737945 17:28:54.392337 17:28:58.963140 17:29:03.617191 17:29:08.236658 17:29:12.908324 17:29:17.548844. I then restarted my network and got one panic at 17:29:34.700421. I'm not sure if I did anything special then, but instead of the expected repeat panics after that one, I got: 17:29:35.773693 wpa_supplicant 39299 - - wlan0: Associated with 16:84:2d:61:a5:c0 17:29:35.773803 kernel - - - wlan0: link state changed to UP 17:29:37.800766 kernel - - - wlan0: link state changed to DOWN 17:29:37.800797 wpa_supplicant 39299 - - wlan0: CTRL-EVENT-DISCONNECTED bssid=16:84:2d:61:a5:c0 reason=0 17:29:39.837375 kernel - - - iwm0: iwm_auth: failed to set multicast 17:29:39.837511 kernel - - - iwm0: iwm_newstate: could not move to auth state: 35 17:29:39.837540 kernel - - - iwm0: could not initiate scan I have no idea what those messages might indicate. Anyway, thereafter all I got from iwm0 was "could not initiate scan", through several net stop and start cycles. I then unloaded the if_iwm and iwm9000fw modules, which the system dutifully reloaded. At that point, everything returned to its broken normal. My next 17 panics were at: 17:43:09.461594 17:43:14.101804 17:43:18.701523 17:43:23.372512 17:43:27.992629 17:43:32.632777 17:43:37.276331 17:43:41.909099 17:44:47.426186 17:44:52.110329 17:44:56.739232 17:45:01.381866 17:45:05.962497 17:45:10.578521 17:45:15.234267 17:45:19.828801 17:45:24.501346. After the last panic, I got these messages. 17:45:28.707390 kernel - - - iwm0: failed to send antennas before calibration: 35 17:45:28.707515 kernel - - - iwm_run_init_ucode: failed 35 17:45:28.707541 kernel - - - iwm_init_hw failed 35 17:45:28.707563 kernel - - - iwm0: could not initiate scan The "could not initiate scan" message was all that I saw out of iwm through 17:52:19.922224, after which I restarted my network. That got me 22 more panics at: 17:52:29.523264 17:52:34.135438 17:52:38.722295 17:52:43.320218 17:52:47.935885 17:52:52.508490 17:52:57.127934 17:53:01.757242 17:53:06.371624 17:53:10.958342 17:53:15.571275 17:53:20.188567 17:53:24.768825 17:53:29.368628 17:53:33.982246 17:53:38.610136 17:53:43.210232 17:53:47.794820 17:53:52.410098 17:53:57.024823 17:54:01.652138 17:54:06.240706. Again I got, 17:54:10.428980 kernel - - - iwm0: failed to send antennas before calibration: 35 17:54:10.429020 kernel - - - iwm_run_init_ucode: failed 35 17:54:10.429037 kernel - - - iwm_init_hw failed 35 17:54:10.429054 kernel - - - iwm0: could not initiate scan That was all she wrote, again through 18:10:29.738890. I then rebooted my machine and it was right back to panics, 8 of them: 18:11:02.294667 18:12:03.428172 18:12:08.034539 18:12:12.736892 18:12:17.359661 18:12:22.045198 18:12:26.740529 18:12:31.464267. I rebooted, got a panic at 18:12:31.464267, which was followed by: 18:12:35.998658 kernel - - - iwm0: iwm_send_phy_db_data: Cannot send HCMD of Phy DB cfg section, 35 18:12:35.998695 kernel - - - iwm_init_hw failed 35 18:12:35.998715 kernel - - - iwm0: could not initiate scan Again, I rebooted, got a panic at 18:15:02.025631, followed by: 18:15:06.250812 kernel - - - iwm0: failed to send antennas before calibration: 35 18:15:06.250837 kernel - - - iwm_run_init_ucode: failed 35 18:15:06.250852 kernel - - - iwm_init_hw failed 35 18:15:06.250866 kernel - - - iwm0: could not initiate scan Again, I rebooted and got 9 more panics: 18:19:19.529518 18:19:24.254847 18:19:28.955165 18:19:33.571993 18:19:38.175545 18:19:42.887308 18:19:47.555632 18:19:52.264708 18:19:57.007505, again followed by: 18:20:01.287715 kernel - - - iwm0: failed to send antennas before calibration: 35 18:20:01.287740 kernel - - - iwm_run_init_ucode: failed 35 18:20:01.287751 kernel - - - iwm_init_hw failed 35 18:20:01.287762 kernel - - - iwm0: could not initiate scan At that point, I gave up on using my hotspot and switched to a USB tether. That's when I read the bug report that suggested that the band was an issue. So I told MyPhone to use 2.4 GHz and wpa_supplicant reported "wlan0: Trying to associate with 7a:a7:4f:79:2a:fe (SSID='MyPhone' freq=2462 MHz)" and the connection proceeded normally. I then told MyPhone to use 5 GHz and wpa_supplicant reported "wlan0: Trying to associate with 8a:c6:22:f7:63:06 (SSID='MyPhone' freq=5745 MHz)" and again the connection proceeded normally. It has remained stable since. -- You are receiving this mail because: You are the assignee for the bug.