Pi4 not reconnecting to WiFi after WAP restart

I have just rebooted my Mesh WAPs and my Pi4 still has not reconnected to the WiFi after 20 minutes. My Pi3 reconnected almost immediately. Do you know why it may not be reconnecting. It looks like I will need to restart it manually.

[edit]
I’ve bumped into an old thread. I am using the official charger and have no USB devices attached, not even a keyboard or mouse as I administer it through SSH or the TV remote.
[/edit]

Hard to tell without logs.

Logs are useless:

2024-03-17 22:36:38.114 T:1411     info <general>: script.module.slyguy - Proxy Started: http://127.0.0.1:52103/
2024-03-17 22:36:38.115 T:1411     info <general>: script.module.slyguy - Widevine Level (fallback): 3
2024-03-17 22:36:38.115 T:1411     info <general>: script.module.slyguy - HDCP Level (fallback): 0.0
2024-03-18 10:58:30.096 T:494      info <general>: Loading skin file: Settings.xml, load type: KEEP_IN_MEMORY
2024-03-18 10:58:46.929 T:494      info <general>: Loading skin file: SettingsCategory.xml, load type: KEEP_IN_MEMORY
2024-03-18 10:59:46.929 T:494      info <general>: Loading skin file: DialogConfirm.xml, load type: KEEP_IN_MEMORY
2024-03-18 11:00:10.578 T:494      info <general>: Loading skin file: SettingsSystemInfo.xml, load type: KEEP_IN_MEMORY
2024-03-18 11:00:25.103 T:494      info <general>: Loading skin file: /usr/share/kodi/addons/service.osmc.settings/resources/skins/Default/1080i/settings_gui_720.xml, load type: LOAD_ON_GUI_INIT
2024-03-18 11:00:25.245 T:547     error <general>: EXCEPTION: Non-Existent Control 300
2024-03-18 11:00:30.772 T:1808    error <general>: CCurlFile::Exists - <http://www.msftconnecttest.com/connecttest.txt> Failed: Couldn't resolve host name(6)
2024-03-18 11:00:30.950 T:494      info <general>: Loading skin file: /usr/share/kodi/addons/script.module.osmcsetting.networking/resources/skins/Default/1080i/network_gui.xml, load type: LOAD_ON_GUI_INIT
2024-03-18 11:00:50.858 T:1808    error <general>: CCurlFile::Exists - <http://www.w3.org/> Failed: Couldn't resolve host name(6)
2024-03-18 11:00:58.446 T:1815    error <general>: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                                    - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                                   Error Type: <class 'KeyError'>
                                                   Error Contents: 'IPV4'
                                                   Traceback (most recent call last):
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 535, in onAction
                                                       self.update_current_ip_settings(WIRELESS_IP_VALUES)
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 995, in update_current_ip_settings
                                                       self.current_network_config[self.internet_protocol]['Address'] = ip_address
                                                   KeyError: 'IPV4'
                                                   -->End of Python script error report<--
                                                   
2024-03-18 11:01:10.354 T:494      info <general>: Skipped 4 duplicate messages..
2024-03-18 11:01:10.354 T:494      info <general>: Loading skin file: DialogSelect.xml, load type: KEEP_IN_MEMORY
2024-03-18 11:01:37.917 T:1815    error <general>: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                                    - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                                   Error Type: <class 'KeyError'>
                                                   Error Contents: 'IPV4'
                                                   Traceback (most recent call last):
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 535, in onAction
                                                       self.update_current_ip_settings(WIRELESS_IP_VALUES)
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 995, in update_current_ip_settings
                                                       self.current_network_config[self.internet_protocol]['Address'] = ip_address
                                                   KeyError: 'IPV4'
                                                   -->End of Python script error report<--
                                                   
2024-03-18 11:01:53.095 T:1815    error <general>: Skipped 4 duplicate messages..
2024-03-18 11:01:53.095 T:1815    error <general>: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                                    - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                                   Error Type: <class 'KeyError'>
                                                   Error Contents: 'IPV4'
                                                   Traceback (most recent call last):
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 535, in onAction
                                                       self.update_current_ip_settings(WIRELESS_IP_VALUES)
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 995, in update_current_ip_settings
                                                       self.current_network_config[self.internet_protocol]['Address'] = ip_address
                                                   KeyError: 'IPV4'
                                                   -->End of Python script error report<--
                                                   
2024-03-18 11:02:06.063 T:1815    error <general>: Skipped 4 duplicate messages..
2024-03-18 11:02:06.063 T:1815    error <general>: EXCEPTION Thrown (PythonToCppException) : -->Python callback/script returned the following error<--
                                                    - NOTE: IGNORING THIS CAN LEAD TO MEMORY LEAKS!
                                                   Error Type: <class 'KeyError'>
                                                   Error Contents: 'IPV4'
                                                   Traceback (most recent call last):
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 535, in onAction
                                                       self.update_current_ip_settings(WIRELESS_IP_VALUES)
                                                     File "/usr/share/kodi/addons/script.module.osmcsetting.networking/resources/lib/osmcnetworking/networking_gui.py", line 995, in update_current_ip_settings
                                                       self.current_network_config[self.internet_protocol]['Address'] = ip_address
                                                   KeyError: 'IPV4'
                                                   -->End of Python script error report<--

The period in question was the 20-30 mins before 11am. The logs after that are me fiddling about with the UI seeing if I could force a reconnect without a reboot.

Snippets of logs are useless, yes…

All I am demonstrating is that there was no logging during the period in question, unfortunately.

The logs that would be useful would be the journal, not Kodi.

Please try https://paste.osmc.tv/ogodevapij.

Sorry for trying to be cute with the logs as I didn’t want to copy the upload string from the TV.

Mar 18 11:11:18 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-DISCONNECTED bssid=00:eb:d8:f4:42:53 reason=6
Mar 18 11:11:18 pi4 connmand[278]: wlan0 {RX} 42731 packets 9769570 bytes
Mar 18 11:11:18 pi4 wpa_supplicant[242]: wlan0: Trying to associate with SSID '14UH'
Mar 18 11:11:18 pi4 connmand[278]: wlan0 {TX} 6185 packets 643438 bytes
Mar 18 11:11:18 pi4 connmand[278]: wlan0 {update} flags 36867 <UP>
Mar 18 11:11:18 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
Mar 18 11:11:18 pi4 connmand[278]: wlan0 {newlink} index 3 address D8:3A:DD:40:26:2E mtu 1500
Mar 18 11:11:18 pi4 connmand[278]: wlan0 {newlink} index 3 operstate 2 <DOWN>

It’s a network issue.

Looks like one mesh pushes the device off, expecting another to pick it up, but that mesh also does the same.

Is the Pi between two mesh points?

One mesh point is in the next room through an open door. The other is upstairs and on the other side of the house.

That is when the reconnection worked. after disabling and re-enabling the adaptor in the Pi. The failure was at about 10:30:

Mar 18 10:30:14 pi4 wpa_supplicant[242]: wlan0: Trying to associate with SSID '14UH'
Mar 18 10:30:14 pi4 connmand[278]: ipconfig state 2 ipconfig method 1
Mar 18 10:30:16 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Mar 18 10:30:19 pi4 wpa_supplicant[242]: wlan0: Trying to associate with SSID '14UH'
Mar 18 10:30:21 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Mar 18 10:30:24 pi4 wpa_supplicant[242]: wlan0: Trying to associate with SSID '14UH'
Mar 18 10:30:27 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Mar 18 10:30:30 pi4 wpa_supplicant[242]: wlan0: Trying to associate with SSID '14UH'
Mar 18 10:30:32 pi4 wpa_supplicant[242]: wlan0: CTRL-EVENT-ASSOC-REJECT bssid=00:00:00:00:00:00 status_code=16
Mar 18 10:30:32 pi4 connmand[278]: ipconfig state 7 ipconfig method 1
Mar 18 10:31:15 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:32:36 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:36:39 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:41:39 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:46:39 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:51:39 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 10:56:39 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:00:41 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:00:47 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:00:54 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:00 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:06 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:12 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:19 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:25 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:32 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan
Mar 18 11:01:38 pi4 wpa_supplicant[242]: wlan0: Failed to initiate sched scan

At about 11am I started fiddling with the Pi UI to see if I could do a reconnect without a reboot. I must have been successful at about 11:11 which is the section of logs you’ve picked out.

BTW, when you upload the logs to the SD card, where do they get put?
[edit]
I found the logs in /var/tmp/uploadlog.txt
[/edit]

See https://forums.raspberrypi.com/viewtopic.php?t=198104

One user reports interference on the HDMI to be the cause of this.

Hmm. The first link says to change a setting in hostapd in the AP, but I can’t change anything like that in the AP. The AP has very few controls. I can’t even change the channel.

The last link in that thread goes on to say HDMI interference. I can try changing the HDMI port, but I don’t particularly want to change the resolution. I can’t restart the AP until the family is out tomorrow.

Having said all that, it did connect when I stopped and started the Pi WiFi so is not a total failure which the others seem to report.

Hmm. The other port does not appear to be CEC enabled, even after a reboot.

This thread lead me to the answer. The brcmfmac module needed loading with a couple of options. I have put the two lines in question in /etc/rc.local (without the sudo), rebooted the Pi4 and then the WAP and the WiFi reconnected fine after the WAP came back up.

I’ve tried creating a file /etc/modprobe.d/brcmfmac.conf and I have put in it:

options brcmfmac roamoff=1 feature_disable=0x82000

But this did not appear to work. I am not sure how else to get the parameters in without unloading the module first. Can it be done with cheat codes on the kernel boot line?

I can’t test any more today as family is home!

You should be able to set it in cmdline.txt

I did try adding:

brcmfmac.roamoff=1 brcmfmac.feature_disable=0x82000

to the end of the line in cmdline.txt, but the Pi hung on boot. Is that the right format?

Yes if that’s the correct kernel module then that should be the case.

Do you get a panic?
Make sure you haven’t truncated the command line in some way.

I don’t have an answer I fully understand.

I’ve tried the cmdline.txt line again and successfully booted, but the Pi didn’t recover from a WAP restart. I undid that and then tried via /etc/modprobe.d/whatever.conf, rebooted then restarted the WAP and the WiFi recovered this time

I suspect there is something marginal going on here.