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\3debellier\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\3debellier\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\3debellier\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\3debellier\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.
|
Operation & Integration Expert |
||
|
ITNO/ISO/ISIO/LSS |
||
|
|
|
|
|
Avenue Jean Mermoz 32 |
|
Tel: +32 (0)2 745 7997 |
