2009-06-29 09:28:04

by Frans Pop

[permalink] [raw]
Subject: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

(Reported earlier in 'no wireless due to RFKILL problem' thread, but
Johannes suggested opening a new thread as it is a separate issue.)

I've tried .31-rc1 on my HP 2510p notebook and noticed a problem when
using the hardware rf kill switch.

If disable wireless using the hardware switch and the enable it again
almost immediately after on 2.6.30, I get:
[disable]
iwlagn 0000:10:00.0: Radio Frequency Kill Switch is On:
Kill switch must be turned off for wireless networking to work.
usb 3-1: USB disconnect, address 2
[enable]
Registered led device: iwl-phy0::radio
Registered led device: iwl-phy0::assoc
Registered led device: iwl-phy0::RX
Registered led device: iwl-phy0::TX
usb 3-1: new full speed USB device using uhci_hcd and address 3
usb 3-1: configuration #1 chosen from 1 choice
wlan0: no probe response from AP 00:14:c1:38:e5:15 - disassociating
iwlagn 0000:10:00.0: index 0 not used in uCode key table.
wlan0: authenticate with AP 00:14:c1:38:e5:15
wlan0: authenticate with AP 00:14:c1:38:e5:15
wlan0: authenticated
wlan0: associate with AP 00:14:c1:38:e5:15
wlan0: RX ReassocResp from 00:14:c1:38:e5:15 (capab=0x411 status=0 aid=1)
wlan0: associated

And without any other action networking is up again.


But with 2.6.31 I get this:
[disable]
wlan0: deauthenticating by local choice (reason=3)
iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
mac80211-phy0: failed to remove key (0, 00:14:c1:38:e5:15) from hardware (-5)
iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
mac80211-phy0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)
usb 3-1: USB disconnect, address 2
[enable]
usb 3-1: new full speed USB device using uhci_hcd and address 3
usb 3-1: configuration #1 chosen from 1 choice

A lot uglier with those errors. And after that I have to run ifdown/ifup
before networking is up again (ifup only does not work as it will complain
"interface already configured"):

[ifdown wlan0]
Registered led device: iwl-phy0::radio
Registered led device: iwl-phy0::assoc
Registered led device: iwl-phy0::RX
Registered led device: iwl-phy0::TX
ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ifup wlan 0]
Registered led device: iwl-phy0::radio
Registered led device: iwl-phy0::assoc
Registered led device: iwl-phy0::RX
Registered led device: iwl-phy0::TX
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: authenticate with AP 00:14:c1:38:e5:15
wlan0: authenticated
wlan0: associate with AP 00:14:c1:38:e5:15
wlan0: RX AssocResp from 00:14:c1:38:e5:15 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready

BTW, would it make sense to bring back the first two lines shown with .30
(or at least the first one):
iwlagn 0000:10:00.0: Radio Frequency Kill Switch is On:
Kill switch must be turned off for wireless networking to work.
IMHO it's good to register the reason for the disconnect.

>From lspci:
10:00.0 Network controller [0280]: Intel Corporation PRO/Wireless
4965 AG or AGN [Kedron] Network Connection [8086:4229] (rev 61)

Cheers,
FJP


2009-06-29 09:48:54

by Frans Pop

[permalink] [raw]
Subject: Re: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

On Monday 29 June 2009, Johannes Berg wrote:
> > [enable]
> > usb 3-1: new full speed USB device using uhci_hcd and address 3
> > usb 3-1: configuration #1 chosen from 1 choice
>
> That is completely unrelated. You plugged in a USB device too :)

No, it's my "bluetooth + wlan" device. Note that disabling wireless with
the hardware switch also gives 'usb 3-1: USB disconnect, address 2'.

>From lsusb:
Bus 003 Device 002: ID 03f0:171d Hewlett-Packard Wireless (Bluetooth +
WLAN) Interface [Integrated Module]

> > A lot uglier with those errors. And after that I have to run
> > ifdown/ifup before networking is up again (ifup only does not work as
> > it will complain "interface already configured"):
>
> And that's actually expected, and/or a bug in the debian networking
> scripts.
> (You can trigger the same problem by doing
> ifup wlan0
> ip link set wlan0 down
> ifup wlan0 -> error)

OK, I can accept that. Wonder why it does work with 2.6.30 then. But it
can certainly wait until the driver problem you mentioned is resolved.

> To get your network connection back automatically we will require
> changes to userland tools to listen to rfkill events.
>
> > BTW, would it make sense to bring back the first two lines shown with
> > .30 (or at least the first one):
> > iwlagn 0000:10:00.0: Radio Frequency Kill Switch is On:
> > Kill switch must be turned off for wireless networking to work.
> > IMHO it's good to register the reason for the disconnect.
>
> I guess something like that could be added to cfg80211:
> phy0: taking interfaces down due to rfkill

Yes, that would be nice.

Thanks,
FJP

2009-06-30 17:44:16

by Reinette Chatre

[permalink] [raw]
Subject: Re: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

Hi Frans,

On Mon, 2009-06-29 at 02:28 -0700, Frans Pop wrote:

> But with 2.6.31 I get this:
> [disable]
> wlan0: deauthenticating by local choice (reason=3)
> iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
> mac80211-phy0: failed to remove key (0, 00:14:c1:38:e5:15) from hardware (-5)
> iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
> mac80211-phy0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)

Here the driver is trying to remove the keys from the device but with
rfkill enabled it is not able to do so.

> usb 3-1: USB disconnect, address 2
> [enable]
> usb 3-1: new full speed USB device using uhci_hcd and address 3
> usb 3-1: configuration #1 chosen from 1 choice
>
> A lot uglier with those errors. And after that I have to run ifdown/ifup
> before networking is up again (ifup only does not work as it will complain
> "interface already configured"):

yes, as Johannes mentioned this is a new required step to get networking
back up after rfkill state changes.


> BTW, would it make sense to bring back the first two lines shown with .30
> (or at least the first one):
> iwlagn 0000:10:00.0: Radio Frequency Kill Switch is On:
> Kill switch must be turned off for wireless networking to work.
> IMHO it's good to register the reason for the disconnect.

It would be nice to get this from the upper layers, but the device can
do it also as it is getting the interrupt.

Could you please try the patch below? It will not send command to device
when rfkill is enabled and it will also print messages indicating that
rfkill state changed.


>From 9935d8bab97448f9ab5418602849172dcb0ba00a Mon Sep 17 00:00:00 2001
From: Reinette Chatre <[email protected]>
Date: Tue, 30 Jun 2009 10:14:25 -0700
Subject: [PATCH] iwlagn: do not send key clear commands when rfkill enabled

Do all key clearing except sending sommands to device when rfkill
enabled. When rfkill enabled the interface is brought down and will
be brought back up correctly after rfkill is enabled again.

Same change is not needed for iwl3945 as it ignores return code when
sending key clearing command to device.

Signed-off-by: Reinette Chatre <[email protected]>
---
drivers/net/wireless/iwlwifi/iwl-agn.c | 4 ++--
drivers/net/wireless/iwlwifi/iwl-sta.c | 12 ++++++++++++
drivers/net/wireless/iwlwifi/iwl-tx.c | 2 +-
3 files changed, 15 insertions(+), 3 deletions(-)

diff --git a/drivers/net/wireless/iwlwifi/iwl-agn.c b/drivers/net/wireless/iwlwifi/iwl-agn.c
index ad50022..32aebd7 100644
--- a/drivers/net/wireless/iwlwifi/iwl-agn.c
+++ b/drivers/net/wireless/iwlwifi/iwl-agn.c
@@ -960,7 +960,7 @@ static void iwl_irq_tasklet_legacy(struct iwl_priv *priv)
CSR_GP_CNTRL_REG_FLAG_HW_RF_KILL_SW))
hw_rf_kill = 1;

- IWL_DEBUG_RF_KILL(priv, "RF_KILL bit toggled to %s.\n",
+ IWL_WARN(priv, "RF_KILL bit toggled to %s.\n",
hw_rf_kill ? "disable radio" : "enable radio");

priv->isr_stats.rfkill++;
@@ -1133,7 +1133,7 @@ static void iwl_irq_tasklet(struct iwl_priv *priv)
CSR_GP_CNTRL_REG_FLAG_HW_RF_KILL_SW))
hw_rf_kill = 1;

- IWL_DEBUG_RF_KILL(priv, "RF_KILL bit toggled to %s.\n",
+ IWL_WARN(priv, "RF_KILL bit toggled to %s.\n",
hw_rf_kill ? "disable radio" : "enable radio");

priv->isr_stats.rfkill++;
diff --git a/drivers/net/wireless/iwlwifi/iwl-sta.c b/drivers/net/wireless/iwlwifi/iwl-sta.c
index 2addf73..ffd5c61 100644
--- a/drivers/net/wireless/iwlwifi/iwl-sta.c
+++ b/drivers/net/wireless/iwlwifi/iwl-sta.c
@@ -566,6 +566,8 @@ int iwl_remove_default_wep_key(struct iwl_priv *priv,
unsigned long flags;

spin_lock_irqsave(&priv->sta_lock, flags);
+ IWL_DEBUG_WEP(priv, "Removing default WEP key: idx=%d\n",
+ keyconf->keyidx);

if (!test_and_clear_bit(keyconf->keyidx, &priv->ucode_key_table))
IWL_ERR(priv, "index %d not used in uCode key table.\n",
@@ -573,6 +575,11 @@ int iwl_remove_default_wep_key(struct iwl_priv *priv,

priv->default_wep_key--;
memset(&priv->wep_keys[keyconf->keyidx], 0, sizeof(priv->wep_keys[0]));
+ if (iwl_is_rfkill(priv)) {
+ IWL_DEBUG_WEP(priv, "Not sending REPLY_WEPKEY command due to RFKILL.\n");
+ spin_unlock_irqrestore(&priv->sta_lock, flags);
+ return 0;
+ }
ret = iwl_send_static_wepkey_cmd(priv, 1);
IWL_DEBUG_WEP(priv, "Remove default WEP key: idx=%d ret=%d\n",
keyconf->keyidx, ret);
@@ -853,6 +860,11 @@ int iwl_remove_dynamic_key(struct iwl_priv *priv,
priv->stations[sta_id].sta.sta.modify_mask = STA_MODIFY_KEY_MASK;
priv->stations[sta_id].sta.mode = STA_CONTROL_MODIFY_MSK;

+ if (iwl_is_rfkill(priv)) {
+ IWL_DEBUG_WEP(priv, "Not sending REPLY_ADD_STA command because RFKILL enabled. \n");
+ spin_unlock_irqrestore(&priv->sta_lock, flags);
+ return 0;
+ }
ret = iwl_send_add_sta(priv, &priv->stations[sta_id].sta, CMD_ASYNC);
spin_unlock_irqrestore(&priv->sta_lock, flags);
return ret;
diff --git a/drivers/net/wireless/iwlwifi/iwl-tx.c b/drivers/net/wireless/iwlwifi/iwl-tx.c
index 753fca3..acff7a2 100644
--- a/drivers/net/wireless/iwlwifi/iwl-tx.c
+++ b/drivers/net/wireless/iwlwifi/iwl-tx.c
@@ -939,7 +939,7 @@ int iwl_enqueue_hcmd(struct iwl_priv *priv, struct iwl_host_cmd *cmd)
!(cmd->meta.flags & CMD_SIZE_HUGE));

if (iwl_is_rfkill(priv)) {
- IWL_DEBUG_INFO(priv, "Not sending command - RF KILL");
+ IWL_DEBUG_INFO(priv, "Not sending command - RF KILL\n");
return -EIO;
}

--
1.5.6.3




2009-06-29 09:33:43

by Johannes Berg

[permalink] [raw]
Subject: Re: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

Now that I took a closer look...

> I've tried .31-rc1 on my HP 2510p notebook and noticed a problem when
> using the hardware rf kill switch.


> But with 2.6.31 I get this:
> [disable]
> wlan0: deauthenticating by local choice (reason=3)
> iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
> mac80211-phy0: failed to remove key (0, 00:14:c1:38:e5:15) from hardware (-5)
> iwlagn 0000:10:00.0: Error sending REPLY_ADD_STA: enqueue_hcmd failed: -5
> mac80211-phy0: failed to remove key (1, ff:ff:ff:ff:ff:ff) from hardware (-5)
> usb 3-1: USB disconnect, address 2

These errors are a driver problem.

> [enable]
> usb 3-1: new full speed USB device using uhci_hcd and address 3
> usb 3-1: configuration #1 chosen from 1 choice

That is completely unrelated. You plugged in a USB device too :)

> A lot uglier with those errors. And after that I have to run ifdown/ifup
> before networking is up again (ifup only does not work as it will complain
> "interface already configured"):

And that's actually expected, and/or a bug in the debian networking
scripts.
(You can trigger the same problem by doing
ifup wlan0
ip link set wlan0 down
ifup wlan0 -> error)

To get your network connection back automatically we will require
changes to userland tools to listen to rfkill events.

> BTW, would it make sense to bring back the first two lines shown with .30
> (or at least the first one):
> iwlagn 0000:10:00.0: Radio Frequency Kill Switch is On:
> Kill switch must be turned off for wireless networking to work.
> IMHO it's good to register the reason for the disconnect.

I guess something like that could be added to cfg80211:
phy0: taking interfaces down due to rfkill

johannes


Attachments:
signature.asc (801.00 B)
This is a digitally signed message part

2009-06-29 09:53:23

by Johannes Berg

[permalink] [raw]
Subject: Re: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

On Mon, 2009-06-29 at 11:48 +0200, Frans Pop wrote:
> On Monday 29 June 2009, Johannes Berg wrote:
> > > [enable]
> > > usb 3-1: new full speed USB device using uhci_hcd and address 3
> > > usb 3-1: configuration #1 chosen from 1 choice
> >
> > That is completely unrelated. You plugged in a USB device too :)
>
> No, it's my "bluetooth + wlan" device. Note that disabling wireless with
> the hardware switch also gives 'usb 3-1: USB disconnect, address 2'.
>
> From lsusb:
> Bus 003 Device 002: ID 03f0:171d Hewlett-Packard Wireless (Bluetooth +
> WLAN) Interface [Integrated Module]

Ah :) That's just bluetooth then though, not wifi.

> > > A lot uglier with those errors. And after that I have to run
> > > ifdown/ifup before networking is up again (ifup only does not work as
> > > it will complain "interface already configured"):
> >
> > And that's actually expected, and/or a bug in the debian networking
> > scripts.
> > (You can trigger the same problem by doing
> > ifup wlan0
> > ip link set wlan0 down
> > ifup wlan0 -> error)
>
> OK, I can accept that. Wonder why it does work with 2.6.30 then. But it
> can certainly wait until the driver problem you mentioned is resolved.

2.6.30 didn't have the "ip link set wlan0 down" on rfkill behaviour, but
overall that makes life for everybody (except people who actually use
ifup/down) much easier.

johannes


Attachments:
signature.asc (801.00 B)
This is a digitally signed message part

2009-07-01 15:58:36

by Frans Pop

[permalink] [raw]
Subject: Re: [2.6.31-rc1] iwlagn (4965): regression when hardware rf switch is used

On Tuesday 30 June 2009, reinette chatre wrote:
> Subject: [PATCH] iwlagn: do not send key clear commands when rfkill
> enabled
>
> Do all key clearing except sending sommands to device when rfkill
> enabled. When rfkill enabled the interface is brought down and will
> be brought back up correctly after rfkill is enabled again.
>
> Same change is not needed for iwl3945 as it ignores return code when
> sending key clearing command to device.

With this patch things look a lot cleaner:

[enable hardware rf kill switch]
iwlagn 0000:10:00.0: RF_KILL bit toggled to disable radio.
wlan0: deauthenticating by local choice (reason=3)
usb 3-1: USB disconnect, address 2
[disable hardware rf kill switch]
iwlagn 0000:10:00.0: RF_KILL bit toggled to enable radio.
usb 3-1: new full speed USB device using uhci_hcd and address 3
usb 3-1: configuration #1 chosen from 1 choice
[ifdown wlan0]
Registered led device: iwl-phy0::radio
Registered led device: iwl-phy0::assoc
Registered led device: iwl-phy0::RX
Registered led device: iwl-phy0::TX
ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ifup wlan0]
Registered led device: iwl-phy0::radio
Registered led device: iwl-phy0::assoc
Registered led device: iwl-phy0::RX
Registered led device: iwl-phy0::TX
ADDRCONF(NETDEV_UP): wlan0: link is not ready
wlan0: authenticate with AP 00:14:c1:38:e5:15
wlan0: authenticated
wlan0: associate with AP 00:14:c1:38:e5:15
wlan0: RX AssocResp from 00:14:c1:38:e5:15 (capab=0x411 status=0 aid=1)
wlan0: associated
ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
wlan0: no IPv6 routers present


