0

Question What could cause a only Raspberry Pi3 devices to lose wifi connectivity at 38 minutes after the hour? Raspberry Pi 4 devices with the same configuration are not impacted.

Issue: Raspberry pi 3 devices on the local network lose connection at 38 minutes past the hour. Raspberry pi 4 devices are not impacted. Wired connections are not impacted. I can replicate this by creating a fresh Bookworm Lite image and booting it on any Pi3.

This problem is new as of Bookworm. The Pi3 devices do not disconnect every hour, but when the problem occurs, it is always at 38 minutes past the hour.

In my test setup, I am running two Pi4 and two Pi3. The Pi4 are never impacted. The Pi4 are connected to 5GHz (channel 40, 48) and the Pi3 are connected to 2.4GHz (channel 6). These devices are located in the Netherlands and connected to Unifi access points.

Restarting the NetworkManager.service resolves the problem temporarily.

Possibly Relevant Information

ArchLinux - Network Dies about every hour - This person had a similar issue with reason=16 which indicates a 4-way handshake failure. I've attempted to do this in the wpa_supplicant configuration file, but it did not resolve the problem.

dd-wrt - WiFi loss after some time - This post indicates that the reason=16 (Group key handshake timeout) issue may be related to the key renewal interval. It's not immediately clear how this relates to the issue, but may be relevant. The AP is set to renew keys every 3600 seconds (1 hour) so that may be correlated with the dropouts I see at 38 minutes after the hour. I have not found a way to monitor the key renewal timing on the AP.

What I've Checked:

  • DHCP Lease time is set for 1 day
  • All devices have static IP provided by the DHCP server (Unifi Dream Machine)
  • Tried multiple devices (2x pi3 and 2x pi4)
  • Tried multiple power supplies on the chance it was brown-out related
  • Attempted to assign a bssid directly using the wpa_supplicant configuration file; this did not resolve the problem

wpa_supplicant with assigned bssid:

ctrl_interface=DIR=/var/run/wpa_supplicant GROUP=netdev update_config=1 network={ ssid="Shackleton N" psk="REDACTED" bssid=E0:63:DA:18:43:DB } 

System Information

PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" 

Pi 3 Model: Raspberry Pi 3 Model B Rev 1.2 Pi 4 Model: Raspberry Pi 4 Model B Rev 1.1

Configuration wpa_supplicant.conf - All devices

ctrl_interface=DIR=/var/run/wpa_supplicant GROUP=netdev update_config=1 

NetworkManager preconfigured.nmconnection:

[connection] id=preconfigured uuid=a0aa67dd-3307-4e1c-8cb5-280e8d9469f4 type=wifi timestamp=1722998303 [wifi] mode=infrastructure ssid=Shackleton N [wifi-security] key-mgmt=wpa-psk psk=REDACTED [ipv4] method=auto [ipv6] addr-gen-mode=default method=auto [proxy] 

LOG OUTPUT

Full NetworkManager/wpa_supplicant output:

2024-08-05T12:38:02.334 2633844492 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 │ │2024-08-05T12:38:02.343 2633853589 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD │ │2024-08-05T12:38:02.345 2633855621 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=NL │ │2024-08-05T12:38:02.350 2633860104 NetworkManager.service NetworkManager[568] INFO <info> [1722854282.3494] device (wlan0): supplicant interface state: completed -> disconnected │ │2024-08-05T12:38:02.351 2633862032 NetworkManager.service NetworkManager[568] INFO <info> [1722854282.3495] device (p2p-dev-wlan0): supplicant management interface state: completed -> disconnected │ │2024-08-05T12:38:02.442 2633952728 NetworkManager.service NetworkManager[568] INFO <info> [1722854282.4424] device (wlan0): supplicant interface state: disconnected -> scanning │ │2024-08-05T12:38:02.443 2633953352 NetworkManager.service NetworkManager[568] INFO <info> [1722854282.4426] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> scanning │ │2024-08-05T12:38:03.027 2634537272 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: Trying to associate with SSID 'Shackleton N' │ │2024-08-05T12:38:03.042 2634552174 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.0416] device (wlan0): supplicant interface state: scanning -> associating │ │2024-08-05T12:38:03.042 2634552950 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.0419] device (p2p-dev-wlan0): supplicant management interface state: scanning -> associating │ │2024-08-05T12:38:03.156 2634666316 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: Associated with e0:63:da:18:43:db │ │2024-08-05T12:38:03.156 2634666944 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-CONNECTED - Connection to e0:63:da:18:43:db completed [id=0 id_str=] │ │2024-08-05T12:38:03.157 2634667537 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 │ │2024-08-05T12:38:03.158 2634668476 wpa_supplicant.service wpa_supplicant[571] STATS wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=NL │ │2024-08-05T12:38:03.163 2634673231 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1630] device (wlan0): supplicant interface state: associating -> completed │ │2024-08-05T12:38:03.163 2634673794 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1631] device (p2p-dev-wlan0): supplicant management interface state: associating -> completed │ │2024-08-05T12:38:03.164 2634674129 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1632] device (wlan0): ip:dhcp4: restarting │ │2024-08-05T12:38:03.182 2634692317 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1820] dhcp4 (wlan0): canceled DHCP transaction │ │2024-08-05T12:38:03.182 2634692906 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1822] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds) │ │2024-08-05T12:38:03.183 2634693265 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1823] dhcp4 (wlan0): state changed no lease │ │2024-08-05T12:38:03.183 2634693570 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.1826] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds) │ │2024-08-05T12:38:03.400 2634911011 NetworkManager.service NetworkManager[568] INFO <info> [1722854283.4004] dhcp4 (wlan0): state changed new lease, address=192.168.1.127 

