You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_uri_callback] (6): Constructed uri 'ldap://sssd-devel.sssd.devel'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_send] (4): Executing START TLS
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://sssd-devel.sssd.devel:389] with fd [23].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(objectclass=*)][].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [*]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [altServer]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [namingContexts]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedControl]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedExtension]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedFeatures]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedLDAPVersion]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [defaultNamingContext]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [lastUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [highestCommittedUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 2
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_parse_entry] (9): OriginalDN: [].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_done] (9): Got rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): No known USN scheme is supported by this server!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): Will use modification timestamp as usn!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read method: 28119
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read bufsize: 59384
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [get_crypto_mech_data] (1): Unsupported cipher type
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [nspr_nss_cleanup] (1): Error shutting down connection to NSS [-8053]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_get_authtok] (1): Cannot convert the obfuscated password back to cleartext
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_send] (1): Cannot parse authtok.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [fo_set_port_status] (4): Marking port 389 of server 'sssd-devel.sssd.devel' as 'not working'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_handle_release] (8): Trace: sh[0x97b8c70], connected[1], ops[(nil)], ldap[0x97b8ca8], destructor_lock[0], release_memory[0]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [remove_connection_callback] (9): Successfully removed connection callback.
From the log we can see to following:
- LDAP provider opens a TLS/SSL connection to the server
- LDAP provider fails to decrypt the password
- LDAP provider dies while trying to close the connection
A backtrace shows that the LDAP provider dies in NSS code:
#0 0x009b3a06 in nssTrustDomain_LockCertCache (td=0x0) at tdcache.c:405
#1 0x009af45e in nssCertificate_Destroy (c=0x9829a78) at certificate.c:144
#2 0x009af4be in NSSCertificate_Destroy (c=0x9829a78) at certificate.c:182
#3 0x009ab80c in CERT_DestroyCertificate (cert=0x98289e0) at stanpcertdb.c:753
#4 0x0012daa2 in ssl_ResetSecurityInfo (sec=0x9813d1c, doMemset=0) at sslsecur.c:957
#5 0x0012ddb0 in ssl_DestroySecurityInfo (sec=0x9813d1c) at sslsecur.c:984
#6 0x001318e2 in ssl_DestroySocketContents (ss=0x9813ce8) at sslsock.c:405
#7 0x00132aa4 in ssl_FreeSocket (ss=0x9813ce8) at sslsock.c:478
#8 0x00128bc5 in ssl_DefClose (ss=0x9813ce8) at ssldef.c:233
#9 0x0012df00 in ssl_SecureClose (ss=0x9813ce8) at sslsecur.c:1069
#10 0x00132038 in ssl_Close (fd=0x980e2a8) at sslsock.c:1570
#11 0x001502d2 in PR_Close (fd=0x980e2a8) at ../../../mozilla/nsprpub/pr/src/io/priometh.c:136
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end of sss_password_decrypt(), because it shuts down NSS globally.
description: If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
{{{
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_uri_callback] (6): Constructed uri 'ldap://sssd-devel.sssd.devel'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_send] (4): Executing START TLS
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://sssd-devel.sssd.devel:389] with fd [23].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(objectclass=)][].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: []
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [altServer]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [namingContexts]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedControl]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedExtension]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedFeatures]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedLDAPVersion]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [defaultNamingContext]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [lastUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [highestCommittedUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 2
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_parse_entry] (9): OriginalDN: [].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_done] (9): Got rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): No known USN scheme is supported by this server!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): Will use modification timestamp as usn!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read method: 28119
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read bufsize: 59384
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [get_crypto_mech_data] (1): Unsupported cipher type
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [nspr_nss_cleanup] (1): Error shutting down connection to NSS [-8053]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_get_authtok] (1): Cannot convert the obfuscated password back to cleartext
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_send] (1): Cannot parse authtok.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [fo_set_port_status] (4): Marking port 389 of server 'sssd-devel.sssd.devel' as 'not working'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_handle_release] (8): Trace: sh[0x97b8c70], connected[1], ops[(nil)], ldap[0x97b8ca8], destructor_lock[0], release_memory[0]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [remove_connection_callback] (9): Successfully removed connection callback.
}}}
From the log we can see to following:
LDAP provider opens a TLS/SSL connection to the server
LDAP provider fails to decrypt the password
LDAP provider dies while trying to close the connection
A backtrace shows that the LDAP provider dies in NSS code:
{{{
#0 0x009b3a06 in nssTrustDomain_LockCertCache (td=0x0) at tdcache.c:405 #1 0x009af45e in nssCertificate_Destroy (c=0x9829a78) at certificate.c:144 #2 0x009af4be in NSSCertificate_Destroy (c=0x9829a78) at certificate.c:182 #3 0x009ab80c in CERT_DestroyCertificate (cert=0x98289e0) at stanpcertdb.c:753 #4 0x0012daa2 in ssl_ResetSecurityInfo (sec=0x9813d1c, doMemset=0) at sslsecur.c:957 #5 0x0012ddb0 in ssl_DestroySecurityInfo (sec=0x9813d1c) at sslsecur.c:984 #6 0x001318e2 in ssl_DestroySocketContents (ss=0x9813ce8) at sslsock.c:405 #7 0x00132aa4 in ssl_FreeSocket (ss=0x9813ce8) at sslsock.c:478 #8 0x00128bc5 in ssl_DefClose (ss=0x9813ce8) at ssldef.c:233 #9 0x0012df00 in ssl_SecureClose (ss=0x9813ce8) at sslsecur.c:1069 #10 0x00132038 in ssl_Close (fd=0x980e2a8) at sslsock.c:1570 #11 0x001502d2 in PR_Close (fd=0x980e2a8) at ../../../mozilla/nsprpub/pr/src/io/priometh.c:136
}}}
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end, because it shuts down NSS globally.
=> If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
{{{
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_uri_callback] (6): Constructed uri 'ldap://sssd-devel.sssd.devel'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_send] (4): Executing START TLS
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://sssd-devel.sssd.devel:389] with fd [23].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(objectclass=)][].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: []
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [altServer]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [namingContexts]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedControl]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedExtension]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedFeatures]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedLDAPVersion]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [defaultNamingContext]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [lastUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [highestCommittedUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 2
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_parse_entry] (9): OriginalDN: [].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_done] (9): Got rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): No known USN scheme is supported by this server!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): Will use modification timestamp as usn!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read method: 28119
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read bufsize: 59384
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [get_crypto_mech_data] (1): Unsupported cipher type
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [nspr_nss_cleanup] (1): Error shutting down connection to NSS [-8053]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_get_authtok] (1): Cannot convert the obfuscated password back to cleartext
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_send] (1): Cannot parse authtok.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [fo_set_port_status] (4): Marking port 389 of server 'sssd-devel.sssd.devel' as 'not working'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_handle_release] (8): Trace: sh[0x97b8c70], connected[1], ops[(nil)], ldap[0x97b8ca8], destructor_lock[0], release_memory[0]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [remove_connection_callback] (9): Successfully removed connection callback.
}}}
From the log we can see to following:
LDAP provider opens a TLS/SSL connection to the server
LDAP provider fails to decrypt the password
LDAP provider dies while trying to close the connection
A backtrace shows that the LDAP provider dies in NSS code:
{{{
#0 0x009b3a06 in nssTrustDomain_LockCertCache (td=0x0) at tdcache.c:405 #1 0x009af45e in nssCertificate_Destroy (c=0x9829a78) at certificate.c:144 #2 0x009af4be in NSSCertificate_Destroy (c=0x9829a78) at certificate.c:182 #3 0x009ab80c in CERT_DestroyCertificate (cert=0x98289e0) at stanpcertdb.c:753 #4 0x0012daa2 in ssl_ResetSecurityInfo (sec=0x9813d1c, doMemset=0) at sslsecur.c:957 #5 0x0012ddb0 in ssl_DestroySecurityInfo (sec=0x9813d1c) at sslsecur.c:984 #6 0x001318e2 in ssl_DestroySocketContents (ss=0x9813ce8) at sslsock.c:405 #7 0x00132aa4 in ssl_FreeSocket (ss=0x9813ce8) at sslsock.c:478 #8 0x00128bc5 in ssl_DefClose (ss=0x9813ce8) at ssldef.c:233 #9 0x0012df00 in ssl_SecureClose (ss=0x9813ce8) at sslsecur.c:1069 #10 0x00132038 in ssl_Close (fd=0x980e2a8) at sslsock.c:1570 #11 0x001502d2 in PR_Close (fd=0x980e2a8) at ../../../mozilla/nsprpub/pr/src/io/priometh.c:136
}}}
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end of sss_password_decrypt(), because it shuts down NSS globally.
This fix does not remove the call to nspr_nss_cleanup(), but converts the obfuscated password only once at startup before any TLS/SSL operations. This way both operations cannot interfere.
Cloned from Pagure issue: https://pagure.io/SSSD/sssd/issue/762
If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
From the log we can see to following:
- LDAP provider opens a TLS/SSL connection to the server
- LDAP provider fails to decrypt the password
- LDAP provider dies while trying to close the connection
A backtrace shows that the LDAP provider dies in NSS code:
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end of sss_password_decrypt(), because it shuts down NSS globally.
Comments
Comment from sbose at 2011-01-05 11:58:12
Fields changed
description: If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
{{{
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_uri_callback] (6): Constructed uri 'ldap://sssd-devel.sssd.devel'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_send] (4): Executing START TLS
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://sssd-devel.sssd.devel:389] with fd [23].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(objectclass=)][].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: []
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [altServer]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [namingContexts]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedControl]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedExtension]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedFeatures]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedLDAPVersion]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [defaultNamingContext]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [lastUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [highestCommittedUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 2
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_parse_entry] (9): OriginalDN: [].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_done] (9): Got rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): No known USN scheme is supported by this server!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): Will use modification timestamp as usn!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read method: 28119
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read bufsize: 59384
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [get_crypto_mech_data] (1): Unsupported cipher type
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [nspr_nss_cleanup] (1): Error shutting down connection to NSS [-8053]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_get_authtok] (1): Cannot convert the obfuscated password back to cleartext
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_send] (1): Cannot parse authtok.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [fo_set_port_status] (4): Marking port 389 of server 'sssd-devel.sssd.devel' as 'not working'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_handle_release] (8): Trace: sh[0x97b8c70], connected[1], ops[(nil)], ldap[0x97b8ca8], destructor_lock[0], release_memory[0]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [remove_connection_callback] (9): Successfully removed connection callback.
}}}
From the log we can see to following:
A backtrace shows that the LDAP provider dies in NSS code:
{{{
#0 0x009b3a06 in nssTrustDomain_LockCertCache (td=0x0) at tdcache.c:405
#1 0x009af45e in nssCertificate_Destroy (c=0x9829a78) at certificate.c:144
#2 0x009af4be in NSSCertificate_Destroy (c=0x9829a78) at certificate.c:182
#3 0x009ab80c in CERT_DestroyCertificate (cert=0x98289e0) at stanpcertdb.c:753
#4 0x0012daa2 in ssl_ResetSecurityInfo (sec=0x9813d1c, doMemset=0) at sslsecur.c:957
#5 0x0012ddb0 in ssl_DestroySecurityInfo (sec=0x9813d1c) at sslsecur.c:984
#6 0x001318e2 in ssl_DestroySocketContents (ss=0x9813ce8) at sslsock.c:405
#7 0x00132aa4 in ssl_FreeSocket (ss=0x9813ce8) at sslsock.c:478
#8 0x00128bc5 in ssl_DefClose (ss=0x9813ce8) at ssldef.c:233
#9 0x0012df00 in ssl_SecureClose (ss=0x9813ce8) at sslsecur.c:1069
#10 0x00132038 in ssl_Close (fd=0x980e2a8) at sslsock.c:1570
#11 0x001502d2 in PR_Close (fd=0x980e2a8) at ../../../mozilla/nsprpub/pr/src/io/priometh.c:136
}}}
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end, because it shuts down NSS globally.
=> If the obfuscated password cannot be decrypted, e.g. because by accident the clear text password was entered, the LDAP provider will die if TLS/SSL are used for id operations.
{{{
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_uri_callback] (6): Constructed uri 'ldap://sssd-devel.sssd.devel'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_send] (4): Executing START TLS
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_ldap_connect_callback_add] (9): New LDAP connection to [ldap://sssd-devel.sssd.devel:389] with fd [23].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_connect_done] (3): START TLS result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_send] (9): Getting rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (6): calling ldap_search_ext with [(objectclass=)][].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: []
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [altServer]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [namingContexts]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedControl]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedExtension]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedFeatures]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedLDAPVersion]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [supportedSASLMechanisms]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [defaultNamingContext]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [lastUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (7): Requesting attrs: [highestCommittedUSN]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_send] (8): ldap_search_ext called, msgid = 2
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: ldap_result found nothing!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_parse_entry] (9): OriginalDN: [].
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_process_result] (8): Trace: sh[0x97b8c70], connected[1], ops[0x97c23f8], ldap[0x97b8ca8]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_generic_done] (6): Search result: Success(0), (null)
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_rootdse_done] (9): Got rootdse
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): No known USN scheme is supported by this server!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_get_server_opts_from_rootdse] (5): Will use modification timestamp as usn!
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read method: 28119
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sss_password_decrypt] (8): Read bufsize: 59384
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [get_crypto_mech_data] (1): Unsupported cipher type
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [nspr_nss_cleanup] (1): Error shutting down connection to NSS [-8053]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_get_authtok] (1): Cannot convert the obfuscated password back to cleartext
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_auth_send] (1): Cannot parse authtok.
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [fo_set_port_status] (4): Marking port 389 of server 'sssd-devel.sssd.devel' as 'not working'
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [sdap_handle_release] (8): Trace: sh[0x97b8c70], connected[1], ops[(nil)], ldap[0x97b8ca8], destructor_lock[0], release_memory[0]
(Wed Jan 5 11:27:06 2011) [sssd[be[SSSD.DEVEL-LDAPONLY]]] [remove_connection_callback] (9): Successfully removed connection callback.
}}}
From the log we can see to following:
A backtrace shows that the LDAP provider dies in NSS code:
{{{
#0 0x009b3a06 in nssTrustDomain_LockCertCache (td=0x0) at tdcache.c:405
#1 0x009af45e in nssCertificate_Destroy (c=0x9829a78) at certificate.c:144
#2 0x009af4be in NSSCertificate_Destroy (c=0x9829a78) at certificate.c:182
#3 0x009ab80c in CERT_DestroyCertificate (cert=0x98289e0) at stanpcertdb.c:753
#4 0x0012daa2 in ssl_ResetSecurityInfo (sec=0x9813d1c, doMemset=0) at sslsecur.c:957
#5 0x0012ddb0 in ssl_DestroySecurityInfo (sec=0x9813d1c) at sslsecur.c:984
#6 0x001318e2 in ssl_DestroySocketContents (ss=0x9813ce8) at sslsock.c:405
#7 0x00132aa4 in ssl_FreeSocket (ss=0x9813ce8) at sslsock.c:478
#8 0x00128bc5 in ssl_DefClose (ss=0x9813ce8) at ssldef.c:233
#9 0x0012df00 in ssl_SecureClose (ss=0x9813ce8) at sslsecur.c:1069
#10 0x00132038 in ssl_Close (fd=0x980e2a8) at sslsock.c:1570
#11 0x001502d2 in PR_Close (fd=0x980e2a8) at ../../../mozilla/nsprpub/pr/src/io/priometh.c:136
}}}
This will also happen if a wrong password is encoded correctly or even if the right password is encoded correctly and the LDAP provider tries to close the connection, e.g. when going offline. But only on systems where OpenLDAP uses NSS for TLS/SSL.
I think the culprit is the nspr_nss_cleanup() call at the end of sss_password_decrypt(), because it shuts down NSS globally.
Comment from gowrishankar at 2011-01-05 12:17:53
https://bugzilla.redhat.com/show_bug.cgi?id=667349
Comment from sgallagh at 2011-01-05 14:30:21
Fields changed
milestone: NEEDS_TRIAGE => SSSD 1.5.1
Comment from sgallagh at 2011-01-05 14:32:57
Fields changed
owner: somebody => sbose
Comment from sbose at 2011-01-07 09:45:25
Fixed by 52b703a
This fix does not remove the call to nspr_nss_cleanup(), but converts the obfuscated password only once at startup before any TLS/SSL operations. This way both operations cannot interfere.
resolution: => fixed
status: new => closed
Comment from dpal at 2012-01-19 03:03:32
Fields changed
rhbz: => 0
Comment from sbose at 2017-02-24 14:40:56
Metadata Update from @sbose:
The text was updated successfully, but these errors were encountered: