roaming issues on a residential LAN with multiple APs

roaming issues on a residential LAN with multiple APs

[Daniel Barter]

I recently added a second wireless AP to my home LAN. All devices
except a laptop running iwd are able to roam successfully between the
two APs.

Laptop is running iwd 2.8 with the following config:

$ cat /etc/iwd/main.conf
[General]
RoamRetryInterval=10
UseDefaultInterface=false

 Running it with --developer and --debug flags, I am able to see both
APs using debug wlan0 get-networks:

<SSID>
      40:b0:76:ad:6f:2e  -61   5600    3192      000000
      40:b0:76:22:27:de  -67   5280    2128      000000
      40:b0:76:ad:6f:2a  -60   2447    1227      000000
      40:b0:76:22:27:da  -72   2437    306       000000

moreover, I am able so successfully roam from one to the other
manually by running debug wlan0 roam <BSSID>, which runs
src/station.c:station_force_roam(). Also, disconnecting and
reconnecting manually, iwd will connected to the best AP. The issue
seems to be that iwd is not automatically roaming when signal gets
bad. The only error I am seeing in the logs is

iwd[32079]: src/station.c:station_early_neighbor_report_cb() ifindex:
5, error: -110(Connection timed out)

which seems like it could be related.

apologies if this is the wrong place for asking such a question,
presumably I am just missing something obvious. Happy to provide any
more information which would help diagnose the issue.

- Daniel

Re: roaming issues on a residential LAN with multiple APs

[Denis Kenzior]

Hi Daniel,

> 
> iwd[32079]: src/station.c:station_early_neighbor_report_cb() ifindex:
> 5, error: -110(Connection timed out)

Shouldn't preclude a roam, just won't use the neighbor report information.  Hard 
to say anything more without seeing logs.  It could be that the roaming 
threshold is never reached, or your kernel driver isn't reporting CQM 
notifications properly, or many other reasons.  What hardware / driver is it? 
Kernel version?

https://iwd.wiki.kernel.org/debugging

Regards,
-Denis

Re: roaming issues on a residential LAN with multiple APs

[Daniel Barter]

here are my logs:
https://gist.github.com/danielbarter/65ddf6aee78546a0e8f9e2d3af65308c

notice that this is a mix of iwd 2.4 (my distro default) and iwd 2.8.

Default roaming thresholds are in the 70s right? I am getting down to
-90dBm without a roam happening.

kernel version is 6.6.0.

here is everything lspci will tell me about the wifi card:

aa:00.0 Network controller: Intel Corporation Wi-Fi 6
AX210/AX211/AX411 160MHz (rev 1a)
    Subsystem: Intel Corporation Wi-Fi 6 AX210 160MHz
    Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop-
ParErr- Stepping- SERR- FastB2B- DisINTx+
    Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
<TAbort- <MAbort- >SERR- <PERR- INTx-
    Latency: 0, Cache Line Size: 64 bytes
    Interrupt: pin A routed to IRQ 17
    IOMMU group: 18
    Region 0: Memory at 7a200000 (64-bit, non-prefetchable) [size=16K]
    Capabilities: [c8] Power Management version 3
        Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA
PME(D0+,D1-,D2-,D3hot+,D3cold+)
        Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
    Capabilities: [d0] MSI: Enable- Count=1/1 Maskable- 64bit+
        Address: 0000000000000000  Data: 0000
    Capabilities: [40] Express (v2) Endpoint, MSI 00
        DevCap:    MaxPayload 128 bytes, PhantFunc 0, Latency L0s
<512ns, L1 unlimited
            ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset+ SlotPowerLimit 0W
        DevCtl:    CorrErr- NonFatalErr- FatalErr- UnsupReq-
            RlxdOrd+ ExtTag- PhantFunc- AuxPwr+ NoSnoop+ FLReset-
            MaxPayload 128 bytes, MaxReadReq 128 bytes
        DevSta:    CorrErr- NonFatalErr- FatalErr- UnsupReq- AuxPwr+ TransPend-
        LnkCap:    Port #0, Speed 5GT/s, Width x1, ASPM L1, Exit Latency L1 <8us
            ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp+
        LnkCtl:    ASPM L1 Enabled; RCB 64 bytes, Disabled- CommClk+
            ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
        LnkSta:    Speed 5GT/s, Width x1
            TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
        DevCap2: Completion Timeout: Range B, TimeoutDis+ NROPrPrP- LTR+
             10BitTagComp- 10BitTagReq- OBFF Via WAKE#, ExtFmt- EETLPPrefix-
             EmergencyPowerReduction Not Supported, EmergencyPowerReductionInit-
             FRS- TPHComp- ExtTPHComp-
             AtomicOpsCap: 32bit- 64bit- 128bitCAS-
        DevCtl2: Completion Timeout: 16ms to 55ms, TimeoutDis- LTR+
