2012-06-22 17:58:29

by Bjørn Mork

[permalink] [raw]
Subject: iwlwifi: "GF was set with SGI:SISO"

Hello,

I just started receiving these mysterious error messages on each
transmitted packet:


Jun 22 19:48:21 nemi kernel: [255522.415447] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
Jun 22 19:48:21 nemi kernel: [255522.445200] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
Jun 22 19:48:21 nemi kernel: [255522.448130] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
Jun 22 19:48:21 nemi kernel: [255522.454865] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
Jun 22 19:48:21 nemi kernel: [255522.474708] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
Jun 22 19:48:21 nemi kernel: [255522.486878] iwlwifi 0000:03:00.0: GF was set with SGI:SISO

which seems to originate from this code in
drivers/net/wireless/iwlwifi/dvm/rs.c :

if (use_green) {
rate_n_flags |= RATE_MCS_GF_MSK;
if (is_siso(tbl->lq_type) && tbl->is_SGI) {
rate_n_flags &= ~RATE_MCS_SGI_MSK;
IWL_ERR(priv, "GF was set with SGI:SISO\n");
}
}



But I do fail to see what I as an user is expected to do about this...

Could the message be improved with some end user guidance? And it
should obviously be rate-limited.

I am using the driver from 3.5-rc2. The initial driver messages are:

bjorn@nemi:~$ grep iwl /var/log/dmesg
[ 11.771797] iwlwifi: Intel(R) Wireless WiFi Link AGN driver for Linux, in-tree:
[ 11.773943] iwlwifi: Copyright(c) 2003-2012 Intel Corporation
[ 11.835304] bus: 'pci': add driver iwlwifi
[ 11.835340] bus: 'pci': driver_probe_device: matched device 0000:03:00.0 with driver iwlwifi
[ 11.835344] bus: 'pci': really_probe: probing driver iwlwifi with device 0000:03:00.0
[ 11.835422] iwlwifi 0000:03:00.0: pci_resource_len = 0x00002000
[ 11.835493] iwlwifi 0000:03:00.0: pci_resource_base = ffffc900057a4000
[ 11.835562] iwlwifi 0000:03:00.0: HW Revision ID = 0x0
[ 11.853318] iwlwifi 0000:03:00.0: irq 45 for MSI/MSI-X
[ 11.853366] driver: '0000:03:00.0': driver_bound: bound to device 'iwlwifi'
[ 11.853425] firmware 0000:03:00.0: firmware: requesting iwlwifi-5000-5.ucode
[ 11.856712] bus: 'pci': really_probe: bound device 0000:03:00.0 to driver iwlwifi
[ 12.521925] iwlwifi 0000:03:00.0: loaded firmware version 8.83.5.1 build 33692
[ 12.522628] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEBUG disabled
[ 12.522675] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEBUGFS disabled
[ 12.522719] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEVICE_TRACING disabled
[ 12.522770] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_DEVICE_TESTMODE disabled
[ 12.522817] iwlwifi 0000:03:00.0: CONFIG_IWLWIFI_P2P disabled
[ 12.522861] iwlwifi 0000:03:00.0: Detected Intel(R) Ultimate N WiFi Link 5300 AGN, REV=0x24
[ 12.522989] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 12.550242] iwlwifi 0000:03:00.0: device EEPROM VER=0x11e, CALIB=0x4
[ 12.550300] iwlwifi 0000:03:00.0: Device SKU: 0xF0
[ 12.550339] iwlwifi 0000:03:00.0: Valid Tx ant: 0x7, Valid Rx ant: 0x7
[ 12.550406] iwlwifi 0000:03:00.0: Tunable channels: 13 802.11bg, 24 802.11a channels
[ 12.578444] ieee80211 phy0: Selected rate control algorithm 'iwl-agn-rs'
[ 30.708681] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 30.709069] iwlwifi 0000:03:00.0: Radio type=0x0-0x2-0x0
[ 30.860998] iwlwifi 0000:03:00.0: L1 Disabled; Enabling L0S
[ 30.865388] iwlwifi 0000:03:00.0: Radio type=0x0-0x2-0x0


This is the first time I notice this issue, so I don't think it's very
reproducible.




Thanks,
Bjørn


2012-06-25 09:00:31

by Bjørn Mork

[permalink] [raw]
Subject: Re: iwlwifi: "GF was set with SGI:SISO"

Johannes Berg <[email protected]> writes:

> There's nothing you can do about it, I'll just downgrade it -- see patch
> below, also for an explanation.

Thanks. That looks like the only sensible solution. I did some commit
digging, and it seems this log message was introduced out of the blue
with no explanation during code refactoring.

>> This is the first time I notice this issue, so I don't think it's very
>> reproducible.
>
> Too bad, I would've been interested in a command trace when this
> happens, but it would have to be a fairly long-running trace before the
> error message happens.
>
> Were you in some special place when this happened?

No it was at home, and it's been a few months since the access points
there were changed in any way (hardware, firmware, config).

> It has to be an 11n
> AP that is greenfield capable, with no 11a/b/g stations connected to it.

That sounds likely at the time this happened. The access points are two
Netgear WNDR4500 routers if that matters. I.e. Linux 2.6.22 with
Broadcoms proprietary closed source drivers.

