EAP-TLS hostapd, wpa_supplicant 0.4.1 and atheros 5212 card fails

Beat Meier bmeier at infovia.com.ar
Mon Jun 20 19:46:15 EDT 2005


Hi

I'm having trouble with EAP-TLS and hostapd, wpa_supplicant 0.4.1 and 
atheros 5212 card.
I have the message "IE in 3/4 msg does not match with IE in 
Beacon/ProbeResp" and they
are really not the same ;-)
I use freeradius-1.0.3 server which seems to authenticate us (see below).
Whats the deal with the phase2? This is not used in EAP-TLS, is it?

It would be nice if there is a "message help catalog" for every method 
(WPA-PSK, EAP-TLS etc.)
with the essential messages in the steps so users know until which step 
it was right.
I've tried days to analyze what's going on in which step ... an still 
have no idea ...
My idea is a catalog like

Message: EAP-TLS: Start (Staring of certificate authentication)
Message: XXX: Server successfully authenticated
Message: XXX: Client successfully authenticated

so users don't have to send always the "full" log and can analyze the 
problems better without
always to botter list users for trivial stuff like wron certificate, or 
wrong key etc. etc.

Thanks for any help

Beat


Freeradius log
************

Login OK: [woc2/<no User-Password attribute>] (from client localhost 
port 0 cli 00-02-6F-21-E3-9F)
Sending Access-Accept of id 12 to 127.0.0.1:1027
        MS-MPPE-Recv-Key = 
0x333676b25070eb8dc4b4e98343e6e1908e3690a642b1c69aa98d640d835405d0
        MS-MPPE-Send-Key = 
0x6be7621b06e0673cba399ab5fd4321195da0aa909af63716304de4e02424a068
        EAP-Message = 0x03050004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "woc2"


wpa_supplicant conf
*****************
eapol_version=1
ap_scan=1
fast_reauth=1
network={
        ssid="wireless-obera-1"
        scan_ssid=1
        key_mgmt=WPA-EAP
        eap=TLS
        identity="woc2"
        ca_cert="/usr/local/openssl/certs/root.pem"
        client_cert="/usr/local/openssl/certs/woc2.pem"
        private_key="/usr/local/openssl/certs/woc2.pem"
        private_key_passwd="VerySecret"
        priority=1
}

hostapd.conf
**********
auth_algs=3
ieee8021x=1
eap_authenticator=0
wpa=2
wpa_key_mgmt=WPA-EAP
wpa_pairwise=TKIP CCMP

The client log (wpa_supplicant)
*******************************

Jun 20 20:15:50.560324: EAP-TLS: Start
Jun 20 20:15:50.560754: SSL: (where=0x10 ret=0x1)
Jun 20 20:15:50.561494: SSL: (where=0x1001 ret=0x1)
Jun 20 20:15:50.561705: SSL: SSL_connect:before/connect initialization
Jun 20 20:15:50.565861: SSL: (where=0x1001 ret=0x1)
Jun 20 20:15:50.566036: SSL: SSL_connect:SSLv3 write client hello A
Jun 20 20:15:50.566229: SSL: (where=0x1002 ret=0xffffffff)
Jun 20 20:15:50.566383: SSL: SSL_connect:error in SSLv3 read server hello A
Jun 20 20:15:50.566571: SSL: SSL_connect - want more data
Jun 20 20:15:50.566739: SSL: 102 bytes pending from ssl_out
Jun 20 20:15:50.566913: SSL: 102 bytes left to be sent out (of total 102 
bytes)
Jun 20 20:15:50.567110: EAP: method process -> ignore=FALSE 
methodState=CONT decision=COND_SUCC
Jun 20 20:15:50.567286: EAP: EAP entering state SEND_RESPONSE
Jun 20 20:15:50.567441: EAP: EAP entering state IDLE
Jun 20 20:15:50.567594: EAPOL: SUPP_BE entering state RESPONSE
Jun 20 20:15:50.567792: EAPOL: txSuppRsp
...
Jun 20 20:15:51.209198: *CTRL-EVENT-EAP-SUCCESS EAP authentication 
completed successfully*
Jun 20 20:15:51.209987: EAPOL: SUPP_BE entering state RECEIVE
Jun 20 20:15:51.210758: EAPOL: SUPP_BE entering state SUCCESS
Jun 20 20:15:51.211529: EAPOL: SUPP_BE entering state IDLE
Jun 20 20:15:51.212537: RX EAPOL from 00:02:6f:21:e3:a3
...
Jun 20 20:15:51.360321: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
Jun 20 20:15:51.361302: WPA: RX message 3 of 4-Way Handshake from 
00:02:6f:21:e3:a3 (ver=2)
Jun 20 20:15:51.362355: WPA: IE KeyData - hexdump(len=72): 30 18 01 00 
00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 01 00 00 dd 26 
00 0f ac 01 02 00 c0 57 0a 0e 34 79 7a cf 45 f7 68 07 36 ba 29 81 95 14 
2c 7e 9e 19 65 4e ac d8 7e ab 59 30 b3 ec dd 00 00 00 00 00
Jun 20 20:15:51.363973: WPA: *IE in 3/4 msg does not match with IE in 
Beacon/ProbeResp (src=00:02:6f:21:e3:a3)*
Jun 20 20:15:51.364901: WPA: RSN IE in Beacon/ProbeResp - 
hexdump(len=24): *30 16 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 
01 00 00 0f ac 01*
Jun 20 20:15:51.366089: WPA: RSN IE in 3/4 msg - 
hexdump(len=26):                       *30 18 01 00 00 0f ac 02 02 00 00 
0f ac 04 00 0f ac 02 01 00 00 0f ac 01 00 00*
Jun 20 20:15:51.367278: State: 4WAY_HANDSHAKE -> DISCONNECTED
Jun 20 20:15:51.368301: wpa_driver_madwifi_disassociate

