Hello,
I'm using FreeRadius 0.1, which I "scabbed" (I wouldn't use the word
"patched") to get around the FreeRadius server crashing when the LDAP
server closed the connection. I remember throwing that out to the list,
and it was considered a bug and all. It was reported to be fixed, etc.
Well, I'm testing out v. 0.4. I know it's high time to upgrade. But
I'm running into almost the same problem. The problem happens after
FreeRadius has connected to the server. It seems FreeRadius keeps the
connection alive. But after 5 minutes, the LDAP server disconnects the
idle connection. The next time FreeRadius tries to authenticate against
the LDAP server, it sees the connection is closed, and fails. It
doesn't try to reopen the connection. Now, the next time it tries to
auth against LDAP after this, it will reconnect properly. Here's a log
from the LDAP server side of the connection showing the first auth and
the disconnect after 5 minutes.
14:37:57.81 4 LDAP-20971([192.168.0.170]) searching(sub) 'cn=ntm.org.pg'
14:37:57.81 4 LDAP-20971([192.168.0.170]) searching where
(|(uid=_)(uid=dan_perik))
14:37:57.81 4 LDAP-20971([192.168.0.170]) searching for (uid objectclass
)
14:37:57.83 4 LDAP-20971([192.168.0.170]) 'uid=dan_perik,cn=ntm.org.pg'
retrieved
14:37:57.83 2 LDAP-20971([192.168.0.170]) search finished
14:37:57.83 4 LDAP-20973([192.168.0.170]) got connection on
[192.168.0.150], port 10389
14:37:57.84 4 LDAP-20973([192.168.0.170]) Logged in as
uid=dan_perik,cn=ntm.org.pg. authType=0
14:37:57.84 4 LDAP-20973([192.168.0.170]) disconnecting
14:37:57.84 4 LDAP-20973([192.168.0.170]) closing connection
14:37:57.84 4 LDAP-20973([192.168.0.170]) releasing stream
notice 5 minutes pass.
14:42:57.84 3 LDAP-20971([192.168.0.170]) read failed. Error Code=read
time-out
14:42:57.84 4 LDAP-20971([192.168.0.170]) closing connection
14:42:57.84 4 LDAP-20971([192.168.0.170]) releasing stream
After this, I use radclient to send an auth request, and this is what I
get. There's nothing on the LDAP server side to show that FreeRadius
tried to open a new connection.
rad_recv: Access-Request packet from host 127.0.0.1:33478, id=39,
length=49
User-Name = "dan_perik"
Password = "<snip>"
rlm_sql: Reserving sql socket id: 2
rlm_sql: Released sql socket id: 2
rlm_sql_authenticate: no rows returned from query (no such user)
rlm_ldap: - authenticate
rlm_ldap: login attempt by "dan_perik" with password "<snip>"
rlm_ldap: ldap_search() failed: Can't contact LDAP server
Login incorrect: [dan_perik/<snip>] (from nas local port 0)
Sending Access-Reject of id 39 to 127.0.0.1:33478
Again, immediately after this, I can do another auth, and rlm_ldap makes
the connection to the LDAP server and it works fine. So the problem
only shows up for the first auth AFTER the LDAP server dropped the
connection.
So basically (correct me if I'm wrong) this looks like a bug in the
FreeRadius rlm_ldap module. What are the chances of getting it fixed?
I'm working on a patch, by my C is extremely rusty. It's not something
I use every day as an systems/network admin.
For the time being I can use configurable_failover so that if the first
try to the ldap module doesn't work, then I'd try again to the same
module, in which case it will reconnect properly.
- Dan
--
- Dan Perik
Computer Services Department
Lapilo Center
New Tribes Mission - PNG
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
