Timing question with 802.11r and OTA roaming.

[Ben Greear]

We are seeing a case where it appears to take around 9ms from the supplicant
roam request Athenticate until the packet hits the air.  The station is ath9k, APs are cisco.

After that first Authenticate packet, it seems things go a good bit quicker.

Any idea if this is expected behaviour or not?  In particular, I wonder about
that PTK failure.  We are running software-crypt on the station, in case that
matters.

Sniffer was running on another wifi NIC on the station machine, so timestamps should
be very accurate.


supplicant log

1403633898.259590: sta1: SME: Trying to authenticate with dc:a5:f4:f3:ce:9d (SSID='aironet1-5' freq=5745 MHz)
1403633898.268524: FT: Failed to set PTK to the driver
1403633898.268570: sta1: Trying to associate with dc:a5:f4:f3:ce:9d (SSID='aironet1-5' freq=5745 MHz)
1403633898.269199: sta1: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=WORLD
1403633898.273264: sta1: Associated with dc:a5:f4:f3:ce:9d
1403633898.273339: sta1: WPA: Key negotiation completed with dc:a5:f4:f3:ce:9d [PTK=CCMP GTK=CCMP]
1403633898.273464: sta1: CTRL-EVENT-CONNECTED - Connection to dc:a5:f4:f3:ce:9d completed [id=0 id_str=]
1403633898.275595: sta1: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US


pcap

8618    1403633897.156652000    00:aa:aa:aa:aa:01    Broadcast    802.11    116    Probe Request, SN=3378, FN=0, Flags=........C, SSID=Broadcast
8619 1403633897.156663000 Cisco_ff:4f:ad -> 00:aa:aa:aa:aa:01 802.11 315 Probe Response, SN=34, FN=0, Flags=....R...C, BI=102, SSID=aironet1-5
8620 1403633897.156667000              -> Cisco_ff:4f:ad (RA) 802.11 62 Acknowledgement, Flags=........C
8621 1403633897.156670000 Cisco_f3:ce:9d -> 00:aa:aa:aa:aa:01 802.11 315 Probe Response, SN=18, FN=0, Flags=....R...C, BI=102, SSID=aironet1-5
8622 1403633897.156673000              -> Cisco_f3:ce:9d (RA) 802.11 62 Acknowledgement, Flags=........C
8623 1403633897.185176000              -> 00:aa:aa:aa:aa:01 (RA) 802.11 62 Acknowledgement, Flags=........C
8624 1403633897.185192000 00:aa:aa:aa:aa:01 -> Cisco_ff:4f:ad 802.11 76 Null function (No data), SN=3380, FN=0, Flags=.......TC
8625 1403633897.185198000              -> 00:aa:aa:aa:aa:01 (RA) 802.11 62 Acknowledgement, Flags=........C
8647 1403633898.267378000 00:aa:aa:aa:aa:01 -> Cisco_f3:ce:9d 802.11 217 Authentication, SN=3381, FN=0, Flags=........C
8648 1403633898.267392000              -> 00:aa:aa:aa:aa:01 (RA) 802.11 62 Acknowledgement, Flags=........C
8649 1403633898.268420000 Cisco_f3:ce:9d -> 00:aa:aa:aa:aa:01 802.11 229 Authentication, SN=786, FN=0, Flags=........C
8650 1403633898.268431000              -> Cisco_f3:ce:9d (RA) 802.11 62 Acknowledgement, Flags=........C
8651 1403633898.269718000 Cisco_ff:4f:ad -> Broadcast    802.11 321 Beacon frame, SN=717, FN=0, Flags=........C, BI=102, SSID=aironet1-5
8652 1403633898.269731000 00:aa:aa:aa:aa:01 -> Cisco_f3:ce:9d 802.11 288 Reassociation Request, SN=3382, FN=0, Flags=........C, SSID=aironet1-5
8653 1403633898.270314000              -> 00:aa:aa:aa:aa:01 (RA) 802.11 62 Acknowledgement, Flags=........C
8654 1403633898.272438000 Cisco_f3:ce:9d -> 00:aa:aa:aa:aa:01 802.11 354 Reassociation Response, SN=787, FN=0, Flags=........C


Thanks,
Ben

-- 
Ben Greear <greearb at candelatech.com>
Candela Technologies Inc  http://www.candelatech.com