Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ZeroW: Wifi: no longer accessible and kernel stack traces when the AP reboots (pi4 based) #3352

Open
msperl opened this issue Nov 27, 2019 · 2 comments
Open

ZeroW: Wifi: no longer accessible and kernel stack traces when the AP reboots (pi4 based) #3352

msperl opened this issue Nov 27, 2019 · 2 comments

Comments

@msperl
Copy link
Contributor

msperl commented Nov 27, 2019

I have a problem, that may be related to #3114, but this time on a Raspberry Pi Zero.

Basic setup:

  • raspberry pi 4 as AP (on board wifi - member of a bridge)
  • raspberry zero w in client mode (onboard wifi) connected to Pi4 above

both: stock 4.19.75+ updated from 2019-09-26-raspbian-buster-lite.zip to latest

Steps to reproduce:

  • reboot raspberry pi 4
  • Afterwards the raspberry pi zero is not reachable any longer (8 hours)
  • zero requires hard reset.

In the syslog of the zero I can find:

Nov 26 22:51:02 area1 kernel: [ 1212.546956] ------------[ cut here ]------------
Nov 26 22:51:02 area1 kernel: [ 1212.548224] WARNING: CPU: 0 PID: 91 at net/wireless/sme.c:752 __cfg80211_connect_result+0x388/0x400 [cfg80211]
Nov 26 22:51:02 area1 kernel: [ 1212.548290] Modules linked in: dm_mod 8021q garp stp llc bmp280_spi bmp280_i2c bmp280 industrialio brcmfmac brcmutil sha256_generic raspberrypi_hwmon hwmon cfg80211 rfkill bcm2835_codec(C) bcm2835_v4l2(C) v4l2_mem2mem v4l2_common bcm2835_mmal_vchiq(C) videobuf2_vmalloc videobuf2_dma_contig videobuf2_memops videobuf2_v4l2 videobuf2_common videodev vc_sm_cma(C) media uio_pdrv_genirq fixed uio spidev i2c_dev spi_bcm2835 i2c_bcm2835 ip_tables x_tables ipv6
Nov 26 22:51:02 area1 kernel: [ 1212.548502] CPU: 0 PID: 91 Comm: kworker/u2:2 Tainted: G         C        4.19.75+ #1270
Nov 26 22:51:02 area1 kernel: [ 1212.548509] Hardware name: BCM2835
Nov 26 22:51:02 area1 kernel: [ 1212.549738] Workqueue: cfg80211 cfg80211_event_work [cfg80211]
Nov 26 22:51:02 area1 kernel: [ 1212.549818] [<c0017f54>] (unwind_backtrace) from [<c0014e9c>] (show_stack+0x20/0x24)
Nov 26 22:51:02 area1 kernel: [ 1212.549853] [<c0014e9c>] (show_stack) from [<c06ba0b0>] (dump_stack+0x20/0x28)
Nov 26 22:51:02 area1 kernel: [ 1212.549889] [<c06ba0b0>] (dump_stack) from [<c00244f0>] (__warn+0xf4/0x11c)
Nov 26 22:51:02 area1 kernel: [ 1212.549915] [<c00244f0>] (__warn) from [<c0024648>] (warn_slowpath_null+0x4c/0x58)
Nov 26 22:51:02 area1 kernel: [ 1212.551228] [<c0024648>] (warn_slowpath_null) from [<bf26612c>] (__cfg80211_connect_result+0x388/0x400 [cfg80211])
Nov 26 22:51:02 area1 kernel: [ 1212.553733] [<bf26612c>] (__cfg80211_connect_result [cfg80211]) from [<bf23a010>] (cfg80211_process_wdev_events+0x13c/0x1c8 [cfg80211])
Nov 26 22:51:02 area1 kernel: [ 1212.556355] [<bf23a010>] (cfg80211_process_wdev_events [cfg80211]) from [<bf23a0dc>] (cfg80211_process_rdev_events+0x40/0x9c [cfg80211])
Nov 26 22:51:02 area1 kernel: [ 1212.558633] [<bf23a0dc>] (cfg80211_process_rdev_events [cfg80211]) from [<bf234258>] (cfg80211_event_work+0x24/0x2c [cfg80211])
Nov 26 22:51:02 area1 kernel: [ 1212.559810] [<bf234258>] (cfg80211_event_work [cfg80211]) from [<c003d278>] (process_one_work+0x130/0x3a0)
Nov 26 22:51:02 area1 kernel: [ 1212.559851] [<c003d278>] (process_one_work) from [<c003d51c>] (worker_thread+0x34/0x530)
Nov 26 22:51:02 area1 kernel: [ 1212.559875] [<c003d51c>] (worker_thread) from [<c0043020>] (kthread+0x11c/0x158)
Nov 26 22:51:02 area1 kernel: [ 1212.559898] [<c0043020>] (kthread) from [<c00090ac>] (ret_from_fork+0x14/0x28)
Nov 26 22:51:02 area1 kernel: [ 1212.559909] Exception stack(0xd6b05fb0 to 0xd6b05ff8)
Nov 26 22:51:02 area1 kernel: [ 1212.559923] 5fa0:                                     00000000 00000000 00000000 00000000
Nov 26 22:51:02 area1 kernel: [ 1212.559937] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Nov 26 22:51:02 area1 kernel: [ 1212.559950] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
Nov 26 22:51:02 area1 kernel: [ 1212.559964] ---[ end trace bbe1eeb5746b511d ]---

