rpi400 & rpicm4l wifi connections fail with WPA used

[Jonathan Cave]

linux-raspi
version: 5.15.0.1056.54
series: jammy
repo: main

All wifi connection tests that attempt to connect to secured AP fail when testing this kernel (and other packages upgraded to current proposed set).

checkbox job IDs:
wireless/wireless_connection_wpa_n_np_wlan0
wireless/wireless_connection_wpa_ac_np_wlan0
wireless/wireless_connection_wpa_bg_np_wlan0

checkbox job output including netplan debug and journal output in the attached file

[Juerg Haefliger (juergh)]

https://test-observer.canonical.com/#/debs/38076

[Jonathan Cave (jocave)]

These symptoms have now been reported as being present when testing other artefacts and linked to this bug raised against checkbox: https://github.com/canonical/checkbox/issues/1303

[Paul Larson (pwlars)]

A bug was found and fixed with a recent update to the checkbox test for this that was causing some formatting problems in the netplan yaml. While we're waiting for the packages to update, we reran these tests on rpi400 and cm4l with the previous good version of checkbox and all but the wpa 802.11n failure went away. However the 802.11n one is still very reproducible.

I sshed into one of the failing devices after it was done and was able to get a working wifi connection to that wpa 802.11n AP that we have in the lab manually on one attempt, then removed the config and I was able to get the checkbox test to pass in isolation one time. After that though, I wasn't able to make it pass again so the passes seem to be a fluke.

Checking dmesg after the failed runs, I found a lot of warning traces that seem to be related to the wifi driver:
https://paste.ubuntu.com/p/5XbRdGP4Cf/

[Juerg Haefliger (juergh)]

