Mysterious hangs - cfg80211 - ath9k

Mysterious hangs - cfg80211 - ath9k

[Jon Wikne]

Hi List,

I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
but with kernel 2.6.39.4. (The kernel that came with the distro did
not work properly with WLAN on this machine at all.)

What happens is that the WLAN comes up flawlessly, and works well
until it suddenly hangs. This happens when (or seconds after) I see
an entry like the following in the log:

Jun 18 19:04:42 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain

I do not understand why cfg80211 does this long after the connection
has been established. If I understand correctly, this "regulatory
domain" business only makes sense when the WLAN interface is started.

Subsequent DHCP requests are issued, but never answered:

Jun 18 19:23:38 redcat dhclient: DHCPREQUEST on wlan0 to 137.138.16.6 
port 67 (xid=0x63998557)
Jun 18 19:24:16 redcat last message repeated 3 times
Jun 18 19:25:30 redcat last message repeated 6 times
.....
Jun 18 19:50:10 redcat dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 
port 67 (xid=0x63998557)
Jun 18 19:50:55 redcat last message repeated 3 times
.....
Jun 18 19:58:41 redcat dhclient: No DHCPOFFERS received.

I interpret this as something has (effectively) been turned off,
but that the drivers do not realize this.

Restarting WLAN when the problem has occurred is simple:

root@redcat 97 # /sbin/ifdown wlan0
root@redcat 98 # /sbin/ifup wlan0

What puzzles me even more is that cfg80211 seems to be activated
and mess up things at highly irregular intervals, ranging from
a few minutes to many hours:

root@redcat 105 # tail -2000l /var/log/messages | grep cfg80211
Jun 17 20:28:51 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 17 23:09:37 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 17 23:36:01 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 09:27:59 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 11:57:48 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 18:42:00 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 18:46:49 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 19:04:42 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 18 22:40:42 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain

At the time of writing this (Tue 19 Jun 2012 09:27:54 CEST) the WLAN
has not stopped since the last entry in the above. What on earth is
governing the timing in this?

Some relevant info on the laptop:

root@redcat 108 # lspci
.....
03:00.0 Network controller: Atheros Communications Inc. AR9285 Wireless 
Network Adapter (PCI-Express) (rev 01)
.....

root@redcat 109 # lsmod
Module                  Size  Used by
.....
ath9k                  89934  0
mac80211              160999  1 ath9k
ath9k_common            3051  1 ath9k
.....
ath9k_hw              291258  2 ath9k,ath9k_common
ath                    15289  2 ath9k,ath9k_hw
.....
cfg80211              141299  3 ath9k,mac80211,ath

Any ideas will be greatly appreciated. I will be happy to test
patches. Please CC me at jon.wikne@cern.ch since I am not on
the list.


Regards,
-- Jon Wikne

Re: Mysterious hangs - cfg80211 - ath9k

[Mohammed Shafi]

On Tue, Jun 19, 2012 at 1:34 PM, Jon Wikne <Jon.Wikne@cern.ch> wrote:
> Hi List,
>
> I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
> F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
> but with kernel 2.6.39.4. (The kernel that came with the distro did
> not work properly with WLAN on this machine at all.)

please quickly try
http://linuxwireless.org/en/users/Download#Where_to_download_bleeding_edge

or the latest wireless testing tree
http://linuxwireless.org/en/developers/Documentation/git-guide#Cloning_latest_wireless-testing

>
> What happens is that the WLAN comes up flawlessly, and works well
> until it suddenly hangs. This happens when (or seconds after) I see
> an entry like the following in the log:
>
> Jun 18 19:04:42 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
>
> I do not understand why cfg80211 does this long after the connection
> has been established. If I understand correctly, this "regulatory
> domain" business only makes sense when the WLAN interface is started.
>
> Subsequent DHCP requests are issued, but never answered:
>
> Jun 18 19:23:38 redcat dhclient: DHCPREQUEST on wlan0 to 137.138.16.6 port
> 67 (xid=0x63998557)
> Jun 18 19:24:16 redcat last message repeated 3 times
> Jun 18 19:25:30 redcat last message repeated 6 times
> .....
> Jun 18 19:50:10 redcat dhclient: DHCPREQUEST on wlan0 to 255.255.255.255
> port 67 (xid=0x63998557)
> Jun 18 19:50:55 redcat last message repeated 3 times
> .....
> Jun 18 19:58:41 redcat dhclient: No DHCPOFFERS received.
>
> I interpret this as something has (effectively) been turned off,
> but that the drivers do not realize this.
>
> Restarting WLAN when the problem has occurred is simple:
>
> root@redcat 97 # /sbin/ifdown wlan0
> root@redcat 98 # /sbin/ifup wlan0
>
> What puzzles me even more is that cfg80211 seems to be activated
> and mess up things at highly irregular intervals, ranging from
> a few minutes to many hours:
>
> root@redcat 105 # tail -2000l /var/log/messages | grep cfg80211
> Jun 17 20:28:51 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 17 23:09:37 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 17 23:36:01 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 09:27:59 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 11:57:48 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 18:42:00 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 18:46:49 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 19:04:42 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
> Jun 18 22:40:42 redcat kernel: cfg80211: Calling CRDA to update world
> regulatory domain
>
> At the time of writing this (Tue 19 Jun 2012 09:27:54 CEST) the WLAN
> has not stopped since the last entry in the above. What on earth is
> governing the timing in this?
>
> Some relevant info on the laptop:
>
> root@redcat 108 # lspci
> .....
> 03:00.0 Network controller: Atheros Communications Inc. AR9285 Wireless
> Network Adapter (PCI-Express) (rev 01)
> .....
>
> root@redcat 109 # lsmod
> Module                  Size  Used by
> .....
> ath9k                  89934  0
> mac80211              160999  1 ath9k
> ath9k_common            3051  1 ath9k
> .....
> ath9k_hw              291258  2 ath9k,ath9k_common
> ath                    15289  2 ath9k,ath9k_hw
> .....
> cfg80211              141299  3 ath9k,mac80211,ath
>
> Any ideas will be greatly appreciated. I will be happy to test
> patches. Please CC me at jon.wikne@cern.ch since I am not on
> the list.
>
>
> Regards,
> -- Jon Wikne
> --
> To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html



-- 
thanks,
shafi

Re: Mysterious hangs - cfg80211 - ath9k

[Jon Wikne]

On 06/19/2012 11:39 AM, Mohammed Shafi wrote:
> On Tue, Jun 19, 2012 at 1:34 PM, Jon Wikne<Jon.Wikne@cern.ch>  wrote:
>> Hi List,
>>
>> I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
>> F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
>> but with kernel 2.6.39.4. (The kernel that came with the distro did
>> not work properly with WLAN on this machine at all.)
>
> please quickly try
> http://linuxwireless.org/en/users/Download#Where_to_download_bleeding_edge

I tried to install compat-wireless-2012-05-10. It worked for 4½ hours,
then same problem.

Maybe there is something wrong with my understanding here, but I do not
see why the "cfg80211: Calling CRDA to update world regulatory domain"
should occur hours after the connection has been established, and what
triggers it, apparently at random....

> or the latest wireless testing tree
> http://linuxwireless.org/en/developers/Documentation/git-guide#Cloning_latest_wireless-testing

Is there a reason to believe it could make a difference if I try
this too?

Regards,
-- Jon Wikne

Re: Mysterious hangs - cfg80211 - ath9k

[Jon Wikne]

On 06/19/2012 08:52 PM, Jon Wikne wrote:
> On 06/19/2012 11:39 AM, Mohammed Shafi wrote:
>> On Tue, Jun 19, 2012 at 1:34 PM, Jon Wikne<Jon.Wikne@cern.ch> wrote:
>>> Hi List,
>>>
>>> I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
>>> F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
>>> but with kernel 2.6.39.4. (The kernel that came with the distro did
>>> not work properly with WLAN on this machine at all.)
>>
>> please quickly try
>> http://linuxwireless.org/en/users/Download#Where_to_download_bleeding_edge
>
> I tried to install compat-wireless-2012-05-10. It worked for 4½ hours,
> then same problem.
>
> Maybe there is something wrong with my understanding here, but I do not
> see why the "cfg80211: Calling CRDA to update world regulatory domain"
> should occur hours after the connection has been established, and what
> triggers it, apparently at random....
>
>> or the latest wireless testing tree
>> http://linuxwireless.org/en/developers/Documentation/git-guide#Cloning_latest_wireless-testing
>
> Is there a reason to believe it could make a difference if I try
> this too?

Now I downloaded this (more than 1GB), just to realize that it is a
complete kernel tree for kernel 3.5.0-rc3. I don't really feel ready
for an experimental upgrade from 2.6.39.4 to that right now....

With basis in compat-wireless-2012-05-10 I tried to comment out the
call to call_crda in net/wireless/reg.c and return -EALREADY in line
1483, just to see if that circumvented the problem. It did not. The
damage (whatever that might be) already seems to be done _before_ the
call_crda is made in reg.c.

I am a bit at a loss as to how to proceed. There are several things
i do not understand.

1) The call to update CRDA (even with my crude, experimental, dummy
return) seems to cause no trouble when it is done the first time
the line comes up. Could someone please explain to me what causes
the subsequent calls at highly irregular intervals, and why that
seems to be necessary or desirable?

2) Is this a known problem that is being worked on (in which case I
will just shut up and wait), or am I the first to report it?

Thanks in advance for any further info or suggestions.

Regards,
-- Jon Wikne

Re: Mysterious hangs - cfg80211 - ath9k

[Mohammed Shafi]

Hi,

On Thu, Jun 28, 2012 at 7:33 PM, Jon Wikne <Jon.Wikne@cern.ch> wrote:
> On 06/19/2012 08:52 PM, Jon Wikne wrote:
>>
>> On 06/19/2012 11:39 AM, Mohammed Shafi wrote:
>>>
>>> On Tue, Jun 19, 2012 at 1:34 PM, Jon Wikne<Jon.Wikne@cern.ch> wrote:
>>>>
>>>> Hi List,
>>>>
>>>> I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
>>>> F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
>>>> but with kernel 2.6.39.4. (The kernel that came with the distro did
>>>> not work properly with WLAN on this machine at all.)
>>>
>>>
>>> please quickly try
>>>
>>> http://linuxwireless.org/en/users/Download#Where_to_download_bleeding_edge
>>
>>
>> I tried to install compat-wireless-2012-05-10. It worked for 4½ hours,
>> then same problem.
>>
>> Maybe there is something wrong with my understanding here, but I do not
>> see why the "cfg80211: Calling CRDA to update world regulatory domain"
>> should occur hours after the connection has been established, and what
>> triggers it, apparently at random....
>>
>>> or the latest wireless testing tree
>>>
>>> http://linuxwireless.org/en/developers/Documentation/git-guide#Cloning_latest_wireless-testing
>>
>>
>> Is there a reason to believe it could make a difference if I try
>> this too?
>
>
> Now I downloaded this (more than 1GB), just to realize that it is a
> complete kernel tree for kernel 3.5.0-rc3. I don't really feel ready
> for an experimental upgrade from 2.6.39.4 to that right now....
>
> With basis in compat-wireless-2012-05-10 I tried to comment out the
> call to call_crda in net/wireless/reg.c and return -EALREADY in line
> 1483, just to see if that circumvented the problem. It did not. The
> damage (whatever that might be) already seems to be done _before_ the
> call_crda is made in reg.c.
>
> I am a bit at a loss as to how to proceed. There are several things
> i do not understand.
>
> 1) The call to update CRDA (even with my crude, experimental, dummy
> return) seems to cause no trouble when it is done the first time
> the line comes up. Could someone please explain to me what causes
> the subsequent calls at highly irregular intervals, and why that
> seems to be necessary or desirable?
>
> 2) Is this a known problem that is being worked on (in which case I
> will just shut up and wait), or am I the first to report it?
>
> Thanks in advance for any further info or suggestions.

please provide the complete log. you can also enable ath9k debugging.
sudo modprobe -v ath9k debug=0x601
http://linuxwireless.org/en/users/Drivers/ath9k/debug
so you need to bring the interface up/down to make it working right ?
a recent fix, but not relevant to this i think
http://permalink.gmane.org/gmane.linux.kernel.wireless.general/92657

>
> Regards,
> -- Jon Wikne
>
>



-- 
thanks,
shafi

Re: Mysterious hangs - cfg80211 - ath9k

[Jon Wikne]

On 06/28/2012 04:22 PM, Mohammed Shafi wrote:
> Hi,
>
> On Thu, Jun 28, 2012 at 7:33 PM, Jon Wikne<Jon.Wikne@cern.ch>  wrote:
>> On 06/19/2012 08:52 PM, Jon Wikne wrote:
>>>
>>> On 06/19/2012 11:39 AM, Mohammed Shafi wrote:
>>>>
>>>> On Tue, Jun 19, 2012 at 1:34 PM, Jon Wikne<Jon.Wikne@cern.ch>  wrote:
>>>>>
>>>>> Hi List,
>>>>>
>>>>> I am experiencing a puzzling problem with WLAN on a Toshiba Qosmio
>>>>> F750 laptop, running CERN SLC 5.8 (mostly identical to RHEL 5.8),
>>>>> but with kernel 2.6.39.4. (The kernel that came with the distro did
>>>>> not work properly with WLAN on this machine at all.)
>>>>
>>>>
>>>> please quickly try
>>>>
>>>> http://linuxwireless.org/en/users/Download#Where_to_download_bleeding_edge
>>>
>>>
>>> I tried to install compat-wireless-2012-05-10. It worked for 4½ hours,
>>> then same problem.
>>>
>>> Maybe there is something wrong with my understanding here, but I do not
>>> see why the "cfg80211: Calling CRDA to update world regulatory domain"
>>> should occur hours after the connection has been established, and what
>>> triggers it, apparently at random....
>>>
>>>> or the latest wireless testing tree
>>>>
>>>> http://linuxwireless.org/en/developers/Documentation/git-guide#Cloning_latest_wireless-testing
>>>
>>>
>>> Is there a reason to believe it could make a difference if I try
>>> this too?
>>
>>
>> Now I downloaded this (more than 1GB), just to realize that it is a
>> complete kernel tree for kernel 3.5.0-rc3. I don't really feel ready
>> for an experimental upgrade from 2.6.39.4 to that right now....
>>
>> With basis in compat-wireless-2012-05-10 I tried to comment out the
>> call to call_crda in net/wireless/reg.c and return -EALREADY in line
>> 1483, just to see if that circumvented the problem. It did not. The
>> damage (whatever that might be) already seems to be done _before_ the
>> call_crda is made in reg.c.
>>
>> I am a bit at a loss as to how to proceed. There are several things
>> i do not understand.
>>
>> 1) The call to update CRDA (even with my crude, experimental, dummy
>> return) seems to cause no trouble when it is done the first time
>> the line comes up. Could someone please explain to me what causes
>> the subsequent calls at highly irregular intervals, and why that
>> seems to be necessary or desirable?
>>
>> 2) Is this a known problem that is being worked on (in which case I
>> will just shut up and wait), or am I the first to report it?
>>
>> Thanks in advance for any further info or suggestions.
>
> please provide the complete log.

There is nothing relevant in the regular logs apart from lines like
these:

Jun 20 17:11:09 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain
Jun 20 17:11:09 redcat kernel: ath9k 0000:03:00.0: PCI INT A -> GSI 18 
(level, low) -> IRQ 18

when the WLAN comes up normally, and and an additional line like this:

Jun 20 17:42:32 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain

when it fails / hangs at some unpredictable point in time later.

> you can also enable ath9k debugging.
> sudo modprobe -v ath9k debug=0x601
> http://linuxwireless.org/en/users/Drivers/ath9k/debug
> so you need to bring the interface up/down to make it working right ?

OK, done. I don't know when the error might reappear, but I will copy
the /sys/kernel/debug/ieee80211/phy0/ tree and put on some server for
forensics when it does. There is a lot of info there which I do not
know how to interpret.

Regards,
-- Jon

Re: Mysterious hangs - cfg80211 - ath9k

[Mohammed Shafi]

>
> OK, done. I don't know when the error might reappear, but I will copy
> the /sys/kernel/debug/ieee80211/phy0/ tree and put on some server for
> forensics when it does. There is a lot of info there which I do not
> know how to interpret.
>

ok, you can also post the complete logs, once the issues appears with ath9k
debug messages


-- 
thanks,
shafi

Re: Mysterious hangs - cfg80211 - ath9k

[Jon Wikne]

On 06/29/2012 08:19 AM, Mohammed Shafi wrote:
>>
>> OK, done. I don't know when the error might reappear, but I will copy
>> the /sys/kernel/debug/ieee80211/phy0/ tree and put on some server for
>> forensics when it does. There is a lot of info there which I do not
>> know how to interpret.
>>
>
> ok, you can also post the complete logs, once the issues appears with ath9k
> debug messages

Thanks.

It has been some months since I have had the possibility to pursue
this issue now. The reason is that the problem occurs only shortly
after a DHCP "lease" is renewed, and not _always_ but seemingly
random. This means that when using this system on networks with long
DHCP lease times, as I mostly do, the problem appears only rarely.
However, with _short_ lease times, like the about 1500 seconds
typically at the CERN WLAN network, the "Calling CRDA" hang appears
more frequently, and does represent a significant problem.

Anyway, since June I have:

1) Upgraded to compat-wireless-2012-05-10, just in case the problem
had been solved. No luck there! ;-)

2) Applied:

modprobe -v ath9k debug=0x601
mount -t debugfs debugfs /sys/kernel/debug/

when using the driver.

When the problem occurs, I still se no other WLAN related messages in
the ordinary log files than:

Oct  9 23:02:55 redcat kernel: wlan0: authenticate with 00:20:a6:b0:c1:0e
Oct  9 23:02:55 redcat kernel: wlan0: send auth to 00:20:a6:b0:c1:0e 
(try 1/3)
Oct  9 23:02:55 redcat kernel: wlan0: authenticated
Oct  9 23:02:55 redcat kernel: ath9k 0000:03:00.0: wlan0: disabling HT 
as WMM/QoS is not supported by the AP
Oct  9 23:02:55 redcat kernel: ath9k 0000:03:00.0: wlan0: disabling VHT 
as WMM/QoS is not supported by the AP
Oct  9 23:02:55 redcat kernel: wlan0: associate with 00:20:a6:b0:c1:0e 
(try 1/3)
Oct  9 23:02:55 redcat kernel: wlan0: RX AssocResp from 
00:20:a6:b0:c1:0e (capab=0x421 status=0 aid=5)
Oct  9 23:02:55 redcat kernel: wlan0: associated
Oct  9 23:02:55 redcat dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 
port 67 (xid=0x7913599d)
Oct  9 23:02:55 redcat dhclient: DHCPACK from 137.138.16.6 (xid=0x7913599d)
Oct  9 23:02:55 redcat avahi-daemon[3736]: New relevant interface 
wlan0.IPv4 for mDNS.
Oct  9 23:02:55 redcat avahi-daemon[3736]: Joining mDNS multicast group 
on interface wlan0.IPv4 with address 128.141.230.110.
Oct  9 23:02:55 redcat avahi-daemon[3736]: Registering new address 
record for 128.141.230.110 on wlan0.
Oct  9 23:02:55 redcat NET[12486]: /sbin/dhclient-script : updated 
/etc/resolv.conf
Oct  9 23:02:55 redcat dhclient: bound to 128.141.230.110 -- renewal in 
1590 seconds.
Oct  9 23:29:25 redcat dhclient: DHCPREQUEST on wlan0 to 137.138.16.6 
port 67 (xid=0x7913599d)
Oct  9 23:29:25 redcat dhclient: DHCPACK from 137.138.16.6 (xid=0x7913599d)
Oct  9 23:29:25 redcat dhclient: bound to 128.141.230.110 -- renewal in 
1488 seconds.
Oct  9 23:54:13 redcat dhclient: DHCPREQUEST on wlan0 to 137.138.16.6 
port 67 (xid=0x7913599d)
Oct  9 23:54:13 redcat dhclient: DHCPACK from 137.138.16.6 (xid=0x7913599d)
Oct  9 23:54:13 redcat dhclient: bound to 128.141.230.110 -- renewal in 
1579 seconds.
Oct  9 23:57:00 redcat kernel: cfg80211: Calling CRDA to update world 
regulatory domain

After the last message here, the WLAN hangs. There is also a message
about the DRDA in dmesg, but nothing else.

Subsequently, as for WLAN related messages, I see only:

Oct 10 00:20:32 redcat dhclient: DHCPREQUEST on wlan0 to 137.138.16.6 
port 67 (xid=0x7913599d)
Oct 10 00:21:19 redcat last message repeated 4 times
Oct 10 00:22:23 redcat last message repeated 5 times

until I restart WLAN, i.e.

/sbin/ifdown wlan0
/sbin/ifup wlan0

I have prepared two files with the content of all the files in the
directory

/sys/kernel/debug/ieee80211/phy0/ath9k/

for "forensics", one when the system functions normally, and one when
the problem is there. These can be downloaded here:

http://shaimina.wikne.no/jon/ath9k/

The only (to me) obvious difference is in:

/sys/kernel/debug/ieee80211/phy0/ath9k/stations

which is practically blank when the CRDA error is present.

To me, it might seem that the WLAN chip (AR9285 in my case) has been
effectively turned off....

Please CC me if posting a reply. I'm not on the list.

Regards,
-- Jon Wikne