Disconnects:

Aug 03 15:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 15:38:56 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=6 Aug 03 17:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 17:38:06 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=15 Aug 03 18:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 19:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 20:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 21:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 22:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 03 23:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 00:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 02:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 03:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 04:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 04:38:07 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=15 Aug 04 05:38:01 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 05:38:06 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=15 Aug 04 07:38:02 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 08:38:02 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 08:38:06 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=15 Aug 04 09:38:02 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 10:38:02 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 04 12:38:02 office-paperpi wpa_supplicant[563]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 05 09:38:02 office-paperpi wpa_supplicant[388859]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 05 10:38:02 office-paperpi wpa_supplicant[388859]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 05 11:38:02 office-paperpi wpa_supplicant[388859]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 Aug 05 11:38:07 office-paperpi wpa_supplicant[388859]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=15 Aug 05 11:54:00 office-paperpi wpa_supplicant[388859]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=3 locally_generated=1 Aug 05 12:38:02 office-paperpi wpa_supplicant[571]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:63:da:18:43:db reason=16 
10
  • You have posted NO meaningful configuration data. "* All devices have static IP" WHY? HOW? The wpa-supplicant file is meaningless, while NM uses wpa-supplicant it calls it directly. Commented Aug 6, 2024 at 22:44
  • @jsotola Thanks for the advice. I've updated the question to hopefully be more focused. Commented Aug 7, 2024 at 8:54
  • @Milliways Thanks for the tips. I've added the networkmanager configuration and described how the static IPs are set. There's a tip from an arch linux post (see above) that indicates pinning to a BSSID might help. I tried to do that in the supplicant file, but that had no meaningful impact. I gather this needs to happen elsewhere? Commented Aug 7, 2024 at 8:56
  • You do not appear to have set static IP (although why so many Pi users WANT to do so eludes me) - indeed method=auto indicates otherwise. There is ABSOLUTELY no point in fiddling with wpa_supplicant.conf because NM DOES NOT use it. The error probably indicates a timeout/authentication failure. You do not appear to have tried the obvious; checking the Pi4 on 2.4GHz which is the most significant difference. I doubt that you problem has anything to do with the Pi - it is probably your network. The most basic diagnostic is ip a && ip r . Commented Aug 7, 2024 at 11:08
  • 1
    @goldilocks Good catch. The key renewal on the AP is set for everyt 3600 seconds which would help explain why the problem occurs at 38 minutes after the hour. I've set the key renewal rate lower to see if I can trigger a different interval in the logs. Commented Aug 7, 2024 at 14:32

1 Answer 1

1

This problem appears to have been related to the group key handshake timeout. The 38 minute repeatability appears to be linked to the time at which the AP renewed the keys: every 3600 seconds.

Setting a new key renewal interval of 600 seconds and then reverting to 3600 (default) appears to have completely eliminated this issue from all of the impacted devices. Why or how changing the renewal rate affected this problem is completely unknown.

This ddwrt forum post: "RT-AC68U client WiFi loss after some time " led me to try reducing the key issue interval to 10 minutes to see if I could definitively link the problem to the group key. After changing the setting to 100 seconds, the problems vanished; resetting the interval to 3600 does not cause the problem to reoccur.

Any further insight as to why this problem occurred in the first place and how changing the interval resolved the problem would be greatly appreciated.

Start asking to get answers

Find the answer to your question by asking.

Ask question

Explore related questions

See similar questions with these tags.