One thing I do not quite get is why both ifdown and ifup result in leds
getting registered. It does not happen when I do a "normal" ifdown (when
the wireless interface is up and rfkill is not enabled).

I could understand the leds being registered immediately after I disable
the rf kill switch, but don't understand why it gets postponed until I do
ifdown. That makes it seem as if the change in RF_KILL only gets
processed halfway through with the registering of leds left dangling.


> Signed-off-by: Reinette Chatre <[email protected]>
Reported-by: Frans Pop <[email protected]>
Tested-by: Frans Pop <[email protected]>


> --- a/drivers/net/wireless/iwlwifi/iwl-agn.c
> +++ b/drivers/net/wireless/iwlwifi/iwl-agn.c
> @@ -960,7 +960,7 @@ static void iwl_irq_tasklet_legacy(struct iwl_priv
> *priv) CSR_GP_CNTRL_REG_FLAG_HW_RF_KILL_SW))
> hw_rf_kill = 1;
>
> - IWL_DEBUG_RF_KILL(priv, "RF_KILL bit toggled to %s.\n",
> + IWL_WARN(priv, "RF_KILL bit toggled to %s.\n",
> hw_rf_kill ? "disable radio" : "enable radio");
>
> priv->isr_stats.rfkill++;
> @@ -1133,7 +1133,7 @@ static void iwl_irq_tasklet(struct iwl_priv
> *priv) CSR_GP_CNTRL_REG_FLAG_HW_RF_KILL_SW))
> hw_rf_kill = 1;
>
> - IWL_DEBUG_RF_KILL(priv, "RF_KILL bit toggled to %s.\n",
> + IWL_WARN(priv, "RF_KILL bit toggled to %s.\n",
> hw_rf_kill ? "disable radio" : "enable radio");

If these two messages get promoted to regular user messages, maybe they
could be made a bit less technical? I doubt "RF_KILL bit toggled" is
going to mean all that much to most users.

Thanks,
FJP