Freeradius with OpenLDAP and AD.

LEOSI radius at pronetis.fr
Tue Feb 17 15:17:12 CET 2009


Hi, I have several problems when I would like to link freeradius with AD
using OpenLDAP.
When I tried to test the binding of OpenLDAP to the AD with radtest, it
responds Access-Accept (as you can see in the log after).
But when I wanted to check with a real supplicant (under WinXP with
MD5-Challenge Auth) I got an access-reject.

Things I changed :
-	modules/ldap :
ldap {
	server = "test.fr"
	identity = "cn=bindradius,cn=Users,dc=test,dc=fr"
	password = bindradius
	basedn = "cn=Users,dc=test,dc=fr"
	filter = "(samaccountname=%{User-Name})"
	..
}
password_attribute = userPassword

-	site-enabled/default & inner-tunnel :
authorize {
		..
		# uncommented :
		ldap
		..
}
authenticate {
		..
		# uncommented :
         	Auth-Type LDAP {
                 	ldap
         	}

Thanks for your help

---------------------------------------------------------------------------------
Radtest :
---------------------------------------------------------------------------------
root at freeradius:~# radtest philippe philippe localhost 0 testing123
Sending Access-Request of id 50 to 127.0.0.1 port 1812
	User-Name = "philippe"
	User-Password = "philippe"
	NAS-IP-Address = 192.168.1.3
	NAS-Port = 0
rad_recv: Access-Accept packet from host 127.0.0.1 port 1812, id=50,
length=20

---------------------------------------------------------------------------------
Freeradius log with radtest :
---------------------------------------------------------------------------------
rad_recv: Access-Request packet from host 127.0.0.1 port 47525, id=50,
length=60
	User-Name = "philippe"
	User-Password = "philippe"
	NAS-IP-Address = 192.168.1.3
	NAS-Port = 0
[..]
Tue Feb 17 15:38:25 2009 : Info: [ldap] performing user authorization for
philippe
Tue Feb 17 15:38:25 2009 : Info: [ldap] 	expand:
(samaccountname=%{User-Name}) -> (samaccountname=philippe)
Tue Feb 17 15:38:25 2009 : Info: [ldap] 	expand: cn=Users,dc=test,dc=fr ->
cn=Users,dc=test,dc=fr
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: attempting LDAP reconnection
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: (re)connect to test.fr:389,
authentication 0
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: bind as
cn=bindradius,cn=Users,dc=test,dc=fr/bindradius to test.fr:389
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: waiting for bind result ...
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: Bind was successful
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: performing search in
cn=Users,dc=test,dc=fr, with filter (samaccountname=philippe)
Tue Feb 17 15:38:25 2009 : Info: [ldap] looking for check items in
directory...
Tue Feb 17 15:38:25 2009 : Info: [ldap] looking for reply items in
directory...
Tue Feb 17 15:38:25 2009 : Debug: WARNING: No "known good" password was
found in LDAP.  Are you sure that the user is configured correctly?
Tue Feb 17 15:38:25 2009 : Info: [ldap] user philippe authorized to use
remote access
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Feb 17 15:38:25 2009 : Info: ++[ldap] returns ok
[..]
Tue Feb 17 15:38:25 2009 : Info: Found Auth-Type = LDAP
Tue Feb 17 15:38:25 2009 : Info: +- entering group LDAP {...}
Tue Feb 17 15:38:25 2009 : Info: [ldap] login attempt by "philippe" with
password "philippe"
Tue Feb 17 15:38:25 2009 : Info: [ldap] user DN:
CN=philippe,CN=Users,DC=test,DC=fr
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: (re)connect to test.fr:389,
authentication 1
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: bind as
CN=philippe,CN=Users,DC=test,DC=fr/philippe to test.fr:389
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: waiting for bind result ...
Tue Feb 17 15:38:25 2009 : Debug: rlm_ldap: Bind was successful
Tue Feb 17 15:38:25 2009 : Info: [ldap] user philippe authenticated
succesfully
[..]
Sending Access-Accept of id 50 to 127.0.0.1 port 47525

---------------------------------------------------------------------------------
With a real supplicant :
---------------------------------------------------------------------------------
Tue Feb 17 15:40:50 2009 : Debug: Ready to process requests.
rad_recv: Access-Request packet from host 192.168.1.1 port 1024, id=5,
length=202
	Framed-MTU = 1480
	NAS-IP-Address = 192.168.1.1
	NAS-Identifier = "SWiTCH"
	User-Name = "philippe"
	Service-Type = Framed-User
	Framed-Protocol = PPP
	NAS-Port = 21
	NAS-Port-Type = Ethernet
	NAS-Port-Id = "21"
	Called-Station-Id = "00-13-21-a8-24-40"
	Calling-Station-Id = "00-15-c5-06-84-d8"
	Connect-Info = "CONNECT Ethernet 100Mbps Full duplex"
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "4"
	EAP-Message = 0x0201000d017068696c69707065
	Message-Authenticator = 0x2e787b9c5fea331ecfc02e8c3b85c55c
Tue Feb 17 15:41:28 2009 : Info: +- entering group authorize {...}
Tue Feb 17 15:41:28 2009 : Info: ++[preprocess] returns ok
Tue Feb 17 15:41:28 2009 : Info: ++[chap] returns noop
Tue Feb 17 15:41:28 2009 : Info: ++[mschap] returns noop
Tue Feb 17 15:41:28 2009 : Info: [suffix] No '@' in User-Name = "philippe",
looking up realm NULL
Tue Feb 17 15:41:28 2009 : Info: [suffix] No such realm "NULL"
Tue Feb 17 15:41:28 2009 : Info: ++[suffix] returns noop
Tue Feb 17 15:41:28 2009 : Info: [eap] EAP packet type response id 1 length
13
Tue Feb 17 15:41:28 2009 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Tue Feb 17 15:41:28 2009 : Info: ++[eap] returns updated
Tue Feb 17 15:41:28 2009 : Info: ++[unix] returns notfound
Tue Feb 17 15:41:28 2009 : Info: [files] users: Matched entry DEFAULT at
line 1
Tue Feb 17 15:41:28 2009 : Info: ++[files] returns ok
Tue Feb 17 15:41:28 2009 : Info: [ldap] performing user authorization for
philippe
Tue Feb 17 15:41:28 2009 : Info: [ldap] 	expand:
(samaccountname=%{User-Name}) -> (samaccountname=philippe)
Tue Feb 17 15:41:28 2009 : Info: [ldap] 	expand: cn=Users,dc=test,dc=fr ->
cn=Users,dc=test,dc=fr
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: attempting LDAP reconnection
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: (re)connect to test.fr:389,
authentication 0
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: bind as
cn=bindradius,cn=Users,dc=test,dc=fr/bindradius to test.fr:389
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: waiting for bind result ...
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: Bind was successful
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: performing search in
cn=Users,dc=test,dc=fr, with filter (samaccountname=philippe)
Tue Feb 17 15:41:28 2009 : Info: [ldap] looking for check items in
directory...
Tue Feb 17 15:41:28 2009 : Info: [ldap] looking for reply items in
directory...
Tue Feb 17 15:41:28 2009 : Debug: WARNING: No "known good" password was
found in LDAP.  Are you sure that the user is configured correctly?
Tue Feb 17 15:41:28 2009 : Info: [ldap] user philippe authorized to use
remote access
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Feb 17 15:41:28 2009 : Info: ++[ldap] returns ok
Tue Feb 17 15:41:28 2009 : Info: ++[expiration] returns noop
Tue Feb 17 15:41:28 2009 : Info: ++[logintime] returns noop
Tue Feb 17 15:41:28 2009 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Tue Feb 17 15:41:28 2009 : Info: ++[pap] returns noop
Tue Feb 17 15:41:28 2009 : Info: Found Auth-Type = EAP
Tue Feb 17 15:41:28 2009 : Info: +- entering group authenticate {...}
Tue Feb 17 15:41:28 2009 : Info: [eap] EAP Identity
Tue Feb 17 15:41:28 2009 : Info: [eap] processing type md5
Tue Feb 17 15:41:28 2009 : Debug: rlm_eap_md5: Issuing Challenge
Tue Feb 17 15:41:28 2009 : Info: ++[eap] returns handled
Sending Access-Challenge of id 5 to 192.168.1.1 port 1024
	EAP-Message = 0x01020016041005f180280d72810cb4b1b9fa2033ede2
	Message-Authenticator = 0x00000000000000000000000000000000
	State = 0x89d76e5089d56a6c48de80e818248c16
Tue Feb 17 15:41:28 2009 : Info: Finished request 0.
Tue Feb 17 15:41:28 2009 : Debug: Going to the next request
Tue Feb 17 15:41:28 2009 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.1.1 port 1024, id=6,
length=237
	Framed-MTU = 1480
	NAS-IP-Address = 192.168.1.1
	NAS-Identifier = "SWiTCH"
	User-Name = "philippe"
	Service-Type = Framed-User
	Framed-Protocol = PPP
	NAS-Port = 21
	NAS-Port-Type = Ethernet
	NAS-Port-Id = "21"
	Called-Station-Id = "00-13-21-a8-24-40"
	Calling-Station-Id = "00-15-c5-06-84-d8"
	Connect-Info = "CONNECT Ethernet 100Mbps Full duplex"
	Tunnel-Type:0 = VLAN
	Tunnel-Medium-Type:0 = IEEE-802
	Tunnel-Private-Group-Id:0 = "4"
	State = 0x89d76e5089d56a6c48de80e818248c16
	EAP-Message =
0x0202001e041046b39f2ac453deec1f14d2b599506e377068696c69707065
	Message-Authenticator = 0x57f0fce82988e78eeb9bc719d015033d
Tue Feb 17 15:41:28 2009 : Info: +- entering group authorize {...}
Tue Feb 17 15:41:28 2009 : Info: ++[preprocess] returns ok
Tue Feb 17 15:41:28 2009 : Info: ++[chap] returns noop
Tue Feb 17 15:41:28 2009 : Info: ++[mschap] returns noop
Tue Feb 17 15:41:28 2009 : Info: [suffix] No '@' in User-Name = "philippe",
looking up realm NULL
Tue Feb 17 15:41:28 2009 : Info: [suffix] No such realm "NULL"
Tue Feb 17 15:41:28 2009 : Info: ++[suffix] returns noop
Tue Feb 17 15:41:28 2009 : Info: [eap] EAP packet type response id 2 length
30
Tue Feb 17 15:41:28 2009 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Tue Feb 17 15:41:28 2009 : Info: ++[eap] returns updated
Tue Feb 17 15:41:28 2009 : Info: ++[unix] returns notfound
Tue Feb 17 15:41:28 2009 : Info: [files] users: Matched entry DEFAULT at
line 1
Tue Feb 17 15:41:28 2009 : Info: ++[files] returns ok
Tue Feb 17 15:41:28 2009 : Info: [ldap] performing user authorization for
philippe
Tue Feb 17 15:41:28 2009 : Info: [ldap] 	expand:
(samaccountname=%{User-Name}) -> (samaccountname=philippe)
Tue Feb 17 15:41:28 2009 : Info: [ldap] 	expand: cn=Users,dc=test,dc=fr ->
cn=Users,dc=test,dc=fr
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: performing search in
cn=Users,dc=test,dc=fr, with filter (samaccountname=philippe)
Tue Feb 17 15:41:28 2009 : Info: [ldap] looking for check items in
directory...
Tue Feb 17 15:41:28 2009 : Info: [ldap] looking for reply items in
directory...
Tue Feb 17 15:41:28 2009 : Debug: WARNING: No "known good" password was
found in LDAP.  Are you sure that the user is configured correctly?
Tue Feb 17 15:41:28 2009 : Info: [ldap] user philippe authorized to use
remote access
Tue Feb 17 15:41:28 2009 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Feb 17 15:41:28 2009 : Info: ++[ldap] returns ok
Tue Feb 17 15:41:28 2009 : Info: ++[expiration] returns noop
Tue Feb 17 15:41:28 2009 : Info: ++[logintime] returns noop
Tue Feb 17 15:41:28 2009 : Info: [pap] WARNING! No "known good" password
found for the user.  Authentication may fail because of this.
Tue Feb 17 15:41:28 2009 : Info: ++[pap] returns noop
Tue Feb 17 15:41:28 2009 : Info: Found Auth-Type = EAP
Tue Feb 17 15:41:28 2009 : Info: +- entering group authenticate {...}
Tue Feb 17 15:41:28 2009 : Info: [eap] Request found, released from the list
Tue Feb 17 15:41:28 2009 : Info: [eap] EAP/md5
Tue Feb 17 15:41:28 2009 : Info: [eap] processing type md5
Tue Feb 17 15:41:28 2009 : Debug: rlm_eap_md5: Cleartext-Password is
required for EAP-MD5 authentication
Tue Feb 17 15:41:28 2009 : Info: [eap] Handler failed in EAP/md5
Tue Feb 17 15:41:28 2009 : Info: [eap] Failed in EAP select
Tue Feb 17 15:41:28 2009 : Info: ++[eap] returns invalid
Tue Feb 17 15:41:28 2009 : Info: Failed to authenticate the user.
Tue Feb 17 15:41:28 2009 : Info: Using Post-Auth-Type Reject
Tue Feb 17 15:41:28 2009 : Info: +- entering group REJECT {...}
Tue Feb 17 15:41:28 2009 : Info: [attr_filter.access_reject] 	expand:
%{User-Name} -> philippe
Tue Feb 17 15:41:28 2009 : Debug:  attr_filter: Matched entry DEFAULT at
line 11
Tue Feb 17 15:41:28 2009 : Info: ++[attr_filter.access_reject] returns
updated
Tue Feb 17 15:41:28 2009 : Info: Delaying reject of request 1 for 1 seconds
Tue Feb 17 15:41:28 2009 : Debug: Going to the next request
Tue Feb 17 15:41:28 2009 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Request packet from host 192.168.1.1 port 1024, id=6,
length=237
Tue Feb 17 15:41:29 2009 : Info: Waiting to send Access-Reject to client
192.168.1.1 port 1024 - ID: 6
Tue Feb 17 15:41:29 2009 : Info: Sending delayed reject for request 1
Sending Access-Reject of id 6 to 192.168.1.1 port 1024
	EAP-Message = 0x04020004
	Message-Authenticator = 0x00000000000000000000000000000000
Tue Feb 17 15:41:29 2009 : Debug: Waking up in 3.9 seconds.
Tue Feb 17 15:41:33 2009 : Info: Cleaning up request 0 ID 5 with timestamp
+38
Tue Feb 17 15:41:33 2009 : Debug: Waking up in 0.9 seconds.
Tue Feb 17 15:41:34 2009 : Info: Cleaning up request 1 ID 6 with timestamp
+38
Tue Feb 17 15:41:34 2009 : Debug: Ready to process requests.


-- 
View this message in context: http://www.nabble.com/Freeradius-with-OpenLDAP-and-AD.-tp22058186p22058186.html
Sent from the FreeRadius - User mailing list archive at Nabble.com.




More information about the Freeradius-Users mailing list