10BitTagReq- OBFF Disabled,
             AtomicOpsCtl: ReqEn-
        LnkCap2: Supported Link Speeds: 2.5-5GT/s, Crosslink- Retimer-
2Retimers- DRS-
        LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
             Transmit Margin: Normal Operating Range,
EnterModifiedCompliance- ComplianceSOS-
             Compliance Preset/De-emphasis: -6dB de-emphasis, 0dB preshoot
        LnkSta2: Current De-emphasis Level: -6dB,
EqualizationComplete- EqualizationPhase1-
             EqualizationPhase2- EqualizationPhase3- LinkEqualizationRequest-
             Retimer- 2Retimers- CrosslinkRes: unsupported
    Capabilities: [80] MSI-X: Enable+ Count=16 Masked-
        Vector table: BAR=0 offset=00002000
        PBA: BAR=0 offset=00003000
    Capabilities: [100 v1] Advanced Error Reporting
        UESta:    DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
        UEMsk:    DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt-
RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
        UESvrt:    DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt-
RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
        CESta:    RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr-
        CEMsk:    RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr+
        AERCap:    First Error Pointer: 00, ECRCGenCap- ECRCGenEn-
ECRCChkCap- ECRCChkEn-
            MultHdrRecCap- MultHdrRecEn- TLPPfxPres- HdrLogCap-
        HeaderLog: 00000000 00000000 00000000 00000000
    Capabilities: [14c v1] Latency Tolerance Reporting
        Max snoop latency: 3145728ns
        Max no snoop latency: 3145728ns
    Capabilities: [154 v1] L1 PM Substates
        L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+
L1_PM_Substates+
              PortCommonModeRestoreTime=30us PortTPowerOnTime=18us
        L1SubCtl1: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+
               T_CommonMode=0us LTR1.2_Threshold=96256ns
        L1SubCtl2: T_PwrOn=44us
    Kernel driver in use: iwlwifi
    Kernel modules: iwlwifi


On Sat, Nov 25, 2023 at 3:29 PM Denis Kenzior <denkenz@gmail.com> wrote:
>
> Hi Daniel,
>
> >
> > iwd[32079]: src/station.c:station_early_neighbor_report_cb() ifindex:
> > 5, error: -110(Connection timed out)
>
> Shouldn't preclude a roam, just won't use the neighbor report information.  Hard
> to say anything more without seeing logs.  It could be that the roaming
> threshold is never reached, or your kernel driver isn't reporting CQM
> notifications properly, or many other reasons.  What hardware / driver is it?
> Kernel version?
>
> https://iwd.wiki.kernel.org/debugging
>
> Regards,
> -Denis

Re: roaming issues on a residential LAN with multiple APs

[Denis Kenzior]

Hi Daniel,

On 11/25/23 18:32, Daniel Barter wrote:
> here are my logs:
> https://gist.github.com/danielbarter/65ddf6aee78546a0e8f9e2d3af65308c
> 
> notice that this is a mix of iwd 2.4 (my distro default) and iwd 2.8.
> 
> Default roaming thresholds are in the 70s right? I am getting down to
> -90dBm without a roam happening.

Default thresholds are -70 db for 2.4 Ghz and -76 for 5Ghz.

I'm not seeing any CQM events in your log, except for this one:

Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() MLME 
notification Notify CQM(64)
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event() Beacon lost event
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() MLME 
notification Notify CQM(64)
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event() Beacon lost event
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_link_notify() event 16 on 
ifindex 3
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() MLME 
notification Del Station(20)
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() MLME 
notification Deauthenticate(39)
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_deauthenticate_event()
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() MLME 
notification Disconnect(48)
Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_disconnect_event()
Nov 24 16:34:15 jasper iwd[768]: Received Deauthentication event, reason: 4, 
from_ap: false
Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_disconnect_event() 3
Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_disassociated() 3
Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_reset_connection_state() 3
Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_roam_state_clear() 3
Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_enter_state() Old State: 
connected, new state: disconnected

Basically a lost-beacon event comes in (twice for some reason) and we're 
disconnected almost instantly after that.  There's no other CQM events that 
would indicate low signal strength where iwd can actually take some action.  Try 
setting a more aggressive roam threshold and see if that helps?  man 5 
iwd.config, RoamThreshold and RoamThreshold5G.

> 
> kernel version is 6.6.0.
> 

It could also be the kernel folks made some change that broke this. For example, 
this looks to be touching the general area:

https://git.kernel.org/pub/scm/linux/kernel/git/wireless/wireless-next.git/commit/?id=37c20b2effe987b806c8de6d12978e4ffeff026f

Try reverting or using a version prior to that commit?

Regards,
-Denis

Re: roaming issues on a residential LAN with multiple APs

[James Prestwood]

Hi Daniel,

