[BUG] wifi: rtw89: 8922ae: no association until module reload

[BUG] wifi: rtw89: 8922ae: no association until module reload

[Kadir Yavuz Kurt]

Hi Ping-Ke,

I have an RTL8922AE (PCIe) that cannot associate with any AP after the
driver probes at boot. Scanning works and APs are listed, but the
interface never sends an authentication frame. Unloading and reloading
the driver fixes it every time, until the next reboot.

This is 100% reproducible here: 9 consecutive boots recorded in the
journal, 9 failures on the initial probe, 9 successes after a reload.

I was unable to pin down the root cause, so I am reporting the data I
have rather than guessing.


Hardware / software
===================

Board:      Gigabyte X870 AORUS ELITE WIFI7 ICE, BIOS F8
Adapter:    07:00.0 Network controller [0280]: Realtek Semiconductor
            RTL8922AE 802.11be PCIe Wireless Network Adapter
            [10ec:8922] (rev 01)
            Subsystem: [10ec:8922]
chip info:  CID: 71, CV: 2, AID: 6933, ACV: 1, RFE: 1
Firmware:   rtw89/rtw8922a_fw-4.bin, version 0.35.80.3 (8ef4f0cf)
            (linux-firmware 20240318.git3b128b60.0ubuntu3.1)
Distro:     Ubuntu 24.04.5 LTS
Kernels:    7.0.0-42-generic and 6.17.0-23-generic (Ubuntu HWE)
            Both affected, identically.
Userspace:  wpa_supplicant 2:2.10-21ubuntu0.4
            NetworkManager 1.46.0-1ubuntu2.8
AP:         WPA2-PSK (no WPA3/SAE, no PMF), 2.4 GHz ch 11 and 5 GHz
            ch 36, signal ~67-77


Symptom
=======

After boot, wlp7s0 comes up and scans normally. `iw dev wlp7s0 scan`
returns 60 BSSs including the target AP. But wpa_supplicant loops:

    supplicant interface state: disconnected -> scanning
    supplicant interface state: scanning -> disconnected

every ~10 s, and after 25 s NetworkManager gives up:

    Activation: (wifi) association took too long, failing activation
    state change: config -> failed (reason 'ssid-not-found')

The 'ssid-not-found' reason is misleading: the AP is present in scan
results throughout.

The decisive observation is in the kernel log. In the broken state
there is no

    wlp7s0: authenticate with xx:xx:xx:xx:xx:xx

line at all. mac80211 never starts authentication; it does not fail,
it never happens. Immediately after a module reload, the first attempt
goes through cleanly:

    wlp7s0: authenticate with 14:8c:4a:6a:c4:ff (local address=...)
    wlp7s0: authenticated
    wlp7s0: associate with 14:8c:4a:6a:c4:ff (try 1/3)
    wlp7s0: associated


Reproducer
==========

1. Boot the machine.
2. Try to connect to any WPA2 AP. It never associates.
3. Run:
     modprobe -r rtw89_8922ae rtw89_8922a rtw89_pci rtw89_core
     modprobe rtw89_8922ae
4. Connect again. Works immediately, every time.


What does and does not recover the device
=========================================

This is the most useful thing I found. Tested in the broken state,
in this order, in one boot:

  ip link set wlp7s0 down; ip link set wlp7s0 up    -> does NOT help
  rfkill block wifi; rfkill unblock wifi            -> does NOT help
  modprobe -r ... ; modprobe rtw89_8922ae           -> ALWAYS fixes it

So neither the mac80211 start/stop path nor an RF off/on cycle clears
the condition. Only re-running probe does. Whatever goes wrong appears
to be established during the initial probe and to persist across
everything short of a reload.


RF calibration is NOT the cause
===============================

I initially suspected RFK, because 'failed to wait RF IQK' and
'failed to wait RF TSSI' do show up in some boots. That turned out to
be a red herring.

With rtw89_core.debug_mask=0x6 (RFK | RFK_TRACK) I captured three
boots in which every calibration completed successfully and well
inside its budget:

    RF PRE_NTFY takes 0 ms to complete
    RF TXGAPK  takes 5 ms to complete
    RF IQK     takes 23 ms to complete      (budget 84 ms)
    RF TSSI    takes 9 ms to complete
    RF DPK     takes 14 ms to complete
    RF RX_DCK  takes 12 ms to complete

Zero 'failed to wait RF' lines in those three boots -- and the
interface still never associated. So RFK success is not sufficient and
the sporadic RFK timeouts are a separate, non-causal symptom.

'timed out to flush queues' also appears in some, but not all, of the
failing boots, so it does not correlate either.


Timing observation (hypothesis, not established)
================================================

The only systematic difference I can see between the failing probe and
the working one is when it runs relative to Bluetooth initialisation.
The RTL8922AE is a combo part; the BT function enumerates as USB
0bda:8922 and is driven by btusb/btrtl.

