MS 2008 NPS and PEAP/MSCHAPv2 - wpa_supplicant not connecting
Gulick Tom-WPD384
Tom.Gulick
Wed Apr 3 10:27:34 PDT 2013
Here's the log from wpa_supplicant:
2013-04-03 13:21:28 [ APCT][Dbg1] D11Probe state: starting supplicant
2013-04-03 13:21:28 [ APCT][Dbg1] Selecting BSS from priority group 0
2013-04-03 13:21:28 [ APCT][Dbg1] Try to find WPA-enabled AP
2013-04-03 13:21:28 [ APCT][Dbg1] 0: 5c:0e:8b:cd:ad:70 ssid='Win8K-RADIUS' wpa_ie_len=0 rsn_ie_len=20 caps=0x8011
2013-04-03 13:21:28 [ APCT][Dbg1] selected based on RSN IE
2013-04-03 13:21:28 [ APCT][Dbg1] selected WPA AP 5c:0e:8b:cd:ad:70 ssid='Win8K-RADIUS'
2013-04-03 13:21:28 [ APCT][Dbg1] Trying to associate with 5c:0e:8b:cd:ad:70 (SSID='Win8K-RADIUS' freq=5240 MHz)
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL_IFACE monitor send 127.0.0.1:1050
2013-04-03 13:21:28 [ APCT][Dbg1] Cancelling scan request
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: clearing own WPA/RSN IE
2013-04-03 13:21:28 [ APCT][Dbg1] Automatic auth_alg selection: 0x1
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_set_auth_alg
2013-04-03 13:21:28 [ APCT][Dbg1] Supplicant using open auth
2013-04-03 13:21:28 [ APCT][Dbg1] RSN: using IEEE 802.11i/D9.0
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 1 proto 2
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: clearing AP WPA IE
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: using GTK CCMP
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: using PTK CCMP
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: using KEY_MGMT 802.1X
2013-04-03 13:21:28 [ APCT][Dbg1] No keys have been configured - skip key clearing
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_set_drop_unencrypted
2013-04-03 13:21:28 [ APCT][Dbg1] State: SCANNING -> ASSOCIATING
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_set_operstate
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_associate wpaIeLen:22 wpaIe[0]:30, wpaIe[1]:14
2013-04-03 13:21:28 [ APCT][Dbg1] Setting authentication timeout: 10 sec 0 usec
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - EAP success=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - EAP fail=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - portControl=Auto
2013-04-03 13:21:28 [ APCT][Dbg1] RSN: Ignored PMKID candidate without preauth flag
2013-04-03 13:21:28 [ APCT][Dbg1] apct_event_process: CTRL-EVENT-SCAN-RESULTS
2013-04-03 13:21:28 [ APCT][Dbg1] apct_event_process: Trying to associate with 5c:0e:8b:cd:ad:70 (SSID='Win8K-RADIUS' freq=5240 MHz)
2013-04-03 13:21:28 [ APCT][Dbg1] MsgProc: type=4 len=0 pData=(nil)
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Stop()
2013-04-03 13:21:28 [ APCT][Dbg1] STARTED state: rcvd START msg from supplicant
2013-04-03 13:21:28 [ APCT][Dbg1] AuthTx: alg:0 seq:1
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Start(1000)
2013-04-03 13:21:28 [ APCT][Dbg1] apct_test_start: state:5, status:0, numL2:0, numSupp:0 cfgL2:3
2013-04-03 13:21:28 [ APCT][Dbg1] apct_test_start: status OK...state:5
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:b0000000, context=2 rate=0 keyIdx=65535 len=30
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:30 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] (k) filter_frame: Mgt Frame from target BSS type=0 sub-type=11
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:30 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] MsgProc: type=6 len=74 pData=0x101203c4
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Stop()
2013-04-03 13:21:28 [ APCT][Dbg1] D11AUTH state:AUTH_ALG=0000
2013-04-03 13:21:28 [ APCT][Dbg1] AssReqTx: Rates IE length=10
2013-04-03 13:21:28 [ APCT][Dbg1] AssReqTx: RSN IE length=22
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Start(1000)
2013-04-03 13:21:28 [ APCT][Dbg1] D11AUTH state: rcvd AUTH good..going to D11ASSOC
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:00000000, context=2 rate=0 keyIdx=65535 len=74
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:74 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] (k) filter_frame: Mgt Frame from target BSS type=0 sub-type=1
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:40 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] MsgProc: type=7 len=84 pData=0x101203c4
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Stop()
2013-04-03 13:21:28 [ APCT][Dbg1] D11ASSOC state: rcvd ASSOCRSP good
2013-04-03 13:21:28 [ APCT][Dbg1] ad_apct_Timer_Start(70000)
2013-04-03 13:21:28 [ APCT][Dbg1] apct_send_assoc_event
2013-04-03 13:21:28 [ APCT][Dbg1] apct_supp_event_receive
2013-04-03 13:21:28 [ APCT][Dbg1] State: ASSOCIATING -> ASSOCIATED
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_set_operstate
2013-04-03 13:21:28 [ APCT][Dbg1] wpa_driver_ad_ecos_get_bssid
2013-04-03 13:21:28 [ APCT][Dbg1] Associated to a new BSS: BSSID=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] No keys have been configured - skip key clearing
2013-04-03 13:21:28 [ APCT][Dbg1] Associated with 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL_IFACE monitor send 127.0.0.1:1050
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: Association event - clear replay counter
2013-04-03 13:21:28 [ APCT][Dbg1] WPA: Clear old PTK
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - portEnabled=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - portValid=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: External notification - portEnabled=1
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_PAE entering state CONNECTING
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: enable timer tick
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state INITIALIZE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] Setting authentication timeout: 10 sec 0 usec
2013-04-03 13:21:28 [ APCT][Dbg1] Cancelling scan request
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:112 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 80
2013-04-03 13:21:28 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] Setting authentication timeout: 70 sec 0 usec
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_PAE entering state RESTART
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state INITIALIZE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_PAE entering state AUTHENTICATING
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Received EAP-Request id=1 method=1 vendor=0 vendorMethod=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDENTITY
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL-EVENT-EAP-STARTED EAP authentication started
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL_IFACE monitor send 127.0.0.1:1050
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state SEND_RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: txSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] TX EAPOL: dst=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] sending EAPOL frame
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] DataTx: Prot=888e,len=14,Dst= 5c-0e-8b-cd-ad-70 keyIdx=65535 prot=0x888e,txCount=1
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:08010000, context=2 rate=0 keyIdx=65535 len=46
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:46 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] test_status_send connPhase=1 status=1 msgLen=24
2013-04-03 13:21:28 [ APCT][Dbg1] apct_event_process: Associated with 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] apct_event_process: CTRL-EVENT-EAP-STARTED EAP authentication started
2013-04-03 13:21:28 [ APCT][Dbg1] MsgProc: type=16 len=0 pData=(nil)
2013-04-03 13:21:28 [ APCT][Dbg1] EAPAUTH state: EAP started
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:72 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 40
2013-04-03 13:21:28 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Received EAP-Request id=2 method=26 vendor=0 vendorMethod=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state GET_METHOD
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: configuration does not allow: vendor 0 method 26
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: vendor 0 method 26 not allowed
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Building EAP-Nak (requested type 26 vendor=0 method=0 not allowed)
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state SEND_RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: txSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] TX EAPOL: dst=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] sending EAPOL frame
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] DataTx: Prot=888e,len=10,Dst= 5c-0e-8b-cd-ad-70 keyIdx=65535 prot=0x888e,txCount=2
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:08010000, context=2 rate=0 keyIdx=65535 len=42
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:42 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:42 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 10
2013-04-03 13:21:28 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Received EAP-Request id=3 method=25 vendor=0 vendorMethod=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state GET_METHOD
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Initialize selected EAP method: vendor 0 method 25 (PEAP)
2013-04-03 13:21:28 [ APCT][Dbg1] TLS: using phase1 config options
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
2013-04-03 13:21:28 [ APCT][Dbg1] CTRL_IFACE monitor send 127.0.0.1:1050
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state METHOD
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: Received packet(len=6) - Flags 0x20
2013-04-03 13:21:28 [ APCT][Dbg1] EAP-PEAP: Start (server ver=0, own ver=1)
2013-04-03 13:21:28 [ APCT][Dbg1] EAP-PEAP: Using PEAP version 0
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x10 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:before/connect initialization
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 write client hello A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1002 ret=0xffffffff)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:error in SSLv3 read server hello A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect - want more data
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: 96 bytes pending from ssl_out
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: 96 bytes left to be sent out (of total 96 bytes)
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state SEND_RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: txSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] TX EAPOL: dst=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] sending EAPOL frame
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] DataTx: Prot=888e,len=110,Dst= 5c-0e-8b-cd-ad-70 keyIdx=65535 prot=0x888e,txCount=3
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:08010000, context=2 rate=0 keyIdx=65535 len=142
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:142 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] apct_event_process: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
2013-04-03 13:21:28 [ APCT][Dbg1] MsgProc: type=17 len=0 pData=(nil)
2013-04-03 13:21:28 [ APCT][Dbg1] EAPAUTH state: EAP Method
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:1432 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 1400
2013-04-03 13:21:28 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Received EAP-Request id=4 method=25 vendor=0 vendorMethod=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state METHOD
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: Received packet(len=1396) - Flags 0xc0
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: TLS Message Length: 2099
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: Need 713 bytes more input data
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: Building ACK (type=25 id=4 ver=0)
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state SEND_RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: txSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] TX EAPOL: dst=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] sending EAPOL frame
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] DataTx: Prot=888e,len=10,Dst= 5c-0e-8b-cd-ad-70 keyIdx=65535 prot=0x888e,txCount=4
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:28 [ APCT][Dbg1] (k) KeyTx buf:08010000, context=2 rate=0 keyIdx=65535 len=42
2013-04-03 13:21:28 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:42 keyIdx:65535
2013-04-03 13:21:28 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Forwarded frame to APCT len:755 radio:1
2013-04-03 13:21:28 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 723
2013-04-03 13:21:28 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: Received EAP-Request id=5 method=25 vendor=0 vendorMethod=0
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state METHOD
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: Received packet(len=719) - Flags 0x00
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 read server hello A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 read server certificate A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 read server certificate request A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 read server done A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 write client certificate A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 write client key exchange A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 write change cipher spec A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 write finished A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1001 ret=0x1)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:SSLv3 flush data
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: (where=0x1002 ret=0xffffffff)
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect:error in SSLv3 read finished A
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: SSL_connect - want more data
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: 594 bytes pending from ssl_out
2013-04-03 13:21:28 [ APCT][Dbg1] SSL: 594 bytes left to be sent out (of total 594 bytes)
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state SEND_RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAP: EAP entering state IDLE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RESPONSE
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: txSuppRsp
2013-04-03 13:21:28 [ APCT][Dbg1] TX EAPOL: dst=5c:0e:8b:cd:ad:70
2013-04-03 13:21:28 [ APCT][Dbg1] sending EAPOL frame
2013-04-03 13:21:28 [ APCT][Dbg1] KeyTx:Sent TxFrame to kernel space
2013-04-03 13:21:28 [ APCT][Dbg1] DataTx: Prot=888e,len=608,Dst= 5c-0e-8b-cd-ad-70 keyIdx=65535 prot=0x888e,txCount=5
2013-04-03 13:21:28 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:28 [ APCT][Dbg1] (k) Key
/root #
/root # cat /var/log/wipsd.log
2013-04-03 13:21:42 [ APCT][Dbg1] (k) AP Test Tx Frame Message:radio 2 len:640 keyIdx:65535
2013-04-03 13:21:42 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:42 [ APCT][Dbg1] (k) Forwarded frame to APCT len:41 radio:1
2013-04-03 13:21:42 [ APCT][Dbg1] (k) filter_frame: Mgt Frame from target BSS type=0 sub-type=12
2013-04-03 13:21:42 [ APCT][Dbg1] (k) proc_aptest(k): sending frame to user space
2013-04-03 13:21:42 [ APCT][Dbg1] (k) Forwarded frame to APCT len:26 radio:1
2013-04-03 13:21:42 [ APCT][Dbg1] L2Rx: pkt from 5c-0e-8b-cd-ad-70, len= 9
2013-04-03 13:21:42 [ APCT][Dbg1] RX EAPOL from 5c:0e:8b:cd:ad:70
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: Received EAP-Packet frame
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: SUPP_BE entering state REQUEST
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: getSuppRsp
2013-04-03 13:21:42 [ APCT][Dbg1] EAP: EAP entering state RECEIVED
2013-04-03 13:21:42 [ APCT][Dbg1] EAP: Received EAP-Failure
2013-04-03 13:21:42 [ APCT][Dbg1] EAP: EAP entering state FAILURE
2013-04-03 13:21:42 [ APCT][Dbg1] CTRL-EVENT-EAP-FAILURE EAP authentication failed
2013-04-03 13:21:42 [ APCT][Dbg1] CTRL_IFACE monitor send 127.0.0.1:1059
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: SUPP_PAE entering state HELD
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: SUPP_BE entering state RECEIVE
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: SUPP_BE entering state FAIL
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL: SUPP_BE entering state IDLE
2013-04-03 13:21:42 [ APCT][Dbg1] EAPOL authentication completed unsuccessfully
2013-04-03 13:21:42 [ APCT][Dbg1] Setting authentication timeout: 2 sec 0 usec
2013-04-03 13:21:42 [ APCT][Dbg1] MsgProc: type=8 len=70 pData=0x101203c4
2013-04-03 13:21:42 [ APCT][Dbg1] EAPAUTH state: DEAUTH rcvd reason=23
2013-04-03 13:21:42 [ APCT][Dbg1] apct_test_start: state:7, status:5, numL2:0, numSupp:3 cfgL2:3
2013-04-03 13:21:42 [ APCT][Dbg1] apct_test_start: giving up...state:7 status:5
2013-04-03 13:21:42 [ APCT][Dbg1] test_status_send connPhase=2 status=14 msgLen=24
2013-04-03 13:21:42 [ APCT][Dbg1] apct_event_process: CTRL-EVENT-EAP-FAILURE EAP authentication failed
2013-04-03 13:21:43 [ APCT][Dbg1] supp_ctrl_cmd: CMD:DISCONNECT
-----Original Message-----
From: hostap-bounces at lists.shmoo.com [mailto:hostap-bounces at lists.shmoo.com] On Behalf Of Gulick Tom-WPD384
Sent: Saturday, March 30, 2013 3:47 PM
To: Jouni Malinen; hostap at lists.shmoo.com
Subject: RE: MS 2008 NPS and PEAP/MSCHAPv2 - wpa_supplicant not connecting
Hi,
We're using OpenSSL 0.9.8p
Server config does not have client certificate required. I got a Wireshark trace of a Win 7 client connecting successfully and the EAP exchange seems the same as wpa_supplicant.
regards,
-tom
________________________________________
From: hostap-bounces at lists.shmoo.com [hostap-bounces at lists.shmoo.com] on behalf of Jouni Malinen [j at w1.fi]
Sent: Saturday, March 30, 2013 1:57 PM
To: hostap at lists.shmoo.com
Subject: Re: MS 2008 NPS and PEAP/MSCHAPv2 - wpa_supplicant not connecting
On Fri, Mar 22, 2013 at 08:08:05PM +0000, Gulick Tom-WPD384 wrote:
> >From Wireshark we see:
> The server sends a TLSv1 message with: Server Hello, Certificate,
> Certificate-Request, and Server Hello Done Supplicant responds with
> Certificate, Client Key Exchange, Change Cipher Spec, and Encrypted Handshake Server resends the first message and then DEAUTH's the supplicant with the reason being "802.1x failed".
>
> What seems different between MS 2008 NPS and the others is its sending Certificate-Request. The others do not have it.
> Supplicant does respond but with Cert but what looks like a zero length certificate.
Which TLS library are you using in this wpa_supplicant build? Is the server configured to try to use client certificate with PEAP?
--
Jouni Malinen PGP id EFC895FA
_______________________________________________
HostAP mailing list
HostAP at lists.shmoo.com
http://lists.shmoo.com/mailman/listinfo/hostap
_______________________________________________
HostAP mailing list
HostAP at lists.shmoo.com
http://lists.shmoo.com/mailman/listinfo/hostap
More information about the Hostap
mailing list