iwlwifi unable to reconnect after suspend since v3.9-rc1

iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

since v3.9-rc1 i have been unable to reconnect to my access point. the
access point is a netgear n600 and the my card is a Centrino Advanced-N
6205 [Taylor Peak] (rev 34). the last kernel that worked was 3.8. when i
boot up the laptop the connection is established but if i bring down the
network with ifdown then i cannot reconnect. this is what i see in the
logs:

 iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
 iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
 wlan0: authenticate with xx:xx:xx:xx:xx:xx
 wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
 wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
 wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
 wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

today i discovered that this happens only if i connect to the 5GHz.
connecting to 2.4GHz works on resume. i tried to do a 'git bisect start
-- drivers/net/wireless' and i ended up with

Bisecting: 0 revisions left to test after this (roughly 0 steps)
[e1a0c6b3a4b27ed5f21291d0bbee2167ec201ef5] mac80211: stop toggling IEEE80211_HT_CAP_SUP_WIDTH_20_40

but i haven't been able to revert it cleanly so i don't know if that's
the problem or not?

any ideas? thanks.

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Tue, 2013-03-26 at 13:52 -0700, Alex Romosan wrote:
> since v3.9-rc1 i have been unable to reconnect to my access point. the
> access point is a netgear n600 and the my card is a Centrino Advanced-N
> 6205 [Taylor Peak] (rev 34). the last kernel that worked was 3.8. when i
> boot up the laptop the connection is established but if i bring down the
> network with ifdown then i cannot reconnect. this is what i see in the
> logs:
> 
>  iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
>  iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
>  wlan0: authenticate with xx:xx:xx:xx:xx:xx
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
>  wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

That sounds like it stopped the queues. Can you check debugfs:

cat /sys/kernel/debug/ieee80211/phy0/queues

when this happens?

> today i discovered that this happens only if i connect to the 5GHz.
> connecting to 2.4GHz works on resume. i tried to do a 'git bisect start
> -- drivers/net/wireless' and i ended up with
> 
> Bisecting: 0 revisions left to test after this (roughly 0 steps)
> [e1a0c6b3a4b27ed5f21291d0bbee2167ec201ef5] mac80211: stop toggling IEEE80211_HT_CAP_SUP_WIDTH_20_40
> 
> but i haven't been able to revert it cleanly so i don't know if that's
> the problem or not?

I don't think it can be the problem since this should only affect things
after the association succeeded, but you restricted the bisect to the
drivers which was probably too much.

git bisect start -- drivers/net/wireless net/wireless net/mac80211

would probably have been more successful.

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> That sounds like it stopped the queues. Can you check debugfs:
>
> cat /sys/kernel/debug/ieee80211/phy0/queues
>
> when this happens?

i don't have anything under /sys/kernel/debug/ so i probably need to
turn some debugging options on, but...

> git bisect start -- drivers/net/wireless net/wireless net/mac80211
>
> would probably have been more successful.

...i did a bisect using the above and it came up with this:

89afe614c0c737fd40eda1f8c8ef686246cf3cb6 is the first bad commit
commit 89afe614c0c737fd40eda1f8c8ef686246cf3cb6
Author: Johannes Berg <johannes.berg@intel.com>
Date:   Wed Feb 13 15:39:57 2013 +0100

    mac80211: fix auth/assoc timeout handling

which makes a lot more sense. i'll try reverting it to see if it fixes
the problem, or i can try patches if you have any.

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 10:35 -0700, Alex Romosan wrote:

> ...i did a bisect using the above and it came up with this:
> 
> 89afe614c0c737fd40eda1f8c8ef686246cf3cb6 is the first bad commit
> commit 89afe614c0c737fd40eda1f8c8ef686246cf3cb6
> Author: Johannes Berg <johannes.berg@intel.com>
> Date:   Wed Feb 13 15:39:57 2013 +0100
> 
>     mac80211: fix auth/assoc timeout handling
> 
> which makes a lot more sense. i'll try reverting it to see if it fixes
> the problem, or i can try patches if you have any.

