can't get WPA/2 and EAP-TTLS to work

15 Feb 2008

      The wpa_supplicant keeps looping looking for missing keys
accordint to Jouni.  I suspected my Cisco access point was
not configured properly, but Cisco claims that FreeRADIUS is
asking the access point about dynamic VLANs which aren't even
configured in FreeRADIUS (see configurations below).

     +-----------------------------------+
     | ThinkPad T42 with D-Link DWL-G660 |
     | (ath0) on FreeBSD 6.2-STABLE      |
     | running wpa_supplicant 0.4.8      |
     +-----------------------------------+
                      ^
           802.1X     |    WPA/2 EAP-TTLS
                      v
   +---------------------------------------+
   | Cisco 1131AG 802.11a/b/g AP  IOS 12.4 |
   +---------------------------------------+
                      ^
          EAP-TTLS    |    RADIUS
                      v
     +-----------------------------------+
     | FreeRADIUS 1.1.7_2 on FreeBSD 7.0 |
     +-----------------------------------+

It almost works in that authentication succeeds (see debug log file
output), but the complete 802.1x connection does not succeed, hence
the looping behaviour...

 =*=*=*=*=*=*=*=*=*= wpa_supplicant.conf =*=*=*=*=*=*=*=*=*=*=*=*=

ctrl_interface=/var/run/wpa_supplicant
ctrl_interface_group=0

network={
    ssid="testing"
    bssid=00:xx:yy:yy:zz:zz
    proto=RSN
    key_mgmt=WPA-EAP
    eap=TTLS
    anonymous_identity="anonymous"
    identity="foo"
    password="password"
    phase2="auth=MD5"
}

 =*=*=*=*=*=*=*=*=*= FreeRADIUS eap.conf =*=*=*=*=*=*=*=*=*=*=*=

eap {
    default_eap_type = ttls
    timer_expire     = 60
    ignore_unknown_eap_types = no
    cisco_accounting_username_bug = yes

    md5 {
    }

    tls {
        private_key_password = whatever
        private_key_file = ${raddbdir}/certs/cert-srv.pem
        certificate_file = ${raddbdir}/certs/cert-srv.pem
        CA_file = ${raddbdir}/certs/demoCA/cacert.pem
        dh_file = ${raddbdir}/certs/dh
        random_file = ${raddbdir}/certs/random
        fragment_size = 1024
        include_length = yes
        cipher_list = "DEFAULT"
    }

    ttls {
        default_eap_type = md5
        copy_request_to_tunnel = yes
        use_tunneled_reply = yes
    }
}

 =*=*=*=*=*=*=*=*=*= FreeRADIUS users =*=*=*=*=*=*=*=*=*=*=*=

foo     User-Password == "password"

 =*=*=*=*=*=*=*=*= simplified radiusd.conf =*=*=*=*=*=*=*=*=*=*=

[snip] less important stuff omitted [/snip]

$INCLUDE ${confdir}/clients.conf
$INCLUDE ${confdir}/eap.conf

instantiate {
}

authorize {
    preprocess
    auth_log
    eap
    files
    pap
}

authenticate {
    Auth-Type PAP {
        pap
    }
    eap
}

preacct {
    preprocess
    acct_unique
}

accounting {
    detail
}

post-auth {
    reply_log
}

 =*=*=*=*=*=*=*=*= -Xxx debug output snippet =*=*=*=*=*=*=*=*=*=

