Cisco WLC PEAP/MSCHAPv2 - unnecessary ldap lookups?

Hi all, I have a functional question about freeradius and the ldap lookups. We currently run cisco wlc440x with WPA2-AES-PEAP-MSCHAPv2 against freeradius, and it is taking a while to authenticate - roughly 35 seconds. It seems most of this is being chewed up by our slow ldap lookups (about 4-6 seconds each, this is an ldap server issue), in combination with the number of ldap lookups freeradius does per session (5-6). Is it normal for the freeradius server to perform this many ldap lookups, or do I have a configuration error? It seems like it does ldap calls each time it receives an access-request from an access-challenge. I've played with the controller auth timeouts, it doesn't seem to make a difference. Here is the debug output from a single session: rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=5, length=196 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) Message-Authenticator = 0x8dd02304de9a3c5e3c732d1a622be134 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log](trimmed) [auth_log] expand: %t -> Wed Jun 17 10:00:10 2009 ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 2 length 27 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 178 ++[files] returns ok ++- entering redundant-load-balance group redundant-load-balance {...} [LDAPsvr2] performing user authorization for test [LDAPsvr2] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [LDAPsvr2] expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=test) [LDAPsvr2] expand: t=company -> t=company rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in t=company, with filter (cn=test) [LDAPsvr2] Added the eDirectory password password in check items as Cleartext-Password [LDAPsvr2] No default NMAS login sequence [LDAPsvr2] looking for check items in directory... [LDAPsvr2] looking for reply items in directory... [LDAPsvr2] user test authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 +++[LDAPsvr2] returns ok ++- redundant-load-balance group redundant-load-balance returns ok ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled Sending Access-Challenge of id 5 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cfeaa7186011d5bcc3cb2528f Finished request 67. Going to the next request Waking up in 9.9 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=6, length=193 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020300060319 State = 0xfea96b9cfeaa7186011d5bcc3cb2528f Message-Authenticator = 0x7efad720ed506e1d3324a14c5f001a4c +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 3 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 178 ++[files] returns ok ++- entering redundant-load-balance group redundant-load-balance {...} [LDAPsvr1] performing user authorization for test [LDAPsvr1] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [LDAPsvr1] expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=test) [LDAPsvr1] expand: t=company -> t=company rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in t=company, with filter (cn=test) [LDAPsvr1] Added the eDirectory password password in check items as Cleartext-Password [LDAPsvr1] No default NMAS login sequence [LDAPsvr1] looking for check items in directory... [LDAPsvr1] looking for reply items in directory... [LDAPsvr1] user test authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 +++[LDAPsvr1] returns ok ++- redundant-load-balance group redundant-load-balance returns ok ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP NAK [eap] EAP-NAK asked for EAP-Type/peap [eap] processing type tls [tls] Initiate [tls] Start returned 1 ++[eap] returns handled Sending Access-Challenge of id 6 to 192.168.21.130 port 32769 EAP-Message = 0x010400061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cffad7286011d5bcc3cb2528f Finished request 68. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=7, length=267 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) State = 0xfea96b9cffad7286011d5bcc3cb2528f Message-Authenticator = 0x4564af3d0b691c04f6aaab9311bcdff3 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 4 length 80 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 70 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 0041], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 0889], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 7 to 192.168.21.130 port 32769 EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cfcac7286011d5bcc3cb2528f Finished request 69. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=8, length=193 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020500061900 State = 0xfea96b9cfcac7286011d5bcc3cb2528f Message-Authenticator = 0xbebcefc1657154e59fa5a56953d3e83e +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 5 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 8 to 192.168.21.130 port 32769 EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = (trimmed) EAP-Message = 0x4f8b38b8c2084860 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cfdaf7286011d5bcc3cb2528f Finished request 70. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=9, length=193 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020600061900 State = 0xfea96b9cfdaf7286011d5bcc3cb2528f Message-Authenticator = 0x6c144e58a145ed24b615ed7080939873 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 6 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 9 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cfaae7286011d5bcc3cb2528f Finished request 71. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=10, length=509 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) EAP-Message = (trimmed) State = 0xfea96b9cfaae7286011d5bcc3cb2528f Message-Authenticator = 0x86b2b14c7b15cfcf3ed534de74b3e379 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 7 length 253 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS TLS Length 310 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange [peap] TLS_accept: SSLv3 read client key exchange A [peap] <<< TLS 1.0 ChangeCipherSpec [length 0001] [peap] <<< TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 read finished A [peap] >>> TLS 1.0 ChangeCipherSpec [length 0001] [peap] TLS_accept: SSLv3 write change cipher spec A [peap] >>> TLS 1.0 Handshake [length 0010], Finished [peap] TLS_accept: SSLv3 write finished A [peap] TLS_accept: SSLv3 flush data [peap] (other): SSL negotiation finished successfully SSL Connection Established [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 10 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cfba17286011d5bcc3cb2528f Finished request 72. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=11, length=193 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = 0x020800061900 State = 0xfea96b9cfba17286011d5bcc3cb2528f Message-Authenticator = 0xa23b09f3a29bebaba1465480b07feef9 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 8 length 6 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake is finished [peap] eaptls_verify returned 3 [peap] eaptls_process returned 3 [peap] EAPTLS_SUCCESS ++[eap] returns handled Sending Access-Challenge of id 11 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cf8a07286011d5bcc3cb2528f Finished request 73. Going to the next request Waking up in 5.2 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=12, length=237 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) State = 0xfea96b9cf8a07286011d5bcc3cb2528f Message-Authenticator = 0xcee77e000cf68223253caa68e05da122 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 9 length 50 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Identity - test [peap] Got tunneled request EAP-Message = (trimmed) server { PEAP: Got tunneled identity of test PEAP: Setting default EAP type for tunneled EAP session. PEAP: Setting User-Name to test Sending tunneled request EAP-Message = (trimmed) FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "test" server { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 9 length 27 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 178 ++[files] returns ok ++- entering redundant-load-balance group redundant-load-balance {...} [LDAPsvr2] performing user authorization for test [LDAPsvr2] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [LDAPsvr2] expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=test) [LDAPsvr2] expand: t=company -> t=company rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in t=company, with filter (cn=test) [LDAPsvr2] Added the eDirectory password password in check items as Cleartext-Password [LDAPsvr2] No default NMAS login sequence [LDAPsvr2] looking for check items in directory... [LDAPsvr2] looking for reply items in directory... [LDAPsvr2] user test authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 +++[LDAPsvr2] returns ok ++- redundant-load-balance group redundant-load-balance returns ok ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server [peap] Got tunneled reply code 11 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3203b3053209a96aacfd5d3ebe154b12 [peap] Got tunneled reply RADIUS code 11 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3203b3053209a96aacfd5d3ebe154b12 [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 12 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cf9a37286011d5bcc3cb2528f Finished request 74. Going to the next request Waking up in 0.4 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=13, length=291 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) State = 0xfea96b9cf9a37286011d5bcc3cb2528f Message-Authenticator = 0x45f0df4032fed071cefcab99032b1d3d +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 10 length 104 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = (trimmed) server { PEAP: Setting User-Name to test Sending tunneled request EAP-Message = (trimmed) FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "test" State = 0x3203b3053209a96aacfd5d3ebe154b12 server { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 10 length 81 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 178 ++[files] returns ok ++- entering redundant-load-balance group redundant-load-balance {...} [LDAPsvr1] performing user authorization for test [LDAPsvr1] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [LDAPsvr1] expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=test) [LDAPsvr1] expand: t=company -> t=company rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in t=company, with filter (cn=test) [LDAPsvr1] Added the eDirectory password password in check items as Cleartext-Password [LDAPsvr1] No default NMAS login sequence [LDAPsvr1] looking for check items in directory... [LDAPsvr1] looking for reply items in directory... [LDAPsvr1] user test authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 +++[LDAPsvr1] returns ok ++- redundant-load-balance group redundant-load-balance returns ok ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] +- entering group MS-CHAP {...} [mschap] Told to do MS-CHAPv2 for test with NT-Password [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server [peap] Got tunneled reply code 11 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3203b3053308a96aacfd5d3ebe154b12 [peap] Got tunneled reply RADIUS code 11 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3203b3053308a96aacfd5d3ebe154b12 [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 13 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cf6a27286011d5bcc3cb2528f Finished request 75. Going to the next request Cleaning up request 67 ID 5 with timestamp +1805 Waking up in 0.4 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=14, length=216 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) State = 0xfea96b9cf6a27286011d5bcc3cb2528f Message-Authenticator = 0xa49cac12cdb0cec38ff0d7e51bf95eb6 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 11 length 29 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x020b00061a03 server { PEAP: Setting User-Name to test Sending tunneled request EAP-Message = 0x020b00061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "test" State = 0x3203b3053308a96aacfd5d3ebe154b12 server { +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 11 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated [files] users: Matched entry DEFAULT at line 178 ++[files] returns ok ++- entering redundant-load-balance group redundant-load-balance {...} [LDAPsvr1] performing user authorization for test [LDAPsvr1] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [LDAPsvr1] expand: (cn=%{Stripped-User-Name:-%{User-Name}}) -> (cn=test) [LDAPsvr1] expand: t=company -> t=company rlm_ldap: ldap_get_conn: Checking Id: 0 rlm_ldap: ldap_get_conn: Got Id: 0 rlm_ldap: performing search in t=company, with filter (cn=test) [LDAPsvr1] Added the eDirectory password password in check items as Cleartext-Password [LDAPsvr1] No default NMAS login sequence [LDAPsvr1] looking for check items in directory... [LDAPsvr1] looking for reply items in directory... [LDAPsvr1] user test authorized to use remote access rlm_ldap: ldap_release_conn: Release Id: 0 +++[LDAPsvr1] returns ok ++- redundant-load-balance group redundant-load-balance returns ok ++[expiration] returns noop ++[logintime] returns noop Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [eap] Freeing handler ++[eap] returns ok +- entering group post-auth {...} [reply_log] expand: (trimmed) [reply_log] (trimmed) [reply_log] expand: %t User-Name = "%{User-Name}" -> Wed Jun 17 10:00:29 2009 User-Name = "test" ++[reply_log] returns ok } # server [peap] Got tunneled reply code 2 EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test" [peap] Got tunneled reply RADIUS code 2 EAP-Message = 0x030b0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test" [peap] Tunneled authentication was successful. [peap] SUCCESS ++[eap] returns handled Sending Access-Challenge of id 14 to 192.168.21.130 port 32769 EAP-Message = (trimmed) Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfea96b9cf7a57286011d5bcc3cb2528f Finished request 76. Going to the next request Cleaning up request 68 ID 6 with timestamp +1809 Cleaning up request 69 ID 7 with timestamp +1814 Cleaning up request 70 ID 8 with timestamp +1814 Cleaning up request 71 ID 9 with timestamp +1814 Cleaning up request 72 ID 10 with timestamp +1814 Cleaning up request 73 ID 11 with timestamp +1814 Waking up in 0.6 seconds. rad_recv: Access-Request packet from host 192.168.21.130 port 32769, id=15, length=225 User-Name = "test" Calling-Station-Id = "00-21-00-D9-10-DB" Called-Station-Id = "00-23-EA-7F-85-40:TFWAPR" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Service-Type = Framed-User Framed-MTU = 1300 NAS-Port-Type = Wireless-802.11 EAP-Message = (trimmed) State = 0xfea96b9cf7a57286011d5bcc3cb2528f Message-Authenticator = 0xa8b037f67e9531b8a502cca033121149 +- entering group authorize {...} [preprocess] expand: %{Called-Station-Id} -> 00-23-EA-7F-85-40:TFWAPR ++[preprocess] returns ok [auth_log] expand: (trimmed) [auth_log] (trimmed) [auth_log] expand: (trimmed) ++[auth_log] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [ntdomain] Looking up realm "company" for User-Name = "test" [ntdomain] Found realm "company" [ntdomain] Adding Stripped-User-Name = "test" [ntdomain] Adding Realm = "company" [ntdomain] Authentication realm is LOCAL. ++[ntdomain] returns ok [eap] EAP packet type response id 12 length 38 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/peap [eap] processing type peap [peap] processing EAP-TLS [peap] eaptls_verify returned 7 [peap] Done initial handshake [peap] eaptls_process returned 7 [peap] EAPTLS_OK [peap] Session established. Decoding tunneled attributes. [peap] Received EAP-TLV response. [peap] Success [eap] Freeing handler ++[eap] returns ok +- entering group post-auth {...} [reply_log] expand: (trimmed) [reply_log] (trimmed) [reply_log] expand: %t User-Name = "%{User-Name}" -> Wed Jun 17 10:00:33 2009 User-Name = "test" ++[reply_log] returns ok Sending Access-Accept of id 15 to 192.168.21.130 port 32769 MS-MPPE-Recv-Key = (trimmed) MS-MPPE-Send-Key = (trimmed) EAP-Message = 0x030c0004 Message-Authenticator = 0x00000000000000000000000000000000 User-Name = "test" Finished request 77. Going to the next request Waking up in 0.6 seconds. Cleaning up request 74 ID 12 with timestamp +1814 Waking up in 4.7 seconds. rad_recv: Accounting-Request packet from host 192.168.21.130 port 32769, id=165, length=154 User-Name = "test" NAS-Port = 1 NAS-IP-Address = 192.168.21.130 Framed-IP-Address = 192.168.21.65 NAS-Identifier = "AIR-WLC4404-DK-1" Airespace-Wlan-Id = 2 Acct-Session-Id = "4a38a2a4/00:21:00:d9:10:db/103" Acct-Authentic = RADIUS Acct-Status-Type = Start Calling-Station-Id = "192.168.21.65" Called-Station-Id = "192.168.21.130" +- entering group preacct {...} [preprocess] expand: %{Called-Station-Id} -> 192.168.21.130 ++[preprocess] returns ok [acct_unique] Hashing 'NAS-Port = 1,Client-IP-Address = 192.168.21.130,NAS-IP-Address = 192.168.21.130,Acct-Session-Id = "4a38a2a4/00:21:00:d9:10:db/103",User-Name = "test"' [acct_unique] Acct-Unique-Session-ID = "241f1d6c7aaf3e38". ++[acct_unique] returns ok [suffix] No '@' in User-Name = "test", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop ++[files] returns noop +- entering group accounting {...} [detail] expand: (trimmed) [detail] (trimmed) [detail] expand: (trimmed) ++[detail] returns ok ++[unix] returns ok [radutmp] expand: /usr/local/var/log/radius/radutmp -> /usr/local/var/log/radius/radutmp [radutmp] expand: %{User-Name} -> test ++[radutmp] returns ok [attr_filter.accounting_response] expand: %{User-Name} -> test attr_filter: Matched entry DEFAULT at line 12 ++[attr_filter.accounting_response] returns updated Sending Accounting-Response of id 165 to 192.168.21.130 port 32769 Finished request 78. Cleaning up request 78 ID 165 with timestamp +1831 Going to the next request Waking up in 2.3 seconds. Cleaning up request 75 ID 13 with timestamp +1819 Waking up in 4.5 seconds. Cleaning up request 76 ID 14 with timestamp +1824 Cleaning up request 77 ID 15 with timestamp +1828 Ready to process requests.