Question about EAP-TTLS and LDAP

Hans Fiedler hans at hermes.louisville.edu
Sat Nov 5 01:21:20 CET 2005 

We're using EAP-TTLS and checking against LDAP for password validation on
our wireless access points (Cisco).  It looks like the radius server is
sending two requests to the LDAP server for every login.  The first is for
anonymous, which I think is for the EAP-TTLS tunnel, which doesn't match
any username in LDAP.  The second one is for the actual username and
matches a LDAP username and authenticates OK.  Our users are getting logged
in OK, but the people managing the LDAP servers are complaining about the
anonymous attempts.  I've been trying to get the radius server to deal with
the anonymous attempts itself, but havn't been able to.  I'm hoping someone
here can give me some ideas.

I'll attach info from the config files and logs.  We have some local
authentication for MAC addresses, everything else goes to LDAP.

users --------------------------------------------------------------------
# We have some MAC based authentication that occurs locally, not sent to
# Make MAC based authentication skip LDAP

DEFAULT User-Name =~ "[0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f]"
	Auth-Type := Reject,
	Fall-Through  =  Yes

# MAC authentication

004096411ddd    User-Password == "004096411ddd"
                Auth-Type := Accept
radiusd.conf -------------------------------------------------------------
	ldap {
		server = "ldaptest.louisville.edu"
		identity = "cn=ldaptest,ou=common,o=ul"
		password = xxxxx
		basedn = "ou=people,o=ul"
		filter = "(&(cn=%{Stripped-User-Name:-%{User-Name}})(uoflWireStatus=ACTV))"
		start_tls = no
		dictionary_mapping = ${raddbdir}/ldap.attrmap
		ldap_connections_number = 5
		timeout = 4
		timelimit = 3
		net_timeout = 1
	}
