Re: cannot get IP when auth with wpa_supplicant + ath0 driver

Joe Love wrote:
> I'm trying to use my wireless connection on my campus's wireless network.
> 
> I'm using FreeBSD 6.0-RC1, with the pre-packaged wpa_supplicant 0.3.9.  
> I've tried using both a linksys wpc11 using the wi driver, and a netgear 
> wg511t using the ath driver.  I'm currently betting on using the netgear 
> permanently, as the linksys card is causing me unending issues as of 
> late.  The campus wireless uses TTLS+PAP, and IPs are assigned dynamically.
> 
> The problem I'm having is that after the connection is established (it 
> seems to authenticate just fine), I cannot get a response to any dhcp 
> requests.
> Jouni Malinen, from the hostap mailing lists, proposed the following as 
> the problem:
> "This AP is using somewhat non-standard key configuration (something 
> that most Cisco APs do with IEEE 802.1X), i.e., unicast key is using 
> non-zero key index (2 or 3) and broadcast key is using the other indexes 
> (alternating between 0 and 1).

This shouldn't matter.

> "The packet dump looked like WEP decryption would not have been done or 
> it would have failed completely. I would assume that the driver code 
> would drop the packet if ICV is incorrect, so I would assume that the 
> packet was not decrypted at all.
> "I have seen this kind of key index use having issues with number of 
> drivers. In other words, this is a question for FreeBSD mailing lists 
> after all. Including the description of key index use with the message 
> should make it easier for the driver/IEEE 802.11 stack authors to take a 
> closer look at this. Anyway, a fix for this may require changing the 
> driver interface code for the set_key handler on wpa_supplicant side, too."
> 
> Included below are the wpa_supplicant configuration I am using and the 
> output of wpa_supplicant -d -iath0 -cwpa_supplicant.conf
> 
> A packet dump of the transaction and some data following it (taken from 
> ethereal 0.10.10) can be found at http://www.getsomewhere.net/wpa.dump

This dump is at the 802.3 level which is not useful; we need to see 
what's going on at the 802.11 level or below in the driver.

