Date: Wed, 25 Mar 2009 16:44:00 -0700 From: Sam Leffler <sam@freebsd.org> To: Daniel Thiele <dthiele@gmx.net> Cc: freebsd-current@freebsd.org Subject: Re: Wireless connection (WPA-EAP) stops working after a while Message-ID: <49CAC1C0.9030506@freebsd.org> In-Reply-To: <49C83038.40300@gmx.net> References: <49C83038.40300@gmx.net>
next in thread | previous in thread | raw e-mail | index | archive | help
Daniel Thiele wrote:
> Hi,
>
> I have a problem with my wireless connection. I am running FreeBSD
> 8.0-CURRENT (from Mar 22) with wpa_supplicant v0.6.8 using an Atheros
> based ExpressCard (D-Link DWA-643 via ath(4)) and alternatively a Ralink
> based USB adapter (Linksys WUSB54GC-EU via rum(4)).
>
> At home using the Atheros card together with a FreeBSD (7.1) based
> access point (using rum(4) in hostap mode) and the wpa_supplicant.conf
> (attached at the end of this email) settings for SSID="home" I don't
> have any problems. With a Linksys WRT54GL-DE access point
> running the OpenWRT White Russian 0.9 firmware and OpenVPN over an open
> wireless LAN also works flawlessly.
>
> At the university, however, (SSID="IDA" in the wpa_supplicant.conf at
> the end of this email) the wireless connection only works for about an
> hour. The vague term "wireless connection" in this case means, that the
> WPA connection is opened and associated, then I get an IP address via
> dhclient. There is a message about "OpenSSL: tls_connection_handshake -
> Failed to read possible Application Data
> error:00000000:lib(0):func(0):reason(0)" and "TLS: Unsupported Phase2
> EAP method 'MSCHAPv2'" but the authentication seems to succeed:
<...stuff deleted...>
>
>
> Mar 23 14:28:45 impala wpa_supplicant[429]: EAP-MSCHAPV2: Authentication
> succeeded
> Mar 23 14:28:45 impala wpa_supplicant[429]: EAP-TLV: TLV Result -
> Success - EAP-TLV/Phase2 Completed
> Mar 23 14:28:46 impala wpa_supplicant[429]: CTRL-EVENT-EAP-SUCCESS EAP
> authentication completed successfully
> Mar 23 14:28:46 impala wpa_supplicant[429]: WPA: Failed to set PTK to
> the driver.
> Mar 23 14:28:46 impala wpa_supplicant[429]: WPA: Key negotiation
> completed with 00:1b:2f:ef:d3:c9 [PTK=CCMP GTK=TKIP]
This doesn't look good. For some reason the PTK key was not plumbed;
this means the ioctl that made the request failed. Unfortunately
there's no more information to explain why but typically this is because
the station is no longer associated. But for some reason wpa_supplicant
didn't seem to handle the error properly; it appears it thinks the key
exchange was completed when it was not. A glance at the code looks like
it's ignoring errors; e.g. in contrib/wpa/src/rsn_supp/wpa.c in
wpa_supplicant_process_3_of_4:
if (key_info & WPA_KEY_INFO_INSTALL) {
wpa_supplicant_install_ptk(sm, key);
}
(the error return by wpa_supplicant_install_ptk is not checked). This
might be handled some other way but it's not clear why it should proceed.
> Mar 23 14:29:01 impala wpa_supplicant[429]: CTRL-EVENT-SCAN-RESULTS
> Mar 23 14:34:03 impala wpa_supplicant[429]: CTRL-EVENT-SCAN-RESULTS
> Mar 23 14:39:05 impala wpa_supplicant[429]: CTRL-EVENT-SCAN-RESULTS
> ----8<--------------------------------------------------------
>
> ifconfig still lists the connection as "associated":
>
> ----8<--------------------------------------------------------
> impala# ifconfig wlan0
> wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu
> 1500
> ether 00:21:91:db:15:30
> media: IEEE 802.11 Wireless Ethernet OFDM/48Mbps mode 11g
> status: associated
> ssid IDA channel 13 (2472 Mhz 11g) bssid 00:1b:2f:ef:d3:c9
> regdomain ETSI indoor ecm authmode WPA2/802.11i privacy ON
> deftxkey UNDEF TKIP 2:128-bit txpower 20 bmiss 7 scanvalid 450
> bgscan
> bgscanintvl 300 bgscanidle 250 roam:rssi 7 roam:rate 5
> protmode CTS
> wme burst roaming MANUAL
> ----8<--------------------------------------------------------
>
> But dhclient does not accept any new leases:
>
> ----8<--------------------------------------------------------
> impala# dhclient wlan0
> DHCPREQUEST on wlan0 to 255.255.255.255 port 67
> DHCPNAK from 192.168.100.1
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 4
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 10
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 12
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 13
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8
> DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 14
> No DHCPOFFERS received.
> Trying recorded lease 192.168.100.54
> bound: renewal in 5900 seconds.
> ----8<--------------------------------------------------------
>
> The site's wireless admin was so kind to provide me with the logs from
> their DHCP server, which seems to offer new leases that somehow don't
> make it through to my machine:
>
> ----8<--------------------------------------------------------
> DHCPDISCOVER from 00:21:91:db:15:30 (impala) via 192.168.100.1
> DHCPOFFER on 192.168.100.54 to 00:21:91:db:15:30 (impala) via
> 192.168.100.1
> ----8<--------------------------------------------------------
>
> If I audaciously assign myself an IP address (192.168.100.54) and set
> the default route to 192.168.100.1, the wireless connection sill won't
> work. I cannot even ping the router at 192.168.100.1.
>
>
> Next, I tried to rule out the wireless adapter. Both the Atheros
> ExpressCard and the Ralink USB Adapter show the above mentioned
> behavior. So the problem might perhaps be located in FreeBSD's wireless
> stack, wpa_supplicant or dhclient? But I'm not an expert in these areas,
> thus this email.
It appears this is an issue in wpa_supplicant but it's hard to say. I'd
need to know if the association was broken during the time the key plumb
failed. That should've been reported to wpa_supplicant which should've
logged a msg so I'm guessing no. So we're back to why the key wasn't
plumbed as everything that follows makes sense (i.e. you can't get data
packets through). If you turn on crypto debugging in net80211 you might
get some info from the console msgs; e.g.
wlandebug crypto
You should also configure wpa_supplicant debugging so we get more info
from the driver; add
wpa_supplicant_flags="-sd"
to your rc.conf file (or start wpa_supplicant by hand).
>
>
> What works in the case of the Ralink USB adapter is simply unplugging
> and replugging the device. Then I get another hour of working wireless
> before it breaks again. Since hot-plugging the ExpressCard currently
> does not seem to work I cannot confirm this for the Atheros adapter.
This sounds like the supplicant is out of sync w/ the ap and you can't
get packets through because you've got the old/wrong key plumbed on the
station.
>
> I also tried
>
> ----8<--------------------------------------------------------
> /etc/rc.d/netif restart
> ----8<--------------------------------------------------------
>
> and
>
> ----8<--------------------------------------------------------
> ifconfig wlan0 destroy
> ifconfig wlan0 create wlandev rum0
> ----8<--------------------------------------------------------
>
> followed by a restart of wpa_suppicant and dhclient, too, but without
> any success. So only re-plugging the device seems to solve or at least
> stall the problem.
That doesn't make sense. Destroying the vap should be equivalent to
ejecting the device. There should no crypto state kept after a vap is
destroyed. You can verify this for the ath device using athregs
(tools/tools/ath/athregs); athregs -k will dump the contents of the h/w
key cache if the ath driver is built with ATH_DIAGAPI).
>
> The output of wpa_supplicant -ddd after the wireless connection stopped
> working can be found at:
> http://www-public.tu-bs.de:8080/~y0023183/FreeBSD/Wireless/wpa_supplicant-ddd.txt
>
>
>
> On a FreeBSD 7.1-STABLE machine with wpa_supplicant v0.5.10 and the
> Ralink USB adapter I did not encounter the problem.
If I understand correctly the above is for FreeBSD HEAD+0.6.8 so a more
useful comparison is HEAD+0.5.11/0.5.10 which would tell us definitely
if this is a supplicant issue.
>
>
> Now, my question is has anyone else encountered this behavior (WPA-PSK
> working nicely and WPA-EAP only for a limited period of time) and knows
> how to fix this issue? Perhaps it is just a misconfiguration on my
> part. If not, how can I help to further investigate this issue. What can
> I do to provide additional debug information?
>
I checked the 0.6.9 release that I suggested might have a fix but was
wrong. The change that caught my attention was for hostapd, not
wpa_supplicant. So we're back to isolating whether this is a regression
in the supplicant. The best suggestion I have is to back-rev your HEAD
tree to just before I imported wpa_supplicant 0.6.8. Talk to me
off-line if you need help w/ that.
Sam
>
> Additioinal information:
>
> impala# uname -a
> FreeBSD impala.vnws.lan 8.0-CURRENT FreeBSD 8.0-CURRENT #2: Sun Mar 22
> 00:34:38 CET 2009
> dthiele@impala.vnws.lan:/usr/obj/usr/src/sys/kernel_8Xv0 i386
> (Kernel and world are in sync)
>
>
> impala# kldstat -v | grep wlan
> 236 wlan
> 235 wlan_wep
> 234 wlan_tkip
> 233 wlan_ccmp
> 232 wlan_amrr
> 237 wlan_sta
>
>
> impala# wpa_supplicant -v
> wpa_supplicant v0.6.8
> Copyright (c) 2003-2009, Jouni Malinen <j@w1.fi> and contributors
>
>
> impala# cat /etc/wpa_supplicant.conf
> ctrl_interface=/var/run/wpa_supplicant
> ctrl_interface_group=wheel
>
> ap_scan=1
> fast_reauth=1
>
> # This is the working setup I am using at home.
> # The AP is a ThinkPad R40 running FreeBSD-7.1-STABLE with a rum(4)
> # wireless adapter in hostap mode.
> network={
> ssid="SuperCollider"
> scan_ssid=1
> mode=0
> proto=WPA
> key_mgmt=WPA-PSK
> psk="[REMOVED]"
> pairwise=CCMP
> priority=10
> }
>
> # This is the "partially-working" setup at the university
> network={
> ssid="IDA"
> mode=0
> proto=WPA2
> key_mgmt=WPA-EAP
> eap=PEAP
> identity="[REMOVED]"
> anonymous_identity="[REMOVED]"
> password="[REMOVED]"
> ca_cert="[REMOVED]"
> phase2="autH=msCHAPv2"
> priority=2
> }
>
>
> impala# cat /etc/dhclient.conf
> timeout 60;
> retry 60;
> interface "wlan0" {
> prepend domain-name-servers [REMOVED], 217.237.150.188;
> request subnet-mask, broadcast-address, time-offset, routers,
> domain-name;
> }
>
>
> impala# grep wlan /etc/rc.conf
> wlans_ath0=wlan0
> ifconfig_wlan0="WPA DHCP"
>
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?49CAC1C0.9030506>