Attachment 910108 Details for Bug 1102365 – INTEL: "-dd -t" output of wpa_supplicant, with a Network Key Rotation Time of 3600

INTEL: "-dd -t" output of wpa_supplicant, with a Network Key Rotation Time of 3600

wpa_supplicant.log (text/x-log), 32.31 KB, created by Eric Griffith on 2014-06-18 17:22:20 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Eric Griffith

Created: 2014-06-18 17:22:20 UTC

Size: 32.31 KB

patch

obsolete

>1403111932.934351: wpa_supplicant v2.0
>1403111932.934453: random: Trying to read entropy from /dev/random
>1403111932.941987: dbus: Register D-Bus object '/fi/w1/wpa_supplicant1'
>1403111932.946363: Providing DBus service 'fi.w1.wpa_supplicant1'.
>1403111932.948194: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.
>1403111932.948232: Successfully initialized wpa_supplicant
>1403111932.948273: random: Got 15/20 bytes from /dev/random
>1403111932.948309: dbus: fi.w1.wpa_supplicant1.CreateInterface (/fi/w1/wpa_supplicant1)
>1403111932.948345: Initializing interface 'wlp2s0' conf 'N/A' driver 'nl80211,wext' ctrl_interface 'N/A' bridge 'N/A'
>1403111932.949051: nl80211: interface wlp2s0 in phy phy0
>1403111932.949119: rfkill: initial event: idx=0 type=1 op=0 soft=0 hard=0
>1403111932.949136: rfkill: initial event: idx=1 type=2 op=0 soft=0 hard=0
>1403111932.950595: nl80211: Set mode ifindex 2 iftype 2 (STATION)
>1403111932.950814: nl80211: Subscribe to mgmt frames with non-AP handle 0x7f8f8fd414d0
>1403111932.950859: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.950874: nl80211: Register frame match - hexdump(len=2): 04 0a
>1403111932.951076: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951138: nl80211: Register frame match - hexdump(len=2): 04 0b
>1403111932.951173: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951189: nl80211: Register frame match - hexdump(len=2): 04 0c
>1403111932.951214: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951229: nl80211: Register frame match - hexdump(len=2): 04 0d
>1403111932.951256: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951524: nl80211: Register frame match - hexdump(len=6): 04 09 50 6f 9a 09
>1403111932.951564: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951581: nl80211: Register frame match - hexdump(len=5): 7f 50 6f 9a 09
>1403111932.951610: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951625: nl80211: Register frame match - hexdump(len=1): 06
>1403111932.951947: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.951968: nl80211: Register frame match - hexdump(len=2): 0a 07
>1403111932.952002: nl80211: Register frame type=0xd0 nl_handle=0x7f8f8fd414d0
>1403111932.952018: nl80211: Register frame match - hexdump(len=2): 0a 11
>1403111932.952050: netlink: Operstate: linkmode=1, operstate=5
>1403111932.952128: nl80211: Using driver-based off-channel TX
>1403111932.952995: nl80211: driver param='(null)'
>1403111932.953456: nl80211: Regulatory information - country=US
>1403111932.953469: nl80211: 2402-2472 @ 40 MHz
>1403111932.953477: nl80211: 5170-5250 @ 80 MHz
>1403111932.953485: nl80211: 5250-5330 @ 80 MHz
>1403111932.953493: nl80211: 5735-5835 @ 80 MHz
>1403111932.953500: nl80211: 57240-63720 @ 2160 MHz
>1403111932.953515: nl80211: Added 802.11b mode based on 802.11g information
>1403111932.959004: wlp2s0: Own MAC address: 88:53:2e:e0:4c:5a
>1403111932.959070: wpa_driver_nl80211_set_key: ifindex=2 alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
>1403111932.959137: wpa_driver_nl80211_set_key: ifindex=2 alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
>1403111932.959184: wpa_driver_nl80211_set_key: ifindex=2 alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
>1403111932.959233: wpa_driver_nl80211_set_key: ifindex=2 alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
>1403111932.959267: wlp2s0: RSN: flushing PMKID list in the driver
>1403111932.959283: nl80211: Flush PMKIDs
>1403111932.959340: wlp2s0: State: DISCONNECTED -> INACTIVE
>1403111932.959369: WPS: Set UUID for interface wlp2s0
>1403111932.959416: WPS: UUID based on MAC address - hexdump(len=16): 64 bd c0 d2 d4 37 52 e6 b0 32 37 f7 1a eb bf 6b
>1403111932.969286: EAPOL: SUPP_PAE entering state DISCONNECTED
>1403111932.969366: EAPOL: Supplicant port status: Unauthorized
>1403111932.969463: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
>1403111932.969482: EAPOL: SUPP_BE entering state INITIALIZE
>1403111932.969497: EAP: EAP entering state DISABLED
>1403111932.969509: EAPOL: Supplicant port status: Unauthorized
>1403111932.969567: EAPOL: Supplicant port status: Unauthorized
>1403111932.969637: dbus: Register interface object '/fi/w1/wpa_supplicant1/Interfaces/1'
>1403111932.970180: wlp2s0: Added interface wlp2s0
>1403111932.970206: wlp2s0: State: INACTIVE -> DISCONNECTED
>1403111932.970220: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1403111932.970232: netlink: Operstate: linkmode=-1, operstate=5
>1403111932.972071: random: Got 5/5 bytes from /dev/random
>1403111932.972230: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1)
>1403111932.972961: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111932.974281: dbus: fi.w1.wpa_supplicant1.Interface.NetworkReply (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111932.974777: dbus: org.freedesktop.DBus.Introspectable.Introspect (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111932.977684: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111932.980479: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111932.980802: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1403111932.985864: Scan requested (ret=0) - scan timeout 10 seconds
>1403111932.987531: nl80211: Event message available
>1403111932.987577: nl80211: Scan trigger
>1403111933.969847: EAPOL: disable timer tick
>1403111933.969886: EAPOL: Supplicant port status: Unauthorized
>1403111934.639950: nl80211: Event message available
>1403111934.640107: nl80211: New scan results available
>1403111934.640132: wlp2s0: Event SCAN_RESULTS (3) received
>1403111934.640230: nl80211: Received scan results (6 BSSes)
>1403111934.640260: wlp2s0: BSS: Start scan result update 1
>1403111934.640273: wlp2s0: BSS: Add new id 0 BSSID 40:16:7e:59:a7:40 SSID 'WhoKnows'
>1403111934.640283: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0'
>1403111934.640389: wlp2s0: BSS: Add new id 1 BSSID 40:16:7e:59:a7:44 SSID 'WhoKnows-5Ghz'
>1403111934.640409: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1'
>1403111934.640532: wlp2s0: BSS: Add new id 2 BSSID 28:92:4a:c2:21:81 SSID 'HP-Print-81-Officejet Pro 8600'
>1403111934.640552: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2'
>1403111934.640675: wlp2s0: BSS: Add new id 3 BSSID 22:e5:2a:08:16:2a SSID 'NETGEAR-Guest'
>1403111934.640695: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3'
>1403111934.640845: wlp2s0: BSS: Add new id 4 BSSID 20:e5:2a:08:16:29 SSID 'NETGEAR22'
>1403111934.640865: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4'
>1403111934.641017: wlp2s0: BSS: Add new id 5 BSSID 00:26:62:e5:b3:e0 SSID 'notwired-bu'
>1403111934.641038: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5'
>1403111934.641149: BSS: last_scan_res_used=6/32 last_scan_full=0
>1403111934.641174: wlp2s0: New scan results available
>1403111934.641224: WPS: AP 20:e5:2a:08:16:29 type 0 added
>1403111934.641245: WPS: AP[0] 20:e5:2a:08:16:29 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1403111934.641266: wlp2s0: No suitable network found
>1403111934.641285: wlp2s0: Short-circuit new scan request since there are no enabled networks
>1403111934.641300: wlp2s0: State: DISCONNECTED -> INACTIVE
>1403111934.641348: wlp2s0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1403111934.641560: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1403111934.641588: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111934.641637: nl80211: if_removed already cleared - ignore event
>1403111934.645239: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111934.650778: dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111934.654006: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111934.654052: dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
>1403111934.654194: scan_ssid=1 (0x1)
>1403111934.654227: proto: 0x3
>1403111934.654254: ssid - hexdump_ascii(len=13):
>     57 68 6f 4b 6e 6f 77 73 2d 35 47 68 7a            WhoKnows-5Ghz   
>1403111934.654285: key_mgmt: 0x2
>1403111934.654305: PSK (ASCII passphrase) - hexdump_ascii(len=10): [REMOVED]
>1403111934.677787: PSK (from passphrase) - hexdump(len=32): [REMOVED]
>1403111934.678421: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111934.678471: wlp2s0: Setting scan request: 0 sec 0 usec
>1403111934.678632: wlp2s0: State: INACTIVE -> SCANNING
>1403111934.678681: Scan SSID - hexdump_ascii(len=13):
>     57 68 6f 4b 6e 6f 77 73 2d 35 47 68 7a            WhoKnows-5Ghz   
>1403111934.678710: wlp2s0: Starting AP scan for wildcard SSID
>1403111934.678746: nl80211: Scan SSID - hexdump_ascii(len=13):
>     57 68 6f 4b 6e 6f 77 73 2d 35 47 68 7a            WhoKnows-5Ghz   
>1403111934.678771: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1403111934.681357: Scan requested (ret=0) - scan timeout 30 seconds
>1403111934.681408: nl80211: Event message available
>1403111934.681431: nl80211: Scan trigger
>1403111934.683748: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111936.280408: nl80211: Event message available
>1403111936.280589: nl80211: New scan results available
>1403111936.280615: wlp2s0: Event SCAN_RESULTS (3) received
>1403111936.280741: nl80211: Received scan results (6 BSSes)
>1403111936.280786: wlp2s0: BSS: Start scan result update 2
>1403111936.280832: BSS: last_scan_res_used=6/32 last_scan_full=0
>1403111936.280856: wlp2s0: New scan results available
>1403111936.280914: WPS: AP[0] 20:e5:2a:08:16:29 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1403111936.280938: wlp2s0: Selecting BSS from priority group 0
>1403111936.280957: wlp2s0: 0: 40:16:7e:59:a7:40 ssid='WhoKnows' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-43
>1403111936.280971: wlp2s0:    skip - SSID mismatch
>1403111936.280988: wlp2s0: 1: 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-64
>1403111936.281005: wlp2s0:    selected based on RSN IE
>1403111936.281022: wlp2s0:    selected BSS 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz'
>1403111936.281040: wlp2s0: Request association: reassociate: 1  selected: 40:16:7e:59:a7:44  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1403111936.281059: wlp2s0: Automatic auth_alg selection: 0x1
>1403111936.281071: RSN: PMKSA cache search - network_ctx=0x7f8f8fd603f0 try_opportunistic=0
>1403111936.281086: RSN: Search for BSSID 40:16:7e:59:a7:44
>1403111936.281101: RSN: No PMKSA cache entry found
>1403111936.281117: wlp2s0: RSN: using IEEE 802.11i/D9.0
>1403111936.281131: wlp2s0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1403111936.281144: wlp2s0: WPA: clearing AP WPA IE
>1403111936.281154: 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
>1403111936.281174: wlp2s0: WPA: using GTK CCMP
>1403111936.281187: wlp2s0: WPA: using PTK CCMP
>1403111936.281207: wlp2s0: WPA: using KEY_MGMT WPA-PSK
>1403111936.281224: 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
>1403111936.281247: wlp2s0: Cancelling scan request
>1403111936.281261: wlp2s0: SME: Trying to authenticate with 40:16:7e:59:a7:44 (SSID='WhoKnows-5Ghz' freq=5785 MHz)
>1403111936.281273: wlp2s0: No keys have been configured - skip key clearing
>1403111936.281285: wlp2s0: State: SCANNING -> AUTHENTICATING
>1403111936.281338: EAPOL: External notification - EAP success=0
>1403111936.281357: EAPOL: Supplicant port status: Unauthorized
>1403111936.281541: EAPOL: External notification - EAP fail=0
>1403111936.281560: EAPOL: Supplicant port status: Unauthorized
>1403111936.281609: EAPOL: External notification - portControl=Auto
>1403111936.281625: EAPOL: Supplicant port status: Unauthorized
>1403111936.281676: nl80211: Authenticate (ifindex=2)
>1403111936.281695:   * bssid=40:16:7e:59:a7:44
>1403111936.281711:   * freq=5785
>1403111936.281732:   * SSID - hexdump_ascii(len=13):
>     57 68 6f 4b 6e 6f 77 73 2d 35 47 68 7a            WhoKnows-5Ghz   
>1403111936.281759:   * IEs - hexdump(len=0): [NULL]
>1403111936.281773:   * Auth Type 0
>1403111936.286594: nl80211: Authentication request send successfully
>1403111936.286641: RSN: Ignored PMKID candidate without preauth flag
>1403111936.286669: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111936.286796: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1403111936.286815: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111936.286887: nl80211: if_removed already cleared - ignore event
>1403111936.286905: nl80211: Event message available
>1403111936.286926: nl80211: New station 40:16:7e:59:a7:44
>1403111936.286942: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1403111936.286998: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1403111936.334864: nl80211: Event message available
>1403111936.334921: nl80211: MLME event 37
>1403111936.334938: nl80211: MLME event frame - hexdump(len=41): b0 00 3c 00 88 53 2e e0 4c 5a 40 16 7e 59 a7 44 40 16 7e 59 a7 44 90 5c 00 00 02 00 00 00 dd 09 00 10 18 02 02 00 1c 00 00
>1403111936.334970: nl80211: Authenticate event
>1403111936.334988: wlp2s0: Event AUTH (11) received
>1403111936.335007: wlp2s0: SME: Authentication response: peer=40:16:7e:59:a7:44 auth_type=0 auth_transaction=2 status_code=0
>1403111936.335022: SME: Authentication response IEs - hexdump(len=11): dd 09 00 10 18 02 02 00 1c 00 00
>1403111936.335046: wlp2s0: Trying to associate with 40:16:7e:59:a7:44 (SSID='WhoKnows-5Ghz' freq=5785 MHz)
>1403111936.335062: wlp2s0: State: AUTHENTICATING -> ASSOCIATING
>1403111936.335076: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1403111936.335092: netlink: Operstate: linkmode=-1, operstate=5
>1403111936.335185: WPA: set own WPA/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 00 00
>1403111936.335215: nl80211: Associate (ifindex=2)
>1403111936.335232:   * bssid=40:16:7e:59:a7:44
>1403111936.335248:   * freq=5785
>1403111936.335262:   * SSID - hexdump_ascii(len=13):
>     57 68 6f 4b 6e 6f 77 73 2d 35 47 68 7a            WhoKnows-5Ghz   
>1403111936.335290:   * IEs - 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
>1403111936.335312:   * pairwise=0xfac04
>1403111936.335325:   * group=0xfac04
>1403111936.335370: nl80211: Association request send successfully
>1403111936.338780: nl80211: Event message available
>1403111936.338845: nl80211: MLME event 38
>1403111936.338861: nl80211: MLME event frame - hexdump(len=139): 10 00 3c 00 88 53 2e e0 4c 5a 40 16 7e 59 a7 44 40 16 7e 59 a7 44 a0 5c 11 00 00 00 03 c0 01 08 8c 12 98 24 b0 48 60 6c 2d 1a ff 09 17 ff ff 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 9d 0d 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 08 00 00 00 00 00 00 00 40 dd 09 00 10 18 02 02 00 1c 00 00 dd 18 00 50 f2 02 01 01 84 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
>1403111936.338916: nl80211: Associate event
>1403111936.338932: wlp2s0: Event ASSOC (0) received
>1403111936.338947: wlp2s0: Association info event
>1403111936.338959: resp_ies - hexdump(len=109): 01 08 8c 12 98 24 b0 48 60 6c 2d 1a ff 09 17 ff ff 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 9d 0d 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 7f 08 00 00 00 00 00 00 00 40 dd 09 00 10 18 02 02 00 1c 00 00 dd 18 00 50 f2 02 01 01 84 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
>1403111936.339003: wlp2s0: freq=5785 MHz
>1403111936.339018: wlp2s0: State: ASSOCIATING -> ASSOCIATED
>1403111936.339031: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1403111936.339045: netlink: Operstate: linkmode=-1, operstate=5
>1403111936.339132: wlp2s0: Associated to a new BSS: BSSID=40:16:7e:59:a7:44
>1403111936.339158: wlp2s0: No keys have been configured - skip key clearing
>1403111936.339186: wlp2s0: Associated with 40:16:7e:59:a7:44
>1403111936.339201: wlp2s0: WPA: Association event - clear replay counter
>1403111936.339214: wlp2s0: WPA: Clear old PTK
>1403111936.339227: EAPOL: External notification - portEnabled=0
>1403111936.339242: EAPOL: Supplicant port status: Unauthorized
>1403111936.339323: EAPOL: External notification - portValid=0
>1403111936.339335: EAPOL: Supplicant port status: Unauthorized
>1403111936.339368: EAPOL: External notification - EAP success=0
>1403111936.339378: EAPOL: Supplicant port status: Unauthorized
>1403111936.339409: EAPOL: External notification - portEnabled=1
>1403111936.339419: EAPOL: SUPP_PAE entering state CONNECTING
>1403111936.339429: EAPOL: enable timer tick
>1403111936.339442: EAPOL: SUPP_BE entering state IDLE
>1403111936.339458: wlp2s0: Setting authentication timeout: 10 sec 0 usec
>1403111936.339471: wlp2s0: Cancelling scan request
>1403111936.339493: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1403111936.339504: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111936.339529: nl80211: if_removed already cleared - ignore event
>1403111936.339539: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1403111936.339548: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111936.339567: nl80211: if_removed already cleared - ignore event
>1403111936.339577: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1403111936.339585: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111936.339604: nl80211: if_removed already cleared - ignore event
>1403111936.339614: nl80211: Event message available
>1403111936.339626: nl80211: Ignore connect event (cmd=46) when using userspace SME
>1403111936.340246: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111936.351690: wlp2s0: RX EAPOL from 40:16:7e:59:a7:44
>1403111936.351719: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 00 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47 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 8b c7 15 16 d7 7f 09 a6 9d 9c c4 72 99 4c 81 b8
>1403111936.351775: wlp2s0: Setting authentication timeout: 10 sec 0 usec
>1403111936.351794: wlp2s0: IEEE 802.1X RX: version=2 type=3 length=117
>1403111936.351810: wlp2s0:   EAPOL-Key type=2
>1403111936.351836: wlp2s0:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
>1403111936.351851: wlp2s0:   key_length=16 key_data_length=22
>1403111936.351862:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 00
>1403111936.351879:   key_nonce - hexdump(len=32): 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47
>1403111936.351901:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1403111936.351919:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1403111936.351935:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1403111936.351950:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1403111936.351971: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 00 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47 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 8b c7 15 16 d7 7f 09 a6 9d 9c c4 72 99 4c 81 b8
>1403111936.352029: wlp2s0: State: ASSOCIATED -> 4WAY_HANDSHAKE
>1403111936.352218: wlp2s0: WPA: RX message 1 of 4-Way Handshake from 40:16:7e:59:a7:44 (ver=2)
>1403111936.352238: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 8b c7 15 16 d7 7f 09 a6 9d 9c c4 72 99 4c 81 b8
>1403111936.352259: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 8b c7 15 16 d7 7f 09 a6 9d 9c c4 72 99 4c 81 b8
>1403111936.352290: RSN: PMKID from Authenticator - hexdump(len=16): 8b c7 15 16 d7 7f 09 a6 9d 9c c4 72 99 4c 81 b8
>1403111936.352307: wlp2s0: RSN: no matching PMKID found
>1403111936.352321: Get randomness: len=32 entropy=13
>1403111936.353262: WPA: Renewed SNonce - hexdump(len=32): 06 8b 32 19 52 06 b0 cb be d6 4d a1 6a dc c2 de 84 a3 6f d1 77 26 45 19 55 b2 4a 9b 5d 93 3c 2d
>1403111936.353317: WPA: PTK derivation - A1=88:53:2e:e0:4c:5a A2=40:16:7e:59:a7:44
>1403111936.353335: WPA: Nonce1 - hexdump(len=32): 06 8b 32 19 52 06 b0 cb be d6 4d a1 6a dc c2 de 84 a3 6f d1 77 26 45 19 55 b2 4a 9b 5d 93 3c 2d
>1403111936.353359: WPA: Nonce2 - hexdump(len=32): 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47
>1403111936.353382: WPA: PMK - hexdump(len=32): [REMOVED]
>1403111936.353394: WPA: PTK - hexdump(len=48): [REMOVED]
>1403111936.353407: 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
>1403111936.353430: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 00
>1403111936.353448: wlp2s0: WPA: Sending EAPOL-Key 2/4
>1403111936.353468: WPA: KCK - hexdump(len=16): [REMOVED]
>1403111936.353484: WPA: Derived Key MIC - hexdump(len=16): 13 bc 45 71 89 28 1a f5 a7 ee 6b 30 03 ca e4 e6
>1403111936.353502: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 00 06 8b 32 19 52 06 b0 cb be d6 4d a1 6a dc c2 de 84 a3 6f d1 77 26 45 19 55 b2 4a 9b 5d 93 3c 2d 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 13 bc 45 71 89 28 1a f5 a7 ee 6b 30 03 ca e4 e6 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1403111936.357284: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111936.358516: wlp2s0: RX EAPOL from 40:16:7e:59:a7:44
>1403111936.358543: RX EAPOL - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 01 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 48 90 3b 2d 00 00 00 00 00 00 00 00 00 00 00 00 00 e5 b3 f1 a1 08 16 cc 99 97 32 fa e1 81 71 bc a9 00 38 17 e7 2a 91 83 f4 5e a8 56 0d 5d db 0d 0f 4c 25 1b db d6 70 3d d3 85 e0 88 78 42 b1 83 1f f2 c8 2b b7 3d e7 5a f0 80 22 c8 1d e3 f3 e5 3e 70 88 f0 c4 7e b6 cd f8 5b 66
>1403111936.358609: wlp2s0: IEEE 802.1X RX: version=2 type=3 length=151
>1403111936.358624: wlp2s0:   EAPOL-Key type=2
>1403111936.358643: wlp2s0:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
>1403111936.358659: wlp2s0:   key_length=16 key_data_length=56
>1403111936.358672:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
>1403111936.358689:   key_nonce - hexdump(len=32): 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47
>1403111936.358712:   key_iv - hexdump(len=16): 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 48
>1403111936.358730:   key_rsc - hexdump(len=8): 90 3b 2d 00 00 00 00 00
>1403111936.358746:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1403111936.358763:   key_mic - hexdump(len=16): e5 b3 f1 a1 08 16 cc 99 97 32 fa e1 81 71 bc a9
>1403111936.358784: WPA: RX EAPOL-Key - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 01 01 f8 a8 ea 16 22 2f c4 ad 43 c9 f9 49 3a 30 30 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 47 09 39 b7 7a fa ca f4 35 d8 ab 3d c4 ee 42 45 48 90 3b 2d 00 00 00 00 00 00 00 00 00 00 00 00 00 e5 b3 f1 a1 08 16 cc 99 97 32 fa e1 81 71 bc a9 00 38 17 e7 2a 91 83 f4 5e a8 56 0d 5d db 0d 0f 4c 25 1b db d6 70 3d d3 85 e0 88 78 42 b1 83 1f f2 c8 2b b7 3d e7 5a f0 80 22 c8 1d e3 f3 e5 3e 70 88 f0 c4 7e b6 cd f8 5b 66
>1403111936.358868: RSN: encrypted key data - hexdump(len=56): 17 e7 2a 91 83 f4 5e a8 56 0d 5d db 0d 0f 4c 25 1b db d6 70 3d d3 85 e0 88 78 42 b1 83 1f f2 c8 2b b7 3d e7 5a f0 80 22 c8 1d e3 f3 e5 3e 70 88 f0 c4 7e b6 cd f8 5b 66
>1403111936.358918: WPA: decrypted EAPOL-Key key data - hexdump(len=48): [REMOVED]
>1403111936.358947: wlp2s0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
>1403111936.358967: wlp2s0: WPA: RX message 3 of 4-Way Handshake from 40:16:7e:59:a7:44 (ver=2)
>1403111936.358981: 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 01 00 b9 74 d4 e3 82 6f 60 82 d8 1b 9a 90 33 be a5 ee dd 00
>1403111936.359010: 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
>1403111936.359031: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
>1403111936.359048: wlp2s0: WPA: Sending EAPOL-Key 4/4
>1403111936.359068: WPA: KCK - hexdump(len=16): [REMOVED]
>1403111936.359083: WPA: Derived Key MIC - hexdump(len=16): 84 73 37 bb 0a 78 25 da 64 d8 bb 54 8c 15 76 18
>1403111936.359101: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 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 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 84 73 37 bb 0a 78 25 da 64 d8 bb 54 8c 15 76 18 00 00
>1403111936.359171: wlp2s0: WPA: Installing PTK to the driver
>1403111936.359230: wpa_driver_nl80211_set_key: ifindex=2 alg=3 addr=0x7f8f8fd3cc68 key_idx=0 set_tx=1 seq_len=6 key_len=16
>1403111936.359257:    addr=40:16:7e:59:a7:44
>1403111936.376737: EAPOL: External notification - portValid=1
>1403111936.376770: wlp2s0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
>1403111936.376839: RSN: received GTK in pairwise handshake - hexdump(len=18): [REMOVED]
>1403111936.376858: WPA: Group Key - hexdump(len=16): [REMOVED]
>1403111936.376875: wlp2s0: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16)
>1403111936.376888: WPA: RSC - hexdump(len=6): 90 3b 2d 00 00 00
>1403111936.376940: wpa_driver_nl80211_set_key: ifindex=2 alg=3 addr=0x7f8f8e17ccfe key_idx=1 set_tx=0 seq_len=6 key_len=16
>1403111936.376956:    broadcast key
>1403111936.377058: wlp2s0: WPA: Key negotiation completed with 40:16:7e:59:a7:44 [PTK=CCMP GTK=CCMP]
>1403111936.377071: wlp2s0: Cancelling authentication timeout
>1403111936.377081: wlp2s0: State: GROUP_HANDSHAKE -> COMPLETED
>1403111936.377091: wlp2s0: CTRL-EVENT-CONNECTED - Connection to 40:16:7e:59:a7:44 completed [id=0 id_str=]
>1403111936.377098: wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)
>1403111936.377106: netlink: Operstate: linkmode=-1, operstate=6
>1403111936.377190: EAPOL: External notification - portValid=1
>1403111936.377210: EAPOL: External notification - EAP success=1
>1403111936.377223: EAPOL: SUPP_PAE entering state AUTHENTICATING
>1403111936.377233: EAPOL: SUPP_BE entering state SUCCESS
>1403111936.377240: EAP: EAP entering state DISABLED
>1403111936.377247: EAPOL: SUPP_PAE entering state AUTHENTICATED
>1403111936.377254: EAPOL: Supplicant port status: Authorized
>1403111936.377300: EAPOL: SUPP_BE entering state IDLE
>1403111936.377312: EAPOL authentication completed successfully
>1403111936.377346: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1403111936.377357: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111936.377381: nl80211: if_removed already cleared - ignore event
>1403111936.381903: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111937.339841: EAPOL: startWhen --> 0
>1403111937.339885: EAPOL: disable timer tick
>1403111955.767030: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111955.767268: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1403111955.768651: Scan requested (ret=0) - scan timeout 30 seconds
>1403111955.768896: nl80211: Event message available
>1403111955.768932: nl80211: Scan trigger
>1403111957.745296: nl80211: Event message available
>1403111957.745368: nl80211: New scan results available
>1403111957.745400: wlp2s0: Event SCAN_RESULTS (3) received
>1403111957.815339: nl80211: Associated on 5785 MHz
>1403111957.815384: nl80211: Associated with 40:16:7e:59:a7:44
>1403111957.815405: nl80211: Received scan results (6 BSSes)
>1403111957.815451: nl80211: Scan results indicate BSS status with 40:16:7e:59:a7:44 as associated
>1403111957.815474: wlp2s0: BSS: Start scan result update 3
>1403111957.815508: BSS: last_scan_res_used=6/32 last_scan_full=0
>1403111957.815522: wlp2s0: New scan results available
>1403111957.815578: WPS: AP 20:e5:2a:08:16:29 type 0 added
>1403111957.815596: WPS: AP[0] 20:e5:2a:08:16:29 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1403111957.815615: wlp2s0: Selecting BSS from priority group 0
>1403111957.815632: wlp2s0: 0: 40:16:7e:59:a7:40 ssid='WhoKnows' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-46
>1403111957.815648: wlp2s0:    skip - SSID mismatch
>1403111957.815664: wlp2s0: 1: 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-62
>1403111957.815677: wlp2s0:    selected based on RSN IE
>1403111957.815693: wlp2s0:    selected BSS 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz'
>1403111957.815707: wlp2s0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1403111957.815729: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403111957.815812: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1403111957.815853: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403111957.816061: nl80211: if_removed already cleared - ignore event
>1403111957.820579: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1403111957.820748: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1403111957.820889: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5
>1403111998.767796: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1403111998.767909: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1403111998.769385: Scan requested (ret=0) - scan timeout 30 seconds
>1403111998.769588: nl80211: Event message available
>1403111998.769616: nl80211: Scan trigger
>1403112000.829182: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1403112000.829241: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlp2s0' added
>1403112000.829460: nl80211: if_removed already cleared - ignore event
>1403112000.829485: nl80211: Event message available
>1403112000.829515: nl80211: New scan results available
>1403112000.829540: wlp2s0: Event SCAN_RESULTS (3) received
>1403112000.832978: nl80211: Associated on 5785 MHz
>1403112000.833012: nl80211: Associated with 40:16:7e:59:a7:44
>1403112000.833037: nl80211: Received scan results (4 BSSes)
>1403112000.833064: nl80211: Scan results indicate BSS status with 40:16:7e:59:a7:44 as associated
>1403112000.833084: wlp2s0: BSS: Start scan result update 4
>1403112000.833115: BSS: last_scan_res_used=4/32 last_scan_full=0
>1403112000.833130: wlp2s0: New scan results available
>1403112000.833179: WPS: AP[0] 20:e5:2a:08:16:29 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1403112000.833197: wlp2s0: Selecting BSS from priority group 0
>1403112000.833211: wlp2s0: 0: 40:16:7e:59:a7:40 ssid='WhoKnows' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-48
>1403112000.833223: wlp2s0:    skip - SSID mismatch
>1403112000.833235: wlp2s0: 1: 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-63
>1403112000.833246: wlp2s0:    selected based on RSN IE
>1403112000.833258: wlp2s0:    selected BSS 40:16:7e:59:a7:44 ssid='WhoKnows-5Ghz'
>1403112000.833271: wlp2s0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1403112000.834729: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1403112000.838191: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1403112000.838325: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1403112000.838396: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1403112000.838452: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5

Actions: View

Attachments on bug 1102365: 900132 | 901030 | 901574 | 906124 | 910108