We are running FreeRADIUS v. 1.0.2
2x load-balanced LDAP servers - Sun
ONE DS 5.2 on W2k3 Ent. with network load balancing. One of the LDAPs
is the primary and is handling the auth traffic.
Here is the issue we're seeing:
Approximately 10-20 times per day users
are unable to authenticate - despite using correct credentials. The
radius server reports bind failed because it "Can't contact LDAP server"
The LDAP logs show the bind, search, and reply for the "does
this user exist" request. Sometimes this search is repeated
a couple of times. However, there is no follow-up bind as this user
for checking the creds. If the user tries again in 30secs or more,
they succeed - with the same creds as before.
Any ideas? Thanks for any help!
Below are excerpts from the logs:
------------------------ Radius
log entry ------------------------
rlm_ldap: - authorize
rlm_ldap: performing user authorization
for someuser
radius_xlat: '(uid=someuser)'
radius_xlat: 'ou=people,dc=uttyler,dc=edu'
rlm_ldap: ldap_get_conn: Checking
Id: 0
rlm_ldap: ldap_get_conn: Got Id:
0
rlm_ldap: performing search in
ou=people,dc=uttyler,dc=edu, with filter (uid=someuser)
rlm_ldap: ldap_search() failed:
LDAP connection lost.
rlm_ldap: Attempting reconnect
rlm_ldap: attempting LDAP reconnection
rlm_ldap: closing existing LDAP
connection
rlm_ldap: (re)connect to ldap.uttyler.edu:389,
authentication 0
rlm_ldap: bind as uid=radiususer,ou=special
users,dc=uttyler,dc=edu/radius_password to ldap.uttyler.edu:389
rlm_ldap: waiting for bind result
...
rlm_ldap: Bind was successful
rlm_ldap: performing search in
ou=people,dc=uttyler,dc=edu, with filter (uid=someuser)
rlm_ldap: looking for check items
in directory...
rlm_ldap: looking for reply items
in directory...
rlm_ldap: user someuser authorized
to use remote access
rlm_ldap: ldap_release_conn: Release
Id: 0
modcall[authorize]: module
"ldap" returns ok for request 987
modcall: group authorize returns
ok for request 987
rad_check_password: Found
Auth-Type LDAP
auth: type "LDAP"
Processing the authenticate
section of radiusd.conf
modcall: entering group Auth-Type
for request 987
rlm_ldap: - authenticate
rlm_ldap: login attempt by "someuser"
with password "04191987"
rlm_ldap: user DN: uid=someuser,ou=People,dc=uttyler,dc=edu
rlm_ldap: (re)connect to ldap.uttyler.edu:389,
authentication 1
rlm_ldap: bind as uid=someuser,ou=People,dc=uttyler,dc=edu/04191987
to ldap.uttyler.edu:389
rlm_ldap: uid=someuser,ou=People,dc=uttyler,dc=edu
bind to ldap.uttyler.edu:389 failed: Can't contact LDAP server
rlm_ldap: ldap_connect() failed
modcall[authenticate]: module
"ldap" returns fail for request 987
modcall: group Auth-Type returns
fail for request 987
auth: Failed to validate the user.
Login incorrect: [someuser/04191987]
(from client AireSpace port 0 cli 10.3.1.72)
Delaying request 987 for 1 seconds
Finished request 987
Going to the next request
-------------------- LDAP Log
------------------------------
[23/Jan/2006:07:47:13 -0600] conn=886
op=1 msgId=2 - SRCH base="ou=people,dc=uttyler,dc=edu" scope=2
filter="(uid=someuser)" attrs="radiusexpiration acctflags
ntpassword lmpassword radiuscallingstationid radiuscalledstationid radiussimultaneoususe
radiusauthtype radiuscheckitem radiusloginlatport radiusportlimit radiusframedappletalkzone
radiusframedappletalknetwork radiusframedappletalklink radiusloginlatgroup
radiusloginlatnode radiusloginlatservice radiusterminationaction radiusidletimeout
radiussessiontimeout radiusclass radiusframedipxnetwork radiuscallbackid
radiuscallbacknumber radiuslogintcpport radiusloginservice radiusloginiphost
radiusframedcompression radiusframedmtu radiusfilterid radiusframedrouting
radiusframedroute radiusframedipnetmask radiusframedipaddress radiusframedprotocol
radiusservicetype radiusreplyitem"
[23/Jan/2006:07:47:13 -0600] conn=886
op=1 msgId=2 - RESULT err=0 tag=101 nentries=1 etime=0
[23/Jan/2006:07:47:24 -0600] conn=886
op=2 msgId=3 - SRCH base="ou=people,dc=uttyler,dc=edu" scope=2
filter="(uid=someuser)" attrs="radiusexpiration acctflags
ntpassword lmpassword radiuscallingstationid radiuscalledstationid radiussimultaneoususe
radiusauthtype radiuscheckitem radiusloginlatport radiusportlimit radiusframedappletalkzone
radiusframedappletalknetwork radiusframedappletalklink radiusloginlatgroup
radiusloginlatnode radiusloginlatservice radiusterminationaction radiusidletimeout
radiussessiontimeout radiusclass radiusframedipxnetwork radiuscallbackid
radiuscallbacknumber radiuslogintcpport radiusloginservice radiusloginiphost
radiusframedcompression radiusframedmtu radiusfilterid radiusframedrouting
radiusframedroute radiusframedipnetmask radiusframedipaddress radiusframedprotocol
radiusservicetype radiusreplyitem"
[23/Jan/2006:07:47:24 -0600] conn=886
op=2 msgId=3 - RESULT err=0 tag=101 nentries=1 etime=0
[23/Jan/2006:07:47:25 -0600] conn=887
op=-1 msgId=-1 - fd=1132 slot=1132 LDAP connection from 198.213.57.20 to
198.213.56.5
[23/Jan/2006:07:47:25 -0600] conn=887
op=0 msgId=1 - BIND dn="uid=someuser,ou=People,dc=uttyler,dc=edu"
method=128 version=3
[23/Jan/2006:07:47:25 -0600] conn=887
op=0 msgId=1 - RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=someuser,ou=people,dc=uttyler,dc=edu"
[23/Jan/2006:07:47:25 -0600] conn=887
op=1 msgId=2 - UNBIND
Tim Crouch
Systems Administrator
Campus Computing Services
903-566-7476