At boot (monotonic timestamps, failing probe):

    [ 3.018707] Bluetooth: hci0: RTL: rom_version status=0 version=1
    [ 3.018809] rtw89_8922ae 0000:07:00.0: loaded firmware
                                           rtw89/rtw8922a_fw-4.bin
    [ 3.018864] rtw89_8922ae 0000:07:00.0: enabling device (0000 -> 0003)
    [ 3.019712] Bluetooth: hci0: RTL: loading rtl_bt/rtl8922au_fw.bin
    [ 3.052054] rtw89_8922ae 0000:07:00.0: chip info CID: 71, CV: 2, ...
    [ 3.097814] rtw89_8922ae 0000:07:00.0 wlp7s0: renamed from wlan0
    [ 3.638714] Bluetooth: hci0: RTL: fw version 0x41c0c905

The entire rtw89 probe (3.018 - 3.098) runs inside the BT firmware
download (3.019 - 3.639), starting 1 ms after it.

The working reload, same boot:

    [53.643379] rtw89_8922ae 0000:07:00.0: loaded firmware
                                           rtw89/rtw8922a_fw-4.bin
    [53.675553] rtw89_8922ae 0000:07:00.0: chip info CID: 71, CV: 2, ...

i.e. 50 s after BT finished initialising.

I want to be clear that this is only a timing correlation. I have not
yet tested booting with btusb blacklisted, and I am not claiming the
two are causally related. It is simply the one difference I could find
that is present in every failing case and absent in every working one.


Already ruled out
=================

- ASPM / power save. /etc/modprobe.d/ with
    options rtw89_pci  disable_clkreq=y disable_aspm_l1=y
                       disable_aspm_l1ss=y
    options rtw89_core disable_ps_mode=y
  I verified these are actually in effect by reading
  /sys/module/rtw89_pci/parameters/ and
  /sys/module/rtw89_core/parameters/ (all Y). No change.
  pcie_aspm=off on the kernel command line: no change either.

- Kernel version. 6.17.0-23 and 7.0.0-42 behave identically.

- Firmware load. Clean, no errors, no crash, no SER.

- The AP and the environment. A phone associates with the same AP
  fine; the same machine also fails against a phone hotspot.

- Credentials / WPA3 / PMF. The network is WPA2-PSK with no SAE, and
  the failure is before authentication, so no key material is involved
  yet.

- Regulatory domain. Was country 00 initially; setting it to the
  correct country (TR, DFS-ETSI) made no difference to this problem.


I can provide further information if needed.

Thanks,

------------
K. Yavuz Kurt
k.yavuzkurt1@gmail.com

RE: [BUG] wifi: rtw89: 8922ae: no association until module reload

[Ping-Ke Shih]

Kadir Yavuz Kurt <k.yavuzkurt1@gmail.com> wrote:
> Timing observation (hypothesis, not established)
> ================================================
> 
> The only systematic difference I can see between the failing probe and
> the working one is when it runs relative to Bluetooth initialisation.
> The RTL8922AE is a combo part; the BT function enumerates as USB
> 0bda:8922 and is driven by btusb/btrtl.
> 
> At boot (monotonic timestamps, failing probe):
> 
>     [ 3.018707] Bluetooth: hci0: RTL: rom_version status=0 version=1
>     [ 3.018809] rtw89_8922ae 0000:07:00.0: loaded firmware
>                                            rtw89/rtw8922a_fw-4.bin
>     [ 3.018864] rtw89_8922ae 0000:07:00.0: enabling device (0000 -> 0003)
>     [ 3.019712] Bluetooth: hci0: RTL: loading rtl_bt/rtl8922au_fw.bin
>     [ 3.052054] rtw89_8922ae 0000:07:00.0: chip info CID: 71, CV: 2, ...
>     [ 3.097814] rtw89_8922ae 0000:07:00.0 wlp7s0: renamed from wlan0
>     [ 3.638714] Bluetooth: hci0: RTL: fw version 0x41c0c905
> 
> The entire rtw89 probe (3.018 - 3.098) runs inside the BT firmware
> download (3.019 - 3.639), starting 1 ms after it.

This is a good point. I think you can add rtw89 into blacklist, and
manually load the modules after booting. 

If this works, add a udev rule to delay loading rtw89.

> 
> The working reload, same boot:
> 
>     [53.643379] rtw89_8922ae 0000:07:00.0: loaded firmware
>                                            rtw89/rtw8922a_fw-4.bin
>     [53.675553] rtw89_8922ae 0000:07:00.0: chip info CID: 71, CV: 2, ...
> 
> i.e. 50 s after BT finished initialising.
> 
> I want to be clear that this is only a timing correlation. I have not
> yet tested booting with btusb blacklisted, and I am not claiming the
> two are causally related. It is simply the one difference I could find
> that is present in every failing case and absent in every working one.

RTL8922AE is a WiFi/BT combo card. I think they have interference with
each other when initializing, because they share hardware resource and
race can happen at that time. 

Ping-Ke