Date: Fri, 15 Apr 2022 12:42:23 +0200 From: "J.R. Oldroyd" <fbsd@opal.com> To: "Bjoern A. Zeeb" <bz@freebsd.org> Cc: Tomoaki AOKI <junchoon@dec.sakura.ne.jp>, Chris <bsd-lists@bsdforge.com>, Eirik =?UTF-8?B?44CTdmVyYnk=?= <ltning-freebsd-wireless@anduin.net>, FreeBSD wireless mailing list <wireless@freebsd.org> Subject: Re: 8265 / 9560 problems + 7260 + AX200 Message-ID: <20220415124212.79dcec58@opal.com> In-Reply-To: <alpine.BSF.2.00.2204150953380.68830@ai.fobar.qr> References: <alpine.BSF.2.00.2204071710370.68830@ai.fobar.qr> <20220408124814.7e7b03e2@opal.com> <bab0b660d7d67455dfe4762bab3fe8678d90e39a.camel@anduin.net> <alpine.BSF.2.00.2204081055000.68830@ai.fobar.qr> <alpine.BSF.2.00.2204081118370.68830@ai.fobar.qr> <20220409104532.5df1cb3edb14d85c25de9078@dec.sakura.ne.jp> <b7b12e1037b298195958b53476c72e97@bsdforge.com> <alpine.BSF.2.00.2204141808210.68830@ai.fobar.qr> <18a809cb00c2f93b212c51d8eb2b8b10@bsdforge.com> <20220415062448.e5a1f00dc989ab4e6c5f9afe@dec.sakura.ne.jp> <20220415105009.0583fb26@opal.com> <alpine.BSF.2.00.2204150953380.68830@ai.fobar.qr>
next in thread | previous in thread | raw e-mail | index | archive | help
On Fri, 15 Apr 2022 09:55:30 +0000 (UTC) "Bjoern A. Zeeb" <bz@freebsd.org> wrote: > > On Fri, 15 Apr 2022, J.R. Oldroyd wrote: > > > I see that iwl_drv_stop() -- which I presume gets called when the interface > > goes down -- it unloads the firmware and then iwl_drv_start() calls > > iwl_request_firmware() to reload it. Remember we talked about the firmware > > not loading if iwm had already been there? Both of these discoveries > > suggest that either the firmware unload routine isn't clean or that the > > firmware load needs to do some sort of reset to get things into a known > > state for the load. > > > > I'll spend some time later today looking through that code to see if I can > > help figure out what is going on. > > Remember that we do not automatically recover from a firmware crash; > that code is not there so we catch the problems (like the ones you are > seeing) at this stage and get a chance to fix them and not have them > missed. > > /bz > What I see in my log is that at 04:11:58 this morning, the wlan0 i/f went down. Don't know why - I was asleep! Anyway, if that means that iwl_drv_stop() was called and so also iwl_dealloc_ucode(), the in-mem copy of the firmware has then been kfree'd and the fw struct has been zeroed. Am I right in having read that the device accesses the in-mem copy of the fw by DMA rather than being sent a copy to it's own memory? If so, the device now has no fw until iwl_request_firmware() is called again which only happens when iwl_drv_start() is called. So it is actually correct that a fw error would now be detected. Now, it did actually reassociate at 04:11:59 and change back to up. So, firmware is reloaded? Or, when you say "we do not automatically recover from a firmware crash", are you saying this reload won't have happened? But then wpa_supplicant fails to reassociate and the link goes back to down. Firmware unloaded again? After that, nothing but diagnostics in the log until I came back to my desk hours later in the morning and restarted things. Here's the snippet of the log from that time. I'll go ahead and send you the full log by mail. -jr Apr 15 04:11:58 susauq kernel: wlan0: link state changed to DOWN Apr 15 04:11:58 susauq wpa_supplicant[282]: wlan0: CTRL-EVENT-DISCONNECTED bssid=d4:6e:0e:xx:xx:xx reason=0 Apr 15 04:11:59 susauq wpa_supplicant[282]: wlan0: Trying to associate with 90:5c:44:xx:xx:xx (SSID='ZiggoFxxxxxx-5GHz' freq=5220 MHz) Apr 15 04:11:59 susauq wpa_supplicant[282]: Failed to add supported operating classes IE Apr 15 04:11:59 susauq wpa_supplicant[282]: wlan0: Associated with 90:5c:44:xx:xx:xx Apr 15 04:11:59 susauq kernel: wlan0: link state changed to UP Apr 15 04:12:00 susauq rtsold[347]: <cap_rssend> sendmsg on wlan0: No buffer space available Apr 15 04:12:00 susauq dhclient[981]: send_packet: No buffer space available Apr 15 04:12:00 susauq syslogd: last message repeated 1 times Apr 15 04:12:00 susauq wpa_supplicant[282]: wlan0: CTRL-EVENT-DISCONNECTED bssid=90:5c:44:xx:xx:xx reason=0 Apr 15 04:12:00 susauq kernel: wlan0: link state changed to DOWN Apr 15 04:12:00 susauq wpa_supplicant[282]: wlan0: WPA: 4-Way Handshake failed - pre-shared key may be incorrect Apr 15 04:12:00 susauq wpa_supplicant[282]: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=19 ssid="ZiggoFxxxxxx-5GHz" auth_failures=1 duration=10 reason=WRONG_KEY Apr 15 04:12:01 susauq wpa_supplicant[282]: wlan0: Trying to associate with d4:6e:0e:34:09:d4 (SSID='ZiggoFxxxxx' freq=2437 MHz) Apr 15 04:12:01 susauq kernel: iwlwifi0: Not associated and the time event is over already... Apr 15 04:12:01 susauq wpa_supplicant[282]: Failed to add supported operating classes IE Apr 15 04:12:07 susauq dhclient[981]: send_packet: Network is down Apr 15 04:12:11 susauq wpa_supplicant[282]: wlan0: Authentication with d4:6e:0e:34:09:d4 timed out. Apr 15 04:12:11 susauq wpa_supplicant[282]: wlan0: CTRL-EVENT-DISCONNECTED bssid=d4:6e:0e:xx:xx:xx reason=3 locally_generated=1 Apr 15 04:12:12 susauq wpa_supplicant[282]: wlan0: CTRL-EVENT-SSID-REENABLED id=19 ssid="ZiggoFxxxxxx-5GHz" Apr 15 04:12:12 susauq wpa_supplicant[282]: wlan0: Trying to associate with 90:5c:44:xx:xx:xx (SSID='ZiggoFxxxxxx-5GHz' freq=5220 MHz) Apr 15 04:12:12 susauq wpa_supplicant[282]: Failed to add supported operating classes IE Apr 15 04:12:12 susauq kernel: iwlwifi0: Microcode SW error detected. Restarting 0x2000000. Apr 15 04:12:12 susauq kernel: iwlwifi0: Start IWL Error Log Dump: Apr 15 04:12:12 susauq kernel: iwlwifi0: Transport status: 0x0000004B, valid: 6 Apr 15 04:12:12 susauq kernel: iwlwifi0: Loaded firmware version: 36.ca7b901d.0 8265-36.ucode Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00003520 | ADVANCED_SYSASSERT Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00A00220 | trm_hw_status0 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000000 | trm_hw_status1 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00024A8C | branchlink2 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x0003AC1E | interruptlink1 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000000 | interruptlink2 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0xDEADBEEF | data1 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0xDEADBEEF | data2 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0xDEADBEEF | data3 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x1F409DAC | beacon time Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x41FE1CCD | tsf low Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000D35 | tsf hi Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000000 | time gp1 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x4B2690D6 | time gp2 Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000001 | uCode revision type Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000024 | uCode version major Apr 15 04:12:12 susauq kernel: iwlwifi0: 0xCA7B901D | uCode version minor Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00000230 | hw version Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x18489000 | board version Apr 15 04:12:12 susauq kernel: iwlwifi0: 0x00270128 | hcmd
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20220415124212.79dcec58>