Thu Feb 14 08:41:05 2008 : Debug:   Processing the authorize section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authorize for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug: radius_xlat:  '/var/log/radacct/www.xxx.yyy.zzz/auth-20080214'
Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-%Y%m%d expands to /var/log/rada
cct/www.xxx.yyy.zzz/auth-20080214
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: EAP packet type response id 7 length 112
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "files" returns notfound for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 6
Thu Feb 14 08:41:05 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user.  Authentication may fai
l because of this.
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Thu Feb 14 08:41:05 2008 : Debug: auth: type "EAP"
Thu Feb 14 08:41:05 2008 : Debug:   Processing the authenticate section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authenticate for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: Request found, released from the list
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: EAP/ttls
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: processing type ttls
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap_ttls: Authenticate
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap_tls: processing TLS
Thu Feb 14 08:41:05 2008 : Debug:   eaptls_verify returned 7
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap_tls: Done initial handshake
Thu Feb 14 08:41:05 2008 : Debug:   eaptls_process returned 7
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
Thu Feb 14 08:41:05 2008 : Debug:   TTLS: Adding old state with 29 1f
Thu Feb 14 08:41:05 2008 : Debug:   Processing the authorize section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authorize for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "preprocess" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling auth_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug: radius_xlat:  '/var/log/radacct/127.0.0.1/auth-20080214'
Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/auth-%Y%m%d expands to /var/log/rada
cct/127.0.0.1/auth-20080214
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from auth_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "auth_log" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: EAP packet type response id 7 length 22
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "eap" returns updated for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling files (rlm_files) for request 6
Thu Feb 14 08:41:05 2008 : Debug:     users: Matched entry foo at line 217
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from files (rlm_files) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "files" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: calling pap (rlm_pap) for request 6
Thu Feb 14 08:41:05 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it.
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authorize]: returned from pap (rlm_pap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authorize]: module "pap" returns noop for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rad_check_password:  Found Auth-Type EAP
Thu Feb 14 08:41:05 2008 : Debug: auth: type "EAP"
Thu Feb 14 08:41:05 2008 : Debug:   Processing the authenticate section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group authenticate for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authenticate]: calling eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: Request found, released from the list
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: EAP/md5
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: processing type md5
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: Freeing handler
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authenticate]: module "eap" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authenticate (returns ok) for request 6
Thu Feb 14 08:41:05 2008 : Error: Trying to look up name of unknown client 127.0.0.1.
Thu Feb 14 08:41:05 2008 : Auth: Login OK: [foo/<no User-Password attribute>] (from client UNKNOWN-CLIENT port 262 cli 0
0-13-46-C1-7A-01)
Thu Feb 14 08:41:05 2008 : Debug:   Processing the post-auth section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group post-auth for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[post-auth]: calling reply_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug: radius_xlat:  '/var/log/radacct/127.0.0.1/reply-detail-20080214'
Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/
log/radacct/127.0.0.1/reply-detail-20080214
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[post-auth]: module "reply_log" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   TTLS: Got tunneled Access-Accept
Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Recv-Key: Unknown attribute
"MS-MPPE-Recv-Key"
Thu Feb 14 08:41:05 2008 : Debug: rlm_eap_tls: add_reply failed to create attribute MS-MPPE-Send-Key: Unknown attribute
"MS-MPPE-Send-Key"
Thu Feb 14 08:41:05 2008 : Debug:   rlm_eap: Freeing handler
Thu Feb 14 08:41:05 2008 : Debug:   TTLS: Freeing handler for user foo
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[authenticate]: returned from eap (rlm_eap) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[authenticate]: module "eap" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group authenticate (returns ok) for request 6
Thu Feb 14 08:41:05 2008 : Auth: Login OK: [anonymous/<no User-Password attribute>] (from client hotbox port 2
62 cli 00-xx-yy-yy-zz-zz)
Thu Feb 14 08:41:05 2008 : Debug:   Processing the post-auth section of radiusd.conf
Thu Feb 14 08:41:05 2008 : Debug: modcall: entering group post-auth for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[post-auth]: calling reply_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug: radius_xlat:  '/var/log/radacct/www.xxx.yyy.zzz/reply-detail-20080214'
Thu Feb 14 08:41:05 2008 : Debug: rlm_detail: /var/log/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/
log/radacct/www.xxx.yyy.zzz/reply-detail-20080214
Thu Feb 14 08:41:05 2008 : Debug:   modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6
Thu Feb 14 08:41:05 2008 : Debug:   modcall[post-auth]: module "reply_log" returns ok for request 6
Thu Feb 14 08:41:05 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6
Sending Access-Accept of id 42 to www.xxx.yyy.zzz port 1645
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "foo\000"
        EAP-Message = 0x03070004                           <<<<===== this looks like success [EAP code == 3]
