Attachment 294460 Details for Bug 432167 – /var/log/wpa_supplicant.log

/var/log/wpa_supplicant.log

wpa_supplicant.log (text/plain), 26.50 KB, created by Enrico Scholz on 2008-02-09 10:55:13 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Enrico Scholz

Created: 2008-02-09 10:55:13 UTC

Size: 26.50 KB

patch

obsolete

>1202552966.132903: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.
>1202552966.132957: Initializing interface 'wlan0' conf '/etc/wpa_supplicant/wpa_supplicant.conf' driver 'default' ctrl_interface 'N/A' bridge 'N/A'
>1202552966.132968: Configuration file '/etc/wpa_supplicant/wpa_supplicant.conf' -> '/etc/wpa_supplicant/wpa_supplicant.conf'
>1202552966.132976: Reading configuration file '/etc/wpa_supplicant/wpa_supplicant.conf'
>1202552966.133001: ctrl_interface='/var/run/wpa_supplicant'
>1202552966.133016: Line: 3 - start of a new network block
>1202552966.133027: ssid - hexdump_ascii(len=10):
>     ...
>1202552966.133039: proto: 0x2
>1202552966.133048: key_mgmt: 0x1
>1202552966.133056: eap methods - hexdump(len=16): 00 00 00 00 15 00 00 00 00 00 00 00 00 00 00 00
>1202552966.133071: anonymous_identity - hexdump_ascii(len=4):
>     77 69 66 69                                       wifi            
>1202552966.133086: identity - hexdump_ascii(len=13):
>     ...
>1202552966.133096: password - hexdump_ascii(len=16):
>     ...
>1202552966.133107: ca_cert - hexdump_ascii(len=31):
>     2f 65 74 63 2f 70 6b 69 2f 65 6e 73 63 2f 63 68   /etc/pki/ensc/ch
>     61 69 6e 73 2f 73 65 72 76 65 72 2e 70 65 6d      ains/server.pem 
>1202552966.133121: phase2 - hexdump_ascii(len=8):
>     61 75 74 68 3d 50 41 50                           auth=PAP        
>1202552966.133161: Priority group 0
>1202552966.133170:    id=0 ssid='...'
>1202552966.133177: Initializing interface (2) 'wlan0'
>1202552966.134649: EAPOL: SUPP_PAE entering state DISCONNECTED
>1202552966.134662: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
>1202552966.134668: EAPOL: SUPP_BE entering state INITIALIZE
>1202552966.134677: EAP: EAP entering state DISABLED
>1202552966.134686: EAPOL: External notification - portEnabled=0
>1202552966.134692: EAPOL: External notification - portValid=0
>1202552966.148378: SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
>1202552966.148406:   capabilities: key_mgmt 0xf enc 0xf
>1202552966.162148: WEXT: Operstate: linkmode=1, operstate=5
>1202552966.164969: Own MAC address: ...
>1202552966.164980: wpa_driver_wext_set_wpa
>1202552966.164990: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
>1202552966.165001: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
>1202552966.165011: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
>1202552966.165020: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
>1202552966.165029: wpa_driver_wext_set_countermeasures
>1202552966.165086: wpa_driver_wext_set_drop_unencrypted
>1202552966.165098: Setting scan request: 0 sec 100000 usec
>1202552966.165185: Added interface wlan0
>1202552966.165196: Daemonize..
>1202552966.165451: RTM_NEWLINK: operstate=0 ifi_flags=0x1002 ()
>1202552966.165484: Wireless event: cmd=0x8b06 len=12
>1202552966.165492: Ignore event for foreign ifindex 3
>1202552966.165499: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1202552966.165508: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1202552966.265988: State: DISCONNECTED -> SCANNING
>1202552966.266215: Starting AP scan (broadcast SSID)
>1202552966.266238: Trying to get current scan results first without requesting a new scan to speed up initial association
>1202552966.266341: Received 0 bytes of scan results (0 BSSes)
>1202552966.266362: Scan results: 0
>1202552966.266411: Selecting BSS from priority group 0
>1202552966.266433: No suitable AP found.
>1202552966.266454: Setting scan request: 0 sec 0 usec
>1202552966.266491: Starting AP scan (broadcast SSID)
>1202552969.266972: Scan timeout - try to get results
>1202552969.267018: Received 0 bytes of scan results (0 BSSes)
>1202552969.267026: Scan results: 0
>1202552969.267076: Selecting BSS from priority group 0
>1202552969.267084: No suitable AP found.
>1202552969.267094: Setting scan request: 5 sec 0 usec
>1202552970.267294: Received 0 bytes of scan results (0 BSSes)
>1202552970.267334: Scan results: 0
>1202552974.267985: Starting AP scan (broadcast SSID)
>1202552976.372575: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1202552976.372605: Wireless event: cmd=0x8b19 len=16
>1202552976.372658: Received 561 bytes of scan results (2 BSSes)
>1202552976.372668: Scan results: 2
>1202552976.372709: Selecting BSS from priority group 0
>1202552976.372718: 0: ... ssid='...' wpa_ie_len=0 rsn_ie_len=22 caps=0x11
>1202552976.372737:    selected based on RSN IE
>1202552976.372755: Trying to associate with ... (SSID='...' freq=2432 MHz)
>1202552976.372769: Cancelling scan request
>1202552976.372778: WPA: clearing own WPA/RSN IE
>1202552976.372785: Automatic auth_alg selection: 0x1
>1202552976.372798: RSN: using IEEE 802.11i/D9.0
>1202552976.372806: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 1 proto 2
>1202552976.372813: WPA: clearing AP WPA IE
>1202552976.372821: WPA: set AP RSN IE - hexdump(len=22): ...
>1202552976.372833: WPA: using GTK CCMP
>1202552976.372840: WPA: using PTK CCMP
>1202552976.372847: WPA: using KEY_MGMT 802.1X
>1202552976.372854: WPA: Set own WPA IE default - hexdump(len=22): ...
>1202552976.372866: No keys have been configured - skip key clearing
>1202552976.372873: wpa_driver_wext_set_drop_unencrypted
>1202552976.372881: State: SCANNING -> ASSOCIATING
>1202552976.372917: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
>1202552976.372930: WEXT: Operstate: linkmode=-1, operstate=5
>1202552976.372957: wpa_driver_wext_associate
>1202552976.378281: Setting authentication timeout: 15 sec 0 usec
>1202552976.378295: EAPOL: External notification - portControl=Auto
>1202552976.378308: RSN: added PMKSA cache candidate ... prio 1000
>1202552976.378316: RSN: processing PMKSA candidate list
>1202552976.378323: RSN: not in suitable state for new pre-authentication
>1202552976.378332: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1202552976.378340: Wireless event: cmd=0x8b06 len=12
>1202552976.378349: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1202552976.378355: Wireless event: cmd=0x8b04 len=16
>1202552976.378363: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1202552976.378376: Wireless event: cmd=0x8b1a len=26
>1202552976.385240: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1202552976.385253: Wireless event: cmd=0x8c02 len=267
>1202552976.385261: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=...)'
>1202552976.385271: Association info event
>1202552976.385278: req_ies - hexdump(len=59): ...
>1202552976.385295: resp_ies - hexdump(len=53): ...
>1202552976.385310: WPA: set own WPA/RSN IE - hexdump(len=22): ...
>1202552976.385323: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1202552976.385332: Wireless event: cmd=0x8b15 len=24
>1202552976.385339: Wireless event: new AP: ...
>1202552976.385346: State: ASSOCIATING -> ASSOCIATED
>1202552976.385389: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
>1202552976.385399: WEXT: Operstate: linkmode=-1, operstate=5
>1202552976.389372: Associated to a new BSS: BSSID=...
>1202552976.389383: No keys have been configured - skip key clearing
>1202552976.389391: Associated with ...
>1202552976.389402: WPA: Association event - clear replay counter
>1202552976.389412: EAPOL: External notification - portEnabled=0
>1202552976.389442: EAPOL: External notification - portValid=0
>1202552976.389451: EAPOL: External notification - portEnabled=1
>1202552976.389458: EAPOL: SUPP_PAE entering state CONNECTING
>1202552976.389464: EAPOL: SUPP_BE entering state IDLE
>1202552976.389472: EAP: EAP entering state INITIALIZE
>1202552976.389479: EAP: EAP entering state IDLE
>1202552976.389489: Setting authentication timeout: 10 sec 0 usec
>1202552976.389498: Cancelling scan request
>1202552976.389507: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1202552976.389516: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1202552979.141992: EAPOL: startWhen --> 0
>1202552979.142044: EAPOL: SUPP_PAE entering state CONNECTING
>1202552979.142060: EAPOL: txStart
>1202552979.142078: TX EAPOL - hexdump(len=4): 01 01 00 00
>1202552979.142987: RX EAPOL from ...
>1202552979.143018: RX EAPOL - hexdump(len=9): 02 00 00 05 01 00 00 05 01
>1202552979.143047: Setting authentication timeout: 70 sec 0 usec
>1202552979.143068: EAPOL: Received EAP-Packet frame
>1202552979.143085: EAPOL: SUPP_PAE entering state RESTART
>1202552979.143101: EAP: EAP entering state INITIALIZE
>1202552979.143118: EAP: EAP entering state IDLE
>1202552979.143135: EAPOL: SUPP_PAE entering state AUTHENTICATING
>1202552979.143150: EAPOL: SUPP_BE entering state REQUEST
>1202552979.143165: EAPOL: getSuppRsp
>1202552979.143180: EAP: EAP entering state RECEIVED
>1202552979.143242: EAP: Received EAP-Request id=0 method=1 vendor=0 vendorMethod=0
>1202552979.143264: EAP: EAP entering state IDENTITY
>1202552979.143281: CTRL-EVENT-EAP-STARTED EAP authentication started
>1202552979.143297: EAP: EAP-Request Identity data - hexdump_ascii(len=0):
>1202552979.143315: EAP: using anonymous identity - hexdump_ascii(len=4):
>     77 69 66 69                                       wifi            
>1202552979.143350: EAP: EAP entering state SEND_RESPONSE
>1202552979.143366: EAP: EAP entering state IDLE
>1202552979.143382: EAPOL: SUPP_BE entering state RESPONSE
>1202552979.143397: EAPOL: txSuppRsp
>1202552979.143414: TX EAPOL - hexdump(len=13): 01 00 00 09 02 00 00 09 01 77 69 66 69
>1202552979.143458: EAPOL: SUPP_BE entering state RECEIVE
>1202552979.150502: RX EAPOL from ...
>1202552979.150527: RX EAPOL - hexdump(len=10): 02 00 00 06 01 01 00 06 15 20
>1202552979.150550: EAPOL: Received EAP-Packet frame
>1202552979.150567: EAPOL: SUPP_BE entering state REQUEST
>1202552979.150582: EAPOL: getSuppRsp
>1202552979.150597: EAP: EAP entering state RECEIVED
>1202552979.150614: EAP: Received EAP-Request id=1 method=21 vendor=0 vendorMethod=0
>1202552979.150633: EAP: EAP entering state GET_METHOD
>1202552979.150650: EAP: Initialize selected EAP method: vendor 0 method 21 (TTLS)
>1202552979.150684: EAP-TTLS: Phase2 type: PAP
>1202552979.150710: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 21 (TTLS) selected
>1202552979.150727: EAP: EAP entering state METHOD
>1202552979.150795: SSL: Received packet(len=6) - Flags 0x20
>1202552979.150818: EAP-TTLS: Start (server ver=0, own ver=0)
>1202552979.150834: EAP-TTLS: Using TTLS version 0
>1202552979.151537: TLS: Trusted root certificate(s) loaded
>1202552979.151564: EAP-TTLS: Start
>1202552979.151635: SSL: (where=0x10 ret=0x1)
>1202552979.151724: SSL: (where=0x1001 ret=0x1)
>1202552979.151752: SSL: SSL_connect:before/connect initialization
>1202552979.152143: SSL: (where=0x1001 ret=0x1)
>1202552979.152166: SSL: SSL_connect:SSLv3 write client hello A
>1202552979.152190: SSL: (where=0x1002 ret=0xffffffff)
>1202552979.152207: SSL: SSL_connect:error in SSLv3 read server hello A
>1202552979.152227: SSL: SSL_connect - want more data
>1202552979.152243: SSL: 97 bytes pending from ssl_out
>1202552979.152261: SSL: 97 bytes left to be sent out (of total 97 bytes)
>1202552979.152280: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552979.152301: EAP: EAP entering state SEND_RESPONSE
>1202552979.152319: EAP: EAP entering state IDLE
>1202552979.152335: EAPOL: SUPP_BE entering state RESPONSE
>1202552979.152350: EAPOL: txSuppRsp
>1202552979.152366: TX EAPOL - hexdump(len=107): ...
>1202552979.152488: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.650288: RX EAPOL from ...
>1202552993.650316: RX EAPOL - hexdump(len=1038): ...
>1202552993.650470: EAPOL: Received EAP-Packet frame
>1202552993.650478: EAPOL: SUPP_BE entering state REQUEST
>1202552993.650484: EAPOL: getSuppRsp
>1202552993.650491: EAP: EAP entering state RECEIVED
>1202552993.650502: EAP: Received EAP-Request id=2 method=21 vendor=0 vendorMethod=0
>1202552993.650510: EAP: EAP entering state METHOD
>1202552993.650521: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.650528: SSL: TLS Message Length: 6734
>1202552993.650536: SSL: Need 5710 bytes more input data
>1202552993.650543: SSL: Building ACK
>1202552993.650568: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.650575: EAP: EAP entering state SEND_RESPONSE
>1202552993.650583: EAP: EAP entering state IDLE
>1202552993.650589: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.650596: EAPOL: txSuppRsp
>1202552993.650603: TX EAPOL - hexdump(len=10): ...
>1202552993.650628: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.676120: RX EAPOL from ...
>1202552993.676131: RX EAPOL - hexdump(len=1038): ...
>1202552993.676286: EAPOL: Received EAP-Packet frame
>1202552993.676293: EAPOL: SUPP_BE entering state REQUEST
>1202552993.676299: EAPOL: getSuppRsp
>1202552993.676305: EAP: EAP entering state RECEIVED
>1202552993.676314: EAP: Received EAP-Request id=3 method=21 vendor=0 vendorMethod=0
>1202552993.676321: EAP: EAP entering state METHOD
>1202552993.676328: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.676334: SSL: TLS Message Length: 6734
>1202552993.676352: SSL: Need 4686 bytes more input data
>1202552993.676360: SSL: Building ACK
>1202552993.676366: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.676372: EAP: EAP entering state SEND_RESPONSE
>1202552993.676379: EAP: EAP entering state IDLE
>1202552993.676385: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.676391: EAPOL: txSuppRsp
>1202552993.676397: TX EAPOL - hexdump(len=10): 01 00 00 06 02 03 00 06 15 00
>1202552993.676412: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.700090: RX EAPOL from ...
>1202552993.700119: RX EAPOL - hexdump(len=1038): ...
>1202552993.700548: EAPOL: Received EAP-Packet frame
>1202552993.700567: EAPOL: SUPP_BE entering state REQUEST
>1202552993.700583: EAPOL: getSuppRsp
>1202552993.700598: EAP: EAP entering state RECEIVED
>1202552993.700622: EAP: Received EAP-Request id=4 method=21 vendor=0 vendorMethod=0
>1202552993.700641: EAP: EAP entering state METHOD
>1202552993.700659: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.700699: SSL: TLS Message Length: 6734
>1202552993.700729: SSL: Need 3662 bytes more input data
>1202552993.700748: SSL: Building ACK
>1202552993.700763: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.700780: EAP: EAP entering state SEND_RESPONSE
>1202552993.700797: EAP: EAP entering state IDLE
>1202552993.700813: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.700828: EAPOL: txSuppRsp
>1202552993.700843: TX EAPOL - hexdump(len=10): 01 00 00 06 02 04 00 06 15 00
>1202552993.700885: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.720484: RX EAPOL from ...
>1202552993.720510: RX EAPOL - hexdump(len=1038): ...
>1202552993.720951: EAPOL: Received EAP-Packet frame
>1202552993.720970: EAPOL: SUPP_BE entering state REQUEST
>1202552993.720986: EAPOL: getSuppRsp
>1202552993.721002: EAP: EAP entering state RECEIVED
>1202552993.721026: EAP: Received EAP-Request id=5 method=21 vendor=0 vendorMethod=0
>1202552993.721072: EAP: EAP entering state METHOD
>1202552993.721092: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.721109: SSL: TLS Message Length: 6734
>1202552993.721126: SSL: Need 2638 bytes more input data
>1202552993.721144: SSL: Building ACK
>1202552993.721159: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.721176: EAP: EAP entering state SEND_RESPONSE
>1202552993.721192: EAP: EAP entering state IDLE
>1202552993.721208: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.721224: EAPOL: txSuppRsp
>1202552993.721239: TX EAPOL - hexdump(len=10): 01 00 00 06 02 05 00 06 15 00
>1202552993.721279: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.744614: RX EAPOL from ...
>1202552993.744641: RX EAPOL - hexdump(len=1038): ...
>1202552993.745079: EAPOL: Received EAP-Packet frame
>1202552993.745097: EAPOL: SUPP_BE entering state REQUEST
>1202552993.745113: EAPOL: getSuppRsp
>1202552993.745129: EAP: EAP entering state RECEIVED
>1202552993.745183: EAP: Received EAP-Request id=6 method=21 vendor=0 vendorMethod=0
>1202552993.745204: EAP: EAP entering state METHOD
>1202552993.745222: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.745239: SSL: TLS Message Length: 6734
>1202552993.745256: SSL: Need 1614 bytes more input data
>1202552993.745273: SSL: Building ACK
>1202552993.745289: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.745306: EAP: EAP entering state SEND_RESPONSE
>1202552993.745322: EAP: EAP entering state IDLE
>1202552993.745339: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.745354: EAPOL: txSuppRsp
>1202552993.745371: TX EAPOL - hexdump(len=10): 01 00 00 06 02 06 00 06 15 00
>1202552993.745411: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.767745: RX EAPOL from ...
>1202552993.767772: RX EAPOL - hexdump(len=1038): ...
>1202552993.768214: EAPOL: Received EAP-Packet frame
>1202552993.768233: EAPOL: SUPP_BE entering state REQUEST
>1202552993.768248: EAPOL: getSuppRsp
>1202552993.768293: EAP: EAP entering state RECEIVED
>1202552993.768318: EAP: Received EAP-Request id=7 method=21 vendor=0 vendorMethod=0
>1202552993.768338: EAP: EAP entering state METHOD
>1202552993.768356: SSL: Received packet(len=1034) - Flags 0xc0
>1202552993.768374: SSL: TLS Message Length: 6734
>1202552993.768392: SSL: Need 590 bytes more input data
>1202552993.768409: SSL: Building ACK
>1202552993.768424: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552993.768442: EAP: EAP entering state SEND_RESPONSE
>1202552993.768458: EAP: EAP entering state IDLE
>1202552993.768474: EAPOL: SUPP_BE entering state RESPONSE
>1202552993.768490: EAPOL: txSuppRsp
>1202552993.768506: TX EAPOL - hexdump(len=10): 01 00 00 06 02 07 00 06 15 00
>1202552993.768546: EAPOL: SUPP_BE entering state RECEIVE
>1202552993.791392: RX EAPOL from ...
>1202552993.791420: RX EAPOL - hexdump(len=604): ...
>1202552993.791672: EAPOL: Received EAP-Packet frame
>1202552993.791690: EAPOL: SUPP_BE entering state REQUEST
>1202552993.791706: EAPOL: getSuppRsp
>1202552993.791722: EAP: EAP entering state RECEIVED
>1202552993.791742: EAP: Received EAP-Request id=8 method=21 vendor=0 vendorMethod=0
>1202552993.791761: EAP: EAP entering state METHOD
>1202552993.791779: SSL: Received packet(len=600) - Flags 0x80
>1202552993.791795: SSL: TLS Message Length: 6734
>1202552993.791960: SSL: (where=0x1001 ret=0x1)
>1202552993.791984: SSL: SSL_connect:SSLv3 read server hello A
>1202552993.795136: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=2 buf='/CN=...'
>1202552993.796760: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=1 buf='/CN=...'
>1202552993.798525: TLS: tls_verify_cb - preverify_ok=1 err=0 (ok) depth=0 buf='/CN=radius..'
>1202552993.798561: SSL: (where=0x1001 ret=0x1)
>1202552993.798580: SSL: SSL_connect:SSLv3 read server certificate A
>1202552993.800320: SSL: (where=0x1001 ret=0x1)
>1202552993.800343: SSL: SSL_connect:SSLv3 read server key exchange A
>1202552993.800364: SSL: (where=0x1001 ret=0x1)
>1202552993.800412: SSL: SSL_connect:SSLv3 read server done A
>1202552994.040210: SSL: (where=0x1001 ret=0x1)
>1202552994.040229: SSL: SSL_connect:SSLv3 write client key exchange A
>1202552994.040343: SSL: (where=0x1001 ret=0x1)
>1202552994.040352: SSL: SSL_connect:SSLv3 write change cipher spec A
>1202552994.040406: SSL: (where=0x1001 ret=0x1)
>1202552994.040414: SSL: SSL_connect:SSLv3 write finished A
>1202552994.040424: SSL: (where=0x1001 ret=0x1)
>1202552994.040430: SSL: SSL_connect:SSLv3 flush data
>1202552994.040438: SSL: (where=0x1002 ret=0xffffffff)
>1202552994.040444: SSL: SSL_connect:error in SSLv3 read finished A
>1202552994.040452: SSL: SSL_connect - want more data
>1202552994.040458: SSL: 582 bytes pending from ssl_out
>1202552994.040469: SSL: 582 bytes left to be sent out (of total 582 bytes)
>1202552994.040481: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
>1202552994.040489: EAP: EAP entering state SEND_RESPONSE
>1202552994.040496: EAP: EAP entering state IDLE
>1202552994.040502: EAPOL: SUPP_BE entering state RESPONSE
>1202552994.040508: EAPOL: txSuppRsp
>1202552994.040515: TX EAPOL - hexdump(len=592): ...
>1202552994.040614: EAPOL: SUPP_BE entering state RECEIVE
>1202553005.970159: RX EAPOL from ...
>1202553005.970223: RX EAPOL - hexdump(len=73): ...
>1202553005.970277: EAPOL: Received EAP-Packet frame
>1202553005.970295: EAPOL: SUPP_BE entering state REQUEST
>1202553005.970311: EAPOL: getSuppRsp
>1202553005.970327: EAP: EAP entering state RECEIVED
>1202553005.970348: EAP: Received EAP-Request id=9 method=21 vendor=0 vendorMethod=0
>1202553005.970367: EAP: EAP entering state METHOD
>1202553005.970391: SSL: Received packet(len=69) - Flags 0x80
>1202553005.970408: SSL: TLS Message Length: 59
>1202553005.970730: SSL: (where=0x1001 ret=0x1)
>1202553005.970755: SSL: SSL_connect:SSLv3 read finished A
>1202553005.970796: SSL: (where=0x20 ret=0x1)
>1202553005.970815: SSL: (where=0x1002 ret=0x1)
>1202553005.970831: SSL: 0 bytes pending from ssl_out
>1202553005.970871: OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
>1202553005.970956: SSL: No data to be sent out
>1202553005.970975: EAP-TTLS: TLS done, proceed to Phase 2
>1202553005.971061: EAP-TTLS: Derived key - hexdump(len=64): ...
>1202553005.971114: EAP-TTLS: received 0 bytes encrypted data for Phase 2
>1202553005.971132: EAP-TTLS: empty data in beginning of Phase 2 - use fake EAP-Request Identity
>1202553005.971149: EAP-TTLS: Phase 2 PAP Request
>1202553005.971167: EAP-TTLS: Encrypting Phase 2 data - hexdump(len=48): ...
>1202553005.971301: EAP-TTLS: Authentication completed successfully
>1202553005.971322: EAP: method process -> ignore=FALSE methodState=DONE decision=COND_SUCC
>1202553005.971341: EAP: EAP entering state SEND_RESPONSE
>1202553005.971358: EAP: EAP entering state IDLE
>1202553005.971374: EAPOL: SUPP_BE entering state RESPONSE
>1202553005.971390: EAPOL: txSuppRsp
>1202553005.971408: TX EAPOL - hexdump(len=132): ...
>1202553005.971513: EAPOL: SUPP_BE entering state RECEIVE
>1202553006.387843: RX EAPOL from ...
>1202553006.387889: RX EAPOL - hexdump(len=8): 02 00 00 04 03 09 00 04
>1202553006.387932: EAPOL: Received EAP-Packet frame
>1202553006.387952: EAPOL: SUPP_BE entering state REQUEST
>1202553006.387968: EAPOL: getSuppRsp
>1202553006.387984: EAP: EAP entering state RECEIVED
>1202553006.388003: EAP: Received EAP-Success
>1202553006.388019: EAP: EAP entering state SUCCESS
>1202553006.388039: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
>1202553006.388058: EAPOL: SUPP_BE entering state RECEIVE
>1202553006.388074: EAPOL: SUPP_BE entering state SUCCESS
>1202553006.388090: EAPOL: SUPP_BE entering state IDLE
>1202553006.388305: RX EAPOL from ...
>1202553006.388328: RX EAPOL - hexdump(len=121): ...
>1202553006.388394: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
>1202553006.388420: IEEE 802.1X RX: version=2 type=3 length=117
>1202553006.388439:   EAPOL-Key type=2
>1202553006.388455:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
>1202553006.388475:   key_length=16 key_data_length=22
>1202553006.388491:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
>1202553006.388511:   key_nonce - hexdump(len=32): ...
>1202553006.388540:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1202553006.388563:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1202553006.388582:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1202553006.388601:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1202553006.388624: WPA: RX EAPOL-Key - hexdump(len=121): ...
>1202553006.388753: State: ASSOCIATED -> 4WAY_HANDSHAKE
>1202553006.388881: WPA: RX message 1 of 4-Way Handshake from ... (ver=2)
>1202553006.388907: RSN: msg 1/4 key data - hexdump(len=22): ...
>1202553006.388961: RSN: PMKID from Authenticator - hexdump(len=16): ...
>1202553006.388984: RSN: no matching PMKID found
>1202553006.389001: WPA: PMK from EAPOL state machines - hexdump(len=32): ...
>1202553006.389051: RSN: added PMKSA cache entry for ...
>1202553006.389079: RSN: the new PMK matches with the PMKID
>1202553006.391174: WPA: Renewed SNonce - hexdump(len=32): ...
>1202553006.391232: WPA: PMK - hexdump(len=32): ...
>1202553006.391262: WPA: PTK - hexdump(len=64): ...
>1202553006.391304: WPA: WPA IE for msg 2/4 - hexdump(len=22): ...
>1202553006.391332: WPA: Sending EAPOL-Key 2/4
>1202553006.391355: WPA: TX EAPOL-Key - hexdump(len=121): ...
>1202553006.393890: RX EAPOL from ...
>1202553006.393900: RX EAPOL - hexdump(len=155): ...
>1202553006.393939: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
>1202553006.393946: IEEE 802.1X RX: version=2 type=3 length=151
>1202553006.393953:   EAPOL-Key type=2
>1202553006.393960:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
>1202553006.393968:   key_length=16 key_data_length=56
>1202553006.393975:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04
>1202553006.393983:   key_nonce - hexdump(len=32): ...
>1202553006.393995:   key_iv - hexdump(len=16): ...
>1202553006.394003:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1202553006.394017:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1202553006.394024:   key_mic - hexdump(len=16): ...
>1202553006.394033: WPA: RX EAPOL-Key - hexdump(len=155): ...
>1202553006.394062: RSN: encrypted key data - hexdump(len=56): ...
>1202553006.394103: WPA: decrypted EAPOL-Key key data - hexdump(len=48): ...
>1202553006.394118: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
>1202553006.394125: WPA: RX message 3 of 4-Way Handshake from ... (ver=2)
>1202553006.394132: WPA: IE KeyData - hexdump(len=48): ...
>1202553006.394147: WPA: Sending EAPOL-Key 4/4
>1202553006.394155: WPA: TX EAPOL-Key - hexdump(len=99): ...
>1202553006.394182: WPA: Installing PTK to the driver.
>1202553006.394190: wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
>1202553006.394207: EAPOL: External notification - portValid=1
>1202553006.394214: EAPOL: SUPP_PAE entering state AUTHENTICATED
>1202553006.394221: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
>1202553006.394260: RSN: received GTK in pairwise handshake - hexdump(len=18): ...
>1202553006.394273: WPA: Group Key - hexdump(len=16): ...
>1202553006.394282: WPA: Installing GTK to the driver (keyidx=2 tx=0).
>1202553006.394289: WPA: RSC - hexdump(len=6): ...
>1202553006.394297: wpa_driver_wext_set_key: alg=3 key_idx=2 set_tx=0 seq_len=6 key_len=16
>1202553006.394313: WPA: Key negotiation completed with ... [PTK=CCMP GTK=CCMP]
>1202553006.394322: Cancelling authentication timeout
>1202553006.394329: State: GROUP_HANDSHAKE -> COMPLETED
>1202553006.394364: CTRL-EVENT-CONNECTED - Connection to ... completed (auth) [id=0 id_str=]
>1202553006.394373: wpa_driver_wext_set_operstate: operstate 0->1 (UP)
>1202553006.394381: WEXT: Operstate: linkmode=-1, operstate=6
>1202553006.398277: EAPOL: External notification - portValid=1
>1202553006.398304: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1202553006.398314: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1202553007.398986: RSN: processing PMKSA candidate list
>1202553007.399036: RSN: PMKSA candidate ... does not need pre-authentication anymore
>1202553007.399064: RSN: no more pending PMKSA candidates
>1202553009.158983: EAPOL: startWhen --> 0
>1202553036.171977: EAPOL: authWhile --> 0
>1202553065.182002: EAPOL: idleWhile --> 0

Actions: View

Attachments on bug 432167: 294460 | 323594 | 323595 | 331532 | 331829