Full_Name: Brian A. Seklecki Version: 2.4.21 OS: FreeBSD, Linux, Plan 9, CP/M, Bubble Memory URL: ftp://ftp.openldap.org/incoming/ Submission from: (NULL) (2607:f000:10:202:21a:a0ff:fec2:7a6c) I'll try not to be ambiguous in my bug report. We received a support request escalation regarding an ambiguous error printed by slapd(8) at init. After review, we found that SSL library calls in OpenLDAP are not properly reporting back to the user fopen() problems when TLSCert* configuration objects are unreadable by the effective POSIX user. E.g., when a private key/cert/intermediary cert chain has POSIX permissions restricting read access by "-u $USER", the following error is printed: User Steve Polyack reports a similar error here: http://www.openldap.org/lists/openldap-software/201002/msg00025.html Also Google says: Results 1-10 of about 1,730 for "main: TLS init def ctx failed: -1". Some of these result all the back to early 2003 If you look at mailing list archives, similar error reports appear thousands of times from confused users who thought they were being diligent in by setting restrictive permissions only to receive an ambiguous error that indicates nothing about excessively restrictive permissions. The problem is that this error gets printed with "-1" under too many conditions in libraries/libldap/tls2.c::ldap_pvt_tls_set_option() ...which in turn sets rc= in servers/slapd/main.c: Which prints: 2010 Feb 5 10:52:34 -08:00 host [slapd][6261] [local4] [debug] slapd[6261]: main: TLS init def ctx failed: -1 So unless you've browsed through the OpenSSL API guide, you wouldn't even know what the CTX data structure is or how it relates to this. They do a pretty shitty job of explaining it even, so why bother mentioning it? Anyway, until we can implement OpenSSL's err(3) framework, we should refer to the user to ssl.h for RC values from ldap_pvt_tls_set_option() greater than 0. For errors, greater than 1, ldap_pvt_tls_set_option() can return that in about 15 different locations. It _could also_ pass on a -1 return code from ldap_int_tls_init_ctx () at: return ldap_int_tls_init_ctx( lo, *(int *)arg ); There are no shortage of places where where -1 could be returned to user in our code, so we should make -1 return codes other negative values to nudge the user along. Additional Debug() statements would be useful, but I don't want to get greedy. ~BAS ----------------- These patches compile-test. I'll push them into our pre-production environment: $ diff -u servers/slapd/main.c-orig servers/slapd/main.c --- servers/slapd/main.c-orig 2010-02-18 16:52:37.000000000 -0500 +++ servers/slapd/main.c 2010-02-18 16:57:30.000000000 -0500 @@ -843,8 +843,16 @@ load_extop( &slap_EXOP_START_TLS, 0, starttls_extop ); } else if ( rc != LDAP_NOT_SUPPORTED ) { Debug( LDAP_DEBUG_ANY, - "main: TLS init def ctx failed: %d\n", + "main: TLS initialization of def SSL/TLS CTX object failed with err: %d\n", rc, 0, 0 ); + + 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 add err(3) support.\n", rc, 0, 0); + } + rc = 1; SERVICE_EXIT( ERROR_SERVICE_SPECIFIC_ERROR, 20 ); goto destroy; $ diff -u ./libraries/libldap/tls2.c-orig ./libraries/libldap/tls2.c --- ./libraries/libldap/tls2.c-orig 2010-02-18 17:14:59.000000000 -0500 +++ ./libraries/libldap/tls2.c 2010-02-18 17:16:25.000000000 -0500 @@ -704,7 +704,7 @@ switch( option ) { case LDAP_OPT_X_TLS: - if ( !arg ) return -1; + if ( !arg ) return -2; switch( *(int *) arg ) { case LDAP_OPT_X_TLS_NEVER: @@ -718,7 +718,7 @@ return 0; } - return -1; + return -3; case LDAP_OPT_X_TLS_CTX: if ( lo->ldo_tls_ctx ) @@ -757,7 +757,7 @@ lo->ldo_tls_crlfile = arg ? LDAP_STRDUP( (char *) arg ) : NULL; return 0; case LDAP_OPT_X_TLS_REQUIRE_CERT: - if ( !arg ) return -1; + if ( !arg ) return -3; switch( *(int *) arg ) { case LDAP_OPT_X_TLS_NEVER: case LDAP_OPT_X_TLS_DEMAND: @@ -767,10 +767,10 @@ lo->ldo_tls_require_cert = * (int *) arg; return 0; } - return -1; + return -4; #ifdef HAVE_OPENSSL_CRL case LDAP_OPT_X_TLS_CRLCHECK: /* OpenSSL only */ - if ( !arg ) return -1; + if ( !arg ) return -5; switch( *(int *) arg ) { case LDAP_OPT_X_TLS_CRL_NONE: case LDAP_OPT_X_TLS_CRL_PEER: @@ -778,7 +778,7 @@ lo->ldo_tls_crlcheck = * (int *) arg; return 0; } - return -1; + return -6; #endif case LDAP_OPT_X_TLS_CIPHER_SUITE: if ( lo->ldo_tls_ciphersuite ) LDAP_FREE( lo->ldo_tls_ciphersuite ); @@ -786,17 +786,17 @@ return 0; case LDAP_OPT_X_TLS_PROTOCOL_MIN: - if ( !arg ) return -1; + if ( !arg ) return -7; lo->ldo_tls_protocol_min = *(int *)arg; return 0; case LDAP_OPT_X_TLS_RANDOM_FILE: if ( ld != NULL ) - return -1; + return -8; if ( lo->ldo_tls_randfile ) LDAP_FREE (lo->ldo_tls_randfile ); lo->ldo_tls_randfile = arg ? LDAP_STRDUP( (char *) arg ) : NULL; break; case LDAP_OPT_X_TLS_NEWCTX: - if ( !arg ) return -1; + if ( !arg ) return -9; if ( lo->ldo_tls_ctx ) ldap_pvt_tls_ctx_free( lo->ldo_tls_ctx ); lo->ldo_tls_ctx = NULL;
changed state Open to Suspended
changed notes changed state Suspended to Open
After some chatter on the mailing list, the problem is now understood: - TLS error messages are indeed reported by OpenLDAP: TLS: could not use key file `/usr/local/etc/openldap/certs/ldap.key.pem'. TLS: error:0200100D:system library:fopen:Permission denied /usr/src/secure/lib/libcrypto/../../../crypto/openssl/crypto/bio/bss_file.c:356 TLS: error:20074002:BIO routines:FILE_CTRL:system lib /usr/src/secure/lib/libcrypto/../../../crypto/openssl/crypto/bio/bss_file.c:358 TLS: error:140B0002:SSL routines:SSL_CTX_use_PrivateKey_file:system lib /usr/src/secure/lib/libssl/../../../crypto/openssl/ssl/ssl_rsa.c:648 - The only way to see these error messages is to start the daemon with '-d stats' -- Setting 'loglevel stats' in slapd.conf will not cause these error messages to be printed. They only appear if the daemon is started in foreground mode with '-d stats'. My suggestions: print the TLS error messages out to syslog, or if that's not possible, print them to stdout regardless of whether the daemon is running in the foreground or not.
On Mon, 2010-03-08 at 16:19 +0000, korvus@comcast.net wrote: > After some chatter on the mailing list, the problem is now understood: > - TLS error messages are indeed reported by OpenLDAP: > TLS: could not use key file `/usr/local/etc/openldap/certs/ldap.key.pem'. ... > - The only way to see these error messages is to start the daemon with > '-d stats' ... > My suggestions: print the TLS error messages out to syslog, or if that's > not possible, print them to stdout regardless of whether the daemon is > running in the foreground or not. Isn't it in local4.* ?
tjoen wrote: >On Mon, 2010-03-08 at 16:19 +0000, korvus@comcast.net wrote: >> After some chatter on the mailing list, the problem is now understood: >> - TLS error messages are indeed reported by OpenLDAP: >> TLS: could not use key file `/usr/local/etc/openldap/certs/ldap.key.pem'. >... >> - The only way to see these error messages is to start the daemon with >> '-d stats' >... >> My suggestions: print the TLS error messages out to syslog, or if that's >> not possible, print them to stdout regardless of whether the daemon is >> running in the foreground or not. > >Isn't it in local4.* ? > No, they do not get sent to local4.* - the only TLS message which makes it there in this scenario is: slapd[72041]: main: TLS init def ctx failed: -1 Like I said, the ONLY way to get the actual TLS error messages is to run the daemon by hand in the foreground with loglevel stats by way of 'slapd -d stats'. Per the manpage this also prevents slapd from forking: -d debug-level Turn on debugging as defined by debug-level. If this option is specified, even with a zero argument, slapd will not fork or disassociate from the invoking terminal. Let me know if I'm still not being clear.
--On Wednesday, March 17, 2010 8:17 PM +0000 korvus@comcast.net wrote: > tjoen wrote: >> On Mon, 2010-03-08 at 16:19 +0000, korvus@comcast.net wrote: >>> After some chatter on the mailing list, the problem is now understood: >>> - TLS error messages are indeed reported by OpenLDAP: >>> TLS: could not use key file >>> `/usr/local/etc/openldap/certs/ldap.key.pem'. >> ... >>> - The only way to see these error messages is to start the daemon with >>> '-d stats' >> ... >>> My suggestions: print the TLS error messages out to syslog, or if >>> that's not possible, print them to stdout regardless of whether the >>> daemon is running in the foreground or not. >> >> Isn't it in local4.* ? >> > > No, they do not get sent to local4.* - the only TLS message which makes > it there in this scenario is: slapd[72041]: main: TLS init def ctx > failed: -1 > > Like I said, the ONLY way to get the actual TLS error messages is to run > the daemon by hand in the foreground with loglevel stats by way of 'slapd > -d stats'. Per the manpage this also prevents slapd from forking: > -d debug-level > Turn on debugging as defined by debug-level. If this > option is specified, even with a zero argument, slapd > will not fork or disassociate from the invoking > terminal. > > > Let me know if I'm still not being clear. If you are trying to debug an issue, you most certainly should be running slapd -d <level>... that's why it exists. --Quanah -- Quanah Gibson-Mount Principal Software Engineer Zimbra, Inc -------------------- Zimbra :: the leader in open source messaging and collaboration
On 3/17/2010 9:25 PM, Quanah Gibson-Mount wrote: > --On Wednesday, March 17, 2010 8:17 PM +0000 korvus@comcast.net wrote: > >> tjoen wrote: >>> On Mon, 2010-03-08 at 16:19 +0000, korvus@comcast.net wrote: >>>> After some chatter on the mailing list, the problem is now >>>> understood: >>>> - TLS error messages are indeed reported by OpenLDAP: >>>> TLS: could not use key file >>>> `/usr/local/etc/openldap/certs/ldap.key.pem'. >>> ... >>>> - The only way to see these error messages is to start the daemon >>>> with >>>> '-d stats' >>> ... >>>> My suggestions: print the TLS error messages out to syslog, or if >>>> that's not possible, print them to stdout regardless of whether the >>>> daemon is running in the foreground or not. >>> >>> Isn't it in local4.* ? >>> >> >> No, they do not get sent to local4.* - the only TLS message which makes >> it there in this scenario is: slapd[72041]: main: TLS init def ctx >> failed: -1 >> >> Like I said, the ONLY way to get the actual TLS error messages is to run >> the daemon by hand in the foreground with loglevel stats by way of >> 'slapd >> -d stats'. Per the manpage this also prevents slapd from forking: >> -d debug-level >> Turn on debugging as defined by debug-level. If this >> option is specified, even with a zero argument, slapd >> will not fork or disassociate from the invoking >> terminal. >> >> >> Let me know if I'm still not being clear. > > If you are trying to debug an issue, you most certainly should be > running slapd -d <level>... that's why it exists. > > --Quanah > That's a valid point. However, it does not explain why the TLS errors aren't (or "shouldn't be") logged via syslog.
changed notes
TLS (libldap) logs don't get to syslog
moved from Incoming to Software Enhancements
*** This issue has been marked as a duplicate of issue 9157 ***