Humm, yes, that makes more sense. That commit fixed a bug in another
commit though, I'm surprised you ended up there?! Curious ... I'll check
over the commit and see if I can find anything wrong with it.

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> On Wed, 2013-03-27 at 10:35 -0700, Alex Romosan wrote:
>
>> ...i did a bisect using the above and it came up with this:
>> 
>> 89afe614c0c737fd40eda1f8c8ef686246cf3cb6 is the first bad commit
>> commit 89afe614c0c737fd40eda1f8c8ef686246cf3cb6
>> Author: Johannes Berg <johannes.berg@intel.com>
>> Date:   Wed Feb 13 15:39:57 2013 +0100
>> 
>>     mac80211: fix auth/assoc timeout handling
>> 
>> which makes a lot more sense. i'll try reverting it to see if it fixes
>> the problem, or i can try patches if you have any.
>
> Humm, yes, that makes more sense. That commit fixed a bug in another
> commit though, I'm surprised you ended up there?! Curious ... I'll
> check over the commit and see if I can find anything wrong with it.

i just reverted that commit on top of 3.9-rc4 and now i can reconnect
when resuming from suspend. so whatever bug that commit fixed, it also
introduced a new one.

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 11:02 -0700, Alex Romosan wrote:

> > Humm, yes, that makes more sense. That commit fixed a bug in another
> > commit though, I'm surprised you ended up there?! Curious ... I'll
> > check over the commit and see if I can find anything wrong with it.
> 
> i just reverted that commit on top of 3.9-rc4 and now i can reconnect
> when resuming from suspend. so whatever bug that commit fixed, it also
> introduced a new one.

Hmm, actually ... I suspect this didn't introduce a bug but rather
unmasked one in iwlwifi/mac80211 interaction.

Are you sure this only happens after suspend/resume? It seems like it
would always happen? At least if there was a beacon in the scan results
already, which should probably always be the case...

Can you enable iwlwifi debugging and set the iwlwifi module parameter
debug=0x40000000 ? I have a feeling you'll see something like
"PASSIVE_NO_RX" in there.

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> On Wed, 2013-03-27 at 11:02 -0700, Alex Romosan wrote:
>
>> > Humm, yes, that makes more sense. That commit fixed a bug in another
>> > commit though, I'm surprised you ended up there?! Curious ... I'll
>> > check over the commit and see if I can find anything wrong with it.
>> 
>> i just reverted that commit on top of 3.9-rc4 and now i can reconnect
>> when resuming from suspend. so whatever bug that commit fixed, it also
>> introduced a new one.
>
> Hmm, actually ... I suspect this didn't introduce a bug but rather
> unmasked one in iwlwifi/mac80211 interaction.
>
> Are you sure this only happens after suspend/resume? It seems like it
> would always happen? At least if there was a beacon in the scan results
> already, which should probably always be the case...

no, it always happens, but i only noticed it after suspend/resume. when
i suspend i do an ifdown (because i haven't figured out a way to
convince my new access point not to drop idle connections) and then i do
an ifup to reconnect on resume. when i'm testing it now, i just take the
network down and then try to bring it back up.

> Can you enable iwlwifi debugging and set the iwlwifi module parameter
> debug=0x40000000 ? I have a feeling you'll see something like
> "PASSIVE_NO_RX" in there.

i'll do it and let you know. i have iwlwifi compiled in the kernel, how
do i specify it at boot time?

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 12:08 -0700, Alex Romosan wrote:

> > Can you enable iwlwifi debugging and set the iwlwifi module parameter
> > debug=0x40000000 ? I have a feeling you'll see something like
> > "PASSIVE_NO_RX" in there.
> 
> i'll do it and let you know. i have iwlwifi compiled in the kernel, how
> do i specify it at boot time?

Oh, you can either specify iwlwifi.debug=0x40000000 or just do

echo 0x40000000 > /sys/module/iwlwifi/parameters/debug

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 12:08 -0700, Alex Romosan wrote:

> > Are you sure this only happens after suspend/resume? It seems like it
> > would always happen? At least if there was a beacon in the scan results
> > already, which should probably always be the case...
> 
> no, it always happens, but i only noticed it after suspend/resume. when
> i suspend i do an ifdown (because i haven't figured out a way to
> convince my new access point not to drop idle connections) and then i do
> an ifup to reconnect on resume. when i'm testing it now, i just take the
> network down and then try to bring it back up.

Ah, right, I guess I'm a little surprised it ever works at all ... We'll
see in the log though.

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> Ah, right, I guess I'm a little surprised it ever works at all ... We'll
> see in the log though.

this is when it works on startup:

[   18.336462] wlan0: authenticate with xx:xx:xx:xx:xx:xx
[   18.377276] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[   18.395294] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
[   18.395309] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
[   18.395317] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0xc0
[   18.395349] wlan0: authenticated
[   18.412835] wlan0: associate with xx:xx:xx:xx:xx:xx (try 1/3)
[   18.428858] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 1 -> 2 (2)
[   18.428874] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
[   18.428882] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=1 ssn=2 seq_ctl=0xd0
[   18.428983] wlan0: RX AssocResp from xx:xx:xx:xx:xx:xx (capab=0x401 status=0 aid=1)
[   18.449793] wlan0: associated

and then after i take the interface down and try to bring it back up:

[   99.097061] wlan0: deauthenticating from xx:xx:xx:xx:xx:xx by local choice (reason=3)
[   99.099874] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 43 -> 44 (44)
[   99.099891] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
[   99.099901] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=43 ssn=44 seq_ctl=0x110
[   99.103816] cfg80211: Calling CRDA to update world regulatory domain
[   99.116363] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[   99.116596] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[   99.247069] cfg80211: World regulatory domain updated:
[   99.247082] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[   99.247090] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   99.247096] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   99.247102] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[   99.247107] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[   99.247112] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  110.171839] wlan0: authenticate with xx:xx:xx:xx:xx:xx
[  110.182503] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[  110.185173] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
[  110.185191] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.185200] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0x60
[  110.187879] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 1 -> 2 (2)
[  110.187890] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.187899] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=1 ssn=2 seq_ctl=0x60
[  110.187927] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
[  110.190721] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 2 -> 3 (3)
[  110.190742] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.190752] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=2 ssn=3 seq_ctl=0x70
[  110.193598] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 3 -> 4 (4)
[  110.193616] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.193625] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=3 ssn=4 seq_ctl=0x70
[  110.194594] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
[  110.197333] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 4 -> 5 (5)
[  110.197351] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.197361] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=4 ssn=5 seq_ctl=0x80
[  110.200088] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 5 -> 6 (6)
[  110.200105] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[  110.200115] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=5 ssn=6 seq_ctl=0x80
[  110.200184] wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 12:33 -0700, Alex Romosan wrote:

> [   18.377276] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
> [   18.395294] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
> [   18.395309] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
> [   18.395317] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0xc0
> [   18.395349] wlan0: authenticated


> [  110.182503] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
> [  110.185173] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
> [  110.185191] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
> [  110.185200] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0x60
> [  110.187879] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 1 -> 2 (2)
> [  110.187890] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
> [  110.187899] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=1 ssn=2 seq_ctl=0x60

As I had expected. Not sure why it's two frames every time?

Unfortunately I can't reproduce it, I suspect my environment isn't clean
enough any more (somebody else bought a 5 GHz AP recently ...)

Could you try this patch?

http://p.sipsolutions.net/617a8667db243e11.txt

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> Unfortunately I can't reproduce it, I suspect my environment isn't clean
> enough any more (somebody else bought a 5 GHz AP recently ...)
>
> Could you try this patch?
>
> http://p.sipsolutions.net/617a8667db243e11.txt

with this patch applied i can take the network down and bring it back
again. this is the log:

[   84.204759] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[   84.204965] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[   84.429015] wlan0: authenticate with xx:xx:xx:xx:xx:xx
[   84.440148] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[   84.442819] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
[   84.442844] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090) rate_n_flags 0x800d retries 0
[   84.442855] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx FrameCnt = 1, idx=0
[   84.442884] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
[   84.442896] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0x90
[   84.532849] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 1 -> 2 (2)
[   84.532867] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
[   84.532875] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=1 ssn=2 seq_ctl=0x0
[   84.533043] wlan0: authenticated
[   84.534066] wlan0: associate with xx:xx:xx:xx:xx:xx (try 1/3)
[   84.535599] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 2 -> 3 (3)
[   84.535616] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
[   84.535624] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=2 ssn=3 seq_ctl=0x10
[   84.535701] wlan0: RX AssocResp from xx:xx:xx:xx:xx:xx (capab=0x401 status=0 aid=1)
[   84.539789] wlan0: associated
[   89.818453] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx Next reclaimed packet:1
[   89.818464] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 2] 0 -> 1 (1)
[   89.818474] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx Next reclaimed packet:1
[   89.818482] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 2 status SUCCESS (0x00000201)
[   89.818489] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=0 ssn=1 seq_ctl=0x0

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 13:03 -0700, Alex Romosan wrote:

> > Could you try this patch?
> >
> > http://p.sipsolutions.net/617a8667db243e11.txt
> 
> with this patch applied i can take the network down and bring it back
> again. this is the log:

> [   84.440148] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
> [   84.442819] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 0 -> 1 (1)
> [   84.442844] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090) rate_n_flags 0x800d retries 0
> [   84.442855] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx FrameCnt = 1, idx=0
> [   84.442884] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status PASSIVE_NO_RX (0x00000090)
> [   84.442896] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x800d retries 0, idx=0 ssn=1 seq_ctl=0x90
> [   84.532849] iwlwifi 0000:03:00.0: I iwl_trans_pcie_reclaim [Q 0] 1 -> 2 (2)
> [   84.532867] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx TXQ 0 status SUCCESS (0x00000201)
> [   84.532875] iwlwifi 0000:03:00.0: I iwlagn_rx_reply_tx                               initial_rate 0x400d retries 0, idx=1 ssn=2 seq_ctl=0x0

Ah so it's even the same packet because we set
IEEE80211_TX_STAT_TX_FILTERED.

Note the delay here -- roughly between 84.4428 and 84.5328 we wait for a
beacon.

I'll apply the patch and add your tested-by, like this:

http://p.sipsolutions.net/7e871bfb5a0b272a.txt

OK?

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> Ah so it's even the same packet because we set
> IEEE80211_TX_STAT_TX_FILTERED.
>
> Note the delay here -- roughly between 84.4428 and 84.5328 we wait for a
> beacon.
>
> I'll apply the patch and add your tested-by, like this:
>
> http://p.sipsolutions.net/7e871bfb5a0b272a.txt
>
> OK?

looks good. thanks.

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Tue, 2013-03-26 at 13:52 -0700, Alex Romosan wrote:
> since v3.9-rc1 i have been unable to reconnect to my access point. the
> access point is a netgear n600 and the my card is a Centrino Advanced-N
> 6205 [Taylor Peak] (rev 34). the last kernel that worked was 3.8. when i
> boot up the laptop the connection is established but if i bring down the
> network with ifdown then i cannot reconnect. this is what i see in the
> logs:
> 
>  iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
>  iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
>  wlan0: authenticate with xx:xx:xx:xx:xx:xx
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
>  wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

Btw, since we're looking at the timeout handling -- do you have a
version of this log with timestamps on each line?

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> On Tue, 2013-03-26 at 13:52 -0700, Alex Romosan wrote:
>> since v3.9-rc1 i have been unable to reconnect to my access point. the
>> access point is a netgear n600 and the my card is a Centrino Advanced-N
>> 6205 [Taylor Peak] (rev 34). the last kernel that worked was 3.8. when i
>> boot up the laptop the connection is established but if i bring down the
>> network with ifdown then i cannot reconnect. this is what i see in the
>> logs:
>> 
>>  iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
>>  iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
>>  wlan0: authenticate with xx:xx:xx:xx:xx:xx
>>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
>>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
>>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
>>  wlan0: authentication with xx:xx:xx:xx:xx:xx timed out
>
> Btw, since we're looking at the timeout handling -- do you have a
> version of this log with timestamps on each line?