> Maybe some 11g client disconnected from the AP and then the messages
> started showing up?

Could very well be. The 11g client would probably be my phone then. It
tends to do connects/disconnects on its own, so it sounds likely that it
could just have disconnected when the log messages started appearing.

> [PATCH] iwlwifi: turn down "GF was set with SGI:SISO" message

I don't think I can test this in any other way than building it, as I am
unable to trigger the problem again. It went away on the first
disconnect/reconnect (while suspending the laptop) and I have not seen
the messages again.

But the solution look sane to me FWIW.


Bjørn

2012-06-26 07:28:28

by Johannes Berg

[permalink] [raw]
Subject: Re: iwlwifi: "GF was set with SGI:SISO"

On Mon, 2012-06-25 at 10:59 +0200, Bjørn Mork wrote:
> Johannes Berg <[email protected]> writes:
>
> > There's nothing you can do about it, I'll just downgrade it -- see patch
> > below, also for an explanation.
>
> Thanks. That looks like the only sensible solution. I did some commit
> digging, and it seems this log message was introduced out of the blue
> with no explanation during code refactoring.

There's also a bug report that I hadn't linked to before:
http://bugzilla.intellinuxwireless.org/show_bug.cgi?id=2361

There, somebody says the RS algorithm also gets "stuck" in this case, so
I may instead of removing the message ratelimit it or so.

He has a trace though, so hopefully we can just find the error soon :)


> > Maybe some 11g client disconnected from the AP and then the messages
> > started showing up?
>
> Could very well be. The 11g client would probably be my phone then. It
> tends to do connects/disconnects on its own, so it sounds likely that it
> could just have disconnected when the log messages started appearing.

Ok, that gives us a plausible scenario. When I get the trace, I'll
investigate in this direction.

johannes


2012-06-25 08:30:50

by Johannes Berg

[permalink] [raw]
Subject: Re: iwlwifi: "GF was set with SGI:SISO"

On Fri, 2012-06-22 at 19:58 +0200, Bjørn Mork wrote:
> Hello,
>
> I just started receiving these mysterious error messages on each
> transmitted packet:
>
>
> Jun 22 19:48:21 nemi kernel: [255522.415447] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
> Jun 22 19:48:21 nemi kernel: [255522.445200] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
> Jun 22 19:48:21 nemi kernel: [255522.448130] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
> Jun 22 19:48:21 nemi kernel: [255522.454865] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
> Jun 22 19:48:21 nemi kernel: [255522.474708] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
> Jun 22 19:48:21 nemi kernel: [255522.486878] iwlwifi 0000:03:00.0: GF was set with SGI:SISO
>
> which seems to originate from this code in
> drivers/net/wireless/iwlwifi/dvm/rs.c :
>
> if (use_green) {
> rate_n_flags |= RATE_MCS_GF_MSK;
> if (is_siso(tbl->lq_type) && tbl->is_SGI) {
> rate_n_flags &= ~RATE_MCS_SGI_MSK;
> IWL_ERR(priv, "GF was set with SGI:SISO\n");
> }
> }
>
>
>
> But I do fail to see what I as an user is expected to do about this...
>
> Could the message be improved with some end user guidance? And it
> should obviously be rate-limited.

There's nothing you can do about it, I'll just downgrade it -- see patch
below, also for an explanation.

> This is the first time I notice this issue, so I don't think it's very
> reproducible.

Too bad, I would've been interested in a command trace when this
happens, but it would have to be a fairly long-running trace before the
error message happens.

Were you in some special place when this happened? It has to be an 11n
AP that is greenfield capable, with no 11a/b/g stations connected to it.
Maybe some 11g client disconnected from the AP and then the messages
started showing up?

johannes


[PATCH] iwlwifi: turn down "GF was set with SGI:SISO" message

Single-stream SGI is incompatible with greenfield,
802.11-12 says:
NOTE—Short GI is not used in HT-greenfield format
with one spatial stream, in which case the HT-SIG
is immediately followed by data. It is very
difficult to parse the HT-SIG in time to demodulate
these data with the correct GI length if the GI
length is not known in advance.

The error indicates that somehow the RS algorithm
tried to select 1x1 with SGI while the station is
in greenfield mode, which shouldn't happen, but
there's no need to flood the log with the message
either.

Signed-off-by: Johannes Berg <[email protected]>
---
drivers/net/wireless/iwlwifi/dvm/rs.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/drivers/net/wireless/iwlwifi/dvm/rs.c b/drivers/net/wireless/iwlwifi/dvm/rs.c
index 6fddd27..39d26f2 100644
--- a/drivers/net/wireless/iwlwifi/dvm/rs.c
+++ b/drivers/net/wireless/iwlwifi/dvm/rs.c
@@ -598,7 +598,8 @@ static u32 rate_n_flags_from_tbl(struct iwl_priv *priv,
rate_n_flags |= RATE_MCS_GF_MSK;
if (is_siso(tbl->lq_type) && tbl->is_SGI) {
rate_n_flags &= ~RATE_MCS_SGI_MSK;
- IWL_ERR(priv, "GF was set with SGI:SISO\n");
+ IWL_DEBUG_RATE(priv,
+ "GF was set with SGI:SISO\n");
}
}
}
--
1.7.10