radius log file ----------------------------------------------------------
Nov  4 18:12:15 hermes radiusd[10287]:   Processing the authorize section of radiusd.conf
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group authorize for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group redundant for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling files (rlm_files) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from files (rlm_files) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "files" returns notfound for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group redundant returns notfound for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: EAP packet type response id 8 length 71
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "eap" returns updated for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: - authorize
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: performing user authorization for anonymous
Nov  4 18:12:15 hermes radiusd[10287]: radius_xlat:  '(&(cn=anonymous)(uoflWireStatus=ACTV))'
Nov  4 18:12:15 hermes radiusd[10287]: radius_xlat:  'ou=people,o=ul'
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_get_conn: Checking Id: 0
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_get_conn: Got Id: 0
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: performing search in ou=people,o=ul, with filter (&(cn=anonymous)(uoflWireStatus=ACTV))
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: object not found or got ambiguous search result
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: search failed
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_release_conn: Release Id: 0
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "ldap" returns notfound for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group authorize returns updated for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   rad_check_password:  Found Auth-Type EAP
Nov  4 18:12:15 hermes radiusd[10287]: auth: type "EAP"
Nov  4 18:12:15 hermes radiusd[10287]:   Processing the authenticate section of radiusd.conf
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group authenticate for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authenticate]: calling eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: Request found, released from the list
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: EAP/ttls
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: processing type ttls
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap_ttls: Authenticate
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap_tls: processing TLS
Nov  4 18:12:15 hermes radiusd[10287]: rlm_eap_tls:  Length Included
Nov  4 18:12:15 hermes radiusd[10287]:   eaptls_verify returned 11 
Nov  4 18:12:15 hermes radiusd[10287]:   eaptls_process returned 7 
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap_ttls: Session established.  Proceeding to decode tunneled attributes.
Nov  4 18:12:15 hermes radiusd[10287]:   Processing the authorize section of radiusd.conf
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group authorize for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group redundant for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling files (rlm_files) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from files (rlm_files) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "files" returns notfound for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group redundant returns notfound for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: No EAP-Message, not doing EAP
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "eap" returns noop for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: calling ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: - authorize
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: performing user authorization for testuser
Nov  4 18:12:15 hermes radiusd[10287]: radius_xlat:  '(&(cn=testuser)(uoflWireStatus=ACTV))'
Nov  4 18:12:15 hermes radiusd[10287]: radius_xlat:  'ou=people,o=ul'
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_get_conn: Checking Id: 0
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_get_conn: Got Id: 0
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: performing search in ou=people,o=ul, with filter (&(cn=testuser)(uoflWireStatus=ACTV))
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: looking for check items in directory...
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: Adding uoflWireStatus as uoflWireStatus, value ACTV & op=21
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: looking for reply items in directory...
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: user testuser authorized to use remote access
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: ldap_release_conn: Release Id: 0
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authorize]: returned from ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authorize]: module "ldap" returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group authorize returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   rad_check_password:  Found Auth-Type LDAP
Nov  4 18:12:15 hermes radiusd[10287]: auth: type "LDAP"
Nov  4 18:12:15 hermes radiusd[10287]:   Processing the authenticate section of radiusd.conf
Nov  4 18:12:15 hermes radiusd[10287]: modcall: entering group Auth-Type for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authenticate]: calling ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: - authenticate
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: login attempt by "testuser" with password "xxxxx"
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: user DN: cn=testuser,ou=people,o=ul
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: (re)connect to ldap.louisville.edu:389, authentication 1
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: bind as cn=testuser,ou=people,o=ul/xxxxx to ldap.louisville.edu:389
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: waiting for bind result ...
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: Bind was successful
Nov  4 18:12:15 hermes radiusd[10287]: rlm_ldap: user testuser authenticated succesfully
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authenticate]: returned from ldap (rlm_ldap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authenticate]: module "ldap" returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group Auth-Type returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]: Login OK: [testuser] (from client localhost port 0)
Nov  4 18:12:15 hermes radiusd[10287]:   TTLS: Got tunneled Access-Accept
Nov  4 18:12:15 hermes radiusd[10287]:   rlm_eap: Freeing handler
Nov  4 18:12:15 hermes radiusd[10287]:   modsingle[authenticate]: returned from eap (rlm_eap) for request 165
Nov  4 18:12:15 hermes radiusd[10287]:   modcall[authenticate]: module "eap" returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]: modcall: group authenticate returns ok for request 165
Nov  4 18:12:15 hermes radiusd[10287]: Login OK: [anonymous] (from client air-02b-1.mitc port 38605 cli 0005.4e44.6b64)
Nov  4 18:12:15 hermes radiusd[10287]: Finished request 165
radius debug output ------------------------------------------------------
rad_recv: Access-Request packet from host 10.255.200.1:1645, id=160, length=218
        User-Name = "anonymous"
        Framed-MTU = 1400
        Called-Station-Id = "000f.3446.7d80"
        Calling-Station-Id = "0005.4e44.6b64"
        Service-Type = Login-User
        Message-Authenticator = 0xd230db4f9d60f9468b8000adb4e7b62c
        EAP-Message = 0x0208004715800000003d1703010038d1fc558225df702e06ea38da314f362be1b0f41437f7cbac8b51a6995662e82fd1952d96d34e1abd7375b6e26f9bb475e225edf18d1c9f8a
        NAS-Port-Type = Wireless-802.11
        NAS-Port = 38605
        State = 0x953d8bee5235a79f4b6ec98f699d8a58
        NAS-IP-Address = 10.255.200.1
        NAS-Identifier = "AIR-02B-1.MITC"
  TTLS tunnel data in 0000: 00 00 00 01 40 00 00 10 68 6b 66 69 65 64 30 31 
  TTLS tunnel data in 0010: 00 00 00 02 40 00 00 10 4d 65 72 6c 69 6e 30 33 
  TTLS: Got tunneled request
        User-Name = "testuser"
        User-Password = "xxxxx"
        FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Sending tunneled request
        User-Name = "testuser"
        User-Password = "xxxxx"
        FreeRADIUS-Proxied-To = 127.0.0.1
  TTLS: Got tunneled reply RADIUS code 2
Sending Access-Accept of id 160 to 10.255.200.1:1645
        MS-MPPE-Recv-Key = 0xa658138cf63b9875896ed04b0b1113b630d0be68c9f0c4689da969d89ee15402
        MS-MPPE-Send-Key = 0xd3303f466f0e7b69f931b89e53e62cd6a370da24ab2fbb220f5d725adf9776c0
        EAP-Message = 0x03080004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "anonymous"

-- 
Hans K. Fiedler                         Information Technology
Network Analyst                         Communications Services
hans at hermes.louisville.edu              University of Louisville
502-852-7427                            Louisville, Ky. 40292

More information about the Freeradius-Users mailing list