Sometimes RxBitrate of 1000 Kbit/s

Sometimes RxBitrate of 1000 Kbit/s

[Patrick Häcker]

[-- Attachment #1: Type: text/plain, Size: 3921 bytes --]

Hello all,

from time to time my RxBitrate (sometimes the TxBitrate, too) goes down to
1000 Kbit/s, whereas it otherwise is in the usual 5 to 6 digit range. This
seems to especially happen some time after waking up from standby (S3), maybe
also from hibernate (S4).

When it happens, wireless usage is super slow to non-existent.

Restarting iwd immediately solves the problem. I routinely also reloaded the
involved kernel modules, but I think this was unnecessary as I
skipped it the last few times and only restarted iwd and this was enough to
get it back to a working state.

Naturally, it seems to occur every few hours, but I might be able to trigger
it more often with extensive standby cycles, but I am not sure.

That's how it looks when it happens (although TxBitrate is often still in the
normal 5 to 6 digit rate; please note ExpectedThroughput being much larger
than TxBitrate or RxBitrate):
# iwctl station wlan0 show
                                 Station: wlan0
--------------------------------------------------------------------------------
  Settable  Property              Value
--------------------------------------------------------------------------------
            Scanning              no
            State                 connected
            Connected network     *redacted*
            IPv4 address          192.168.0.10
            ConnectedBss          98:9b:cb:4b:b1:cc
            Frequency             2412
            Security              WPA3-Personal
            RSSI                  -44 dBm
            AverageRSSI           -55 dBm
            TxBitrate             1000 Kbit/s
            RxBitrate             1000 Kbit/s
            ExpectedThroughput    56906 Kbit/s

This is how it looks after restarting iwd:
# systemctl restart iwd
# iwctl station wlan0 show
                                 Station: wlan0
--------------------------------------------------------------------------------
  Settable  Property              Value
--------------------------------------------------------------------------------
            Scanning              no
            State                 connected
            Connected network     *redacted*
            IPv4 address          192.168.0.10
            ConnectedBss          98:9b:cb:4b:b1:cd
            Frequency             5180
            Security              WPA3-Personal
            RSSI                  -72 dBm
            AverageRSSI           -72 dBm
            RxMode                802.11n
            RxMCS                 9
            TxMode                802.11n
            TxMCS                 3
            TxBitrate             60000 Kbit/s
            RxBitrate             60000 Kbit/s
            ExpectedThroughput    31125 Kbit/s

Please note, that currently the router steers clients towards either 2.4 GHz
or 5 GHz. I already tried to restrict the client to either of both frequency
bands, but that did not seem to avoid the problem.

# uname -a
Linux mmm 6.0.0-2-amd64 #1 SMP PREEMPT_DYNAMIC Debian 6.0.5-1 (2022-10-28)
x86_64 GNU/Linux

(Probably) involved kernel modules:
rt2800usb rt2x00usb rt2800lib rt2x00lib mac80211 cfg80211

The device is a USB device
Ralink Technology, Corp. RT5572 Wireless Adapter

Any tips how to debug this?

From https://iwd.wiki.kernel.org/debugging I would assume, that IWD_GENL_DEBUG
might the relevant environment variable, but I am really not sure.
I could obviously implement some kind of watchdog checking the output of iwctl
every some seconds and restarting iwd in case, but I would avoid that if there
is a cleaner solution available.

I think is problem started to occur some months ago. It might be related with
some kernel or iwd update some time ago. But due to the long time until
occuring, a sound bisect might take more than a week.

Kind regards
Patrick

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Sometimes RxBitrate of 1000 Kbit/s

[Denis Kenzior]

Hi Patrick,

On 11/6/22 08:36, Patrick Häcker wrote:
> Hello all,
> 
> from time to time my RxBitrate (sometimes the TxBitrate, too) goes down to
> 1000 Kbit/s, whereas it otherwise is in the usual 5 to 6 digit range. This
> seems to especially happen some time after waking up from standby (S3), maybe
> also from hibernate (S4).

iwd doesn't do anything on sleep (it isn't even aware of sleep).  So it is up to 
the kernel driver to do the right thing.  Maybe it isn't?  You'll have to ask 
the kernel / driver / firmware people for your hardware.

> 
> When it happens, wireless usage is super slow to non-existent.
> 
> Restarting iwd immediately solves the problem. I routinely also reloaded the
> involved kernel modules, but I think this was unnecessary as I
> skipped it the last few times and only restarted iwd and this was enough to
> get it back to a working state.

