#996713 firmware-brcm80211: firmware becomes non-responsive while running as an access point on RPI4

#996713#5
Date:
2021-10-17 17:10:19 UTC
From:
To:
This bug is mostly for documentation purposes.

When running a raspberry pi 4b as an access point, after a random
period of time the on-chip firmware will crash and leave the wireless
driver (brcmfmac) unusable until the chip is reset. The rest of
the kernel is still fine, but the driver is unusable.

Here's the firmware version that's in Debian 11 (bullseye):

[   16.365079] brcmfmac mmc0:0001:1: firmware: direct-loading firmware brcm/brcmfmac43455-sdio.clm_blob
[   16.373443] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Sep 18 2020 02:27:58 version 7.45.221 (3a6d3a0 CY) FWID 01-bbd9282b

Here's one example of the firmware crashing:

Oct 12 17:40:06 wifi1 kernel: [263542.782712] brcmfmac: mmc_submit_one: CMD53 sg block write failed -84
Oct 12 17:40:06 wifi1 kernel: [263542.785401] brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Oct 12 17:40:52 wifi1 kernel: [263589.238359] brcmfmac: brcmf_sdio_hdparse: seq 77: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.678597] brcmfmac: brcmf_sdio_hdparse: seq 240: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.681542] brcmfmac: brcmf_sdio_hdparse: seq 241: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.684591] brcmfmac: brcmf_sdio_hdparse: seq 242: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.687778] brcmfmac: brcmf_sdio_hdparse: seq 252: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.690801] brcmfmac: brcmf_sdio_hdparse: seq 253: max tx seq number error
Oct 12 17:40:54 wifi1 kernel: [263591.693780] brcmfmac: brcmf_sdio_hdparse: seq 254: max tx seq number error
Oct 12 17:41:36 wifi1 kernel: [263633.105406] brcmfmac: brcmf_sdio_hdparse: seq 171: max tx seq number error
Oct 12 17:50:57 wifi1 kernel: [264194.196126] brcmfmac: mmc_submit_one: CMD53 sg block write failed -84
Oct 12 17:50:57 wifi1 kernel: [264194.199127] brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame
Oct 12 17:52:12 wifi1 kernel: [264268.874931] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct 12 17:52:14 wifi1 kernel: [264271.434963] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct 12 17:52:14 wifi1 kernel: [264271.438681] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110

Here's another one:

Oct  9 15:59:31 wifi1 kernel: [1543849.606976] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct  9 15:59:34 wifi1 kernel: [1543852.169907] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct  9 15:59:34 wifi1 kernel: [1543852.173684] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Oct  9 15:59:42 wifi1 kernel: [1543860.103164] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct  9 15:59:44 wifi1 kernel: [1543862.663196] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct  9 15:59:44 wifi1 kernel: [1543862.666950] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
Oct  9 15:59:57 wifi1 kernel: [1543875.207367] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
Oct  9 15:59:59 wifi1 kernel: [1543877.767429] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110

Notice how the crashes happened 3 days apart. The crash prior
to Oct 9th happened a full month before, so I no longer have
logs. I haven't found any kind of pattern in timing.

I'm currently trying a newer Cypress firmware (from unstable), so
we'll see if it also has the same crash.

#996713#10
Date:
2021-10-25 22:00:16 UTC
From:
To:
On Sun, 17 Oct 2021 13:10:19 -0400 Andres Salomon wrote:
[...]
 >
 > I'm currently trying a newer Cypress firmware (from unstable), so
 > we'll see if it also has the same crash.
 >

Same thing with the firmware-brcm80211 20210818-1 in unstable.

Oct 17 12:49:58 wifi1 kernel: [   14.057714] brcmfmac mmc0:0001:1:
firmware: direct-loading firmware brcm/brcmfmac43455-sdio.clm_blob
Oct 17 12:49:58 wifi1 kernel: [   14.065628] brcmfmac:
brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Apr 15 2021 03:03:20
version 7.45.234 (4ca95bb CY) FWID 01-996384e2

[709371.885059] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd:
brcmf_proto_bcdc_msg failed w/status -110
[709374.445137] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd:
brcmf_proto_bcdc_msg failed w/status -110
[709374.448854] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO
failed, -110
[709384.429474] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd:
brcmf_proto_bcdc_msg failed w/status -110

[709386.989536] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd:
brcmf_proto_bcdc_msg failed w/status -110


Now I'll try a 5.14 kernel backport (with the firmware from bullseye).
If it STILL happens, then I'll try and get a patch upstream to detect
this issue and reinit the hardware.

#996713#15
Date:
2021-11-15 08:22:06 UTC
From:
To:
Yesterday on #debian-raspberrypi we had a user running a RPi 3B (not 3B+, so no
5 Ghz band (thx steev!)) using it as an AP, reporting something similar/same:
mentioned this bug report, so I'll log it here.

The first thing I found was:
https://lore.kernel.org/all/fcf95129-cba7-817d-4bfd-8efaf92f957f@gmail.com/

which seems to indicate it's primary a firmware issue (firmware-brcm80211),
but I've found out that there is also a change in the kernel code block
related to this.
I'm not 100% sure as it was a quick scan, but I found this commit:
https://github.com/torvalds/linux/commit/78f0a64f66d4f582987bbe45433374b61c21500f
This code is present in 5.14, but not in 5.10.

Andres: You mentioned bullseye in your initial report, but it didn't have the
usual footer mentioning various program versions and I'm especially interested
in the kernel version. Could you mention that in subsequent reports (if any)?

The user in #debian-raspberrypi was using kernel 5.10.0-9-arm64 on a Bullseye
system. I then suggested to try the firmware-brcm80211 from testing to see
whether that would make a difference.
I'll leave the progress reporting up to the users themselves.

Cheers,
  Diederik

#996713#20
Date:
2021-11-15 09:19:33 UTC
From:
To:
I was originally using 5.10.0-9-arm64 5.10.70-1, and that is what I
tested both firmware-brcm80211 packages with.

I haven't tried earlier 5.10 kernels.

#996713#25
Date:
2022-01-05 00:42:21 UTC
From:
To:
On Mon, 25 Oct 2021 18:00:16 -0400 Andres Salomon wrote:

 >
 >
 > Now I'll try a 5.14 kernel backport (with the firmware from bullseye).
 > If it STILL happens, then I'll try and get a patch upstream to detect
 > this issue and reinit the hardware.
 >
 >


Just an update - shortly after I tried testing the 5.14 kernel, the
microsd card in my pi4 died. While I waited for a new card to arrive, I
also picked up a much faster wifi adapter. So while I'm still using the
brcm80211 chip for our 2.4ghz AP, I have a 5ghz that every other device
in our house except for one is using. So despite still using a 5.10
kernel, I haven't been able to reproduce this because the 2.4ghz wifi
just isn't that busy. Clearly the bug was being triggered by either
multiple 2.4ghz wifi devices, or a lot of 2.4ghz traffic (or both).