Re: Ambiguous SSL/TLS error messages from slapd

On 02/19/10 11:51, Howard Chu wrote:
> Brian A. Seklecki (CFI NOC) wrote:
>> Steve, I agree:
>>
>>
>>     This error gets printed with "-1" under too many
>>     conditions.  Just look at:
>>        libraries/libldap/tls2.c::ldap_pvt_tls_set_option()
>>
>>     RC Return Code -1 could happen in about a dozen places.
>>
>>     I think we need to take a two step approach to fixing this:
>>
>>     1) Long term, implement OpenSSL's err(3)
>
> What are you talking about? tlso_report_error() already prints the 
> OpenSSL error messages. All OpenSSL error messages have been fully 
> logged, for years.
>
>>     2) Short term, in servers/slapd/main.c:
>>
>>      Debug( LDAP_DEBUG_ANY,
>>        "main: TLS init def ctx failed: %d\n",
>>           rc, 0, 0 );
>>
>>     We should change / append to this to clarify:
>>
>>       if (rc<  0)
>>     Debug( LDAP_DEBUG_ANY, "main: something has gone terribly
>>             wrong in creation of the SSL data structure.  Check
>>             filesystem permissions, ownership bits, ACLs, configuration
>>             file paths.  Resort to strace(1)/ktrace(1)
>>              debugging.\n",rc,0,0);
>>
>>      if (rc>  0)
>>     Debug( LDAP_DEBUG_ANY, "main: something has gone wrong
>>             in creation of the SSL socket data structure.  Please
>>             check the OpenSSL error code above against:
>>             /usr/include/openssl/ssl until we err(3) support\n",rc,0,0);
>
> Pointless, since all failures inside init_ctx already call 
> tlso_report_error().
>

Great, however it doesn't change the fact that no meaningful error is 
being reported:

(slapd runs as the user ldap)
# chown root certs/ldap.key.pem
# ls -la certs/ldap.key.pem
-r--------  1 root  wheel  1679 Feb 19 18:29 certs/ldap.key.pem
# /usr/local/etc/rc.d/slapd start
Starting slapd.
Feb 19 18:36:45  slapd[85526]: @(#) $OpenLDAP: slapd 2.4.21 (Jan 11 2010 
22:02:31) $     
root@:/var/ports/usr/ports/net/openldap24-server/work/openldap-2.4.21/servers/slapd
Feb 19 18:36:45  slapd[85526]: line 33 (modulepath    
/usr/local/libexec/openldap)
Feb 19 18:36:45  slapd[85526]: line 34 (moduleload    back_bdb)
Feb 19 18:36:45  slapd[85526]: loaded module back_bdb
Feb 19 18:36:45  slapd[85526]: module back_bdb: null module registered
Feb 19 18:36:45  slapd[85526]: line 35 (moduleload    back_ldap)
Feb 19 18:36:45  slapd[85526]: loaded module back_ldap
Feb 19 18:36:45  slapd[85526]: module back_ldap: null module registered
Feb 19 18:36:45  slapd[85526]: line 38 (disallow bind_anon)
Feb 19 18:36:45  slapd[85526]: line 59 (database    bdb)
Feb 19 18:36:45  slapd[85526]: line 60 (suffix        "dc=xxxxxxxx,dc=com")
Feb 19 18:36:45  slapd[85526]: line 61 (rootdn        
"cn=xxx,dc=xxxxxxxx,dc=com")
Feb 19 18:36:45  slapd[85526]: line 66 (rootpw ***)
Feb 19 18:36:45  slapd[85526]: line 71 (TLSCipherSuite HIGH:MEDIUM:+SSLv2)
Feb 19 18:36:45  slapd[85526]: line 72 (TLSVerifyClient allow)
Feb 19 18:36:45  slapd[85526]: line 76 (TLSCACertificateFile 
/usr/local/etc/openldap/certs/cacert.pem)
Feb 19 18:36:45  slapd[85526]: line 80 (TLSCertificateFile 
/usr/local/etc/openldap/certs/ldap.crt.pem)
Feb 19 18:36:45  slapd[85526]: line 81 (TLSCertificateKeyFile 
/usr/local/etc/openldap/certs/ldap.key.pem)
Feb 19 18:36:45  slapd[85526]: line 86 (directory    /var/db/openldap-data)
Feb 19 18:36:45  slapd[85526]: line 89 (index   
objectClass,entryCSN,entryUUID          eq)
Feb 19 18:36:45  slapd[85526]: index objectClass 0x0004
Feb 19 18:36:45  slapd[85526]: index entryCSN 0x0004
Feb 19 18:36:45  slapd[85526]: index entryUUID 0x0004
Feb 19 18:36:45  slapd[85526]: main: TLS init def ctx failed: -1
Feb 19 18:36:45  slapd[85526]: slapd stopped.
Feb 19 18:36:45  slapd[85526]: connections_destroy: nothing to destroy.

# chown ldap certs/ldap.key.pem
# /usr/local/etc/rc.d/slapd start
Starting slapd.
Feb 19 18:37:49  slapd[85545]: @(#) $OpenLDAP: slapd 2.4.21 (Jan 11 2010 
22:02:31) $     
root@:/var/ports/usr/ports/net/openldap24-server/work/openldap-2.4.21/servers/slapd
Feb 19 18:37:49  slapd[85545]: line 33 (modulepath    
/usr/local/libexec/openldap)
Feb 19 18:37:49  slapd[85545]: line 34 (moduleload    back_bdb)
Feb 19 18:37:49  slapd[85545]: loaded module back_bdb
Feb 19 18:37:49  slapd[85545]: module back_bdb: null module registered
Feb 19 18:37:49  slapd[85545]: line 35 (moduleload    back_ldap)
Feb 19 18:37:49  slapd[85545]: loaded module back_ldap
Feb 19 18:37:49  slapd[85545]: module back_ldap: null module registered
Feb 19 18:37:49  slapd[85545]: line 38 (disallow bind_anon)
Feb 19 18:37:49  slapd[85545]: line 59 (database    bdb)
Feb 19 18:37:49  slapd[85545]: line 60 (suffix        "dc=xxxxxxxx,dc=com")
Feb 19 18:37:49  slapd[85545]: line 61 (rootdn        
"cn=xxx,dc=xxxxxxxx,dc=com")
Feb 19 18:37:49  slapd[85545]: line 66 (rootpw ***)
Feb 19 18:37:49  slapd[85545]: line 71 (TLSCipherSuite HIGH:MEDIUM:+SSLv2)
Feb 19 18:37:49  slapd[85545]: line 72 (TLSVerifyClient allow)
Feb 19 18:37:49  slapd[85545]: line 76 (TLSCACertificateFile 
/usr/local/etc/openldap/certs/cacert.pem)
Feb 19 18:37:49  slapd[85545]: line 80 (TLSCertificateFile 
/usr/local/etc/openldap/certs/ldap.crt.pem)
Feb 19 18:37:49  slapd[85545]: line 81 (TLSCertificateKeyFile 
/usr/local/etc/openldap/certs/ldap.key.pem)
Feb 19 18:37:49  slapd[85545]: line 86 (directory    /var/db/openldap-data)
Feb 19 18:37:49  slapd[85545]: line 89 (index   
objectClass,entryCSN,entryUUID          eq)
Feb 19 18:37:49  slapd[85545]: index objectClass 0x0004
Feb 19 18:37:49  slapd[85545]: index entryCSN 0x0004
Feb 19 18:37:49  slapd[85545]: index entryUUID 0x0004
Feb 19 18:37:50  slapd[85546]: bdb_db_open: "dc=xxxxxxxx,dc=com"
Feb 19 18:37:50  slapd[85546]: slapd starting
Feb 19 18:37:50  slapd[85546]: daemon: added 4r listener=0x0
Feb 19 18:37:50  slapd[85546]: daemon: added 6r listener=0x801839180
Feb 19 18:37:50  slapd[85546]: daemon: added 7r listener=0x801839240
Feb 19 18:37:50  slapd[85546]: daemon: select: listen=6 active_threads=0 
tvp=NULL
Feb 19 18:37:50  slapd[85546]: daemon: select: listen=7 active_threads=0 
tvp=NULL
Feb 19 18:37:50  slapd[85546]: daemon: activity on 1 descriptor
Feb 19 18:37:50  slapd[85546]: daemon: waked
Feb 19 18:37:50  slapd[85546]: daemon: select: listen=6 active_threads=0 
tvp=NULL
Feb 19 18:37:50  slapd[85546]: daemon: select: listen=7 active_threads=0 
tvp=NULL

Any suggestions on getting these errors to actually print?