Might have found an obscure rlm_ldap Bug?

[Andy Fleming]

I'm not really a coder, so I'm posting to the users list first in hopes of some guidance on the next step.  I've been looking at the rlm_ldap.c code and some from the openldap libraries it uses.  I didn't want to go directly to a bug report incase this has already been fixed in the current 2.x release.  Maybe I just need someone to explain how the code is expected to act in this particular case.  


I'm running a RHEL6 clone, Scientific Linux.  freeradius-2.1.12-4.el6_3.x86_64  

It looks like the RHEL package has only had a couple of patches since the 2.1.12 release.  


* Mon Sep 24 2012 John Dennis <jdennis at redhat.com> - 2.1.12-4
- resolves: bug#855316
  CVE-2012-3547 freeradius: Stack-based buffer overflow by processing
  certain expiration date fields of a certificate during x509 certificate
  validation

* Tue Apr 10 2012 John Dennis <jdennis at redhat.com> - 2.1.12-2
- resolves: bug#810605 Segfault with freeradius-perl threading

* Mon Feb 27 2012 John Dennis <jdennis at redhat.com> - 2.1.12-1
- Upgrade to latest upstream release: 2.1.12


I stumbled upon this issue because of some brute force login attempts to a device pointed at a FreeRadius server.  (This is a router using pap.)  


Environment:  My LDAP server is the 389ds server.  I run samba off of this same DS, so I did have a user with uid=root along with our typical users.  The uid=root account dose not have a "user password" attribute, only a NTpassword attribute because its only there for Samba.  

So if FreeRadius tries to an LDAP search on uid=root in the authorize phase, it dose find a DN.  Then in the authentication phase when it tries to bind at that DN, it gets the message back "failed Inappropriate authentication" rather then the typical "Bind failed with invalid credentials".  It makes since that my LDAP server would send back a different error message.  

Thus far, things seem to be working correctly, but I think the message is confusing the rlm_ldap module and I'm getting back "returns fail" rather then "return reject".  I think that return fail rather then reject might be part of what is triggering the bug.  If I get 6 access-request in a row that "fail" and then send an access-request with a valid username/password, the LDAP module returns fail without even trying to do a bind.  But it dose still do the search fine and get the correct DN.  

If a successful LDAP bind happens in the authentication phase, the count of 6 "Inappropriate authentication" logins starts resets to 0.  I'm thinking maybe when the rlm_ldap returns fail rather then reject it marks that connection in the pool bad or something and it it runs out of connections?  

On the one hand I could see where when you get "failed Inappropriate authentication" the module should return reject rather then fail, but I could also see where you might get the same message back from the LDAP server when you have a bad radius server configuration.  I guess I'm also not sure where the 6 attempts are coming from and why that causes it to not ever try a bind in the authentication stage in future requests.  


I can provide full debug logs and config, but here is the debug from the authentication stage.  The first is with the LDAP server returning the "Inappropriate authentication" error and the second is the exact same request for the same user, but with a "Bind failed with invalid credentials" error because I set a password on the account in LDAP.  


Now that I've figured out what triggers the issues I can tweak some ldap search filters and add some ulang checks to help keep it from happening, but I still think there might be a bug.  


(User not having a password in LDAP thus getting failed Inappropriate authentication)


Wed Oct 16 10:16:08 2013 : Debug:   [ldap] waiting for bind result ...
ldap_result ld 0x7f597847b080 msgid 1
wait4msg ld 0x7f597847b080 msgid 1 (timeout 4000000 usec)
wait4msg continue ld 0x7f597847b080 msgid 1 all 1
** ld 0x7f597847b080 Connections:
* host: redacted.kanren.net  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Wed Oct 16 10:16:08 2013


** ld 0x7f597847b080 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x7f597847b080 request count 1 (abandoned 0)
** ld 0x7f597847b080 Response Queue:
   Empty
  ld 0x7f597847b080 response count 0
ldap_chkResponseList ld 0x7f597847b080 msgid 1 all 1
ldap_chkResponseList returns ld 0x7f597847b080 NULL
ldap_int_select
read1msg: ld 0x7f597847b080 msgid 1 all 1
read1msg: ld 0x7f597847b080 msgid 1 message type bind
read1msg: ld 0x7f597847b080 0 new referrals
read1msg:  mark request completed, ld 0x7f597847b080 msgid 1
request done: ld 0x7f597847b080 msgid 1
res_errno: 48, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
ldap_err2string
Wed Oct 16 10:16:08 2013 : Error:   [ldap] uid=root,ou=People,dc=kanren,dc=net bind to redacted.kanren.net:636 failed Inappropriate authentication
ldap_free_connection 1 1
ldap_send_unbind
ldap_free_connection: actually freed
Wed Oct 16 10:16:08 2013 : Info: [ldap] ldap_connect() failed
Wed Oct 16 10:16:08 2013 : Info: ++[ldap] returns fail
Wed Oct 16 10:16:08 2013 : Info: Failed to authenticate the user.


After [ldap] returns fail 6 times in a row, it won't even try and bind, it just returns [ldap] return fail.  



(Same user having a password in LDAP thus getting Bind failed with invalid credentials.  Thus never seeming to have the issue.)

Wed Oct 16 10:32:54 2013 : Debug:   [ldap] waiting for bind result ...
ldap_result ld 0x7f9ca1b5fc40 msgid 1
wait4msg ld 0x7f9ca1b5fc40 msgid 1 (timeout 4000000 usec)
wait4msg continue ld 0x7f9ca1b5fc40 msgid 1 all 1
** ld 0x7f9ca1b5fc40 Connections:
* host: redacted.kanren.net  port: 636  (default)
  refcnt: 2  status: Connected
  last used: Wed Oct 16 10:32:54 2013


** ld 0x7f9ca1b5fc40 Outstanding Requests:
 * msgid 1,  origid 1, status InProgress
   outstanding referrals 0, parent count 0
  ld 0x7f9ca1b5fc40 request count 1 (abandoned 0)
** ld 0x7f9ca1b5fc40 Response Queue:
   Empty
  ld 0x7f9ca1b5fc40 response count 0
ldap_chkResponseList ld 0x7f9ca1b5fc40 msgid 1 all 1
ldap_chkResponseList returns ld 0x7f9ca1b5fc40 NULL
ldap_int_select
read1msg: ld 0x7f9ca1b5fc40 msgid 1 all 1
read1msg: ld 0x7f9ca1b5fc40 msgid 1 message type bind
read1msg: ld 0x7f9ca1b5fc40 0 new referrals
read1msg:  mark request completed, ld 0x7f9ca1b5fc40 msgid 1
request done: ld 0x7f9ca1b5fc40 msgid 1
res_errno: 49, res_error: <>, res_matched: <>
ldap_free_request (origid 1, msgid 1)
ldap_parse_result
ldap_msgfree
Wed Oct 16 10:32:54 2013 : Debug:   [ldap] Bind failed with invalid credentials
ldap_free_connection 1 1
ldap_send_unbind
ldap_free_connection: actually freed
Wed Oct 16 10:32:54 2013 : Info: ++[ldap] returns reject
Wed Oct 16 10:32:54 2013 : Info: Failed to authenticate the user.



Thanks again for any ideas.  -- Andy