> 
> Thanks,
> -Joe
> 
> wpa_supplicant.conf:
> ctrl_interface=/var/run/wpa_supplicant
> eapol_version=2
> ap_scan=1
> #ap_scan=2 # suggested.
> network={
>        ssid="UIC-Wireless"
>        scan_ssid=1
>        #key_mgmt=IEEE8021X WPA-EAP
>        mode=0
>        key_mgmt=IEEE8021X
>        eap=TTLS
>        identity="jlove1"
>        password="CENSORED"
>        anonymous_identity="anonymous"
>        ca_cert="thawte.pem"
>        #phase1="include_tls_length=1"
>        phase2="auth=PAP"
> }
> 
> wpa_supplicant output:
> # wpa_supplicant -d -iath0 -cwpa_supplicant.conf
> Initializing interface 'ath0' conf 'wpa_supplicant.conf' driver 'default'
> Configuration file 'wpa_supplicant.conf' -> 
> '/usr/home/lyfe/wpa_supplicant.conf'
> Reading configuration file '/usr/home/lyfe/wpa_supplicant.conf'
> ctrl_interface='/var/run/wpa_supplicant'
> eapol_version=2
> ap_scan=1
> Priority group 0
>   id=0 ssid='UIC-Wireless'
> Initializing interface (2) 'ath0'
> EAPOL: SUPP_PAE entering state DISCONNECTED
> EAPOL: KEY_RX entering state NO_KEY_RECEIVE
> EAPOL: SUPP_BE entering state INITIALIZE
> EAP: EAP entering state DISABLED
> EAPOL: External notification - portEnabled=0
> EAPOL: External notification - portValid=0
> Own MAC address: 00:0f:b5:62:28:e3
> wpa_driver_bsd_set_wpa: enabled=1
> wpa_driver_bsd_set_wpa_internal: wpa=3 privacy=1
> wpa_driver_bsd_del_key: keyidx=0
> wpa_driver_bsd_del_key: keyidx=1
> wpa_driver_bsd_del_key: keyidx=2
> wpa_driver_bsd_del_key: keyidx=3
> wpa_driver_bsd_set_countermeasures: enabled=0
> wpa_driver_bsd_set_drop_unencrypted: enabled=1
> Setting scan request: 0 sec 100000 usec
> Starting AP scan (specific SSID)
> Scan SSID - hexdump_ascii(len=12):
>     55 49 43 2d 57 69 72 65 6c 65 73 73               UIC-Wireless   
> Received 0 bytes of scan results (3 BSSes)
> Scan results: 3
> Selecting BSS from priority group 0
> 0: 00:12:00:d7:0e:00 ssid='' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 1: 00:0c:41:75:12:a0 ssid='Linksys' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 2: 00:13:46:15:84:5a ssid='powerlab' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> No suitable AP found.
> Setting scan request: 5 sec 0 usec
> Starting AP scan (broadcast SSID)
> Received 0 bytes of scan results (4 BSSes)
> Scan results: 4
> Selecting BSS from priority group 0
> 0: 00:12:00:d7:0e:00 ssid='' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 1: 00:40:05:26:d5:24 ssid='mie-g' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 2: 00:0c:41:75:12:a0 ssid='Linksys' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 3: 00:13:46:15:84:5a ssid='powerlab' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> No suitable AP found.
> Setting scan request: 5 sec 0 usec
> Starting AP scan (specific SSID)
> Scan SSID - hexdump_ascii(len=12):
>     55 49 43 2d 57 69 72 65 6c 65 73 73               UIC-Wireless   
> Received 0 bytes of scan results (3 BSSes)
> Scan results: 3
> Selecting BSS from priority group 0
> 0: 00:12:00:d7:0e:00 ssid='UIC-Wireless' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 1: 00:0c:41:75:12:a0 ssid='Linksys' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
> 2: 00:13:46:15:84:5a ssid='powerlab' wpa_ie_len=0 rsn_ie_len=0
>   skip - no WPA/RSN IE
>   selected non-WPA AP 00:12:00:d7:0e:00 ssid='UIC-Wireless'
> Trying to associate with 00:12:00:d7:0e:00 (SSID='UIC-Wireless' 
> freq=2462 MHz)
> Cancelling scan request
> Automatic auth_alg selection: 0x1
> No keys have been configured - skip key clearing
> wpa_driver_bsd_set_drop_unencrypted: enabled=1
> wpa_driver_bsd_associate: ssid 'UIC-Wireless' wpa ie len 0 pairwise 4 
> group 4 key mgmt 3
> wpa_driver_bsd_associate: set PRIVACY 1
> Setting authentication timeout: 5 sec 0 usec
> EAPOL: External notification - portControl=Auto
> Association event - clear replay counter
> Associated to a new BSS: BSSID=00:12:00:d7:0e:00
> No keys have been configured - skip key clearing
> Associated with 00:12:00:d7:0e:00
> EAPOL: External notification - portEnabled=0
> EAPOL: External notification - portValid=0
> EAPOL: External notification - portEnabled=1
> EAPOL: SUPP_PAE entering state CONNECTING
> EAPOL: txStart
> EAPOL: SUPP_BE entering state IDLE
> EAP: EAP entering state INITIALIZE
> EAP: EAP entering state IDLE
> Setting authentication timeout: 10 sec 0 usec
> RX EAPOL from 00:12:00:d7:0e:00
> Setting authentication timeout: 70 sec 0 usec
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_PAE entering state RESTART
> EAP: EAP entering state INITIALIZE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_PAE entering state AUTHENTICATING
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=1 id=1
> EAP: EAP entering state IDENTITY
> EAP: EAP-Request Identity data - hexdump_ascii(len=0):
> EAP: using anonymous identity - hexdump_ascii(len=9):
>     61 6e 6f 6e 79 6d 6f 75 73                        anonymous      
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> WPA: EAPOL frame too short, len 46, expecting at least 99
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=1 id=2
> EAP: EAP entering state IDENTITY
> EAP: EAP-Request Identity data - hexdump_ascii(len=0):
> EAP: using anonymous identity - hexdump_ascii(len=9):
>     61 6e 6f 6e 79 6d 6f 75 73                        anonymous      
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> WPA: EAPOL frame too short, len 46, expecting at least 99
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=21 id=3
> EAP: EAP entering state GET_METHOD
> EAP: initialize selected EAP method (21, TTLS)
> EAP-TTLS: Phase2 type: PAP
> TLS: Trusted root certificate(s) loaded
> EAP: EAP entering state METHOD
> EAP-TTLS: Received packet(len=6) - Flags 0x20
> EAP-TTLS: Start
> SSL: (where=0x10 ret=0x1)
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:before/connect initialization
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 write client hello A
> SSL: (where=0x1002 ret=0xffffffff)
> SSL: SSL_connect:error in SSLv3 read server hello A
> SSL: SSL_connect - want more data
> SSL: 100 bytes pending from ssl_out
> SSL: 100 bytes left to be sent out (of total 100 bytes)
> EAP: method process -> ignore=FALSE methodState=CONT decision=FAIL
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> WPA: EAPOL frame too short, len 46, expecting at least 99
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=21 id=4
> EAP: EAP entering state METHOD
> EAP-TTLS: Received packet(len=1396) - Flags 0xc0
> EAP-TTLS: TLS Message Length: 2196
> SSL: Need 810 bytes more input data
> SSL: Building ACK
> EAP: method process -> ignore=FALSE methodState=CONT decision=FAIL
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> IEEE 802.1X RX: version=1 type=0 length=1396
> WPA: EAPOL frame (type 0) discarded, not a Key frame
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=21 id=5
> EAP: EAP entering state METHOD
> EAP-TTLS: Received packet(len=816) - Flags 0x00
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 read server hello A
> TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=1 
> buf='/C=ZA/ST=Western Cape/L=Cape Town/O=Thawte Consulting 
> cc/OU=Certification Services Division/CN=Thawte Server 
> CA/emailAddress=server-certs_at_thawte.com'
> TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=0 
> buf='/C=US/ST=Illinois/L=Chicago/O=University of Illinois at 
> Chicago/OU=Academic Computer Center/CN=odyssey1.cc.uic.edu'
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 read server certificate A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 read server key exchange A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 read server done A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 write client key exchange A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 write change cipher spec A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 write finished A
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 flush data
> SSL: (where=0x1002 ret=0xffffffff)
> SSL: SSL_connect:error in SSLv3 read finished A
> SSL: SSL_connect - want more data
> SSL: 190 bytes pending from ssl_out
> SSL: 190 bytes left to be sent out (of total 190 bytes)
> EAP: method process -> ignore=FALSE methodState=CONT decision=FAIL
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> IEEE 802.1X RX: version=1 type=0 length=816
> WPA: EAPOL frame (type 0) discarded, not a Key frame
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Request method=21 id=6
> EAP: EAP entering state METHOD
> EAP-TTLS: Received packet(len=61) - Flags 0x80
> EAP-TTLS: TLS Message Length: 51
> SSL: (where=0x1001 ret=0x1)
> SSL: SSL_connect:SSLv3 read finished A
> SSL: (where=0x20 ret=0x1)
> SSL: (where=0x1002 ret=0x1)
> SSL: 0 bytes pending from ssl_out
> SSL: No data to be sent out
> EAP-TTLS: TLS done, proceed to Phase 2
> EAP-TTLS: Derived key - hexdump(len=64): [REMOVED]
> EAP-TTLS: received 0 bytes encrypted data for Phase 2
> EAP-TTLS: empty data in beginning of Phase 2 - use fake EAP-Request 
> Identity
> EAP-TTLS: Phase 2 PAP Request
> EAP-TTLS: Encrypting Phase 2 data - hexdump(len=40): [REMOVED]
> EAP-TTLS: Authentication completed successfully
> EAP: method process -> ignore=FALSE methodState=DONE decision=COND_SUCC
> EAP: EAP entering state SEND_RESPONSE
> EAP: EAP entering state IDLE
> EAPOL: SUPP_BE entering state RESPONSE
> EAPOL: txSuppRsp
> EAPOL: SUPP_BE entering state RECEIVE
> WPA: EAPOL frame too short, len 65, expecting at least 99
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAP-Packet frame
> EAPOL: SUPP_BE entering state REQUEST
> EAPOL: getSuppRsp
> EAP: EAP entering state RECEIVED
> EAP: Received EAP-Success
> EAP: Workaround for unexpected identifier field in EAP Success: reqId=7 
> lastId=6 (these are supposed to be same)
> EAP: EAP entering state SUCCESS
> EAPOL: SUPP_BE entering state RECEIVE
> EAPOL: SUPP_BE entering state SUCCESS
> EAPOL: SUPP_BE entering state IDLE
> WPA: EAPOL frame too short, len 46, expecting at least 99
> RX EAPOL from 00:12:00:d7:0e:00
> EAPOL: Received EAPOL-Key frame
> EAPOL: KEY_RX entering state KEY_RECEIVE
> EAPOL: processKey
> EAPOL: RX IEEE 802.1X ver=1 type=3 len=57 EAPOL-Key: type=1 
> key_length=13 key_index=0x1
> EAPOL: EAPOL-Key key signature verified
> EAPOL: Decrypted(RC4) key - hexdump(len=13): [REMOVED]
> EAPOL: Setting dynamic WEP key: broadcast keyidx 1 len 13
> wpa_driver_bsd_set_key: alg=WEP addr=ff:ff:ff:ff:ff:ff key_idx=1 
> set_tx=0 seq_len=0 key_len=13

