Bug#521617: libnss-ldapd: "tls_reqcert never" doesn't work
Jamie Heilman
Version: 0.6.8
With 0.6.7 if I have "tls_reqcert never" in /etc/ldap/ldap.conf then
nslcd can connect to my ldap servers (which unfortunately have
certificate problems and are outside of my administrative control) and
things work quite happily. The switch to 0.6.8 broke this capability
(almost surely the "clean the environment and set LDAPNOINIT" change
is responsible), even when I put "tls_reqcert never" in my
/etc/nss-ldapd.conf, which notably hasn't been well tested according
to the warning messages.
Without "tls_reqcert never" in /etc/nss-ldapd.conf I just got this:
Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id3.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:41 deadhour nslcd[11653]: [8c895d] failed to bind to LDAP server ldaps://id3.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:41 deadhour nslcd[11653]: [8c895d] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:41 deadhour nslcd[11653]: [8c895d] no available LDAP server found, sleeping 1 seconds
Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] no available LDAP server found, sleeping 1 seconds
Mar 28 03:39:42 deadhour nslcd[11653]: [8c895d] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:42 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:42 deadhour nslcd[11653]: [8c895d] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:42 deadhour nslcd[11653]: [8c895d] no available LDAP server found, sleeping 1 seconds
Mar 28 03:39:42 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:39:42 deadhour nslcd[11653]: [6c6125] no available LDAP server found, sleeping 1 seconds
Mar 28 03:39:43 deadhour nslcd[11653]: [8c895d] no available LDAP server found
Mar 28 03:39:43 deadhour nslcd[11653]: [6c6125] no available LDAP server found
While I'm not surprised it couldn't establish the connection due to
not being able to verify the certs, the error message could stand to be
more informative.
After adding "tls_reqcert never" to /etc/nss-ldapd.conf the messages
changed slightly to:
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: No such file or directory
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id3.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] no available LDAP server found, sleeping 1 seconds
Mar 28 03:41:03 deadhour nslcd[7158]: [8b4567] no available LDAP server found
Downgrading to 0.6.7 restores normal operation and things work
smoothly.
--
Jamie Heilman http://audible.transient.net/~jamie/
"Most people wouldn't know music if it came up and bit them on the ass."
-Frank Zappa
--
To UNSUBSCRIBE, email to debian-bugs-...@lists.debian.org
with a subject of "unsubscribe". Trouble? Contact listm...@lists.debian.org
Arthur de Jong
On Sat, 2009-03-28 at 16:57 -0700, Jamie Heilman wrote:
> With 0.6.7 if I have "tls_reqcert never" in /etc/ldap/ldap.conf then
> nslcd can connect to my ldap servers (which unfortunately have
> certificate problems and are outside of my administrative control) and
> things work quite happily. The switch to 0.6.8 broke this capability
> (almost surely the "clean the environment and set LDAPNOINIT" change
> is responsible), even when I put "tls_reqcert never" in my
> /etc/nss-ldapd.conf, which notably hasn't been well tested according
> to the warning messages.
Could you give me an summary of /etc/ldap/ldap.conf and
/etc/nss-ldapd.conf? That would make it easier to track this down.
> Without "tls_reqcert never" in /etc/nss-ldapd.conf I just got this:
>
> Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: Operation now in progress
[...]
> While I'm not surprised it couldn't establish the connection due to
> not being able to verify the certs, the error message could stand to be
> more informative.
The problem is that I've no idea how to get better error messages out of
the OpenLDAP library. "Can't contact LDAP server" is what I get from
OpenLDAP and "Operation now in progress" is what I get from errno (which
may or may not be useful). Running nslcd in debug mode (nslcd -d) could
give more details in some situations.
> After adding "tls_reqcert never" to /etc/nss-ldapd.conf the messages
> changed slightly to:
>
> Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: No such file or directory
[...]
Could you include the output of nslcd -d here? Can you also give some
more details on what kind of certificate is used (self-signed, etc).
Thanks for your bugreport.
--
-- arthur - ade...@debian.org - http://people.debian.org/~adejong --
Jamie Heilman
> Sorry to not reply sooner.
>
> On Sat, 2009-03-28 at 16:57 -0700, Jamie Heilman wrote:
> > With 0.6.7 if I have "tls_reqcert never" in /etc/ldap/ldap.conf then
> > nslcd can connect to my ldap servers (which unfortunately have
> > certificate problems and are outside of my administrative control) and
> > things work quite happily. The switch to 0.6.8 broke this capability
> > (almost surely the "clean the environment and set LDAPNOINIT" change
> > is responsible), even when I put "tls_reqcert never" in my
> > /etc/nss-ldapd.conf, which notably hasn't been well tested according
> > to the warning messages.
>
> Could you give me an summary of /etc/ldap/ldap.conf and
> /etc/nss-ldapd.conf? That would make it easier to track this down.
/etc/ldap/ldap.conf is real simple:
ldap_version 3
base dc=marchex,dc=com
tls_reqcert never
/etc/nss-ldapd.conf for 0.6.7 which works is:
uri ldaps://id.sea/
uri ldaps://id3.sea/
uri ldaps://id4.sea/
uri ldaps://id1.sea/
uri ldaps://id2.sea/
base dc=marchex,dc=com
base passwd ou=users,dc=marchex,dc=com
base shadow ou=users,dc=marchex,dc=com
base group ou=groups,dc=marchex,dc=com
uid nslcd
gid nslcd
/etc/nss-ldapd.conf for 0.6.8 which fails to work is the same as
0.6.7's with the addition of "tls_reqcert never"
> > Without "tls_reqcert never" in /etc/nss-ldapd.conf I just got this:
> >
> > Mar 28 03:39:41 deadhour nslcd[11653]: [6c6125] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: Operation now in progress
> [...]
> > While I'm not surprised it couldn't establish the connection due to
> > not being able to verify the certs, the error message could stand to be
> > more informative.
>
> The problem is that I've no idea how to get better error messages out of
> the OpenLDAP library. "Can't contact LDAP server" is what I get from
> OpenLDAP and "Operation now in progress" is what I get from errno (which
> may or may not be useful). Running nslcd in debug mode (nslcd -d) could
> give more details in some situations.
Yeah, the errno appears to largely irrelevant from what I can see with
an strace against nslcd and what's actually going on during the first
and subsequent queries. Debug mode output (-d) isn't of any help
either. From strace its possible to see nslcd is attempting to
communicate with my ldap servers, sends some data back and forth, but
gives up eventually.
> > After adding "tls_reqcert never" to /etc/nss-ldapd.conf the messages
> > changed slightly to:
> >
> > Mar 28 03:41:02 deadhour nslcd[7158]: [8b4567] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: No such file or directory
> [...]
>
> Could you include the output of nslcd -d here? Can you also give some
> more details on what kind of certificate is used (self-signed, etc).
here's a lookup of two users, both of which fail (and shouldn't) with
0.6.8
deadhour.sea:~# nslcd -d
nslcd: /etc/nss-ldapd.conf:6: option tls_reqcert is currently untested (please report any successes)
nslcd: DEBUG: add_uri(ldaps://id.sea/)
nslcd: DEBUG: add_uri(ldaps://id3.sea/)
nslcd: DEBUG: add_uri(ldaps://id4.sea/)
nslcd: DEBUG: add_uri(ldaps://id1.sea/)
nslcd: DEBUG: add_uri(ldaps://id2.sea/)
nslcd: version 0.6.8 starting
nslcd: DEBUG: unlink() of /var/run/nslcd/socket failed (ignored): No such file or directory
nslcd: DEBUG: setgroups(0,NULL) done
nslcd: DEBUG: setgid(114) done
nslcd: DEBUG: setuid(108) done
nslcd: accepting connections
nslcd: [8b4567] DEBUG: connection from pid=28745 uid=0 gid=0
nslcd: [8b4567] DEBUG: nslcd_passwd_byname(pwc)
nslcd: [8b4567] DEBUG: myldap_search(base="ou=users,dc=marchex,dc=com", filter="(&(objectClass=posixAccount)(uid=pwc))")
nslcd: [8b4567] DEBUG: simple anonymous bind to ldaps://id.sea/
nslcd: [8b4567] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: No such file or directory
nslcd: [8b4567] DEBUG: simple anonymous bind to ldaps://id3.sea/
nslcd: [8b4567] failed to bind to LDAP server ldaps://id3.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [8b4567] DEBUG: simple anonymous bind to ldaps://id4.sea/
nslcd: [8b4567] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [8b4567] DEBUG: simple anonymous bind to ldaps://id1.sea/
nslcd: [8b4567] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [8b4567] DEBUG: simple anonymous bind to ldaps://id2.sea/
nslcd: [8b4567] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [8b4567] no available LDAP server found, sleeping 1 seconds
nslcd: [8b4567] no available LDAP server found
nslcd: [7b23c6] DEBUG: connection from pid=28745 uid=0 gid=0
nslcd: [7b23c6] DEBUG: nslcd_passwd_byname(yang)
nslcd: [7b23c6] DEBUG: myldap_search(base="ou=users,dc=marchex,dc=com", filter="(&(objectClass=posixAccount)(uid=yang))")
nslcd: [7b23c6] no available LDAP server found, sleeping 14 seconds
nslcd: [3c9869] DEBUG: connection from pid=637 uid=1038 gid=100
nslcd: [3c9869] DEBUG: nslcd_passwd_byname(yang)
nslcd: [3c9869] DEBUG: myldap_search(base="ou=users,dc=marchex,dc=com", filter="(&(objectClass=posixAccount)(uid=yang))")
nslcd: [3c9869] no available LDAP server found, sleeping 9 seconds
nslcd: [7b23c6] DEBUG: simple anonymous bind to ldaps://id.sea/
nslcd: [3c9869] DEBUG: simple anonymous bind to ldaps://id.sea/
nslcd: [7b23c6] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [7b23c6] DEBUG: simple anonymous bind to ldaps://id3.sea/
nslcd: [7b23c6] failed to bind to LDAP server ldaps://id3.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [7b23c6] DEBUG: simple anonymous bind to ldaps://id4.sea/
nslcd: [3c9869] failed to bind to LDAP server ldaps://id.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [3c9869] DEBUG: simple anonymous bind to ldaps://id4.sea/
nslcd: [3c9869] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [3c9869] DEBUG: simple anonymous bind to ldaps://id1.sea/
nslcd: [7b23c6] failed to bind to LDAP server ldaps://id4.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [7b23c6] DEBUG: simple anonymous bind to ldaps://id1.sea/
nslcd: [3c9869] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [3c9869] DEBUG: simple anonymous bind to ldaps://id2.sea/
nslcd: [7b23c6] failed to bind to LDAP server ldaps://id1.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [7b23c6] DEBUG: simple anonymous bind to ldaps://id2.sea/
nslcd: [3c9869] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [3c9869] no available LDAP server found, sleeping 1 seconds
nslcd: [7b23c6] failed to bind to LDAP server ldaps://id2.sea/: Can't contact LDAP server: Operation now in progress
nslcd: [7b23c6] no available LDAP server found, sleeping 1 seconds
nslcd: [3c9869] no available LDAP server found
nslcd: [7b23c6] no available LDAP server found
The certificates are all signed by a private CA (although I don't
actually have the CA certificate for the first 3 configured URIs),
none of them are self-signed. The servers are a mix of openldap and
eDirectory servers (id1 and id2 are eDirectory, id3 and id4 are
openldap, id is a loadbalanced vip of id3 and id4). Just to ensure
none of that complexity is even part of the problem though I stripped
the config down to just id1.sea and it didn't make anything work any
better. Then I went further and set up the CA certificate file for
id1.sea (which is actually one I do have, and I've verified is sane)
and I can't even get ldaps working with 0.6.8 against a Novell
eDirectory server with a known good CA certificate file, and I can
make it work just fine with 0.6.7, so frankly I wouldn't be surprised
if the changes in 0.6.8 just broke SSL handling completely (which
would make this bug more severe than I thought at first).