On 11/26/23 21:00, Denis Kenzior wrote:
> Hi Daniel,
>
> On 11/25/23 18:32, Daniel Barter wrote:
>> here are my logs:
>> https://gist.github.com/danielbarter/65ddf6aee78546a0e8f9e2d3af65308c
>>
>> notice that this is a mix of iwd 2.4 (my distro default) and iwd 2.8.
>>
>> Default roaming thresholds are in the 70s right? I am getting down to
>> -90dBm without a roam happening.
>
> Default thresholds are -70 db for 2.4 Ghz and -76 for 5Ghz.
>
> I'm not seeing any CQM events in your log, except for this one:
>
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() 
> MLME notification Notify CQM(64)
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event() 
> Beacon lost event
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() 
> MLME notification Notify CQM(64)
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event() 
> Beacon lost event
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_link_notify() 
> event 16 on ifindex 3
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() 
> MLME notification Del Station(20)
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() 
> MLME notification Deauthenticate(39)
> Nov 24 16:34:15 jasper iwd[768]: 
> src/netdev.c:netdev_deauthenticate_event()
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify() 
> MLME notification Disconnect(48)
> Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_disconnect_event()
> Nov 24 16:34:15 jasper iwd[768]: Received Deauthentication event, 
> reason: 4, from_ap: false
> Nov 24 16:34:15 jasper iwd[768]: 
> src/station.c:station_disconnect_event() 3
> Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_disassociated() 3
> Nov 24 16:34:15 jasper iwd[768]: 
> src/station.c:station_reset_connection_state() 3
> Nov 24 16:34:15 jasper iwd[768]: 
> src/station.c:station_roam_state_clear() 3
> Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_enter_state() 
> Old State: connected, new state: disconnected
>
> Basically a lost-beacon event comes in (twice for some reason) and 
> we're disconnected almost instantly after that.  There's no other CQM 
> events that would indicate low signal strength where iwd can actually 
> take some action.  Try setting a more aggressive roam threshold and 
> see if that helps?  man 5 iwd.config, RoamThreshold and RoamThreshold5G.
>
>>
>> kernel version is 6.6.0.
>>
>
> It could also be the kernel folks made some change that broke this. 
> For example, this looks to be touching the general area:
>
> https://git.kernel.org/pub/scm/linux/kernel/git/wireless/wireless-next.git/commit/?id=37c20b2effe987b806c8de6d12978e4ffeff026f 
>
>
> Try reverting or using a version prior to that commit?

It does appear _something_ is wrong with QCM notifications in the 
kernel. There was an RFC fix with one user commenting that roaming in 
wpa_supplicant is broken as of 6.1. I am able to roam fine on ath11k 
with a stock 6.2 Ubuntu kernel so not sure if its only some drivers or what.

https://lore.kernel.org/linux-wireless/20231106231715.3a506ac2dadb.Ie774b85b9d4ff934a1236e77096cb9c6c9fe6561@changeid/

Thanks,

James

Re: roaming issues on a residential LAN with multiple APs

[Daniel Barter]

Thanks James, that does seem like it is related.

I have done a few more tests on the machine (booting from various
nixos iso images):

6.1, iwd: no roaming
6.1, wpa_supplicant: no roaming
6.2, wpa_supplicant: no roaming
6.2, iwd: no roaming
6.6, iwd: no roaming

i have a Debian-12, 6.1 machine with the same network card running
wpa_supplicant that is able to roam, which suggests it may be some
issue with how the kernel is configured.

here is some dmesg output if in case it is useful:

$ dmesg | grep wifi
[    3.113334] iwlwifi 0000:aa:00.0: enabling device (0000 -> 0002)
[    3.130735] iwlwifi 0000:aa:00.0: Detected crf-id 0x400410, cnv-id
0x400410 wfpm id 0x80000000
[    3.130992] iwlwifi 0000:aa:00.0: PCI dev 2725/0024, rev=0x420, rfid=0x10d000
[    3.180360] iwlwifi 0000:aa:00.0: api flags index 2 larger than
supported by driver
[    3.180388] iwlwifi 0000:aa:00.0: TLV_FW_FSEQ_VERSION: FSEQ Version: 0.0.2.41
[    3.180877] iwlwifi 0000:aa:00.0: loaded firmware version
83.e8f84e98.0 ty-a0-gf-a0-83.ucode op_mode iwlmvm
[    3.586622] iwlwifi 0000:aa:00.0: Detected Intel(R) Wi-Fi 6 AX210
160MHz, REV=0x420
[    3.594294] iwlwifi 0000:aa:00.0: WRT: Invalid buffer destination
[    3.753298] iwlwifi 0000:aa:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    3.753319] iwlwifi 0000:aa:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    3.753332] iwlwifi 0000:aa:00.0: WFPM_AUTH_KEY_0: 0x90
[    3.753343] iwlwifi 0000:aa:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
[    3.754727] iwlwifi 0000:aa:00.0: loaded PNVM version 181407b3
[    3.770223] iwlwifi 0000:aa:00.0: Detected RF GF, rfid=0x10d000
[    3.840925] iwlwifi 0000:aa:00.0: base HW address: f4:7b:09:9c:04:3c
[    3.882078] iwlwifi 0000:aa:00.0: WRT: Invalid buffer destination
[    4.041703] iwlwifi 0000:aa:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    4.041789] iwlwifi 0000:aa:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    4.041834] iwlwifi 0000:aa:00.0: WFPM_AUTH_KEY_0: 0x90
[    4.041847] iwlwifi 0000:aa:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0
[    4.148311] iwlwifi 0000:aa:00.0: Registered PHC clock:
iwlwifi-PTP, with index: 0
[    5.616569] iwlwifi 0000:aa:00.0: WRT: Invalid buffer destination
[    5.786287] iwlwifi 0000:aa:00.0: WFPM_UMAC_PD_NOTIFICATION: 0x20
[    5.786351] iwlwifi 0000:aa:00.0: WFPM_LMAC2_PD_NOTIFICATION: 0x1f
[    5.786364] iwlwifi 0000:aa:00.0: WFPM_AUTH_KEY_0: 0x90
[    5.786382] iwlwifi 0000:aa:00.0: CNVI_SCU_SEQ_DATA_DW9: 0x0






On Wed, Nov 29, 2023 at 4:49 AM James Prestwood <prestwoj@gmail.com> wrote:
>
> Hi Daniel,
>
> On 11/26/23 21:00, Denis Kenzior wrote:
> > Hi Daniel,
> >
> > On 11/25/23 18:32, Daniel Barter wrote:
> >> here are my logs:
> >> https://gist.github.com/danielbarter/65ddf6aee78546a0e8f9e2d3af65308c
> >>
> >> notice that this is a mix of iwd 2.4 (my distro default) and iwd 2.8.
> >>
> >> Default roaming thresholds are in the 70s right? I am getting down to
> >> -90dBm without a roam happening.
> >
> > Default thresholds are -70 db for 2.4 Ghz and -76 for 5Ghz.
> >
> > I'm not seeing any CQM events in your log, except for this one:
> >
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify()
> > MLME notification Notify CQM(64)
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event()
> > Beacon lost event
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify()
> > MLME notification Notify CQM(64)
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_cqm_event()
> > Beacon lost event
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_link_notify()
> > event 16 on ifindex 3
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify()
> > MLME notification Del Station(20)
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify()
> > MLME notification Deauthenticate(39)
> > Nov 24 16:34:15 jasper iwd[768]:
> > src/netdev.c:netdev_deauthenticate_event()
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_mlme_notify()
> > MLME notification Disconnect(48)
> > Nov 24 16:34:15 jasper iwd[768]: src/netdev.c:netdev_disconnect_event()
> > Nov 24 16:34:15 jasper iwd[768]: Received Deauthentication event,
> > reason: 4, from_ap: false
> > Nov 24 16:34:15 jasper iwd[768]:
> > src/station.c:station_disconnect_event() 3
> > Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_disassociated() 3
> > Nov 24 16:34:15 jasper iwd[768]:
> > src/station.c:station_reset_connection_state() 3
> > Nov 24 16:34:15 jasper iwd[768]:
> > src/station.c:station_roam_state_clear() 3
> > Nov 24 16:34:15 jasper iwd[768]: src/station.c:station_enter_state()
> > Old State: connected, new state: disconnected
> >
> > Basically a lost-beacon event comes in (twice for some reason) and
> > we're disconnected almost instantly after that.  There's no other CQM
> > events that would indicate low signal strength where iwd can actually
> > take some action.  Try setting a more aggressive roam threshold and
> > see if that helps?  man 5 iwd.config, RoamThreshold and RoamThreshold5G.
> >
> >>
> >> kernel version is 6.6.0.
> >>
> >
> > It could also be the kernel folks made some change that broke this.
> > For example, this looks to be touching the general area:
> >
> > https://git.kernel.org/pub/scm/linux/kernel/git/wireless/wireless-next.git/commit/?id=37c20b2effe987b806c8de6d12978e4ffeff026f
> >
> >
> > Try reverting or using a version prior to that commit?
>
> It does appear _something_ is wrong with QCM notifications in the
> kernel. There was an RFC fix with one user commenting that roaming in
> wpa_supplicant is broken as of 6.1. I am able to roam fine on ath11k
> with a stock 6.2 Ubuntu kernel so not sure if its only some drivers or what.
>
> https://lore.kernel.org/linux-wireless/20231106231715.3a506ac2dadb.Ie774b85b9d4ff934a1236e77096cb9c6c9fe6561@changeid/
>
> Thanks,
>
> James
>