Attachment 716083 Details for Bug 927191 – working trace from wpa_supplicant --ddKt

working trace from wpa_supplicant --ddKt

working.log (text/plain), 24.00 KB, created by Linus Torvalds on 2013-03-25 16:00:51 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Linus Torvalds

Created: 2013-03-25 16:00:51 UTC

Size: 24.00 KB

patch

obsolete

>1364226489.005327: wpa_supplicant v1.0-rc3
>1364226489.005388: random: Trying to read entropy from /dev/random
>1364226489.005414: Initializing interface 'wlan0' conf 'wpa_conf.txt' driver 'default' ctrl_interface 'N/A' bridge 'N/A'
>1364226489.005446: Configuration file 'wpa_conf.txt' -> '/home/torvalds/wpa_conf.txt'
>1364226489.005450: Reading configuration file '/home/torvalds/wpa_conf.txt'
>1364226489.005483: Line: 1 - start of a new network block
>1364226489.005507: ssid - hexdump_ascii(len=10):
>     6c 6f 64 67 65 63 6f 6e 64 6f                     lodgecondo      
>1364226489.005526: PSK - hexdump(len=32): 0d 93 03 20 3e a6 67 ff 6e 5e 8e 57 06 36 b2 5a d1 20 b2 ac 31 26 be a2 05 0f 75 08 53 9b 57 62
>1364226489.005573: Priority group 0
>1364226489.005576:    id=0 ssid='lodgecondo'
>1364226489.005787: WEXT: cfg80211-based driver detected
>1364226489.005867: wext: interface wlan0 phy: phy0
>1364226489.006196: rfkill: initial event: idx=0 type=2 op=0 soft=0 hard=0
>1364226489.006203: rfkill: initial event: idx=1 type=1 op=0 soft=0 hard=0
>1364226489.021562: SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
>1364226489.021571:   capabilities: key_mgmt 0xf enc 0xf flags 0x0
>1364226489.026039: netlink: Operstate: linkmode=1, operstate=5
>1364226489.034885: wlan0: Own MAC address: 9c:2a:70:55:68:a3
>1364226489.034897: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
>1364226489.034913: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
>1364226489.034919: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
>1364226489.034923: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
>1364226489.034927: wpa_driver_wext_set_countermeasures
>1364226489.034932: wlan0: RSN: flushing PMKID list in the driver
>1364226489.034942: wlan0: Setting scan request: 0 sec 100000 usec
>1364226489.034954: WPS: Set UUID for interface wlan0
>1364226489.035444: WPS: UUID based on MAC address - hexdump(len=16): 1a ba 4d 1f 50 e4 5c e9 93 46 46 f8 33 74 cd 5e
>1364226489.038532: EAPOL: SUPP_PAE entering state DISCONNECTED
>1364226489.038539: EAPOL: Supplicant port status: Unauthorized
>1364226489.038541: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
>1364226489.038542: EAPOL: SUPP_BE entering state INITIALIZE
>1364226489.038548: EAP: EAP entering state DISABLED
>1364226489.038549: EAPOL: Supplicant port status: Unauthorized
>1364226489.038550: EAPOL: Supplicant port status: Unauthorized
>1364226489.038569: wlan0: Added interface wlan0
>1364226489.038608: random: Got 20/20 bytes from /dev/random
>1364226489.038631: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226489.038642: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226489.038775: WEXT: if_removed already cleared - ignore event
>1364226489.038782: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226489.038784: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226489.038903: WEXT: if_removed already cleared - ignore event
>1364226489.038906: Wireless event: cmd=0x8b06 len=12
>1364226489.038911: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226489.038913: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226489.039003: WEXT: if_removed already cleared - ignore event
>1364226489.039005: Wireless event: cmd=0x8b1a len=16
>1364226489.135178: wlan0: State: DISCONNECTED -> SCANNING
>1364226489.135203: wlan0: Starting AP scan for wildcard SSID
>1364226489.142746: Scan requested (ret=0) - scan timeout 10 seconds
>1364226490.039559: EAPOL: disable timer tick
>1364226490.039578: EAPOL: Supplicant port status: Unauthorized
>1364226492.730120: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226492.730147: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.730728: WEXT: if_removed already cleared - ignore event
>1364226492.730760: Wireless event: cmd=0x8b19 len=16
>1364226492.730929: wlan0: Event SCAN_RESULTS (3) received
>1364226492.731103: Received 1296 bytes of scan results (3 BSSes)
>1364226492.731129: wlan0: BSS: Start scan result update 1
>1364226492.731149: wlan0: BSS: Add new id 0 BSSID 50:46:5d:02:85:08 SSID 'lodgecondo'
>1364226492.731168: wlan0: BSS: Add new id 1 BSSID 50:46:5d:02:85:0c SSID 'lodgecondo'
>1364226492.731392: wlan0: BSS: Add new id 2 BSSID 00:11:50:43:b5:75 SSID 'GOVYGENERAL'
>1364226492.731409: Add randomness: count=1 entropy=0
>1364226492.731415: Add randomness: count=2 entropy=1
>1364226492.731419: Add randomness: count=3 entropy=2
>1364226492.731426: wlan0: New scan results available
>1364226492.731454: wlan0: Selecting BSS from priority group 0
>1364226492.731468: wlan0: 0: 50:46:5d:02:85:08 ssid='lodgecondo' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-75
>1364226492.731487: wlan0:    selected based on RSN IE
>1364226492.731496: wlan0:    selected BSS 50:46:5d:02:85:08 ssid='lodgecondo'
>1364226492.731514: wlan0: Request association: reassociate: 0  selected: 50:46:5d:02:85:08  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1364226492.731531: wlan0: Trying to associate with 50:46:5d:02:85:08 (SSID='lodgecondo' freq=2412 MHz)
>1364226492.731536: wlan0: Cancelling scan request
>1364226492.731542: wlan0: WPA: clearing own WPA/RSN IE
>1364226492.731547: wlan0: Automatic auth_alg selection: 0x1
>1364226492.731573: wlan0: RSN: using IEEE 802.11i/D9.0
>1364226492.731580: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1364226492.731585: wlan0: WPA: clearing AP WPA IE
>1364226492.731589: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1364226492.731612: wlan0: WPA: using GTK CCMP
>1364226492.731616: wlan0: WPA: using PTK CCMP
>1364226492.731620: wlan0: WPA: using KEY_MGMT WPA-PSK
>1364226492.731624: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1364226492.731648: wlan0: No keys have been configured - skip key clearing
>1364226492.731654: wlan0: State: SCANNING -> ASSOCIATING
>1364226492.731658: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
>1364226492.731663: netlink: Operstate: linkmode=-1, operstate=5
>1364226492.731692: wpa_driver_wext_associate
>1364226492.731715: wpa_driver_wext_set_drop_unencrypted
>1364226492.731746: wpa_driver_wext_set_psk
>1364226492.746201: wlan0: Association request to the driver failed
>1364226492.746209: wlan0: Setting authentication timeout: 10 sec 0 usec
>1364226492.746212: EAPOL: External notification - EAP success=0
>1364226492.746214: EAPOL: Supplicant port status: Unauthorized
>1364226492.746217: EAPOL: External notification - EAP fail=0
>1364226492.746218: EAPOL: Supplicant port status: Unauthorized
>1364226492.746219: EAPOL: External notification - portControl=Auto
>1364226492.746222: EAPOL: Supplicant port status: Unauthorized
>1364226492.746225: RSN: Ignored PMKID candidate without preauth flag
>1364226492.746226: RSN: Ignored PMKID candidate without preauth flag
>1364226492.746228: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1364226492.746234: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226492.746236: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.746315: WEXT: if_removed already cleared - ignore event
>1364226492.746317: Wireless event: cmd=0x8b1a len=16
>1364226492.746320: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226492.746321: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.746373: WEXT: if_removed already cleared - ignore event
>1364226492.746375: Wireless event: cmd=0x8b06 len=12
>1364226492.746378: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1364226492.746379: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.746426: WEXT: if_removed already cleared - ignore event
>1364226492.746427: Wireless event: cmd=0x8b1a len=26
>1364226492.752583: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1364226492.752593: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.752685: WEXT: if_removed already cleared - ignore event
>1364226492.752690: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1364226492.752692: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.752752: WEXT: if_removed already cleared - ignore event
>1364226492.752796: Wireless event: cmd=0x8c08 len=140
>1364226492.752810: AssocResp IE wireless event - hexdump(len=124): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 2d 1a fd 19 1b ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 01 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 01 01 dd 09 00 10 18 02 10 f0 3c 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
>1364226492.752844: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1364226492.752846: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1364226492.752910: WEXT: if_removed already cleared - ignore event
>1364226492.752912: Wireless event: cmd=0x8b15 len=24
>1364226492.752913: Wireless event: new AP: 50:46:5d:02:85:08
>1364226492.752918: wlan0: Event ASSOCINFO (4) received
>1364226492.752921: wlan0: Association info event
>1364226492.752922: resp_ies - hexdump(len=124): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 2d 1a fd 19 1b ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 01 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 01 01 dd 09 00 10 18 02 10 f0 3c 00 00 dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
>1364226492.752951: wlan0: Event ASSOC (0) received
>1364226492.752954: wlan0: State: ASSOCIATING -> ASSOCIATED
>1364226492.752956: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
>1364226492.752958: netlink: Operstate: linkmode=-1, operstate=5
>1364226492.752975: wlan0: Associated to a new BSS: BSSID=50:46:5d:02:85:08
>1364226492.752976: Add randomness: count=4 entropy=3
>1364226492.752979: wlan0: No keys have been configured - skip key clearing
>1364226492.752982: wlan0: Associated with 50:46:5d:02:85:08
>1364226492.752990: wlan0: WPA: Association event - clear replay counter
>1364226492.752992: wlan0: WPA: Clear old PTK
>1364226492.752993: EAPOL: External notification - portEnabled=0
>1364226492.752995: EAPOL: Supplicant port status: Unauthorized
>1364226492.752998: EAPOL: External notification - portValid=0
>1364226492.752999: EAPOL: Supplicant port status: Unauthorized
>1364226492.753000: EAPOL: External notification - EAP success=0
>1364226492.753001: EAPOL: Supplicant port status: Unauthorized
>1364226492.753002: EAPOL: External notification - portEnabled=1
>1364226492.753003: EAPOL: SUPP_PAE entering state CONNECTING
>1364226492.753005: EAPOL: enable timer tick
>1364226492.753007: EAPOL: SUPP_BE entering state IDLE
>1364226492.753009: wlan0: Setting authentication timeout: 10 sec 0 usec
>1364226492.753014: wlan0: Cancelling scan request
>1364226492.772285: wlan0: RX EAPOL from 50:46:5d:02:85:08
>1364226492.772295: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 00 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 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 16 dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226492.772355: wlan0: Setting authentication timeout: 10 sec 0 usec
>1364226492.772368: wlan0: IEEE 802.1X RX: version=2 type=3 length=117
>1364226492.772371: wlan0:   EAPOL-Key type=2
>1364226492.772390: wlan0:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
>1364226492.772394: wlan0:   key_length=16 key_data_length=22
>1364226492.772396:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226492.772402:   key_nonce - hexdump(len=32): b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa
>1364226492.772420:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1364226492.772455:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226492.772464:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226492.772470:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1364226492.772484: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 00 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 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 16 dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226492.772707: wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE
>1364226492.772721: wlan0: WPA: RX message 1 of 4-Way Handshake from 50:46:5d:02:85:08 (ver=2)
>1364226492.772724: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226492.772741: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226492.772764: RSN: PMKID from Authenticator - hexdump(len=16): f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226492.772789: wlan0: RSN: no matching PMKID found
>1364226492.772793: Get randomness: len=32 entropy=4
>1364226492.775169: WPA: Renewed SNonce - hexdump(len=32): 15 d7 fa e0 a1 c6 f5 f9 ba dc 88 17 c7 b2 2a d3 91 d5 10 e0 20 b8 29 00 e2 8a d7 1f 5b 07 53 91
>1364226492.775226: WPA: PTK derivation - A1=9c:2a:70:55:68:a3 A2=50:46:5d:02:85:08
>1364226492.775234: WPA: Nonce1 - hexdump(len=32): 15 d7 fa e0 a1 c6 f5 f9 ba dc 88 17 c7 b2 2a d3 91 d5 10 e0 20 b8 29 00 e2 8a d7 1f 5b 07 53 91
>1364226492.775258: WPA: Nonce2 - hexdump(len=32): b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa
>1364226492.775281: WPA: PMK - hexdump(len=32): 0d 93 03 20 3e a6 67 ff 6e 5e 8e 57 06 36 b2 5a d1 20 b2 ac 31 26 be a2 05 0f 75 08 53 9b 57 62
>1364226492.775304: WPA: PTK - hexdump(len=48): 5a a5 76 50 14 ac bb 77 5b 72 70 ab 23 9b f1 32 0b 5e cd 19 83 c1 a3 26 81 1a d0 0e 35 fe ff 03 94 37 13 2e 4b cd 15 2c 72 6b 1f c3 9a f9 0e 83
>1364226492.775348: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1364226492.775372: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226492.775386: wlan0: WPA: Sending EAPOL-Key 2/4
>1364226492.775400: WPA: KCK - hexdump(len=16): 5a a5 76 50 14 ac bb 77 5b 72 70 ab 23 9b f1 32
>1364226492.775413: WPA: Derived Key MIC - hexdump(len=16): 30 75 cd e6 25 0a 2e 17 26 e4 0f 45 c7 b4 1c c7
>1364226492.775426: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 00 15 d7 fa e0 a1 c6 f5 f9 ba dc 88 17 c7 b2 2a d3 91 d5 10 e0 20 b8 29 00 e2 8a d7 1f 5b 07 53 91 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 30 75 cd e6 25 0a 2e 17 26 e4 0f 45 c7 b4 1c c7 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1364226493.753977: EAPOL: startWhen --> 0
>1364226493.753999: EAPOL: disable timer tick
>1364226493.754006: EAPOL: SUPP_PAE entering state CONNECTING
>1364226493.754009: EAPOL: enable timer tick
>1364226493.754019: EAPOL: txStart
>1364226493.754027: WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
>1364226493.944343: wlan0: RX EAPOL from 50:46:5d:02:85:08
>1364226493.944360: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 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 16 dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226493.946390: wlan0: IEEE 802.1X RX: version=2 type=3 length=117
>1364226493.946399: wlan0:   EAPOL-Key type=2
>1364226493.946409: wlan0:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
>1364226493.946414: wlan0:   key_length=16 key_data_length=22
>1364226493.946417:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
>1364226493.946427:   key_nonce - hexdump(len=32): b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa
>1364226493.946450:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1364226493.946578:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226493.946587:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226493.946594:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1364226493.946612: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 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 16 dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226493.947838: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
>1364226493.947848: wlan0: WPA: RX message 1 of 4-Way Handshake from 50:46:5d:02:85:08 (ver=2)
>1364226493.947850: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226493.947862: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226493.947873: RSN: PMKID from Authenticator - hexdump(len=16): f1 9a 16 f6 6f ba fe f6 ea 11 c7 9d f5 4e bd cf
>1364226493.947882: wlan0: RSN: no matching PMKID found
>1364226493.947920: WPA: PTK derivation - A1=9c:2a:70:55:68:a3 A2=50:46:5d:02:85:08
>1364226493.947926: WPA: Nonce1 - hexdump(len=32): 15 d7 fa e0 a1 c6 f5 f9 ba dc 88 17 c7 b2 2a d3 91 d5 10 e0 20 b8 29 00 e2 8a d7 1f 5b 07 53 91
>1364226493.947941: WPA: Nonce2 - hexdump(len=32): b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa
>1364226493.947955: WPA: PMK - hexdump(len=32): 0d 93 03 20 3e a6 67 ff 6e 5e 8e 57 06 36 b2 5a d1 20 b2 ac 31 26 be a2 05 0f 75 08 53 9b 57 62
>1364226493.947969: WPA: PTK - hexdump(len=48): 5a a5 76 50 14 ac bb 77 5b 72 70 ab 23 9b f1 32 0b 5e cd 19 83 c1 a3 26 81 1a d0 0e 35 fe ff 03 94 37 13 2e 4b cd 15 2c 72 6b 1f c3 9a f9 0e 83
>1364226493.947990: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1364226493.948004: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01
>1364226493.948012: wlan0: WPA: Sending EAPOL-Key 2/4
>1364226493.948021: WPA: KCK - hexdump(len=16): 5a a5 76 50 14 ac bb 77 5b 72 70 ab 23 9b f1 32
>1364226493.948029: WPA: Derived Key MIC - hexdump(len=16): b9 26 43 d6 99 be c0 87 69 1a 2c f3 62 5a fa 60
>1364226493.948037: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 15 d7 fa e0 a1 c6 f5 f9 ba dc 88 17 c7 b2 2a d3 91 d5 10 e0 20 b8 29 00 e2 8a d7 1f 5b 07 53 91 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 b9 26 43 d6 99 be c0 87 69 1a 2c f3 62 5a fa 60 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1364226493.962291: wlan0: RX EAPOL from 50:46:5d:02:85:08
>1364226493.962301: RX EAPOL - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 02 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fb 8a 8e 07 00 00 00 00 00 00 00 00 00 00 00 00 00 19 9a 79 0c df 9f 7a 50 72 c3 e3 8e 5f f5 db 16 00 38 7e 53 2e 7f 00 98 45 9c 20 f7 3e ae 10 b8 00 0f 00 ab fe fb 5c 24 d8 79 f0 fb de 52 33 e4 09 2d 79 92 91 63 e8 11 96 12 ef af 2d 52 42 f0 13 67 b2 f5 99 35 cf dc ea 6d
>1364226493.962373: wlan0: IEEE 802.1X RX: version=2 type=3 length=151
>1364226493.962377: wlan0:   EAPOL-Key type=2
>1364226493.962385: wlan0:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
>1364226493.962389: wlan0:   key_length=16 key_data_length=56
>1364226493.962391:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
>1364226493.962397:   key_nonce - hexdump(len=32): b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa
>1364226493.962411:   key_iv - hexdump(len=16): 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fb
>1364226493.962420:   key_rsc - hexdump(len=8): 8a 8e 07 00 00 00 00 00
>1364226493.962512:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1364226493.962522:   key_mic - hexdump(len=16): 19 9a 79 0c df 9f 7a 50 72 c3 e3 8e 5f f5 db 16
>1364226493.962541: WPA: RX EAPOL-Key - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 02 b7 e3 5e de a3 39 4b a8 c7 02 d8 8b ef 5c f1 d7 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fa 59 29 c2 c5 92 4c ec ac 1e 9a 98 9d 56 52 24 fb 8a 8e 07 00 00 00 00 00 00 00 00 00 00 00 00 00 19 9a 79 0c df 9f 7a 50 72 c3 e3 8e 5f f5 db 16 00 38 7e 53 2e 7f 00 98 45 9c 20 f7 3e ae 10 b8 00 0f 00 ab fe fb 5c 24 d8 79 f0 fb de 52 33 e4 09 2d 79 92 91 63 e8 11 96 12 ef af 2d 52 42 f0 13 67 b2 f5 99 35 cf dc ea 6d
>1364226493.962688: RSN: encrypted key data - hexdump(len=56): 7e 53 2e 7f 00 98 45 9c 20 f7 3e ae 10 b8 00 0f 00 ab fe fb 5c 24 d8 79 f0 fb de 52 33 e4 09 2d 79 92 91 63 e8 11 96 12 ef af 2d 52 42 f0 13 67 b2 f5 99 35 cf dc ea 6d
>1364226493.962778: WPA: decrypted EAPOL-Key key data - hexdump(len=48): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00 dd 16 00 0f ac 01 02 00 a3 3b 32 cb 57 76 8b 6c 31 9d 7d 2f ea ab f7 e1 dd 00
>1364226493.962841: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
>1364226493.962851: wlan0: WPA: RX message 3 of 4-Way Handshake from 50:46:5d:02:85:08 (ver=2)
>1364226493.962854: WPA: IE KeyData - hexdump(len=48): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00 dd 16 00 0f ac 01 02 00 a3 3b 32 cb 57 76 8b 6c 31 9d 7d 2f ea ab f7 e1 dd 00
>1364226493.962887: WPA: RSN IE in EAPOL-Key - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1364226493.962899: WPA: GTK in EAPOL-Key - hexdump(len=24): dd 16 00 0f ac 01 02 00 a3 3b 32 cb 57 76 8b 6c 31 9d 7d 2f ea ab f7 e1
>1364226493.962924: wlan0: WPA: Sending EAPOL-Key 4/4
>1364226493.962935: WPA: KCK - hexdump(len=16): 5a a5 76 50 14 ac bb 77 5b 72 70 ab 23 9b f1 32
>1364226493.962944: WPA: Derived Key MIC - hexdump(len=16): 56 a8 2b 35 fd f6 d3 68 9a 74 23 27 b0 4d a1 31
>1364226493.962952: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 00 00 00 00 00 00 00 00 00 02 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 56 a8 2b 35 fd f6 d3 68 9a 74 23 27 b0 4d a1 31 00 00
>1364226493.963046: wlan0: WPA: Installing PTK to the driver
>1364226493.963050: wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
>1364226493.963255: EAPOL: External notification - portValid=1
>1364226493.963265: wlan0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
>1364226493.963270: RSN: received GTK in pairwise handshake - hexdump(len=18): 02 00 a3 3b 32 cb 57 76 8b 6c 31 9d 7d 2f ea ab f7 e1
>1364226493.963283: WPA: Group Key - hexdump(len=16): a3 3b 32 cb 57 76 8b 6c 31 9d 7d 2f ea ab f7 e1
>1364226493.963318: wlan0: WPA: Installing GTK to the driver (keyidx=2 tx=0 len=16)
>1364226493.963320: WPA: RSC - hexdump(len=6): 8a 8e 07 00 00 00
>1364226493.963325: wpa_driver_wext_set_key: alg=3 key_idx=2 set_tx=0 seq_len=6 key_len=16
>1364226493.963402: wlan0: WPA: Key negotiation completed with 50:46:5d:02:85:08 [PTK=CCMP GTK=CCMP]
>1364226493.963407: wlan0: Cancelling authentication timeout
>1364226493.963411: wlan0: State: GROUP_HANDSHAKE -> COMPLETED
>1364226493.963418: wlan0: CTRL-EVENT-CONNECTED - Connection to 50:46:5d:02:85:08 completed (auth) [id=0 id_str=]
>1364226493.963420: wpa_driver_wext_set_operstate: operstate 0->1 (UP)
>1364226493.963423: netlink: Operstate: linkmode=-1, operstate=6
>1364226493.963501: EAPOL: External notification - portValid=1
>1364226493.963506: EAPOL: External notification - EAP success=1
>1364226493.963508: EAPOL: SUPP_PAE entering state AUTHENTICATING
>1364226493.963510: EAPOL: SUPP_BE entering state SUCCESS
>1364226493.963511: EAP: EAP entering state DISABLED
>1364226493.963513: EAPOL: SUPP_PAE entering state AUTHENTICATED
>1364226493.963515: EAPOL: Supplicant port status: Authorized
>1364226493.963517: EAPOL: SUPP_BE entering state IDLE
>136

Actions: View

Attachments on bug 927191: 715950 | 716083 | 716290 | 716576 | 716586 | 736457 | 736458 | 758623 | 758624 | 758625 | 758626 | 758627 | 758628 | 758629 | 758630 | 758631 | 758632 | 763954 | 763955 | 763956 | 763967 | 763968 | 789310