Cisco WLC PEAP/MSCHAPv2 - unnecessary ldap lookups?

Brian Wilson briw111 at yahoo.com
Thu Jun 18 10:11:17 CEST 2009


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.


      
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20090618/84574bb1/attachment.html>


More information about the Freeradius-Users mailing list