Thu Feb 14 08:41:05 2008 : Debug: Finished request 6
Thu Feb 14 08:41:05 2008 : Debug: Going to the next request
Thu Feb 14 08:41:05 2008 : Debug: Waking up in 6 seconds...

 =*=*=*=*=*=*=*=*= Cisco debug log snippet =*=*=*=*=*=*=*=*=*=

Feb 14 13:40:56.976: dot11_auth_dot1x_run_rfsm: Executing Action(CLIENT_WAIT,CLIENT_REPLY) for 00xx.yyyy.zzzz
Feb 14 13:40:56.976: dot11_auth_dot1x_send_response_to_server: Sending client 00xx.yyyy.zzzz data to server
Feb 14 13:40:56.977: dot11_auth_dot1x_send_response_to_server: Started timer server_timeout 60 seconds
Feb 14 13:40:56.990: dot11_auth_dot1x_parse_aaa_resp: Received server response: PASS
Feb 14 13:40:56.990: dot11_auth_dot1x_parse_aaa_resp: found eap pak in server response
Feb 14 13:40:56.990: dot11_auth_server_chk_ssid: Checking for SSID in server attributes
Feb 14 13:40:56.990: dot11_auth_server_vlan_number: Checking for VLAN ID in server attributes
Feb 14 13:40:56.990: dot11_auth_dot1x_run_rfsm: Executing Action(SERVER_WAIT,SERVER_PASS) for 00xx.yyyy.zzzz
Feb 14 13:40:56.990: dot11_auth_dot1x_send_response_to_client: Forwarding server message to client 00xx.yyyy.zzzz
Feb 14 13:40:56.990: EAPOL pak dump tx
Feb 14 13:40:56.990: EAPOL Version: 0x1  type: 0x0  length: 0x0004
Feb 14 13:40:56.991: EAP code: 0x3  id: 0x7  length: 0x0004              <<<<<=====  [EAP success code == 3]
01802DA0: 01000004 03070004                    ........
Feb 14 13:40:56.991: dot11_auth_send_msg:  sending data to requestor status 1
Feb 14 13:40:56.991: dot11_auth_send_msg: Sending EAPOL to requestor
Feb 14 13:40:56.991: dot1x-registry:registry:dot1x_ether_macaddr called
Feb 14 13:40:56.991: dot11_auth_dot1x_send_response_to_client: Started timer client_timeout 30 seconds
Feb 14 13:40:56.991: dot11_auth_send_msg:  sending data to requestor status 2
Feb 14 13:40:56.991: dot11_auth_send_msg: resp->nsk_len 0 resp->auth_key_len 0
Feb 14 13:40:56.992: dot11_auth_send_msg: client authenticated 00xx.yyyy.zzzz, node_type 64 for application 0x1
Feb 14 13:40:56.992: dot11_auth_delete_client_entry: 00xx.yyyy.zzzz is deleted for application 0x1
Feb 14 13:40:56.992: dot1x-registry:registry:dot1x_ether_macaddr called
Feb 14 13:40:56.998: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0.
Feb 14 13:40:56.998: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q
Feb 14 13:40:57.092: dot1x-registry:registry:dot1x_ether_macaddr called
Feb 14 13:40:57.093: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0.
Feb 14 13:40:57.093: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q
Feb 14 13:40:57.192: dot1x-registry:registry:dot1x_ether_macaddr called
Feb 14 13:40:57.193: dot1x-ev:dot1x_mgr_pre_process_eapol_pak: Role determination not required on Dot11Radio0.
Feb 14 13:40:57.193: dot1x-packet:dot1x_mgr_process_eapol_pak: queuing an EAPOL pkt on Authenticator Q
Feb 14 08:40:57.292 -0500: %DOT11-7-AUTH_FAILED: Station 00xx.yyyy.zzzz Authentication failed
                                    ^^^^^^^^^^^                         ^^^^^^^^^^^^^^^^^^^^^
Clearly the access point isn't helping here...

 =*=*=*=*=*=*=*=*=*=*=*=*= wpa_supplicant "-dd" output =*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=

Initializing interface 'ath0' conf '/etc/wpa_supplicant.conf' driver 'default' ctrl_interface 'N/A'
Configuration file '/etc/wpa_supplicant.conf' -> '/etc/wpa_supplicant.conf'
Reading configuration file '/etc/wpa_supplicant.conf'
ctrl_interface='/var/run/wpa_supplicant'
ctrl_interface_group=0 (from group name 'wheel')
Line: 7 - start of a new network block
ssid - hexdump_ascii(len=7):
     74 65 73 74 69 6e 67                              testing
BSSID - hexdump(len=6): 00 xx xx xx xx xx
proto: 0x2
key_mgmt: 0x1
eap methods - hexdump(len=2): 15 00
anonymous_identity - hexdump_ascii(len=9):
     61 6e 6f 6e 79 6d 6f 75 73                        anonymous
identity - hexdump_ascii(len=3):
     66 6f 6f                                          foo             
password - hexdump_ascii(len=8): [REMOVED]
phase2 - hexdump_ascii(len=11):
     61 75 74 68 65 61 70 3d 4d 44 35                  autheap=MD5     
Priority group 0
   id=0 ssid='testing'
Initializing interface (2) 'ath0'
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: KEY_RX entering state NO_KEY_RECEIVE
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
Own MAC address: 00:xx:xx:xx:xx:xx
wpa_driver_bsd_set_wpa: enabled=1
wpa_driver_bsd_set_wpa_internal: wpa=3 privacy=1
wpa_driver_bsd_del_key: keyidx=0
wpa_driver_bsd_del_key: keyidx=1
wpa_driver_bsd_del_key: keyidx=2
wpa_driver_bsd_del_key: keyidx=3
wpa_driver_bsd_set_countermeasures: enabled=0
wpa_driver_bsd_set_drop_unencrypted: enabled=1
Setting scan request: 0 sec 100000 usec
Added interface ath0
State: DISCONNECTED -> SCANNING
Starting AP scan (broadcast SSID)
Received 0 bytes of scan results (7 BSSes)
Scan results: 7
Selecting BSS from priority group 0
0: 00:xx:xx:xx:xx:xx ssid='JoesROOM' wpa_ie_len=0 rsn_ie_len=22 caps=0x31
   skip - SSID mismatch
1: 00:xx:xx:xx:xx:xx ssid='testing' wpa_ie_len=0 rsn_ie_len=22 caps=0x31
   selected based on RSN IE
Trying to associate with 00:xx:xx:xx:xx:xx (SSID='testing' freq=2442 MHz)
Cancelling scan request
WPA: clearing own WPA/RSN IE
Automatic auth_alg selection: 0x1
wpa_driver_bsd_set_auth_alg alg 0x1 authmode 1
RSN: using IEEE 802.11i/D9.0
WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 1
WPA: clearing AP WPA IE
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 01 28 00
WPA: using GTK CCMP
WPA: using PTK CCMP
WPA: using KEY_MGMT 802.1X
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 01 00 00
No keys have been configured - skip key clearing
wpa_driver_bsd_set_drop_unencrypted: enabled=1
State: SCANNING -> ASSOCIATING
wpa_driver_bsd_associate: ssid 'testing' wpa ie len 22 pairwise 3 group 3 key mgmt 0
wpa_driver_bsd_associate: set PRIVACY 1
Setting authentication timeout: 10 sec 0 usec
EAPOL: External notification - portControl=Auto
RSN: Ignored PMKID candidate without preauth flag
State: ASSOCIATING -> ASSOCIATED
Associated to a new BSS: BSSID=00:xx:xx:xx:xx:xx
No keys have been configured - skip key clearing
Associated with 00:xx:xx:xx:xx:xx
WPA: Association event - clear replay counter
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
Setting authentication timeout: 10 sec 0 usec
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=48): 01 00 00 33 01 01 00 33 01 00 6e 65 74 77 6f 72 6b 69 64 3d 74 65 73 74 69 6e 67 2c 6e 61 73 69 64 3d 63 69 73 63 6f 2c 70 6f 72 74 69 64 3d 30
Setting authentication timeout: 70 sec 0 usec
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_PAE entering state RESTART
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=1 id=1
EAP: EAP entering state IDENTITY
CTRL-EVENT-EAP-STARTED EAP authentication started
EAP: EAP-Request Identity data - hexdump_ascii(len=39):
     00 6e 65 74 77 6f 72 6b 69 64 3d 74 65 73 74 69   _networkid=testi
     6e 67 2c 6e 61 73 69 64 3d 63 69 73 63 6f 2c 70   ng,nasid=cisco,p
     6f 72 74 69 64 3d 30                              ortid=0  
