Enabling TLS problem on openldap2-2.3.39

["Keagle, Chuck" <chuck.keagle@boeing.com>]

I'm configuring slapd to use TLS.  First I just want to make it work,
then I'll go into requiring encryption.

The system is SLES 9.3
The openldap2 is 2.3.39
Other certifictes are in /etc/ssl/certs as specified by default in
slapd.conf for openldap2 2.3.39.

The database is currently empty, just getting started.

Generated a self-signed x509 certificate
	cd /etc/openldap
	openssl genrsa 1024 >server.key
	chmod 0440 server.key
	chown root:ldap server.key
	openssl req -new -key server.key -x509 -days 100 -out server.crt
		Entered all the important stuff
	chmod 0444 server.crt

Checked certificate and it looked acceptable
	openssl x509 -text -in server.crt

Changed following lines in slapd.conf:
	TLSCertificateFile /etc/openldap/server.crt
	TLSCertificateKeyFile /etc/openldap/server.key

Added following line to /etc/openldap/ldap.conf
	TLS_CACERT	/etc/openldap/server.crt

A command not using encryption works fine:
	ldapsearch -x -H ldap://example.com -b "" -s base
'objectclass=*' '+' '*'

A command using encryption fails:
	ldapsearch -x -Z -H ldap://example.com -b "" -s base
'objectclass=*' '+' '*'
	ldap_start_tls: Connect error (-11)
	        additional info: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed
	ldap_result: Can't contact LDAP server (-1)
	        additional info: error:14090086:SSL
routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed

Here are the ldap log entries when loglevel is set to -1:
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on 1
descriptor
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on:
	Nov 16 16:53:47 testsvr slapd[19533]:
	Nov 16 16:53:47 testsvr slapd[19533]: >>>
slap_listener(ldap:///)
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: listen=8, new
connection on 14
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: added 14r (active)
listener=(nil)
	Nov 16 16:53:47 testsvr slapd[19533]: conn=4 fd=14 ACCEPT from
IP=1.1.1.1:3535 (IP=0.0.0.0:389)
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=7
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=8
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on 1
descriptor
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on:
	Nov 16 16:53:47 testsvr slapd[19533]:  14r
	Nov 16 16:53:47 testsvr slapd[19533]:
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: read active on 14
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14)
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14): got
connid=4
	Nov 16 16:53:47 testsvr slapd[19533]: connection_read(14):
checking for input on id=4
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=7
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=8
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: do_extended
	Nov 16 16:53:47 testsvr slapd[19533]: do_extended:
oid=1.3.6.1.4.1.1466.20037
	Nov 16 16:53:47 testsvr slapd[19533]: conn=4 op=0 STARTTLS
	Nov 16 16:53:47 testsvr slapd[19533]: send_ldap_extended: err=0
oid= len=0
	Nov 16 16:53:47 testsvr slapd[19533]: send_ldap_response:
msgid=1 tag=120 err=0
	Nov 16 16:53:47 testsvr slapd[19533]: conn=4 op=0 RESULT oid=
err=0 text=
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on 1
descriptor
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on:
	Nov 16 16:53:47 testsvr slapd[19533]:  14r
	Nov 16 16:53:47 testsvr slapd[19533]:
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: read active on 14
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14)
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14): got
connid=4
	Nov 16 16:53:47 testsvr slapd[19533]: connection_read(14):
checking for input on id=4
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=7
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=8
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on 1
descriptor
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on:
	Nov 16 16:53:47 testsvr slapd[19533]:  14r
	Nov 16 16:53:47 testsvr slapd[19533]:
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: read active on 14
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14)
	Nov 16 16:53:47 testsvr slapd[19533]: connection_get(14): got
connid=4
	Nov 16 16:53:47 testsvr slapd[19533]: connection_read(14):
checking for input on id=4
	Nov 16 16:53:47 testsvr slapd[19533]: connection_read(14): TLS
accept failure error=-1 id=4, closing
	Nov 16 16:53:47 testsvr slapd[19533]: connection_closing:
readying conn=4 sd=14 for close
	Nov 16 16:53:47 testsvr slapd[19533]: connection_close: conn=4
sd=-1
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: removing 14
	Nov 16 16:53:47 testsvr slapd[19533]: conn=4 fd=14 closed (TLS
negotiation failure)
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=7
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=8
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on 1
descriptor
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: activity on:
	Nov 16 16:53:47 testsvr slapd[19533]:
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=7
active_threads=0 tvp=zero
	Nov 16 16:53:47 testsvr slapd[19533]: daemon: epoll: listen=8
active_threads=0 tvp=zero

It looks like TLS started OK, then there was a negotiation failure with
slapd.

I figure I just missed something simple here, but have spent quite a bit
of time not getting it figured out.

Any insights?

Thank you.

----
Not all who wander are lost.

                          |     ----  ___o  |  chuck.keagle@boeing.com
Chuck Keagle              |  -------  \ <,  |  Work:  (425) 865-1488
Enterprise Servers:  HPC  |  ----- ( )/ ( ) |  Cell:  (425) 417-3434