PMKSA-cache: 802.1x authentication is forced even if AP have PMKID of the STA in its PMKSA-cache

[Ajeet Nankani]

I mailed this a week back, but still have not got answer, so mailing it 
again.

Jouni can you look into this.

I have 2 Hostapd APs, and one STA with wpa_supplicant(ap_scan=1). All
are prism(1.7.4) based. I am using freeradius for authentication.

When i roam back to the AP, to which i athenticated, just few minutes
before, I see that STA sends PMKID from its PMKSA cache in the
re-association frame, and in the AP log i see a message "PMKID found
from PMKSA cache", but even then it starts 802.1x authentication with
STA, which it should not, as AP has found PMKID in its cache, and can 
use that one to drive PTKs and GTKs.

here are the snippets of the log of AP,

================================================
mgmt::auth
authentication: STA=00:a0:c5:7f:28:db auth_alg=0 auth_transaction=1
status_code=0 wep=0
   New STA
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.11: authentication OK (open
system)
wlan0: STA 00:a0:c5:7f:28:db WPA: event 0 notification
authentication reply: STA=00:a0:c5:7f:28:db auth_alg=0
auth_transaction=2 resp=0
Received 30 bytes management frame
MGMT (TX callback) ACK
mgmt::auth cb
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.11: authenticated
Received 80 bytes management frame
MGMT
mgmt::assoc_req



association request: STA=00:a0:c5:7f:28:db capab_info=0x11
listen_interval=10
RSN IE: STA PMKID - hexdump(len=16): c1 9a b7 71 c2 d4 5d 04 7f eb 68 30
1d ed c8 12
wlan0: STA 00:a0:c5:7f:28:db WPA: PMKID found from PMKSA cache
   new AID 1
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.11: association OK (aid 1)
Received 36 bytes management frame
MGMT (TX callback) ACK
mgmt::assoc_resp cb


wlan0: STA 00:a0:c5:7f:28:db IEEE 802.11: associated (aid 1, accounting
session 42305BC2-00000002)
wlan0: STA 00:a0:c5:7f:28:db WPA: event 1 notification
wlan0: STA 00:a0:c5:7f:28:db IAPP: IAPP-ADD.request(seq=2329)
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.1X: start authentication
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state INITIALIZE
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state INITIALIZE
wlan0: STA 00:a0:c5:7f:28:db WPA: start authentication
WPA: 00:a0:c5:7f:28:db WPA_PTK entering state INITIALIZE
WPA: 00:a0:c5:7f:28:db WPA_PTK_GROUP entering state IDLE
WPA: 00:a0:c5:7f:28:db WPA_PTK entering state AUTHENTICATION
WPA: 00:a0:c5:7f:28:db WPA_PTK entering state AUTHENTICATION2
Wireless event: cmd=0x8c03 len=20
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state DISCONNECTED
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.1X: unauthorizing port
IEEE 802.1X: 00:a0:c5:7f:28:db BE_AUTH entering state IDLE
IEEE 802.1X: 00:a0:c5:7f:28:db REAUTH_TIMER entering state INITIALIZE
IEEE 802.1X: 00:a0:c5:7f:28:db CTRL_DIR entering state FORCE_BOTH
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state RESTART
IEEE 802.1X: station 00:a0:c5:7f:28:db - new auth session, clearing
State
IEEE 802.1X: Generated EAP Request-Identity for 00:a0:c5:7f:28:db
(identifier 0, timeout 30)
IEEE 802.1X: 00:a0:c5:7f:28:db REAUTH_TIMER entering state INITIALIZE
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state CONNECTING
IEEE 802.1X: 00:a0:c5:7f:28:db REAUTH_TIMER entering state INITIALIZE
IEEE 802.1X: 00:a0:c5:7f:28:db AUTH_PAE entering state AUTHENTICATING
IEEE 802.1X: 00:a0:c5:7f:28:db BE_AUTH entering state REQUEST
IEEE 802.1X: Sending EAP Packet to 00:a0:c5:7f:28:db (identifier 0)
IEEE 802.1X: 00:a0:c5:7f:28:db REAUTH_TIMER entering state INITIALIZE
IEEE 802.1X: 00:a0:c5:7f:28:db REAUTH_TIMER entering state INITIALIZE
Received 46 bytes management frame
DATA (TX callback) ACK
IEEE 802.1X: 00:a0:c5:7f:28:db TX status - version=2 type=0 length=10 -
ack=1
Received 53 bytes management frame
DATA
IEEE 802.1X: 21 bytes from 00:a0:c5:7f:28:db
    IEEE 802.1X: version=2 type=0 length=17
    EAP: code=2 identifier=0 length=17 (response)
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.1X: received EAP packet (code=2
id=0 len=17) from STA: EAP Response-Identity (1)
wlan0: STA 00:a0:c5:7f:28:db IEEE 802.1X: STA identity 'example-user'
IEEE 802.1X: 00:a0:c5:7f:28:db BE_AUTH entering state RESPONSE
Encapsulating EAP message into a RADIUS packet
........

=====================================================================

So what could be worng here?

Any suggestions.

-ajeet.