i do but the timestamp is the same on all the lines:

Mar 27 09:43:14 trinculo kernel: iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
Mar 27 09:43:14 trinculo kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Mar 27 09:43:16 trinculo kernel: wlan0: authenticate with xx:xx:xx:xx:xx:xx
Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
Mar 27 09:43:16 trinculo kernel: wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Johannes Berg]

On Wed, 2013-03-27 at 10:48 -0700, Alex Romosan wrote:
> Johannes Berg <johannes@sipsolutions.net> writes:
> 
> > On Tue, 2013-03-26 at 13:52 -0700, Alex Romosan wrote:
> >> since v3.9-rc1 i have been unable to reconnect to my access point. the
> >> access point is a netgear n600 and the my card is a Centrino Advanced-N
> >> 6205 [Taylor Peak] (rev 34). the last kernel that worked was 3.8. when i
> >> boot up the laptop the connection is established but if i bring down the
> >> network with ifdown then i cannot reconnect. this is what i see in the
> >> logs:
> >> 
> >>  iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
> >>  iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
> >>  wlan0: authenticate with xx:xx:xx:xx:xx:xx
> >>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
> >>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
> >>  wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
> >>  wlan0: authentication with xx:xx:xx:xx:xx:xx timed out
> >
> > Btw, since we're looking at the timeout handling -- do you have a
> > version of this log with timestamps on each line?
> 
> i do but the timestamp is the same on all the lines:
> 
> Mar 27 09:43:14 trinculo kernel: iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
> Mar 27 09:43:14 trinculo kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
> Mar 27 09:43:16 trinculo kernel: wlan0: authenticate with xx:xx:xx:xx:xx:xx
> Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
> Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
> Mar 27 09:43:16 trinculo kernel: wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
> Mar 27 09:43:16 trinculo kernel: wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

Ok, well, that doesn't tell us all that much since you don't have
sub-second timestamps. Maybe you can enable printk timestamps:

echo Y > /sys/module/printk/parameters/time

johannes

Re: iwlwifi unable to reconnect after suspend since v3.9-rc1

[Alex Romosan]

Johannes Berg <johannes@sipsolutions.net> writes:

> Ok, well, that doesn't tell us all that much since you don't have
> sub-second timestamps. Maybe you can enable printk timestamps:
>
> echo Y > /sys/module/printk/parameters/time

in case it helps. first the logs when the card connected on startup:

[   18.198708] wlan0: authenticate with xx:xx:xx:xx:xx:xx
[   18.236585] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[   18.255020] wlan0: authenticated
[   18.271878] wlan0: associate with xx:xx:xx:xx:xx:xx (try 1/3)
[   18.273285] wlan0: RX AssocResp from xx:xx:xx:xx:xx:xx (capab=0x401 status=0 aid=1)
[   18.275783] wlan0: associated

and then when i took the interface down and tried to bring it back up:

[  135.930592] wlan0: deauthenticating from xx:xx:xx:xx:xx:xx by local choice (reason=3)
[  135.938013] cfg80211: Calling CRDA to update world regulatory domain
[  135.951043] iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
[  135.951274] iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
[  136.072911] cfg80211: World regulatory domain updated:
[  136.072924] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[  136.072932] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  136.072938] cfg80211:   (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[  136.072944] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[  136.072949] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  136.072955] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[  144.804742] wlan0: authenticate with xx:xx:xx:xx:xx:xx
[  144.816187] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 1/3)
[  144.821469] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 2/3)
[  144.826866] wlan0: send auth to xx:xx:xx:xx:xx:xx (try 3/3)
[  144.832539] wlan0: authentication with xx:xx:xx:xx:xx:xx timed out

--alex--

-- 
| I believe the moment is at hand when, by a paranoiac and active |
|  advance of the mind, it will be possible (simultaneously with  |
|  automatism and other passive states) to systematize confusion  |
|  and thus to help to discredit completely the world of reality. |