FreeRadius and LDAP from Nortel Switch
BELLIERE Eric
Eric.BELLIERE at mail.mobistar.be
Tue Sep 28 14:31:26 CEST 2010
Dears,
I would like to make a radius authentication while access to a Network
Elements (Nortel ERS 8600).
This authentication will be done via LDAP.
Everything seems to be ok except that when the request is sent from the
Network elements the password is not in clear text and then FreeRadius says
that password didn't matches.
When I try from RadPing (from my laptop) then my LDAP authentication is OK
Can you please help me?
>From RadPing
rad_recv: Access-Request packet from host 172.18.113.82 port 3340, id=1,
length=48
User-Name = "ebellier"
User-Password = "xxxxxxxxxx"
Tue Sep 28 14:25:30 2010 : Info: +- entering group authorize {...}
Tue Sep 28 14:25:30 2010 : Info: ++[preprocess] returns ok
Tue Sep 28 14:25:30 2010 : Info: [auth_log] expand:
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/radius/radacct/172.18.113.82/auth-detail-20100928
Tue Sep 28 14:25:30 2010 : Info: [auth_log]
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to
/var/log/radius/radacct/172.18.113.82/auth-detail-20100928
Tue Sep 28 14:25:30 2010 : Info: [auth_log] expand: %t -> Tue Sep 28
14:25:30 2010
Tue Sep 28 14:25:30 2010 : Info: ++[auth_log] returns ok
Tue Sep 28 14:25:30 2010 : Info: ++[chap] returns noop
Tue Sep 28 14:25:30 2010 : Info: ++[mschap] returns noop
Tue Sep 28 14:25:30 2010 : Info: [suffix] No '@' in User-Name = "ebellier",
looking up realm NULL
Tue Sep 28 14:25:30 2010 : Info: [suffix] Found realm "DEFAULT"
Tue Sep 28 14:25:30 2010 : Info: [suffix] Adding Stripped-User-Name =
"ebellier"
Tue Sep 28 14:25:30 2010 : Info: [suffix] Adding Realm = "DEFAULT"
Tue Sep 28 14:25:30 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Sep 28 14:25:30 2010 : Info: ++[suffix] returns ok
Tue Sep 28 14:25:30 2010 : Info: [eap] No EAP-Message, not doing EAP
Tue Sep 28 14:25:30 2010 : Info: ++[eap] returns noop
Tue Sep 28 14:25:30 2010 : Info: ++[unix] returns updated
Tue Sep 28 14:25:30 2010 : Debug: [ldap] Entering ldap_groupcmp()
Tue Sep 28 14:25:30 2010 : Info: [files] expand:
ou=Staff,o=mobistar.be -> ou=Staff,o=mobistar.be
Tue Sep 28 14:25:30 2010 : Info: [files] expand:
%{Stripped-User-Name} -> ebellier
Tue Sep 28 14:25:30 2010 : Info: [files] expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ebellier)
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter (uid=ebellier)
request done: ld 0x1fb4500 msgid 8
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:25:30 2010 : Info: [files] expand:
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass
=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=uid\3debellier\2cou\3dStaff\2c
o\3dmobistar.be))(&(objectClass=GroupOfUniqueNames)(uniquemember=uid\3debell
ier\2cou\3dStaff\2c o\3dmobistar.be)))
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter
(&(cn=GF_FW_networkManagementProdAdmin)(|(&(objectClass=GroupOfNames)(member
=uid\3debellier\2cou\3dStaff\2c
o\3dmobistar.be))(&(objectClass=GroupOfUniqueNames)(uniquemember=uid\3debell
ier\2cou\3dStaff\2c o\3dmobistar.be))))
request done: ld 0x1fb4500 msgid 9
Tue Sep 28 14:25:30 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in
group GF_FW_networkManagementProdAdmin
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:25:30 2010 : Info: ++[files] returns noop
Tue Sep 28 14:25:30 2010 : Info: [ldap] performing user authorization for
ebellier
Tue Sep 28 14:25:30 2010 : Info: [ldap] expand:
%{Stripped-User-Name} -> ebellier
Tue Sep 28 14:25:30 2010 : Info: [ldap] expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ebellier)
Tue Sep 28 14:25:30 2010 : Info: [ldap] expand:
ou=Staff,o=mobistar.be -> ou=Staff,o=mobistar.be
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:25:30 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter (uid=ebellier)
request done: ld 0x1fb4500 msgid 10
Tue Sep 28 14:25:30 2010 : Info: [ldap] looking for check items in
directory...
Tue Sep 28 14:25:30 2010 : Info: [ldap] looking for reply items in
directory...
Tue Sep 28 14:25:30 2010 : Debug: WARNING: No "known good" password was
found in LDAP. Are you sure that the user is configured correctly?
Tue Sep 28 14:25:30 2010 : Info: [ldap] Setting Auth-Type = LDAP
Tue Sep 28 14:25:30 2010 : Info: [ldap] user ebellier authorized to use
remote access
Tue Sep 28 14:25:30 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:25:30 2010 : Info: ++[ldap] returns ok
Tue Sep 28 14:25:30 2010 : Info: ++[expiration] returns noop
Tue Sep 28 14:25:30 2010 : Info: ++[logintime] returns noop
Tue Sep 28 14:25:30 2010 : Info: [pap] Found existing Auth-Type, not
changing it.
Tue Sep 28 14:25:30 2010 : Info: ++[pap] returns noop
Tue Sep 28 14:25:30 2010 : Info: Found Auth-Type = LDAP
Tue Sep 28 14:25:30 2010 : Info: +- entering group LDAP {...}
Tue Sep 28 14:25:30 2010 : Info: [ldap] login attempt by "ebellier" with
password "xxxxxxx"
Tue Sep 28 14:25:30 2010 : Info: [ldap] user DN: uid=ebellier,ou=Staff,
o=mobistar.be
Tue Sep 28 14:25:30 2010 : Debug: [ldap] (re)connect to
192.168.154.50:389, authentication 1
Tue Sep 28 14:25:30 2010 : Debug: [ldap] bind as uid=ebellier,ou=Staff,
o=mobistar.be/Mamour20 to 192.168.154.50:389
Tue Sep 28 14:25:30 2010 : Debug: [ldap] waiting for bind result ...
request done: ld 0x1fbcdb0 msgid 1
Tue Sep 28 14:25:30 2010 : Debug: [ldap] Bind was successful
Tue Sep 28 14:25:30 2010 : Info: [ldap] user ebellier authenticated
succesfully
Tue Sep 28 14:25:30 2010 : Info: ++[ldap] returns ok
Tue Sep 28 14:25:30 2010 : Auth: Login OK: [ebellier/Mamour20] (from client
172.18.113.82/32 port 0)
Tue Sep 28 14:25:30 2010 : Info: +- entering group post-auth {...}
Tue Sep 28 14:25:30 2010 : Info: [reply_log] expand:
/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d ->
/var/log/radius/radacct/172.18.113.82/reply-detail-20100928
Tue Sep 28 14:25:30 2010 : Info: [reply_log]
/var/log/radius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to
/var/log/radius/radacct/172.18.113.82/reply-detail-20100928
Tue Sep 28 14:25:30 2010 : Info: [reply_log] expand: %t -> Tue Sep 28
14:25:30 2010
Tue Sep 28 14:25:30 2010 : Info: ++[reply_log] returns ok
Tue Sep 28 14:25:30 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 1 to 172.18.113.82 port 3340
Tue Sep 28 14:25:30 2010 : Info: Finished request 3.
Tue Sep 28 14:25:30 2010 : Debug: Going to the next request
Tue Sep 28 14:25:30 2010 : Debug: Waking up in 4.9 seconds.
Tue Sep 28 14:25:35 2010 : Info: Cleaning up request 3 ID 1 with timestamp
+176
Tue Sep 28 14:25:35 2010 : Info: Ready to process requests.
>From Nortel ERS :
rad_recv: Access-Request packet from host 192.168.250.64 port 4439, id=186,
length=60
User-Name = "ebellier"
User-Password = "%\357\350\t\310}\341Ú¡9\327F\336F\034\364"
NAS-IP-Address = 192.168.250.64
NAS-Port = 1
Tue Sep 28 14:22:40 2010 : Info: +- entering group authorize {...}
Tue Sep 28 14:22:40 2010 : Info: ++[preprocess] returns ok
Tue Sep 28 14:22:40 2010 : Info: [auth_log] expand:
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/radius/radacct/192.168.250.64/auth-detail-20100928
Tue Sep 28 14:22:40 2010 : Info: [auth_log]
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to
/var/log/radius/radacct/192.168.250.64/auth-detail-20100928
Tue Sep 28 14:22:40 2010 : Info: [auth_log] expand: %t -> Tue Sep 28
14:22:40 2010
Tue Sep 28 14:22:40 2010 : Info: ++[auth_log] returns ok
Tue Sep 28 14:22:40 2010 : Info: ++[chap] returns noop
Tue Sep 28 14:22:40 2010 : Info: ++[mschap] returns noop
Tue Sep 28 14:22:40 2010 : Info: [suffix] No '@' in User-Name = "ebellier",
looking up realm NULL
Tue Sep 28 14:22:40 2010 : Info: [suffix] Found realm "DEFAULT"
Tue Sep 28 14:22:40 2010 : Info: [suffix] Adding Stripped-User-Name =
"ebellier"
Tue Sep 28 14:22:40 2010 : Info: [suffix] Adding Realm = "DEFAULT"
Tue Sep 28 14:22:40 2010 : Info: [suffix] Authentication realm is LOCAL.
Tue Sep 28 14:22:40 2010 : Info: ++[suffix] returns ok
Tue Sep 28 14:22:40 2010 : Info: [eap] No EAP-Message, not doing EAP
Tue Sep 28 14:22:40 2010 : Info: ++[eap] returns noop
Tue Sep 28 14:22:40 2010 : Info: ++[unix] returns updated
Tue Sep 28 14:22:40 2010 : Debug: [ldap] Entering ldap_groupcmp()
Tue Sep 28 14:22:40 2010 : Info: [files] expand:
ou=Staff,o=mobistar.be -> ou=Staff,o=mobistar.be
Tue Sep 28 14:22:40 2010 : Info: [files] expand:
%{Stripped-User-Name} -> ebellier
Tue Sep 28 14:22:40 2010 : Info: [files] expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ebellier)
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] attempting LDAP reconnection
Tue Sep 28 14:22:40 2010 : Debug: [ldap] (re)connect to
192.168.154.50:389, authentication 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] bind as / to 192.168.154.50:389
Tue Sep 28 14:22:40 2010 : Debug: [ldap] waiting for bind result ...
request done: ld 0x1fb4500 msgid 1
Tue Sep 28 14:22:40 2010 : Debug: [ldap] Bind was successful
Tue Sep 28 14:22:40 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter (uid=ebellier)
request done: ld 0x1fb4500 msgid 2
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:22:40 2010 : Info: [files] expand:
(|(&(objectClass=GroupOfNames)(member=%{control:Ldap-UserDn}))(&(objectClass
=GroupOfUniqueNames)(uniquemember=%{control:Ldap-UserDn}))) ->
(|(&(objectClass=GroupOfNames)(member=uid\3debellier\2cou\3dStaff\2c
o\3dmobistar.be))(&(objectClass=GroupOfUniqueNames)(uniquemember=uid\3debell
ier\2cou\3dStaff\2c o\3dmobistar.be)))
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter
(&(cn=GF_FW_networkManagementProdAdmin)(|(&(objectClass=GroupOfNames)(member
=uid\3debellier\2cou\3dStaff\2c
o\3dmobistar.be))(&(objectClass=GroupOfUniqueNames)(uniquemember=uid\3debell
ier\2cou\3dStaff\2c o\3dmobistar.be))))
request done: ld 0x1fb4500 msgid 3
Tue Sep 28 14:22:40 2010 : Debug: rlm_ldap::ldap_groupcmp: User found in
group GF_FW_networkManagementProdAdmin
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:22:40 2010 : Info: ++[files] returns noop
Tue Sep 28 14:22:40 2010 : Info: [ldap] performing user authorization for
ebellier
Tue Sep 28 14:22:40 2010 : Info: [ldap] expand:
%{Stripped-User-Name} -> ebellier
Tue Sep 28 14:22:40 2010 : Info: [ldap] expand:
(uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=ebellier)
Tue Sep 28 14:22:40 2010 : Info: [ldap] expand:
ou=Staff,o=mobistar.be -> ou=Staff,o=mobistar.be
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_get_conn: Got Id: 0
Tue Sep 28 14:22:40 2010 : Debug: [ldap] performing search in
ou=Staff,o=mobistar.be, with filter (uid=ebellier)
request done: ld 0x1fb4500 msgid 4
Tue Sep 28 14:22:40 2010 : Info: [ldap] looking for check items in
directory...
Tue Sep 28 14:22:40 2010 : Info: [ldap] looking for reply items in
directory...
Tue Sep 28 14:22:40 2010 : Debug: WARNING: No "known good" password was
found in LDAP. Are you sure that the user is configured correctly?
Tue Sep 28 14:22:40 2010 : Info: [ldap] Setting Auth-Type = LDAP
Tue Sep 28 14:22:40 2010 : Info: [ldap] user ebellier authorized to use
remote access
Tue Sep 28 14:22:40 2010 : Debug: [ldap] ldap_release_conn: Release Id: 0
Tue Sep 28 14:22:40 2010 : Info: ++[ldap] returns ok
Tue Sep 28 14:22:40 2010 : Info: ++[expiration] returns noop
Tue Sep 28 14:22:40 2010 : Info: ++[logintime] returns noop
Tue Sep 28 14:22:40 2010 : Info: [pap] Found existing Auth-Type, not
changing it.
Tue Sep 28 14:22:40 2010 : Info: ++[pap] returns noop
Tue Sep 28 14:22:40 2010 : Info: Found Auth-Type = LDAP
Tue Sep 28 14:22:40 2010 : Info: +- entering group LDAP {...}
Tue Sep 28 14:22:40 2010 : Info: [ldap] login attempt by "ebellier" with
password "%ïè È}áÚ¡9×FÞF?ô"
Tue Sep 28 14:22:40 2010 : Info: [ldap] user DN: uid=ebellier,ou=Staff,
o=mobistar.be
Tue Sep 28 14:22:40 2010 : Debug: [ldap] (re)connect to
192.168.154.50:389, authentication 1
Tue Sep 28 14:22:40 2010 : Debug: [ldap] bind as uid=ebellier,ou=Staff,
o=mobistar.be/%ïè È}áÚ¡9×FÞF?ô to 192.168.154.50:389
Tue Sep 28 14:22:40 2010 : Debug: [ldap] waiting for bind result ...
request done: ld 0x1fbcd90 msgid 1
Tue Sep 28 14:22:40 2010 : Debug: [ldap] Bind failed with invalid
credentials
Tue Sep 28 14:22:40 2010 : Info: ++[ldap] returns reject
Tue Sep 28 14:22:40 2010 : Info: Failed to authenticate the user.
Tue Sep 28 14:22:40 2010 : Auth: Login incorrect ( [ldap] Bind as user
failed): [ebellier/%\357\350\t\310}\341Ú¡9\327F\336F\034\364] (from client
192.168.250.64 port 1)
Tue Sep 28 14:22:40 2010 : Debug: WARNING: Unprintable characters in the
password. Double-check the shared secret on the server and the NAS!
Tue Sep 28 14:22:40 2010 : Info: Using Post-Auth-Type Reject
Tue Sep 28 14:22:40 2010 : Info: +- entering group REJECT {...}
Tue Sep 28 14:22:40 2010 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> ebellier
Tue Sep 28 14:22:40 2010 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Tue Sep 28 14:22:40 2010 : Info: ++[attr_filter.access_reject] returns
updated
Tue Sep 28 14:22:40 2010 : Info: Delaying reject of request 0 for 1 seconds
Tue Sep 28 14:22:40 2010 : Debug: Going to the next request
Tue Sep 28 14:22:40 2010 : Debug: Waking up in 0.9 seconds.
Tue Sep 28 14:22:41 2010 : Info: Sending delayed reject for request 0
Sending Access-Reject of id 186 to 192.168.250.64 port 4439
Tue Sep 28 14:22:41 2010 : Debug: Waking up in 4.9 seconds.
Tue Sep 28 14:22:46 2010 : Info: Cleaning up request 0 ID 186 with timestamp
+6
Tue Sep 28 14:22:46 2010 : Info: Ready to process requests.
<http://k-village/team_members/who_s_who/kpeople01.asp?login=ebellier> Eric
Bellière
Operation & Integration Expert
ITNO/ISO/ISIO/LSS
Mobistar NV/SA
Avenue Jean Mermoz 32
6041 Gosselies
cid:image003.jpg at 01C961E5.77656AB0
Tel: +32 (0)2 745 7997
GSM: +32(0)495 55 1343
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100928/703e663a/attachment.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image001.jpg
Type: image/jpeg
Size: 7981 bytes
Desc: not available
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100928/703e663a/attachment.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: image002.jpg
Type: image/jpeg
Size: 2879 bytes
Desc: not available
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100928/703e663a/attachment-0001.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/x-pkcs7-signature
Size: 7296 bytes
Desc: not available
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20100928/703e663a/attachment.bin>
More information about the Freeradius-Users
mailing list