EAP: using anonymous identity - hexdump_ascii(len=9):
     61 6e 6f 6e 79 6d 6f 75 73                        anonymous
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=18): 01 00 00 18 02 01 00 18 01 61 6e 6f 6e 79 6d 6f 75 73 
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=46): 01 00 00 06 01 02 00 06 15 20 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
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=2
EAP: EAP entering state GET_METHOD
EAP: initialize selected EAP method (21, TTLS)
EAP-TTLS: Phase2 type: EAP
EAP-TTLS: Phase2 EAP types - hexdump(len=1): 04
CTRL-EVENT-EAP-METHOD EAP method 21 (TTLS) selected
EAP: EAP entering state METHOD
SSL: Received packet(len=6) - Flags 0x20
EAP-TTLS: Start
SSL: (where=0x10 ret=0x1)
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:before/connect initialization
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client hello A
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read server hello A
SSL: SSL_connect - want more data
SSL: 100 bytes pending from ssl_out
SSL: 100 bytes left to be sent out (of total 100 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=110): 01 00 00 6a 02 02 00 6a 15 00 16 03 01 00 5f 01 00 00 5b 03 01 47 a9 b1 f0 85 22 af ea 08 17 80 24 ee a6 61 19 34 ba 99 d9 94 9d 0e b6 d6 31 ff 6b 83 ac f9 a0 00 00 34 00 39 00 38 00 35 00 16 00 13 00 0a 00 33 00 32 00 2f 00 66 00 05 00 04 00 63 00 62 00 61 00 15 00 12 00 09 00 65 00 64 00 60 00 14 00 11 00 08 00 06 00 03 01 00
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=1038): [deleted]
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=3
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 2126
SSL: Need 1102 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=10): 01 00 00 06 02 03 00 06 15 00
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=1038): [deleted]
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=4
EAP: EAP entering state METHOD
SSL: Received packet(len=1034) - Flags 0xc0
SSL: TLS Message Length: 2126
SSL: Need 78 bytes more input data
SSL: Building ACK
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=10): 01 00 00 06 02 04 00 06 15 00
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=92): 01 00 00 58 01 05 00 58 15 80 00 00 08 4e 9e 69 96 15 00 d2 3a 5a a5 8a 72 56 25 f3 2e fe 2c 1c ac b1 88 a7 de a7 1d 18 94 5e ac 5a 1e 15 cc c6 3d 2d 98 96 87 4b 1e a6 4e 93 50 33 c5 c0 c0 ac 67 8b bc d3 fc 8d 8f 63 04 21 90 77 06 ec 1e 94 85 b6 a2 16 03 01 00 04 0e 00 00 00
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=5
EAP: EAP entering state METHOD
SSL: Received packet(len=88) - Flags 0x80
SSL: TLS Message Length: 2126
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server hello A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server certificate A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server key exchange A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server done A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client key exchange A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write change cipher spec A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write finished A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 flush data
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read finished A
SSL: SSL_connect - want more data
SSL: 134 bytes pending from ssl_out
SSL: 134 bytes left to be sent out (of total 134 bytes)
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=144): 01 00 00 8c 02 05 00 8c 15 00 16 03 01 00 46 10 00 00 42 00 40 82 45 b6 b2 83 6a 15 52 cb c1 d8 7c 57 05 4d da aa fd 65 d4 73 2c 86 fd d9 99 12 17 b2 a5 f1 de 68 80 81 6e df dd fc d2 3e 8e 2a fe 72 61 34 55 9d 92 85 3b 21 27 5e 72 e2 bc 2c 7c 21 61 e8 a1 14 03 01 00 01 01 16 03 01 00 30 be 1e 85 a3 09 4b 34 31 17 06 74 06 a8 18 0d 7d 91 08 75 66 9d 19 07 71 b0 2a 55 51 b3 fd 51 d9 41 08 54 c8 7d 7e b6 64 95 7d 28 89 97 18 02 7a
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=73): 01 00 00 45 01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01 16 03 01 00 30 4d 08 fa 7d 74 55 0c d1 da f0 32 ac f8 71 4e c6 1d a3 17 de de 23 fa 43 9d 09 aa 60 c9 e3 ff 59 c3 98 49 9c e5 54 0e 28 76 8e 25 a1 a7 96 7f 6e
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=6
EAP: EAP entering state METHOD
SSL: Received packet(len=69) - Flags 0x80
SSL: TLS Message Length: 59
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read finished A
SSL: (where=0x20 ret=0x1)
SSL: (where=0x1002 ret=0x1)
SSL: 0 bytes pending from ssl_out
SSL: No data to be sent out
EAP-TTLS: TLS done, proceed to Phase 2
EAP-TTLS: Derived key - hexdump(len=64): [REMOVED]
EAP-TTLS: received 0 bytes encrypted data for Phase 2
EAP-TTLS: empty data in beginning of Phase 2 - use fake EAP-Request Identity
EAP-TTLS: Phase 2 EAP Request: type=1
EAP: using real identity - hexdump_ascii(len=3):
     66 6f 6f                                          foo             
