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.
Hi,
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:
what version of freeradius are you running and what are you using LDAP for? I now have a single lookup with my FR 2.x configuration because I am using the inner-tunnel method and only use it for authentication rather than authorization etc. in 2.x: basically, if you are using eg EAP then you dont really care about the outer stuff at all - so prune all the bits out and ensure that the inner-tunnel virtual server is called for EAP methods with immediate ok = return for the function (ensure EAP is above other methods if you still have them enabled!) this is pretty much the default config for current 2.1.x release(!) there are ways (nasty ways) of getting similar behaviour under 1.x but the flow isnt pretty and you have to be very careful with the exact order of everything alan
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.
It doesn't. It does it first two times while eap type is established and then for inner tunnel requests.
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:
You can change default eap type in eap.conf to peap (it's mschav2 now; leave mschapv2 in peap section) and loose the first exchange. Ivan Kalik Kalik Informatika ISP
Hi,
You can change default eap type in eap.conf to peap (it's mschav2 now; leave mschapv2 in peap section) and loose the first exchange.
...assuming you mean eap { default_eap_type = peap ... .. ttls { default_eap_type = mschapv2 ... .. } peap { default_eap_type = mschapv2 ... .. } ... ... } isnt having default_eap_type = mschapv2 in the very outer layer (for main EAP definition) just very wrong anyway? alan
participants (3)
-
A.L.M.Buxey@lboro.ac.uk -
Brian Wilson -
Ivan Kalik