So my guess is that the reconnect is somehow triggering this.

An upgrade to 4.19.85+ using rpi-update on the zero also shows this behaviour.
After a reboot of the rpi4 AP the zero is still no longer accessible (but I can not reboot it either)

The hostapd logs of the PI4 after the Reboot of zero:

Nov 27 05:44:04 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 05:44:04 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d RADIUS: starting accounting session 56904D34A74A3AB4
Nov 27 05:44:04 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d WPA: pairwise key handshake completed (RSN)
Nov 27 07:55:05 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:55:39 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:55:39 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d RADIUS: starting accounting session C5F117BF5204156D
Nov 27 07:55:39 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d WPA: pairwise key handshake completed (RSN)

So here it is connecting

Logs after the reboot of the Pi4 (07:57:39):

Nov 27 07:57:52 gateway hostapd[810]: Configuration file: /etc/hostapd/hostapd-wlan0.conf
Nov 27 07:57:52 gateway hostapd[810]: wlan0: interface state UNINITIALIZED->COUNTRY_UPDATE
Nov 27 07:57:58 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:13 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:15 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:19 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:21 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:25 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:26 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:27 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:28 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
...
Nov 27 07:58:28 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:28 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
...
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:32 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:35 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: associated
Nov 27 07:58:35 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d RADIUS: starting accounting session D2D2C9F1EB7626D6
Nov 27 07:58:35 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d WPA: pairwise key handshake completed (RSN)
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
Nov 27 07:58:38 gateway hostapd: wlan0: STA b8:27:eb:96:4c:9d IEEE 802.11: disassociated
<stopped here>

No longer connected or pingable...
@msperl msperl changed the title ZeroW: Wifi: kernel stack traces when the AP vanishes ZeroW: Wifi: no longer accessible and kernel stack traces when the AP reboots (pi4 based) Nov 27, 2019
@msperl
Copy link
Contributor Author

msperl commented Dec 1, 2019

Actually after lots of testing (also with other USB wifi sticks on the AP side) is that this exception occurs when on the AP side the wifi card is member of a bridge with STP enabled.

On the AP a simple:

sudo brctl stp br0 off

and everything is solved and the error message does not occur any longer.
But when I reenable stp and reboot the Pi4-AP then the exception occurs on the Zero...

So in summary:

  • brcm WIFI is not the only wifi one impacted (on the AP point side)
  • disable STP on AP is a workaround - a bug still seems to exist in the kernel itself on the client side

@pelwell
Copy link
Contributor

pelwell commented Dec 1, 2019 •
edited
Loading

Thank you for that piece of detective work. It gives us a potential route to reproducing the issue, and it gives others a workaround.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@msperl @pelwell