EAP-TTLS: AVP encapsulate EAP Response - hexdump(len=8): 02 06 00 08 01 66 6f 6f
EAP-TTLS: Encrypting Phase 2 data - hexdump(len=16): [REMOVED]
EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=100): 01 00 00 60 02 06 00 60 15 00 17 03 01 00 20 b5 05 8a a6 5e 78 16 9e e2 f6 fd 52 6e 86 d6 42 69 36 a7 3f 3b b1 80 12 13 6a 29 7f 91 8a b3 b0 17 03 01 00 30 b8 41 cc 87 65 b4 21 f6 ad b2 9e 1b d8 12 be f1 2f b0 60 ca ac 14 70 61 d6 93 4b 56 e0 de 32 40 4c b5 96 f4 92 08 ae 2b 34 42 63 6c d0 09 a8 f6
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=83): 01 00 00 4f 01 07 00 4f 15 80 00 00 00 45 17 03 01 00 40 ea 30 50 29 6d a3 63 42 7f 47 0c 98 01 af 14 f3 f4 44 cc 76 a1 20 7d 85 47 42 de f3 76 16 48 79 ab 95 2d d5 c0 c4 ff 5a 3f 42 1c 6c 04 92 f7 f2 13 b8 12 8b 9b e1 49 d7 c7 4b 9a e2 23 42 60 8b
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=21 id=7
EAP: EAP entering state METHOD
SSL: Received packet(len=79) - Flags 0x80
SSL: TLS Message Length: 69
EAP-TTLS: received 69 bytes encrypted data for Phase 2
EAP-TTLS: Decrypted Phase 2 AVPs - hexdump(len=32): 00 00 00 4f 40 00 00 1e 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80 00 00
EAP-TTLS: AVP: code=79 flags=0x40 length=30
EAP-TTLS: AVP data - hexdump(len=22): 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80
EAP-TTLS: AVP - EAP Message
EAP-TTLS: Phase 2 EAP - hexdump(len=22): 01 07 00 16 04 10 f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80
EAP-TTLS: received Phase 2: code=1 identifier=7 length=22
EAP-TTLS: Phase 2 EAP Request: type=4
EAP-TTLS: Selected Phase 2 EAP method 4
EAP-MD5: Challenge - hexdump(len=16): f0 7d 0e 84 ea da c9 80 d7 2b bd f0 76 2f 03 80
EAP-MD5: generating Challenge Response
EAP-MD5: Response - hexdump(len=16): 7a ba fd 26 e7 f0 62 3d c8 87 1d 1c bf 89 28 7e
EAP-TTLS: AVP encapsulate EAP Response - hexdump(len=22): 02 07 00 16 04 10 7a ba fd 26 e7 f0 62 3d c8 87 1d 1c bf 89 28 7e
EAP-TTLS: Encrypting Phase 2 data - hexdump(len=32): [REMOVED]
EAP-TTLS: Authentication completed successfully
EAP: method process -> ignore=FALSE methodState=DONE decision=UNCOND_SUCC
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
TX EAPOL - hexdump(len=116): 01 00 00 70 02 07 00 70 15 00 17 03 01 00 20 47 89 49 56 e6 61 64 d4 ef 83 a2 87 80 6a 8c 6d c7 6e 75 75 59 17 1f f4 6b 29 73 25 6b ba dd 9f 17 03 01 00 40 de a7 87 c8 51 85 32 1b 58 6a 2b 40 24 2c 33 52 16 f5 82 40 00 d6 27 5a ca 41 4e 1c d1 99 20 cf 72 28 98 04 5c b6 18 7b f4 e8 86 6c d3 7b d1 ff d8 6a 0e fd d5 ab ad bd 75 08 f8 a8 a7 08 59 54
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=46): 01 00 00 04 03 07 00 04 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
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Success
EAP: EAP entering state SUCCESS
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: SUPP_BE entering state SUCCESS
EAPOL: SUPP_BE entering state IDLE
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2a 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 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=2 type=3 length=117
  EAPOL-Key type=2
WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2a 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 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
State: ASSOCIATED -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
RSN: no matching PMKID found
WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED]
RSN: added PMKSA cache entry for 00:xx:xx:xx:xx:xx
RSN: no PMKSA entry found - trigger full EAP authentication
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 02 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2b 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 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=2 type=3 length=117
  EAPOL-Key type=2
WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 02 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2b 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 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00
RSN: PMKID from Authenticator - hexdump(len=16): 43 41 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00
RSN: no matching PMKID found
WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED]
WPA: reusing previous PMKSA entry
RSN: no PMKSA entry found - trigger full EAP authentication
RX EAPOL from 00:xx:xx:xx:xx:xx
RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 03 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2c 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 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=2 type=3 length=117
  EAPOL-Key type=2
WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 03 17 07 47 46 61 66 67 b9 96 02 eb b4 94 ce ed cc c7 33 13 1d 59 bb d6 6e 3b 59 08 ef e9 9c f5 2c 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 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
WPA: RX message 1 of 4-Way Handshake from 00:xx:xx:xx:xx:xx (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
RSN: no matching PMKID found
WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED]
WPA: reusing previous PMKSA entry
RSN: no PMKSA entry found - trigger full EAP authentication
Setting scan request: 0 sec 100000 usec
Added BSSID 00:xx:xx:xx:xx:xx into blacklist
State: 4WAY_HANDSHAKE -> DISCONNECTED
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portValid=0
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
wpa_driver_bsd_del_key: keyidx=0
wpa_driver_bsd_del_key: keyidx=1
wpa_driver_bsd_del_key: keyidx=2
wpa_driver_bsd_del_key: keyidx=3
wpa_driver_bsd_del_key: addr=00:00:00:00:00:00 keyidx=0
State: DISCONNECTED -> SCANNING

 =*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=*=

When I contacted Cisco support, they said the two following lines
which are from the above Cisco debug logs:

Feb 14 13:40:56.990: dot11_auth_server_chk_ssid: Checking for SSID in server attributes
Feb 14 13:40:56.990: dot11_auth_server_vlan_number: Checking for VLAN ID in server attributes

indicated to them that FreeRADIUS was sending dynamic VLAN attributes
to the access point.  I do not have any VLAN or other tunnelling
attributes set on the FreeRADIUS side.

Jouni suggested that these lines from the wpa_supplicant "-dd"
debug log above:

RSN: PMKID from Authenticator - hexdump(len=16): 42 4e 00 ff 53 4d 42 25 00 00 00 00 00 00 00 00
RSN: no matching PMKID found
WPA: PMK from EAPOL state machines - hexdump(len=32): [REMOVED]
RSN: added PMKSA cache entry for 00:xx:xx:xx:xx:xx
RSN: no PMKSA entry found - trigger full EAP authentication

indicated that the access point is not sending the correct keys.

I cannot understand whether my problems lie in the FreeRADIUS area
(my misconfiguration of which) or in the Cisco access point (my
misconfiguration of which).  I would be happy to include all or
parts of my Cisco running configuration if necessary, but this
email message is already too long.

Regards,

web...

--
William Bulley                     Email: web@umich.edu