The server log (hostapd)
********************
Jun 20 20:15:50.496003: RADIUS packet matching with station 
00:02:6f:21:e3:9f
Jun 20 20:15:50.496022: MS-MPPE-Send-Key (len=32): 6b e7 62 1b 06 e0 67 
3c ba 39 9a b5 fd 43 21 19 5d a0 aa 90 9a f6 37 16 30 4d e4 e0 24 24 a0 68
Jun 20 20:15:50.496043: MS-MPPE-Recv-Key (len=32): 33 36 76 b2 50 70 eb 
8d c4 b4 e9 83 43 e6 e1 90 8e 36 90 a6 42 b1 c6 9a a9 8d 64 0d 83 54 05 d0
Jun 20 20:15:50.496087: ath0: STA 00:02:6f:21:e3:9f WPA: added PMKSA 
cache entry
Jun 20 20:15:50.496120: RSN: added PMKID - hexdump(len=16): 26 15 fa 57 
0a c6 50 16 53 38 51 06 ad 03 20 8b
Jun 20 20:15:50.496142: ath0: STA 00:02:6f:21:e3:9f IEEE 802.1X: 
decapsulated EAP packet (code=-1073748028 id=0 len=0) from RADIUS server:
Jun 20 20:15:50.496166: IEEE 802.1X: 00:02:6f:21:e3:9f BE_AUTH entering 
state SUCCESS
Jun 20 20:15:50.496176: IEEE 802.1X: Sending EAP Packet to 
00:02:6f:21:e3:9f (identifier 5)
Jun 20 20:15:50.496187: TX EAPOL - hexdump(len=22): 00 02 6f 21 e3 9f 00 
02 6f 21 e3 a3 88 8e 02 00 00 04 03 05 00 04
Jun 20 20:15:50.496230: IEEE 802.1X: 00:02:6f:21:e3:9f REAUTH_TIMER 
entering state INITIALIZE
Jun 20 20:15:50.496269: IEEE 802.1X: 00:02:6f:21:e3:9f BE_AUTH entering 
state IDLE
Jun 20 20:15:50.496279: IEEE 802.1X: 00:02:6f:21:e3:9f REAUTH_TIMER 
entering state INITIALIZE
Jun 20 20:15:50.496288: IEEE 802.1X: 00:02:6f:21:e3:9f REAUTH_TIMER 
entering state INITIALIZE
Jun 20 20:15:50.496305: WPA: 00:02:6f:21:e3:9f WPA_PTK entering state 
INITPMK
Jun 20 20:15:50.496317: WPA: PMK from EAPOL state machine (len=32)
Jun 20 20:15:50.496326: WPA: 00:02:6f:21:e3:9f WPA_PTK entering state 
PTKSTART
Jun 20 20:15:50.496339: ath0: STA 00:02:6f:21:e3:9f WPA: sending 1/4 msg 
of 4-Way Handshake
Jun 20 20:15:50.496360: TX EAPOL - hexdump(len=113): 00 02 6f 21 e3 9f 
00 02 6f 21 e3 a3 88 8e 02 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 
01 e0 b0 e1 f1 0f ef de ca df b3 f9 89 ff 15 1e b6 cd db 17 b6 db 1f 82 
6f 2c 3d fa 97 93 26 88 dc 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00
Jun 20 20:15:50.642294: IEEE 802.1X: 121 bytes from 00:02:6f:21:e3:9f
Jun 20 20:15:50.642343:    IEEE 802.1X: version=1 type=3 length=117
J*un 20 20:15:50.642364: ath0: STA 00:02:6f:21:e3:9f WPA: received 
EAPOL-Key frame (Gìÿ¿Gìÿ¿)*
Jun 20 20:15:50.642402: WPA: 00:02:6f:21:e3:9f WPA_PTK entering state 
PTKCALCNEGOTIATING
Jun 20 20:15:50.642437: PMK - hexdump(len=32): 33 36 76 b2 50 70 eb 8d 
c4 b4 e9 83 43 e6 e1 90 8e 36 90 a6 42 b1 c6 9a a9 8d 64 0d 83 54 05 d0
Jun 20 20:15:50.642460: PTK - hexdump(len=64): c2 ee 37 4d 16 a1 e7 d6 
b4 74 41 9b 8c cf 2c 58 09 2d c7 0c 11 bf 9c 90 21 16 76 db 62 a1 27 1a 
08 42 3c 21 4f 28 28 d6 41 10 98 1b cd 2e 35 fb 4e a9 9c 96 43 59 1f fe 
98 6f 7d 10 1c 9d f9 ee
Jun 20 20:15:50.642503: WPA: 00:02:6f:21:e3:9f WPA_PTK entering state 
PTKCALCNEGOTIATING2
Jun 20 20:15:50.642513: WPA: 00:02:6f:21:e3:9f WPA_PTK entering state 
PTKINITNEGOTIATING
Jun 20 20:15:50.642525: madwifi_get_seqnum: addr=00:00:00:00:00:00 idx=2
Jun 20 20:15:50.642545: ath0: STA 00:02:6f:21:e3:9f WPA: sending 3/4 msg 
of 4-Way Handshake
Jun 20 20:15:50.642566: Plaintext EAPOL-Key Key Data - hexdump(len=80): 
30 18 01 00 00 0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 01 
00 00 dd 26 00 0f ac 01 02 00 c0 57 0a 0e 34 79 7a cf 45 f7 68 07 36 ba 
29 81 95 14 2c 7e 9e 19 65 4e ac d8 7e ab 59 30 b3 ec dd 00 00 00 00 00 
00 00 00 00 00 00 00 00
Jun 20 20:15:50.642646: TX EAPOL - hexdump(len=193): 00 02 6f 21 e3 9f 
00 02 6f 21 e3 a3 88 8e 02 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 
02 e0 b0 e1 f1 0f ef de ca df b3 f9 89 ff 15 1e b6 cd db 17 b6 db 1f 82 
6f 2c 3d fa 97 93 26 88 dc 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 73 62 20 2d fb b5 0f 
0d dd ad 20 6c 8b 1d 5f e9 00 50 25 f8 fb d5 5a 04 ed c5 cb 5f 69 bc 11 
31 a8 2d 55 65 15 9a f5 1a ed 78 95 f4 e2 84 21 7d 07 a1 1b f9 24 86 a7 
9a 7a e6 75 b2 b9 ea 5b 67 2b f2 da 8e c2 92 d4 7f ec 73 d6 ba 19 25 c5 
77 e5 5e 54 f0 00 74 99 56 d3 e8 e3 ac 22 19 33 a0 6e eb
Jun 20 20:15:50.665891: Wireless event: cmd=0x8c02 len=105
Jun 20 20:15:50.665940: Custom wireless event: 'STA-TRAFFIC-STAT
mac=00:02:6f:21:e3:9f
rx_packets=8
tx_packets=9
rx_bytes=2387
tx_bytes=2398
'
Jun 20 20:15:50.665969: Wireless event: cmd=0x8c04 len=20
Jun 20 20:15:50.665988: ath0: STA 00:02:6f:21:e3:9f IEEE 802.11: 
deassociated


-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.shmoo.com/pipermail/hostap/attachments/20050620/2b3d79c0/attachment.htm 


More information about the HostAP mailing list