On Mon, Sep 09, 2019 at 10:38:25AM BST, Stefan Sperling wrote:
> On Mon, Sep 09, 2019 at 10:26:37AM +0100, Raf Czlonka wrote:
> > Your email prompted me today to have a look at what is happening
> > while the laptop loses connectivity - it's been disconnected for 3
> > days after about 30 minutes of being connected (enough time to run
> > 'pkg_add -u'). After putting the interface into debug modes:
> >
> > # ifconfig iwn0 debug
> >
> > /var/log/messages shows:
> >
> > iwn0: AUTH -> SCAN
> > iwn0: end active scan
> > iwn0: - [...]
> > iwn0: - 12:34:56:12:34:56 11 +212 54M ess privacy rsn "MYNWID2"!
> > iwn0: + 12:34:56:12:34:57 44 +203 54M ess privacy rsn "MYNWID5"
> > iwn0: - [...]
> > iwn0: SCAN -> AUTH
> > iwn0: sending auth to 12:34:56:12:34:57 on channel 44 mode 11a
>
> This small part of the log is not useful by itself, unfortunately.
> You need to show debug output where iwn left RUN state in the first place.
After 10 hours of running without issues it had a similar blip but
managed to reconnect fine:
Sep 10 20:44:35 host /bsd: iwn0: RUN -> AUTH
Sep 10 20:44:35 host /bsd: iwn0: sending action to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:35 host /bsd: iwn0: sending action to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:35 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:39 host /bsd: iwn0: AUTH -> SCAN
Sep 10 20:44:42 host /bsd: iwn0: end active scan
Sep 10 20:44:42 host /bsd: iwn0: - 12:34:56:12:34:56 11 +214 54M
ess privacy rsn "MYNWID2"!
Sep 10 20:44:42 host /bsd: iwn0: + 12:34:56:12:34:57 44 +198 54M
ess privacy rsn "MYNWID5"
Sep 10 20:44:42 host /bsd: iwn0: SCAN -> AUTH
Sep 10 20:44:42 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11a
Sep 10 20:44:47 host /bsd: iwn0: AUTH -> SCAN
Sep 10 20:44:50 host /bsd: iwn0: end active scan
Sep 10 20:44:50 host /bsd: iwn0: - 12:34:56:12:34:56 11 +214 54M
ess privacy rsn "MYNWID2"!
Sep 10 20:44:50 host /bsd: iwn0: + 12:34:56:12:34:57 44 +198 54M
ess privacy rsn "MYNWID5"
Sep 10 20:44:50 host /bsd: iwn0: SCAN -> AUTH
Sep 10 20:44:50 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11a
Sep 10 20:44:50 host /bsd: iwn0: AUTH -> ASSOC
Sep 10 20:44:50 host /bsd: iwn0: sending assoc_req to 12:34:56:12:34:57
on channel 44 mode 11a
Sep 10 20:44:50 host /bsd: iwn0: ASSOC -> RUN
Sep 10 20:44:50 host /bsd: iwn0: associated with 12:34:56:12:34:57 ssid
"MYNWID5" channel 44 start MCS 0 long preamble short slot time HT enabled
Sep 10 20:44:50 host /bsd: iwn0: missed beacon threshold set to 7
beacons, beacon interval is 100 TU
Sep 10 20:44:50 host /bsd: iwn0: received msg 1/4 of the 4-way
handshake from 12:34:56:12:34:57
Sep 10 20:44:50 host /bsd: iwn0: sending msg 2/4 of the 4-way handshake
to 12:34:56:12:34:57
Sep 10 20:44:50 host /bsd: iwn0: received msg 3/4 of the 4-way
handshake from 12:34:56:12:34:57
Sep 10 20:44:50 host /bsd: iwn0: sending msg 4/4 of the 4-way handshake
to 12:34:56:12:34:57
Sep 10 20:44:50 host /bsd: iwn0: sending action to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:51 host last message repeated 3 times
Sep 10 20:44:54 host /bsd: iwn0: RUN -> AUTH
Sep 10 20:44:54 host /bsd: iwn0: sending action to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:54 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:44:59 host /bsd: iwn0: AUTH -> SCAN
Sep 10 20:45:02 host /bsd: iwn0: end active scan
Sep 10 20:45:02 host /bsd: iwn0: - 12:34:56:12:34:56 11 +214 54M
ess privacy rsn "MYNWID2"!
Sep 10 20:45:02 host /bsd: iwn0: + 12:34:56:12:34:57 44 +197 54M
ess privacy rsn "MYNWID5"
Sep 10 20:45:02 host /bsd: iwn0: SCAN -> AUTH
Sep 10 20:45:02 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11a
Sep 10 20:45:07 host /bsd: iwn0: AUTH -> SCAN
Sep 10 20:45:10 host /bsd: iwn0: end active scan
Sep 10 20:45:10 host /bsd: iwn0: - 12:34:56:12:34:56 11 +214 54M
ess privacy rsn "MYNWID2"!
Sep 10 20:45:10 host /bsd: iwn0: + 12:34:56:12:34:57 44 +197 54M
ess privacy rsn "MYNWID5"
Sep 10 20:45:10 host /bsd: iwn0: SCAN -> AUTH
Sep 10 20:45:10 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11a
Sep 10 20:45:15 host /bsd: iwn0: AUTH -> SCAN
Sep 10 20:45:18 host /bsd: iwn0: end active scan
Sep 10 20:45:18 host /bsd: iwn0: - 12:34:56:12:34:56 11 +208 54M
ess privacy rsn "MYNWID2"!
Sep 10 20:45:18 host /bsd: iwn0: + 12:34:56:12:34:57 44 +197 54M
ess privacy rsn "MYNWID5"
Sep 10 20:45:18 host /bsd: iwn0: SCAN -> AUTH
Sep 10 20:45:18 host /bsd: iwn0: sending auth to 12:34:56:12:34:57 on
channel 44 mode 11a
Sep 10 20:45:18 host /bsd: iwn0: AUTH -> ASSOC
Sep 10 20:45:18 host /bsd: iwn0: sending assoc_req to 12:34:56:12:34:57
on channel 44 mode 11a
Sep 10 20:45:18 host /bsd: iwn0: ASSOC -> RUN
Sep 10 20:45:18 host /bsd: iwn0: associated with 12:34:56:12:34:57 ssid
"MYNWID5" channel 44 start MCS 0 long preamble short slot time HT enabled
Sep 10 20:45:18 host /bsd: iwn0: missed beacon threshold set to 7
beacons, beacon interval is 100 TU
Sep 10 20:45:18 host /bsd: iwn0: received msg 1/4 of the 4-way
handshake from 12:34:56:12:34:57
Sep 10 20:45:18 host /bsd: iwn0: sending msg 2/4 of the 4-way handshake
to 12:34:56:12:34:57
Sep 10 20:45:18 host /bsd: iwn0: received msg 3/4 of the 4-way
handshake from 12:34:56:12:34:57
Sep 10 20:45:18 host /bsd: iwn0: sending msg 4/4 of the 4-way handshake
to 12:34:56:12:34:57
Sep 10 20:45:18 host /bsd: iwn0: sending action to 12:34:56:12:34:57 on
channel 44 mode 11n
Sep 10 20:45:21 host last message repeated 3 times
Sep 10 21:45:14 host /bsd: iwn0: received msg 1/2 of the group key
handshake from 12:34:56:12:34:57
Sep 10 21:45:14 host /bsd: iwn0: sending msg 2/2 of the group key
handshake to 12:34:56:12:34:57
> > What seems strange there is the mode - after a very brief look, it
> > seems like the laptop is "stuck" trying to use 11a mode.
> >
> > After forcing the 11n mode:
> >
> > # ifconfig iwn0 mode 11n
> >
> > it connects instantaneously:
>
> This command resets everything and the condition which triggered the
> problem is now gone.
Sure, that was only to show how to get iwn to reconnect with the AP.
Was there anything I could have done/checked in that state which
would have given more information? As per above, I've only enabled
the debug mode post factum.
> It connected fine to your 2 GHz AP. You have only shown failing connection
> attempts to your 5 GHz AP. Did your 5 GHz AP ever actually work with iwn?
>
As per above debug log - yes, iwn and my 5 GHz AP work fine together:
iwn0: flags=808847<UP,BROADCAST,DEBUG,RUNNING,SIMPLEX,MULTICAST,AUTOCONF4> mtu
1500
lladdr 00:11:22:aa:bb:cc
index 2 priority 4 llprio 3
groups: wlan egress
media: IEEE802.11 autoselect (HT-MCS7 mode 11n)
status: active
ieee80211: join MYNWID5 chan 44 bssid 12:34:56:12:34:57 -56dBm wpakey
wpaprotos wpa2 wpaakms psk wpaciphers ccmp wpagroupcipher ccmp
inet 10.0.0.12 netmask 0xffffff00 broadcast 10.0.0.255
And no, I don't know whether channel has changed before.
Is this at all useful?
Regards,
Raf
