Hi,
Today I began to move my LDAP-Server to a Linux VServer jail. On the host and on the VServer I run Debian etch 4.0. Installing slapd was no problem (aptitude install slapd). I just copied all configuration and data files from the host which worked perfectly before and copied them 1:1 into the VServer.
slapd starts without any warnings. But connecting with a client is not possible, neither inside the VServer nor outside.
For security reasons, I just allow access with SSL or TLS-required (the very same file worked greatly on the host!):
pidfile /var/run/slapd/slapd.pid argsfile /var/run/slapd/slapd.args loglevel 0 disallow bind_anon require authc security tls=1
TLSCACertificateFile /etc/ldap/ssl/cacert.crt TLSCertificateFile /etc/ldap/ssl/ldap.crt TLSCertificateKeyFile /etc/ldap/ssl/ldap.key TLSVerifyClient never
All key files and database files are accessible by slapd (user=openldap, group=openldap).
Connecting to ldap and ldaps works greatly from inside the VServer and also from outside:
$ nc 192.168.0.2 ldap ^c $ nc 192.168.0.2 ldaps ^c $
There are no packet filters installed, debugging with tcpdump (local interface) shows the complete TCP traffic and handshake with no errors.
The strange error is always the same: The clients do not want to connect, sending SSL stuff is always possible but after that, nothing is received. Let's begin with plain SSL:
$ openssl s_client -connect 192.168.0.2:636 -debug CONNECTED(00000003) write to 0x80bee90 [0x80bf4e8] (118 bytes => 118 (0x76)) 0000 - 80 74 01 03 01 00 4b 00-00 00 20 00 00 39 00 00 .t....K... ..9.. 0010 - 38 00 00 35 00 00 16 00-00 13 00 00 0a 07 00 c0 8..5............ 0020 - 00 00 33 00 00 32 00 00-2f 03 00 80 00 00 05 00 ..3..2../....... 0030 - 00 04 01 00 80 00 00 15-00 00 12 00 00 09 06 00 ................ 0040 - 40 00 00 14 00 00 11 00-00 08 00 00 06 04 00 80 @............... 0050 - 00 00 03 02 00 80 f5 5d-10 d2 64 21 24 0c b1 c3 .......]..d!$... 0060 - 92 37 72 7a 4a 9c 09 88-46 b2 f8 39 ef f6 c4 c8 .7rzJ...F..9.... 0070 - 84 74 8e a6 79 e1 .t..y. read from 0x80bee90 [0x80c4a48] (7 bytes => 0 (0x0)) 20500:error:140790E5:SSL routines:SSL23_WRITE:ssl handshake failure:s23_lib.c:188: $
I did lots of tests with many LDAP clients (ldapwhoami, ldapsearch commandline tools, PHP, Softerra LDAP Administrator and Clients in exim4, Courier etc). In this case I show connecting with SSL using ldapwhoami:
$ ldapwhoami -x -H ldaps://nobaq.intern.stiftingtal.net -D "uid=nobaq,ou=users,dc=intern,dc=stiftingtal,dc=net" -w secret -v -d 999 ldap_initialize( ldaps://nobaq.intern.stiftingtal.net ) ldap_create ldap_url_parse_ext(ldaps://nobaq.intern.stiftingtal.net) ldap_extended_operation_s ldap_extended_operation ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_connect_to_host: TCP nobaq.intern.stiftingtal.net:636 ldap_new_socket: 3 ldap_prepare_socket: 3 ldap_connect_to_host: Trying 192.168.0.2:636 ldap_connect_timeout: fd: 3 tm: -1 async: 0 TLS trace: SSL_connect:before/connect initialization tls_write: want=118, written=118 0000: 80 74 01 03 01 00 4b 00 00 00 20 00 00 39 00 00 .t....K... ..9.. 0010: 38 00 00 35 00 00 16 00 00 13 00 00 0a 07 00 c0 8..5............ 0020: 00 00 33 00 00 32 00 00 2f 03 00 80 00 00 05 00 ..3..2../....... 0030: 00 04 01 00 80 00 00 15 00 00 12 00 00 09 06 00 ................ 0040: 40 00 00 14 00 00 11 00 00 08 00 00 06 04 00 80 @............... 0050: 00 00 03 02 00 80 20 25 c9 bb fe 68 e8 52 6c 87 ...... %...h.Rl. 0060: 04 ae 25 d1 8b f5 73 c8 3d ca 73 ab e3 92 3f 9f ..%...s.=.s...?. 0070: c9 9d 79 4e aa fb ..yN.. TLS trace: SSL_connect:SSLv2/v3 write client hello A tls_read: want=7, got=0
TLS: can't connect. ldap_perror ldap_start_tls: Can't contact LDAP server (-1) $
As you can see, reading fails. And now using a normal connection but with TLS:
ldapwhoami -x -H ldap://192.168.0.2 -D "uid=nobaq,ou=users,dc=intern,dc=stiftingtal,dc=net" -w secret -v -d 999 -ZZ ldap_initialize( ldap://192.168.0.2 ) ldap_create ldap_url_parse_ext(ldap://192.168.0.2) ldap_extended_operation_s ldap_extended_operation ldap_send_initial_request ldap_new_connection 1 1 0 ldap_int_open_connection ldap_connect_to_host: TCP 192.168.0.2:389 ldap_new_socket: 3 ldap_prepare_socket: 3 ldap_connect_to_host: Trying 192.168.0.2:389 ldap_connect_timeout: fd: 3 tm: -1 async: 0 ldap_open_defconn: successful ldap_send_server_request ber_scanf fmt ({it) ber: ber_scanf fmt ({) ber: ber_flush: 31 bytes to sd 3 0000: 30 1d 02 01 01 77 18 80 16 31 2e 33 2e 36 2e 31 0....w...1.3.6.1 0010: 2e 34 2e 31 2e 31 34 36 36 2e 32 30 30 33 37 .4.1.1466.20037 ldap_write: want=31, written=31 0000: 30 1d 02 01 01 77 18 80 16 31 2e 33 2e 36 2e 31 0....w...1.3.6.1 0010: 2e 34 2e 31 2e 31 34 36 36 2e 32 30 30 33 37 .4.1.1466.20037 ldap_result ld 0x8051088 msgid 1 ldap_chkResponseList ld 0x8051088 msgid 1 all 1 ldap_chkResponseList returns ld 0x8051088 NULL wait4msg ld 0x8051088 msgid 1 (infinite timeout) wait4msg continue ld 0x8051088 msgid 1 all 1 ** ld 0x8051088 Connections: * host: 192.168.0.2 port: 389 (default) refcnt: 2 status: Connected last used: Wed Aug 29 00:04:19 2007 ** ld 0x8051088 Outstanding Requests: * msgid 1, origid 1, status InProgress outstanding referrals 0, parent count 0 ** ld 0x8051088 Response Queue: Empty ldap_chkResponseList ld 0x8051088 msgid 1 all 1 ldap_chkResponseList returns ld 0x8051088 NULL ldap_int_select read1msg: ld 0x8051088 msgid 1 all 1 ber_get_next ldap_read: want=8, got=8 0000: 30 0c 02 01 01 78 07 0a 0....x.. ldap_read: want=6, got=6 0000: 01 00 04 00 04 00 ...... ber_get_next: tag 0x30 len 12 contents: read1msg: ld 0x8051088 msgid 1 message type extended-result ber_scanf fmt ({eaa) ber: read1msg: ld 0x8051088 0 new referrals read1msg: mark request completed, ld 0x8051088 msgid 1 request done: ld 0x8051088 msgid 1 res_errno: 0, res_error: <>, res_matched: <> ldap_free_request (origid 1, msgid 1) ldap_free_connection 0 1 ldap_free_connection: refcnt 1 ldap_parse_extended_result ber_scanf fmt ({eaa) ber: ldap_parse_result ber_scanf fmt ({iaa) ber: ber_scanf fmt (}) ber: ldap_msgfree TLS trace: SSL_connect:before/connect initialization tls_write: want=118, written=118 0000: 80 74 01 03 01 00 4b 00 00 00 20 00 00 39 00 00 .t....K... ..9.. 0010: 38 00 00 35 00 00 16 00 00 13 00 00 0a 07 00 c0 8..5............ 0020: 00 00 33 00 00 32 00 00 2f 03 00 80 00 00 05 00 ..3..2../....... 0030: 00 04 01 00 80 00 00 15 00 00 12 00 00 09 06 00 ................ 0040: 40 00 00 14 00 00 11 00 00 08 00 00 06 04 00 80 @............... 0050: 00 00 03 02 00 80 83 33 38 7c c9 0a f9 0b 42 67 .......38|....Bg 0060: 76 97 03 8b e3 47 55 fe 74 ed 86 08 83 fe ed 88 v....GU.t....... 0070: 0e 40 53 97 e5 3e .@S..> TLS trace: SSL_connect:SSLv2/v3 write client hello A tls_read: want=7, got=0
TLS: can't connect. ldap_perror ldap_start_tls: Connect error (-11) $
Connecting without the '-ZZ' seems to work, I get the "confidentiality required" message:
$ ldapwhoami -x -H ldap://192.168.0.2 -D "uid=nobaq,ou=users,dc=intern,dc=stiftingtal,dc=net" -w secret -v ldap_initialize( ldap://192.168.0.2 ) ldap_bind: Confidentiality required (13) additional info: TLS confidentiality required $
So I guess the problem is SSL. As said, all SSL files are accessible and there are no errors in the logs or when starting slapd with '-d'. The certificates CN is exactly the hostname.
I'm very frustrated because I can't find any errors. I repeat: the very same configuration worked perfectly on the host system.
Is this a bug?
Thank you very much in advance for any advice,
Niki
Niki Hammler wrote:
Please show the slapd debug logs when running with "-d -1" for these connection attempts.
Howard Chu wrote:
Also give the actual version numbers of the OpenLDAP software in use, and your SSL library. I have no idea what Debian bundles in their releases.
Howard Chu schrieb:
Hi,
Thank you for your quick answer!
This is the output (after startup-output) when connecting via SSL:
daemon: activity on 1 descriptor
slap_listener(ldaps:///)daemon: listen=6, new connection on 11
ldap_pvt_gethostbyname_a: host=wlan.intern.stiftingtal.net, r=0 daemon: added 11r (active) listener=(nil) conn=0 fd=11 ACCEPT from IP=192.168.0.2:43760 (IP=0.0.0.0:636) daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL daemon: activity on 1 descriptor daemon: activity on: 11r daemon: read activity on 11 connection_get(11) connection_get(11): got connid=0 connection_read(11): checking for input on id=0 TLS trace: SSL_accept:before/accept initialization tls_read: want=11, got=11 0000: 80 74 01 03 01 00 4b 00 00 00 20 .t....K... tls_read: want=107, got=107 0000: 00 00 39 00 00 38 00 00 35 00 00 16 00 00 13 00 ..9..8..5....... 0010: 00 0a 07 00 c0 00 00 33 00 00 32 00 00 2f 03 00 .......3..2../.. 0020: 80 00 00 05 00 00 04 01 00 80 00 00 15 00 00 12 ................ 0030: 00 00 09 06 00 40 00 00 14 00 00 11 00 00 08 00 .....@.......... 0040: 00 06 04 00 80 00 00 03 02 00 80 fb fb f7 a3 58 ...............X 0050: ee 80 3e 8d 15 ea 2b 74 23 8d 4a c6 bd 0d 27 5c ..>...+t#.J...'\ 0060: bc ca cb b0 d2 45 42 3d 41 21 da .....EB=A!. TLS trace: SSL_accept:error in SSLv3 read client hello B TLS trace: SSL_accept:error in SSLv3 read client hello B TLS: can't accept. TLS: error:140B512D:SSL routines:SSL_GET_NEW_SESSION:ssl session id callback failed ssl_sess.c:232 connection_read(11): TLS accept failure error=-1 id=0, closing connection_closing: readying conn=0 sd=11 for close connection_close: conn=0 sd=11 daemon: removing 11 conn=0 fd=11 closed (TLS negotiation failure) daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL daemon: activity on 1 descriptor daemon: waked daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL
And this is the output for ldap://192.168.0.2 with '-ZZ' (i.e. using TLS secured channel):
daemon: activity on 1 descriptor
slap_listener(ldap:///)daemon: listen=7, new connection on 11
daemon: added 11r (active) listener=(nil) conn=1 fd=11 ACCEPT from IP=192.168.0.2:42464 (IP=0.0.0.0:389) daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL daemon: activity on 1 descriptor daemon: activity on: 11r daemon: read activity on 11 connection_get(11) connection_get(11): got connid=1 connection_read(11): checking for input on id=1 ber_get_next ldap_read: want=8, got=8 0000: 30 1d 02 01 01 77 18 80 0....w.. ldap_read: want=23, got=23 0000: 16 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e 31 34 36 .1.3.6.1.4.1.146 0010: 36 2e 32 30 30 33 37 6.20037 ber_get_next: tag 0x30 len 29 contents: ber_dump: buf=0x081a0c20 ptr=0x081a0c20 end=0x081a0c3d len=29 0000: 02 01 01 77 18 80 16 31 2e 33 2e 36 2e 31 2e 34 ...w...1.3.6.1.4 0010: 2e 31 2e 31 34 36 36 2e 32 30 30 33 37 .1.1466.20037 ber_get_next ldap_read: want=8 error=Resource temporarily unavailable ber_get_next on fd 11 failed errno=11 (Resource temporarily unavailable) daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL do_extended ber_scanf fmt ({m) ber: ber_dump: buf=0x081a0c20 ptr=0x081a0c23 end=0x081a0c3d len=26 0000: 77 18 80 16 31 2e 33 2e 36 2e 31 2e 34 2e 31 2e w...1.3.6.1.4.1. 0010: 31 34 36 36 2e 32 30 30 33 37 1466.20037 do_extended: oid=1.3.6.1.4.1.1466.20037 conn=1 op=0 STARTTLS send_ldap_extended: err=0 oid= len=0 send_ldap_response: msgid=1 tag=120 err=0 ber_flush: 14 bytes to sd 11 0000: 30 0c 02 01 01 78 07 0a 01 00 04 00 04 00 0....x........ daemon: activity on 1 descriptor daemon: activity on: 11r daemon: read activity on 11 connection_get(11) ldap_write: want=14, written=14 0000: 30 0c 02 01 01 78 07 0a 01 00 04 00 04 00 0....x........ connection_get(11): got connid=1 connection_read(11): checking for input on id=1 TLS trace: SSL_accept:before/accept initialization tls_read: want=11, got=11 0000: 80 74 01 03 01 00 4b 00 00 00 20 .t....K... tls_read: want=107, got=107 0000: 00 00 39 00 00 38 00 00 35 00 00 16 00 00 13 00 ..9..8..5....... 0010: 00 0a 07 00 c0 00 00 33 00 00 32 00 00 2f 03 00 .......3..2../.. 0020: 80 00 00 05 00 00 04 01 00 80 00 00 15 00 00 12 ................ 0030: 00 00 09 06 00 40 00 00 14 00 00 11 00 00 08 00 .....@.......... 0040: 00 06 04 00 80 00 00 03 02 00 80 03 af 43 95 78 .............C.x 0050: f9 c3 d9 5f 92 17 53 1b 7a a7 aa 7a e1 ee ec 03 ..._..S.z..z.... 0060: 6e ce 2b 18 a9 66 5b 45 38 6e ac n.+..f[E8n. TLS trace: SSL_accept:error in SSLv3 read client hello B TLS trace: SSL_accept:error in SSLv3 read client hello B TLS: can't accept. TLS: error:140B512D:SSL routines:SSL_GET_NEW_SESSION:ssl session id callback failed ssl_sess.c:232 connection_read(11): TLS accept failure error=-1 id=1, closing connection_closing: readying conn=1 sd=11 for close connection_close: deferring conn=1 sd=11 daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL daemon: activity on 1 descriptor daemon: waked daemon: select: listen=6 active_threads=0 tvp=NULL daemon: select: listen=7 active_threads=0 tvp=NULL conn=1 op=0 RESULT oid= err=0 text= connection_resched: attempting closing conn=1 sd=11 connection_close: conn=1 sd=11 daemon: removing 11 conn=1 fd=11 closed (TLS negotiation failure)
Normally, slapd is started with:
/usr/sbin/slapd -h ldaps:/// ldap:/// -g openldap -u openldap -4
(In Debian with /etc/init.d/slapd, this is from ps aux).
Now I started with
slapd -h ldaps:/// ldap:/// -g openldap -u openldap -4 -d -1
But now I noticed also one very interesting thing: Starting slapd as root makes everything work fine!
/usr/sbin/slapd -h ldaps:/// ldap:/// -4
But it would be very great if I could start slapd as "openldap" for security reasons!
# dpkg -s slapd | grep Version Version: 2.3.30-5 # slapd -V @(#) $OpenLDAP: slapd 2.3.30 (Mar 9 2007 05:43:02) $
root@windlord:/tmp/buildd/openldap2.3-2.3.30/debian/build/servers/slapd
# dpkg -s libssl0.9.8 | grep Version Version: 0.9.8c-4 # dpkg -s openssl | grep Version Version: 0.9.8c-4
Thank you very much again, Niki
Niki Hammler wrote:
That's enough. The SSL library has obviously failed:
TLS: error:140B512D:SSL routines:SSL_GET_NEW_SESSION:ssl session id callback failed ssl_sess.c:232
This failure indicates that the SSL library was unable to generate a session ID for the session. Generating the session ID just requires generating a single random number (and checking that the number hasn't been used before). On a freshly started server, this should never fail.
Check the permissions of /dev/random and /dev/urandom on your virtual server. Make sure they are readable by the openldap user.
No bug here, just a misconfigured system...
Howard Chu schrieb:
Thank you very much! For strange reasons the /dev directory had 700 permissons (I saw that all VServer have these permissions by default).
Thank you for this hint, I never would have guessed this as all the output did not contain any reference to /dev...
Thank you, now everything works fine :-)
Niki
Niki Hammler wrote:
It might be worthwhile to submit a bug report to the OpenSSL folks, asking them to log something useful when they fail to open /dev/random...
Thank you, now everything works fine :-)
Niki
-
Howard Chu -
Niki Hammler