WPA_supplicant trouble connecting client to AP
Francisco Cuesta
ndarkness
Thu May 16 22:58:17 PDT 2013
2013/5/16 Dan Williams <dcbw at redhat.com>:
> On Thu, 2013-05-16 at 10:41 +0200, Francisco Cuesta wrote:
>> 2013/5/15 Dan Williams <dcbw at redhat.com>:
>> > On Wed, 2013-05-15 at 16:44 +0200, Francisco Cuesta wrote:
>> >> 2013/5/15 Dan Williams <dcbw at redhat.com>:
>> >> > On Wed, 2013-05-15 at 16:17 +0200, Francisco Cuesta wrote:
>> >> >> 2013/5/15 Dan Williams <dcbw at redhat.com>:
>> >> >> > On Wed, 2013-05-15 at 14:01 +0200, Francisco Cuesta wrote:
>> >> >> >> Hi Jouni,
>> >> >> >>
>> >> >> >> >Which wpa_supplicant are you using?
>> >> >> >>
>> >> >> >> I'm currently using wpa_supplicant v2.0-devel
>> >> >> >>
>> >> >> >> >What is this fixed_freq parameter? It sounds like this wpa_supplicant
>> >> >> >> >version has some changes that do not exist in hostap.git and as such, it
>> >> >> >> >is unclear how it behaves.
>> >> >> >>
>> >> >> >> This parameters I think represent that the frequency of the AP is
>> >> >> >> already fixed. This wpa_supplicant configuration file is parsed from a
>> >> >> >> generic wpa_supplicant configuration, this is done in this way in
>> >> >> >> OpenWRT; they launches hostapd which parses this generic file and
>> >> >> >> calls wpa_supplicant with it.
>> >> >> >
>> >> >> > His point is that fixed_freq is *not* an option in the official
>> >> >> > hostap/wpa_supplicant sources, so whatever you're running, it's been
>> >> >> > modified by whoever you got it from.
>> >> >> >
>> >> >>
>> >> >>
>> >> >> >> >How do you know what it does after this? The -B option on the command
>> >> >> >> >line requests wpa_supplicant to move into the background and that stops
>> >> >> >> >the debug log to stdout. If you want to see after this, you would need
>> >> >> >> >to either direct the log to a file or syslog or remove the -B option.
>> >> >> >>
>> >> >> >> I've followed your advice, and I have disabled the -B option and now I
>> >> >> >> get more output once I launch wpa_supplicant, which is this one
>> >> >> >>
>> >> >> >> wlan1: State: DISCONNECTED -> SCANNING
>> >> >> >> Scan SSID - hexdump_ascii(len=18):
>> >> >> >> 69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 X-X-X-X
>> >> >> >> 62 65 -X
>> >> >> >> wlan1: Starting AP scan for wildcard SSID
>> >> >> >> nl80211: Scan SSID - hexdump_ascii(len=18):
>> >> >> >> 69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 X-X-X-X
>> >> >> >> 62 65 -X
>> >> >> >> nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>> >> >> >> Scan requested (ret=0) - scan timeout 30 seconds
>> >> >> >> nl80211: Event message available
>> >> >> >> nl80211: Scan trigger
>> >> >> >> RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>> >> >> >> netlink: Operstate: linkmode=-1, operstate=6
>> >> >> >> The num-Xr of sent bytes in netlink_send_oper_ifla are 37
>> >> >> >> RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
>> >> >> >> nl80211: if_removed already cleared - ignore event
>> >> >> >> nl80211: Event message available
>> >> >> >> nl80211: New scan results available
>> >> >> >> wlan1: Event SCAN_RESULTS (3) received
>> >> >> >> nl80211: Received scan results (1 BSSes)
>> >> >> >> wlan1: BSS: Start scan result update 6
>> >> >> >> BSS: last_scan_res_used=1/32 last_scan_full=0
>> >> >> >> wlan1: New scan results available
>> >> >> >> wlan1: Selecting BSS from priority group 0
>> >> >> >> wlan1: 0: 64:70:02:3e:a7:82 ssid='X-X-X-X-X' wpa_ie_len=0 rsn_ie_len=0
>> >> >> >> caps=0x1 level=-70
>> >> >> >> A BSSID in blacklist is this: 4896660
>> >> >> >> The BSSID of blacklist selected is this: 4896660
>> >> >> >
>> >> >> > These messages are also not part of official hostap/wpa_supplicant, so
>> >> >> > your version has been patched by somebody, and that may be introducing
>> >> >> > new bugs.
>> >> >> >
>> >> >>
>> >> >> What messages do you refer to? The X-X-X... which appears there, I
>> >> >> have set it by myself, as well I have put some extra printf in the
>> >> >> code to see the running sequence
>> >> >
>> >> > I mean the "A BSSID in the blacklist" messages. Are those your local
>> >> > modifications?
>> >> >
>> >>
>> >> Yes they're, I added a prinrf on the code.
>> >>
>> >> >> >> wlan1: skip - blacklisted (count=1 limit=0)
>> >> >> >> wlan1: No APs found - clear blacklist and try again
>> >> >> >> Removed BSSID 64:70:02:3e:a7:82 from blacklist (clear)
>> >> >> >> wlan1: Selecting BSS from priority group 0
>> >> >> >> wlan1: 0: 64:70:02:3e:a7:82 ssid='X-X-X-X-X' wpa_ie_len=0 rsn_ie_len=0
>> >> >> >> caps=0x1 level=-70
>> >> >> >> wlan1: allow in non-WPA/WPA2
>> >> >> >> The channel that wpa_s struct has got is 36
>> >> >> >> The frequency that wpa_s struct has got is 5180 MHz
>> >> >> >> The set channel on rate_match function is 2364476
>> >> >> >> The set frequency on rate_match function is 5180 MHz
>> >> >> >> The set frequency on rate_match function is 5180 MHz
>> >> >> >> The comparison freq == bss->freq is true
>> >> >> >> wlan1: selected BSS 64:70:02:3e:a7:82 ssid='X-X-X-X-X'
>> >> >> >> wlan1: Request association: reassociate: 0 selected:
>> >> >> >> 64:70:02:3e:a7:82 bssid: 00:00:00:00:00:00 pending:
>> >> >> >> 00:00:00:00:00:00 wpa_state: SCANNING
>> >> >> >> wlan1: Automatic auth_alg selection: 0x1
>> >> >> >> wlan1: WPA: clearing AP WPA IE
>> >> >> >> wlan1: WPA: clearing AP RSN IE
>> >> >> >> wlan1: WPA: clearing own WPA/RSN IE
>> >> >> >> wlan1: Cancelling scan request
>> >> >> >> wlan1: SME: Trying to authenticate with 64:70:02:3e:a7:82
>> >> >> >> (SSID='X-X-X-X-X' freq=5180 MHz)
>> >> >> >> wlan1: No keys have -Xen configured - skip key clearing
>> >> >> >> wlan1: State: SCANNING -> AUTHENTICATING
>> >> >> >> nl80211: Authenticate (ifindex=33)
>> >> >> >> * bssid=64:70:02:3e:a7:82
>> >> >> >> * freq=5180
>> >> >> >> * SSID - hexdump_ascii(len=18):
>> >> >> >> 69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 X-X-X-X
>> >> >> >> 62 65 -X
>> >> >> >> * IEs - hexdump(len=0): [NULL]
>> >> >> >> * Auth Type 0
>> >> >> >> nl80211: Authentication request send successfully
>> >> >> >> wlan1: Checking for other virtual interfaces sharing same radio (phy1)
>> >> >> >> in event_scan_results
>> >> >> >> nl80211: Event message available
>> >> >> >> nl80211: New station 64:70:02:3e:a7:82
>> >> >> >> nl80211: Event message available
>> >> >> >> nl80211: Delete station 64:70:02:3e:a7:82
>> >> >> >> nl80211: Event message available
>> >> >> >> nl80211: MLME event 37; timeout with 64:70:02:3e:a7:82
>> >> >> >> wlan1: Event AUTH_TIMED_OUT (14) received
>> >> >> >> wlan1: SME: Authentication timed out
>> >> >> >
>> >> >> > This indicates that the kernel driver has not been able to authenticate
>> >> >> > with the AP, so the problem may be due to kernel driver issues. Which
>> >> >> > kernel are you using and which wifi driver?
>> >> >> >
>> >> >>
>> >> >> I'm using a linux kernel which is 3.3.8. The wifi devices are an
>> >> >> atheros AR9341 (integrated
>> >> >> 2.4ghz) + AR9580 (5ghz) (onboard), both devices are managed with ath9k
>> >> >> driver plus compat wireless drivers called compat-wireless-2012-09-07.
>> >> >
>> >> > That kernel version is pretty old; are you able to try a newer one like
>> >> > 3.8.x or 3.9.x? Plus you might want to update your compat-wireless as
>> >> > well; a lot happens in 8 months. In any case, I'm not as familiar with
>> >> > the ath9k drivers as Jouni or others are so I'll let them answer about
>> >> > the state of compat-wireless from Sept 2012 and the 3.3.8 kernel.
>> >> >
>> >> I see, I'm afraid not, because that is the kernel that the latest
>> >> version of openwrt has, and I don't now how it might be updated.
>> >> Thanks for your replies, I'll wait for their replies in such a
>> >> matters.
>> >>
>> >>
>> >> >> Could you tell me where in the kernel driver are defined the channels
>> >> >> that might be authenticated with the AP?
>> >> >
>> >> > It's a state machine, so there aren't any channels. The kernel driver
>> >> > and the kernel mac80211 stack do quite a few operations during the
>> >> > association process so if you're able to turn on kernel debugging, or if
>> >> > you have any kernel log messages from 'dmesg' that would be helpful.
>> >> >
>> >> I have issued the dmesg command getting this
>> >>
>> >> wlan1: authentication with 64:70:02:3e:a7:82 timed out
>> >> [ 191.470000] wlan1: authenticate with 64:70:02:3e:a7:82
>> >> [ 191.480000] wlan1: send auth to 64:70:02:3e:a7:82 (try 1/3)
>> >> [ 191.700000] wlan1: send auth to 64:70:02:3e:a7:82 (try 2/3)
>> >> [ 191.910000] wlan1: send auth to 64:70:02:3e:a7:82 (try 3/3)
>> >> [ 192.120000] wlan1: authentication with 64:70:02:3e:a7:82 timed out
>> >> [ 195.590000] wlan1: authenticate with 64:70:02:3e:a7:82
>> >> [ 195.600000] wlan1: send auth to 64:70:02:3e:a7:82 (try 1/3)
>> >> [ 195.820000] wlan1: send auth to 64:70:02:3e:a7:82 (try 2/3)
>> >> [ 196.030000] wlan1: send auth to 64:70:02:3e:a7:82 (try 3/3)
>> >
>> > Yeah, this says that the driver doesn't see any response from the AP.
>> > The next thing you get to do is to sniff frames using a different
>> > machine to see if the AP actually does reply, which would indicate that
>> > the driver is busted. But again, a driver/stack from Sept 2012 is
>> > pretty old, and if there was a bug, it may well have been fixed long
>> > since.
>> >
>>
>> I see , another question, can this error be also due to the client
>> frequency is different from the AP one? I say this, because I've seen
>> on the wpa supplicant debug
>>
>> nl80211: Authenticate (ifindex=17)
>> * bssid=64:70:02:3e:a7:82
>> * freq=5180 <----------------------------------------THIS
>
> The frequency should be found from the scan results; what results do you
> get when you run the supplicant with "-dddt"? It should print out the
> frequency then.
>
The output of a complete cycle that I get are the following:
wlan1: State: DISCONNECTED -> SCANNING
1315503198.069739: Scan SSID - hexdump_ascii(len=18):
69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 <SSID>
62 65 <SSID>
1315503198.070008: wlan1: Starting AP scan for wildcard SSID
1315503198.070078: nl80211: Scan SSID - hexdump_ascii(len=18):
69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 <SSID>
62 65 <SSID>
1315503198.070326: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1315503198.070529: Scan requested (ret=0) - scan timeout 30 seconds
1315503198.070632: nl80211: Event message available
1315503198.070693: nl80211: Scan trigger
1315503201.436117: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1315503201.436206: netlink: Operstate: linkmode=-1, operstate=6
1315503201.436408: The number of sent bytes in netlink_send_oper_ifla are 37
1315503201.436468: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1315503201.442886: nl80211: if_removed already cleared - ignore event
1315503201.442972: nl80211: Event message available
1315503201.443049: nl80211: New scan results available
1315503201.443117: wlan1: Event SCAN_RESULTS (3) received
1315503201.443287: nl80211: Received scan results (1 BSSes)
1315503201.443977: Sorted scan results
1315503201.444019: <BSSID> freq=5180 qual=0 noise=-93 level=-70 snr=23 flags=0x9
1315503201.444099: IEs - hexdump(len=237): 00 12 69 72 74 2d 61 68 2d
69 6e 72 69 61 2d 73 69 65 62 65 01 08 8c 12 98 24 b0 48 60 6c 03 01
24 07 7c 55 53 20 24 01 11 28 01 15 2c 02 11 95 04 15 a5 01 14 b6 01
15 b7 01 15 b8 01 15 b9 01 15 ba 01 15 bb 01 15 bc 01 15 bd 01 15 be
01 15 bf 01 15 c0 01 15 c1 01 15 c2 01 15 c3 01 15 c4 01 15 da 01 15
0c 01 15 34 01 15 48 01 15 5c 01 15 70 01 15 d4 01 15 de 01 15 94 01
15 f8 01 15 5c 01 15 c0 01 15 de 01 15 e8 01 15 f2 01 15 fc 01 15 06
01 15 10 01 15 1a 01 15 24 01 15 00 2d 1a ed 11 1b ff ff ff 00 00 00
00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 3d 16 24 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 dd 18 00 50 f2
02 01 01 00 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
1315503201.445224: Beacon IEs - hexdump(len=243): 00 12 69 72 74 2d 61
68 2d 69 6e 72 69 61 2d 73 69 65 62 65 01 08 8c 12 98 24 b0 48 60 6c
03 01 24 05 04 01 02 00 00 07 7c 55 53 20 24 01 11 28 01 15 2c 02 11
95 04 15 a5 01 14 b6 01 15 b7 01 15 b8 01 15 b9 01 15 ba 01 15 bb 01
15 bc 01 15 bd 01 15 be 01 15 bf 01 15 c0 01 15 c1 01 15 c2 01 15 c3
01 15 c4 01 15 da 01 15 0c 01 15 34 01 15 48 01 15 5c 01 15 70 01 15
d4 01 15 de 01 15 94 01 15 f8 01 15 5c 01 15 c0 01 15 de 01 15 e8 01
15 f2 01 15 fc 01 15 06 01 15 10 01 15 1a 01 15 24 01 15 00 2d 1a ed
11 1b ff ff ff 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00
00 00 3d 16 24 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 dd 18 00 50 f2 02 01 01 00 00 03 a4 00 00 27 a4 00 00 42 43
5e 00 62 32 2f 00
1315503201.446394: wlan1: BSS: Start scan result update 7
1315503201.446448: BSS: last_scan_res_used=1/32 last_scan_full=0
1315503201.446531: Add randomness: count=7 entropy=6
1315503201.446566: random pool - hexdump(len=128): [REMOVED]
1315503201.446598: random_mix_pool - hexdump(len=8): [REMOVED]
1315503201.446632: random_mix_pool - hexdump(len=5): [REMOVED]
1315503201.446663: random pool - hexdump(len=128): [REMOVED]
1315503201.446704: wlan1: New scan results available
1315503201.446762: wlan1: Selecting BSS from priority group 0
1315503201.446852: wlan1: 0: <BSSID> ssid='<SSID>' wpa_ie_len=0
rsn_ie_len=0 caps=0x1 level=-70
1315503201.446889: A BSSID in blacklist is this: 6147292
1315503201.446918: The BSSID of blacklist selected is this: 6147292
1315503201.446962: wlan1: skip - blacklisted (count=1 limit=0)
1315503201.447002: wlan1: No APs found - clear blacklist and try again
1315503201.447034: Removed BSSID <BSSID> from blacklist (clear)
1315503201.447097: wlan1: Selecting BSS from priority group 0
1315503201.447182: wlan1: 0: <BSSID> ssid='<SSID>' wpa_ie_len=0
rsn_ie_len=0 caps=0x1 level=-70
1315503201.447229: wlan1: allow in non-WPA/WPA2
1315503201.447260: The channel that wpa_s struct has got is 36
1315503201.447289: The frequency that wpa_s struct has got is 5180 MHz
1315503201.447317: The number of channels on rate_match of wpa_s is59
1315503201.447344: The set channel on rate_match function is 2364476
1315503201.447371: The set frequency on rate_match function is 5180 MHz
1315503201.447397: The set frequency on rate_match function is 5180 MHz
1315503201.447424: The comparison freq == bss->freq is true
1315503201.447483: wlan1: selected BSS <BSSID> ssid='<SSID>'
1315503201.447597: wlan1: Request association: reassociate: 0
selected: <BSSID> bssid: 00:00:00:00:00:00 pending:
00:00:00:00:00:00 wpa_state: SCANNING
1315503201.447649: wlan1: The neighbour BSS frequency passed to
wpa_supplicant_associate is 5180 MHz
1315503201.447693: wlan1: The ssid frequency passed to
wpa_supplicant_associate is 0 MHz
1315503201.447737: wlan1: Automatic auth_alg selection: 0x1
1315503201.447778: wlan1: WPA: clearing AP WPA IE
1315503201.447816: wlan1: WPA: clearing AP RSN IE
1315503201.447854: wlan1: WPA: clearing own WPA/RSN IE
1315503201.447894: wlan1: Cancelling scan request
1315503201.447966: wlan1: SME: Trying to authenticate with <BSSID>
(SSID='<SSID>' freq=5180 MHz)
1315503201.448010: wlan1: No keys have been configured - skip key clearing
1315503201.448056: wlan1: State: SCANNING -> AUTHENTICATING
1315503201.448097: nl80211: Authenticate (ifindex=43)
1315503201.448133: * bssid=<BSSID>
1315503201.448179: * freq=5180
1315503201.448205: * SSID - hexdump_ascii(len=18):
69 72 74 2d 61 68 2d 69 6e 72 69 61 2d 73 69 65 <SSID>
62 65 <SSID>
1315503201.448364: * IEs - hexdump(len=0): [NULL]
1315503201.448397: * Auth Type 0
1315503201.466024: nl80211: Authentication request send successfully
1315503201.466592: wlan1: Checking for other virtual interfaces
sharing same radio (phy1) in event_scan_results
1315503201.467133: nl80211: Event message available
1315503201.467652: nl80211: New station <BSSID>
1315503202.098936: nl80211: Event message available
1315503202.099047: nl80211: Delete station <BSSID>
1315503202.099129: nl80211: Event message available
1315503202.099175: nl80211: MLME event 37; timeout with <BSSID>
1315503202.099256: wlan1: Event AUTH_TIMED_OUT (14) received
1315503202.099300: wlan1: SME: Authentication timed out
1315503202.099336: Added BSSID <BSSID> into blacklist
1315503202.099406: wlan1: Setting scan request: 0 sec 100000 usec
1315503202.099461: wlan1: State: AUTHENTICATING -> DISCONNECTED
1315503202.099495: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1315503202.099535: The linkmode=-1 is set on wpa_driver_nl80211_set_operstate
1315503202.099563: netlink: Operstate: linkmode=-1, operstate=5
1315503202.099619: The number of sent bytes in netlink_send_oper_ifla are 37
1315503202.199646: wlan1: State: DISCONNECTED -> SCANNING
As you see, the frequency of the BSSID is 5180 the first 5GHz
channel, but I'm not working on that channel... Maybe the
wpa_supplicant uses it to stablish the connection and then switches
the channel to the one I wanted?
> But also, do you still have the "fixed_freq=1" parameter? No idea what
> that is, it's not part of the official hostap, so you might as well
> remove it. It appears to be have been a proposed patch that was
> rejected, plus that patch was only meant for IBSS mode, not STA mode:
>
> http://lists.shmoo.com/pipermail/hostap/2012-June/026056.html
>
I'm going to try remove it to see what happens.
Thanks again!
> Dan
>
>> But such a frequency is not the one in which the AP is working
>> in...I've read that wpa_supplicant wpa_ssid->frequency always starts
>> in the initial channel of the working band, so I guess that as the
>> possible reason for the above frequency, but I'm not sure since that
>> frequency is set in the driver (nl80211), isn't it?
>>
>> Thanks
>>
>> > Dan
>> >
>> >> ... and so on
>> >>
>> >> but I think that is not enough, so I'll need a way of enabling debug
>> >> mode on my system.
>> >>
>> >>
>> >>
>> >> > Dan
>> >> >
>> >> >> Ps: sorry for the triple post, but I didn't reply well to all the
>> >> >> members of the mail.
>> >> >>
>> >> >> > Dan
>> >> >> >
>> >> >> >> Added BSSID 64:70:02:3e:a7:82 into blacklist
>> >> >> >> wlan1: Setting scan request: 0 sec 100000 usec
>> >> >> >> wlan1: State: AUTHENTICATING -> DISCONNECTED
>> >> >> >> wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>> >> >> >> The linkmode=-1 is set on wpa_driver_nl80211_set_operstate
>> >> >> >> netlink: Operstate: linkmode=-1, operstate=5
>> >> >> >> The num-Xr of sent bytes in netlink_send_oper_ifla are 37
>> >> >> >> wlan1: State: DISCONNECTED -> SCANNING
>> >> >> >> _______________________________________________
>> >> >> >> HostAP mailing list
>> >> >> >> HostAP at lists.shmoo.com
>> >> >> >> http://lists.shmoo.com/mailman/listinfo/hostap
>> >> >> >
>> >> >> >
>> >> >
>> >> >
>> >
>> >
>
>
More information about the Hostap
mailing list