This is the only call to install a key and it sets up a rx-only key 
(set_tx=0).  I don't see the unicast key being setup.  I need a packet 
trace at the 802.11 layer to see if frames are being dropped for some 
reason.  Alternatively you could use the athstats and 80211stats tools 
found in tools/tools/ath to check the statistics counters.  It might 
also be instructive to see the state of the interface at this point 
(before you hit ^C); use ifconfig to get that info.

	Sam


> WPA: EAPOL frame too short, len 61, expecting at least 99
> 
> ^CSignal 2 received - terminating
> wpa_driver_bsd_deauthenticate
> wpa_driver_bsd_del_key: keyidx=0
> wpa_driver_bsd_del_key: keyidx=1
> wpa_driver_bsd_del_key: keyidx=2
> wpa_driver_bsd_del_key: keyidx=3
> wpa_driver_bsd_del_key: addr=00:12:00:d7:0e:00 keyidx=0
> ioctl[SIOCS80211, op 20, len 7]: Can't assign requested address
> EAPOL: External notification - portEnabled=0
> EAPOL: SUPP_PAE entering state DISCONNECTED
> EAPOL: KEY_RX entering state NO_KEY_RECEIVE
> EAPOL: SUPP_BE entering state INITIALIZE
> EAP: EAP entering state DISABLED
> EAPOL: External notification - portValid=0
> wpa_driver_bsd_set_wpa: enabled=0
> wpa_driver_bsd_set_wpa_internal: wpa=0 privacy=0
> wpa_driver_bsd_set_drop_unencrypted: enabled=0
> wpa_driver_bsd_set_countermeasures: enabled=0
> No keys have been configured - skip key clearing
> wpa_driver_bsd_set_wpa_internal: wpa=0 privacy=0
> EAP: deinitialize previously used EAP method (21, TTLS) at EAP deinit
> #
> 
> _______________________________________________
> freebsd-current_at_freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-current
> To unsubscribe, send any mail to "freebsd-current-unsubscribe_at_freebsd.org"
> 
>