[ 580.033621] ------------[ cut here ]------------
[ 580.033645] WARNING: CPU: 1 PID: 7 at net/wireless/sme.c:756 __cfg80211_connect_result+0x2c8/0x2f0 [cfg80211]
[ 580.033881] Modules linked in: cmac algif_hash algif_skcipher af_alg bnep hci_uart btqca btrtl btbcm btintel btsdio bluetooth ecdh_generic ecc bcm2835_codec(C) bcm2835_v4l2(C) brcmfmac bcm2835_isp(C) v4l2_mem2mem bcm2835_mmal_vchiq(C) brcmutil videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops cfg80211 snd_bcm2835(C) videobuf2_v4l2 raspberrypi_hwmon videobuf2_common snd_pcm videodev snd_timer snd mc vc_sm_cma(C) bcm2835_gpiomem rpivid_mem uio_pdrv_genirq nvmem_rmem uio dm_multipath sch_fq_codel drm ip_tables x_tables autofs4 btrfs blake2b_generic zstd_compress raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor xor_neon raid6_pq libcrc32c raid1 raid0 uas usb_storage multipath linear spidev dwc2 i2c_bcm2835 crct10dif_ce roles udc_core spi_bcm2835 phy_generic aes_arm64
[ 580.034199] CPU: 1 PID: 7 Comm: kworker/u8:0 Tainted: G C 5.15.0-1005-raspi #5-Ubuntu
[ 580.034212] Hardware name: Raspberry Pi Compute Module 4 Rev 1.0 (DT)
[ 580.034220] Workqueue: cfg80211 cfg80211_event_work [cfg80211]
[ 580.034390] pstate: 80400005 (Nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[ 580.034402] pc : __cfg80211_connect_result+0x2c8/0x2f0 [cfg80211]
[ 580.034561] lr : __cfg80211_connect_result+0x29c/0x2f0 [cfg80211]
[ 580.034715] sp : ffff80000805bcb0
[ 580.034720] x29: ffff80000805bcb0 x28: 0000000000000000 x27: 0000000000000000
[ 580.034740] x26: ffffaf1baffd6430 x25: dead000000000100 x24: dead000000000122
[ 580.034759] x23: ffff0dc6c4a820e0 x22: ffff80000805bce8 x21: ffff0dc6c8639000
[ 580.034776] x20: ffff0dc6c4a82008 x19: ffff0dc6c28bea18 x18: 0000000000000000
[ 580.034794] x17: 002f3262005e4342 x16: ffffaf1bc2009030 x15: 0084010102f25000
[ 580.034812] x14: ffffffffffffffff x13: 0000000000000000 x12: c47c36f6eb500001
[ 580.034829] x11: 7f7f7f7f7f7f7f7f x10: fefefefefefefeff x9 : ffffaf1bc200908c
[ 580.034846] x8 : 0000000000000001 x7 : 0000000000000000 x6 : 0000000000000012
[ 580.034863] x5 : 0000000000000000 x4 : ffffaf1bc2afe2f8 x3 : 0000000000000000
[ 580.034880] x2 : 0000000000000030 x1 : 0000000100000000 x0 : 0000000000000000
[ 580.034898] Call trace:
[ 580.034903] __cfg80211_connect_result+0x2c8/0x2f0 [cfg80211]
[ 580.035058] cfg80211_process_wdev_events+0x148/0x1d4 [cfg80211]
[ 580.035213] cfg80211_process_rdev_events+0x3c/0x5c [cfg80211]
[ 580.035367] cfg80211_event_work+0x34/0x50 [cfg80211]
[ 580.035521] process_one_work+0x204/0x4c0
[ 580.035541] worker_thread+0x144/0x470
[ 580.035552] kthread+0x12c/0x140
[ 580.035562] ret_from_fork+0x10/0x20
[ 580.035574] ---[ end trace 555dd23be7074327 ]---

[Juerg Haefliger (juergh)]

I cannot reproduce this locally so far, so seems to be specific to the lab network. Apparently this issue has been there form the beginning (of jammy), see trace in the previous comment which is from the GA kernel. So not per-se a regression in the latest kernel.

[Juerg Haefliger (juergh)]

$ checkbox.checkbox-cli
$PROVIDERPATH is defined, so following provider sources are ignored ['/home/ubuntu/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
=========================[ Resume Incomplete Session ]==========================
There are 0 incomplete sessions that might be resumed
Preparing...
There were no tests to select from!
ubuntu@rpi-cm4-rev1d0-0643:~$ checkbox.checkbox-cli
$PROVIDERPATH is defined, so following provider sources are ignored ['/home/ubuntu/.local/share/plainbox-providers-1', '/var/tmp/checkbox-providers-develop']
=========================[ Resume Incomplete Session ]==========================
There are 0 incomplete sessions that might be resumed
Preparing...
============[ Bootstrap com.canonical.certification::device (1/1) ]=============
Saving manifest to /var/tmp/checkbox-ng/machine-manifest.json
Reports will be saved to: /home/ubuntu/.local/share/checkbox-ng
==============[ Running job 1 / 2. Estimated time left: 0:00:17 ]===============
-----[ Identify what service is managing each physical network interface ]------
ID: com.canonical.certification::net_if_management
Category: com.canonical.plainbox::uncategorised
... 8< -------------------------------------------------------------------------
device: eth0
managed_by: networkd
master_mode_managed_by: not-applicable

device: wlan0
managed_by: networkd
master_mode_managed_by: unspecified

------------------------------------------------------------------------- >8 ---
Outcome: job passed
==============[ Running job 2 / 2. Estimated time left: 0:00:15 ]===============
-----[ Connect to WPA-encrypted 802.11n Wi-Fi network on wlan0 - netplan ]------
ID: com.canonical.certification::wireless/wireless_connection_wpa_n_np_wlan0
Category: com.canonical.plainbox::wireless
... 8< -------------------------------------------------------------------------
Interface wlan0 using module brcmfmac
  Parameters:
    alternative_fw_path:
    debug: 0
    roamoff: 0

Checking kernel ring buffer for brcmfmac messages:
kern :debug : [Wed Jun 26 07:10:08 2024] brcmfmac: F1 signature read @0x18000000=0x15264345
kern :info : [Wed Jun 26 07:10:08 2024] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
kern :info : [Wed Jun 26 07:10:08 2024] usbcore: registered new interface driver brcmfmac
kern :warn : [Wed Jun 26 07:10:08 2024] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-compute-module.bin failed with error -2
kern :info : [Wed Jun 26 07:10:08 2024] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
kern :info : [Wed Jun 26 07:10:08 2024] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
kern :info : [Wed Jun 26 07:10:08 2024] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
kern :info : [Wed Jun 26 07:10:09 2024] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
kern :info : [Wed Jun 26 07:43:40 2024] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled

## Backup any existing netplan configuration files
Clea...

[Paul Larson (pwlars)]

I haven't heard yet what could have changed, but I think something may have been fixed regarding this AP in the lab in the last day or two. I was hitting similar problems on another set of devices with a different kernel now, but I'm not able to reproduce those anymore. So I decided to go back and retry this 5.15 kernel again on cm4l also. I'm not able to reproduce this anymore either.
So I think it must have been some issue with the AP