Killing iwd most likely power-cycles the card (since it brings the interface 
down, or even destroys it completely), and probably reloads the firmware. 
Removing the kernel modules probably doesn't matter.

We have seen some reports where (for example iwlwifi) behavior can change 
between kernel versions due to different firmware behavior.

Some network managers (like NM) will explicitly IFDOWN wireless interfaces on 
suspend and bring them up on resume.  This isn't cost free and we'd rather not 
do this.

<snip>

> This is how it looks after restarting iwd:
> # systemctl restart iwd
> # iwctl station wlan0 show
>                                   Station: wlan0
> --------------------------------------------------------------------------------
>    Settable  Property              Value
> --------------------------------------------------------------------------------
>              Scanning              no
>              State                 connected
>              Connected network     *redacted*
>              IPv4 address          192.168.0.10
>              ConnectedBss          98:9b:cb:4b:b1:cd
>              Frequency             5180
>              Security              WPA3-Personal
>              RSSI                  -72 dBm
>              AverageRSSI           -72 dBm
>              RxMode                802.11n
>              RxMCS                 9
>              TxMode                802.11n
>              TxMCS                 3
>              TxBitrate             60000 Kbit/s
>              RxBitrate             60000 Kbit/s
>              ExpectedThroughput    31125 Kbit/s
> 

Some of these numbers seem suspect, but iwd has no influence on them.  RX/TX MCS 
selection is done by the driver / firmware.  All iwd does is report what the 
driver is telling it.

<snip>

>  From https://iwd.wiki.kernel.org/debugging I would assume, that IWD_GENL_DEBUG
> might the relevant environment variable, but I am really not sure.

This isn't what you're looking for.  That variable is for debugging generic 
netlink communication which we haven't needed to do in years.  We probably 
should take this out completely.

> I could obviously implement some kind of watchdog checking the output of iwctl
> every some seconds and restarting iwd in case, but I would avoid that if there
> is a cleaner solution available.

You could try adding an ifdown / ifup for the wifi interface triggered by 
suspend / resume (or rfkill) and see what happens?

You can also try to run run iwmon in order to capture what is happening on the 
nl80211 API level when entering / leaving suspend.  The driver people might be 
interested in this information.

> 
> I think is problem started to occur some months ago. It might be related with
> some kernel or iwd update some time ago. But due to the long time until
> occuring, a sound bisect might take more than a week.

I'd start with the kernel, it is hard for me to imagine what iwd might be doing 
to trigger this.

Regards,
-Denis

Re: Sometimes RxBitrate of 1000 Kbit/s

[Patrick Häcker]

[-- Attachment #1: Type: text/plain, Size: 1330 bytes --]

Hi Denis,

> iwd doesn't do anything on sleep (it isn't even aware of sleep).  So it is
> up to the kernel driver to do the right thing.  Maybe it isn't?  You'll
> have to ask the kernel / driver / firmware people for your hardware.
thanks a lot for the answer. I'll contact the kernel / driver / firmware people
for my hardware.

> Some network managers (like NM) will explicitly IFDOWN wireless interfaces
> on suspend and bring them up on resume.  This isn't cost free and we'd
> rather not do this.
Would it make sense to do this optionally if a new config option were
explicitly set? Or do you think this is the wrong layer or wrong approach to
do so?

> You can also try to run run iwmon in order to capture what is happening on
> the nl80211 API level when entering / leaving suspend.  The driver people
> might be interested in this information.
I was monitoring with iwmon for the last days whenever the computer was in
use, but so far the problem did not occur again (it occurs during normal
operation, I just have the feeling that the probability is highest some
minutes after waking up from suspend).

The only thing I got was a segfault from iwmon once, so it's now running with
valgrind. This is, however, probably an unrelated issue, if it should repeat
at all.

Thanks again
Patrick


[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Sometimes RxBitrate of 1000 Kbit/s

[Denis Kenzior]

Hi Patrick,

>> Some network managers (like NM) will explicitly IFDOWN wireless interfaces
>> on suspend and bring them up on resume.  This isn't cost free and we'd
>> rather not do this.
> Would it make sense to do this optionally if a new config option were
> explicitly set? Or do you think this is the wrong layer or wrong approach to
> do so?

It isn't really clear, to be honest.  I would expect this to be handled by the 
driver itself not iwd.  But maybe if the drivers / firmware are broken then this 
is something we might have to (optionally?) enable.

I would be curious to know whether manually triggering ifdown/ifup on 
suspend/resume fixes your particular problem.

Regards,
-Denis