When SSSD is started with a debug level that should show failures, lots of messages that have nothing to do with failure show up. This obscures the actual problems. I'll submit some patches to reassign some of the messages to the correct locations. Example: [root@stef-desktop data]# /usr/sbin/sssd -d 0x00F0 -i (Tue Apr 10 09:08:01:333969 2012) [sssd] [check_file] (0x0020): lstat for [/var/run/nscd/socket] failed: [2][No such file or directory]. (Tue Apr 10 09:08:01:335171 2012) [sssd] [confdb_get_domain_internal] (0x0020): No enumeration for [ad.thewalter.lan]! (Tue Apr 10 09:08:01 2012) [sssd] [server_setup] (0x0080): CONFDB: /var/lib/sss/db/config.ldb (Tue Apr 10 09:08:01 2012) [sssd] [sbus_new_server] (0x0080): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-monitor,guid=eab88a161d7b3ba30f5012f300001624 (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [server_setup] (0x0080): CONFDB: /var/lib/sss/db/config.ldb (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_context_init] (0x0080): Created new fail over context, retry timeout is 30 (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [confdb_get_domain_internal] (0x0020): No enumeration for [ad.thewalter.lan]! (Tue Apr 10 09:08:01 2012) [sssd] [monitor_service_init] (0x0080): Initializing D-BUS Service (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [sbus_new_server] (0x0080): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-dp_ad.thewalter.lan.12534,guid=62df5fee35e9244dbc19011900001624 (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [sssm_ldap_id_init] (0x0020): Missing ldap_uri, will use service discovery (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_new_service] (0x0080): Creating new service 'LDAP' (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'LDAP' using tcp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [sdap_gssapi_init] (0x0020): Missing krb5_server option, using service discovery! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_new_service] (0x0080): Creating new service 'KERBEROS' (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KERBEROS' using udp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KERBEROS' using tcp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [find_principal_in_keytab] (0x0080): No principal matching stef-desktop.thewalter.lan$@AD.THEWALTER.LAN found in keytab. (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [sssm_krb5_auth_init] (0x0020): Missing krb5_server option, using service discovery! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KERBEROS' using udp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KERBEROS' using tcp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_new_service] (0x0080): Creating new service 'KPASSWD' (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KPASSWD' using udp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [fo_add_srv_server] (0x0080): Adding new SRV server in domain 'unknown', to service 'KPASSWD' using tcp (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [check_and_export_options] (0x0020): No KDC explicitly configured, using defaults. (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [check_and_export_options] (0x0020): No kpasswd server explicitly configured, using the KDC or defaults. (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [ldap_get_autofs_options] (0x0040): Error: no autofs search base set (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [load_backend_module] (0x0010): Error (2) in module (ldap) initialization (sssm_ldap_autofs_init)! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [be_process_init] (0x0080): No autofs module provided for [ad.thewalter.lan] !! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [be_process_init] (0x0020): No Session module provided for [ad.thewalter.lan] !! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [be_process_init] (0x0020): No host info module provided for [ad.thewalter.lan] !! (Tue Apr 10 09:08:01 2012) [sssd[be[ad.thewalter.lan]]] [main] (0x0020): Backend provider (ad.thewalter.lan) started! (Tue Apr 10 09:08:01 2012) [sssd[nss]] [server_setup] (0x0080): (Tue Apr 10 09:08:01 2012) [sssd[pam]] [server_setup] (0x0080): CONFDB: /var/lib/sss/db/config.ldb CONFDB: /var/lib/sss/db/config.ldb (Tue Apr 10 09:08:01 2012) [sssd[pam]] [confdb_get_domain_internal] (0x0020): No enumeration for [ad.thewalter.lan]! (Tue Apr 10 09:08:01 2012) [sssd[nss]] [confdb_get_domain_internal] (0x0020): No enumeration for [ad.thewalter.lan]! (Tue Apr 10 09:08:01 2012) [sssd] [monitor_service_init] (0x0080): Initializing D-BUS Service (Tue Apr 10 09:08:01 2012) [sssd[pam]] [sss_process_init] (0x0020): Responder Initialization complete (Tue Apr 10 09:08:01 2012) [sssd] [monitor_service_init] (0x0080): Initializing D-BUS Service (Tue Apr 10 09:08:01 2012) [sssd[nss]] [sss_process_init] (0x0020): Responder Initialization complete (Tue Apr 10 09:08:01 2012) [sssd[nss]] [nss_process_init] (0x0020): NSS Initialization complete
Upstream ticket: https://fedorahosted.org/sssd/ticket/1294
(In reply to comment #0) > When SSSD is started with a debug level that should show failures, lots of > messages that have nothing to do with failure show up. This obscures the actual > problems. > Many of the DEBUG statements, especially in code that hasn't been touched for some time, still use the old numeric levels. Changing them to the new debug levels (SSSDBG_*) would certainly be welcome. > I'll submit some patches to reassign some of the messages to the correct > locations. > Thank you. See https://fedorahosted.org/pipermail/sssd-devel/2011-June/006420.html for a short explanation of the different log levels.
Created attachment 577074 [details] Move some debug lines to new debug log levels * These are common lines of debug output when starting up sssd Comments on some of the changes: This isn't an error, legitimate configuration: + DEBUG(SSSDBG_TRACE_FUNC, ("No enumeration for [%s]!\n", domain->name)); Not errors, using service discovery is 'best' practice: + DEBUG(SSSDBG_TRACE_FUNC, ("No KDC explicitly configured, using defaults.\n")); + DEBUG(SSSDBG_TRACE_FUNC, ("No kpasswd server explicitly configured, " + "using the KDC or defaults.\n")); + DEBUG(SSSDBG_TRACE_FUNC, ("Missing krb5_server option, using service discovery!\n + DEBUG(SSSDBG_TRACE_FUNC, ("Missing krb5_server option, using service discovery!\n + DEBUG(SSSDBG_TRACE_FUNC, ("Missing ldap_uri, will use service discovery\n")); Describe where the pid file failed to be created: + DEBUG(0, ("Error creating pidfile: %s/%s! (%d [%s])\n", + PID_PATH, name, ret, strerror(ret))); In cases where this is an error, caller prints out a relevant message: - DEBUG(SSSDBG_MINOR_FAILURE, + DEBUG(SSSDBG_TRACE_FUNC, ("No principal matching %s@%s found in keytab.\n", pattern_primary, pattern_realm)); This is expected to fail in many cases. In cases where this is an error caller prints out a relevant message: - DEBUG(1, ("lstat for [%s] failed: [%d][%s].\n", filename, errno, - strerror(errno))); + DEBUG(SSSDBG_TRACE_FUNC, ("lstat for [%s] failed: [%d][%s].\n", filename, errno, + strerror(errno)))
(In reply to comment #3) > Created attachment 577074 [details] > Move some debug lines to new debug log levels > > * These are common lines of debug output when starting > up sssd > > Comments on some of the changes: > > This isn't an error, legitimate configuration: > + DEBUG(SSSDBG_TRACE_FUNC, ("No enumeration for [%s]!\n", > domain->name)); > > Not errors, using service discovery is 'best' practice: > + DEBUG(SSSDBG_TRACE_FUNC, ("No KDC explicitly configured, using > defaults.\n")); > + DEBUG(SSSDBG_TRACE_FUNC, ("No kpasswd server explicitly configured, " > + "using the KDC or defaults.\n")); > + DEBUG(SSSDBG_TRACE_FUNC, ("Missing krb5_server option, using service > discovery!\n > + DEBUG(SSSDBG_TRACE_FUNC, ("Missing krb5_server option, using service > discovery!\n > + DEBUG(SSSDBG_TRACE_FUNC, ("Missing ldap_uri, will use service > discovery\n")); > All of the above should be SSSDBG_CONF_SETTINGS, not SSSDBG_TRACE_FUNC > Describe where the pid file failed to be created: > + DEBUG(0, ("Error creating pidfile: %s/%s! (%d [%s])\n", > + PID_PATH, name, ret, strerror(ret))); > Please do not add numeric debug levels. In this case it should be SSSDBG_FATAL_FAILURE because this error prevents the entire system from working. > In cases where this is an error, caller prints out a relevant message: > - DEBUG(SSSDBG_MINOR_FAILURE, > + DEBUG(SSSDBG_TRACE_FUNC, > ("No principal matching %s@%s found in keytab.\n", > pattern_primary, pattern_realm)); > Looks right. > This is expected to fail in many cases. In cases where this is an error > caller prints out a relevant message: > - DEBUG(1, ("lstat for [%s] failed: [%d][%s].\n", filename, errno, > - strerror(errno))); > + DEBUG(SSSDBG_TRACE_FUNC, ("lstat for [%s] failed: [%d][%s].\n", > filename, errno, > + > strerror(errno))) Looks right. I haven't reviewed the rest of the patch yet.
Created attachment 577155 [details] Updated for Stephen's initial review Move some debug lines to new debug log levels * These are common lines of debug output when starting up sssd
This bug appears to have been reported against 'rawhide' during the Fedora 19 development cycle. Changing version to '19'. (As we did not run this process for some time, it could affect also pre-Fedora 19 development cycle bugs. We are very sorry. It will help us with cleanup during Fedora 19 End Of Life. Thank you.) More information and reason for this action is here: https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora19
This message is a notice that Fedora 19 is now at end of life. Fedora has stopped maintaining and issuing updates for Fedora 19. It is Fedora's policy to close all bug reports from releases that are no longer maintained. Approximately 4 (four) weeks from now this bug will be closed as EOL if it remains open with a Fedora 'version' of '19'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 19 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Still an issue, planned for next upstream version.
This bug appears to have been reported against 'rawhide' during the Fedora 23 development cycle. Changing version to '23'. (As we did not run this process for some time, it could affect also pre-Fedora 23 development cycle bugs. We are very sorry. It will help us with cleanup during Fedora 23 End Of Life. Thank you.) More information and reason for this action is here: https://fedoraproject.org/wiki/BugZappers/HouseKeeping/Fedora23
This message is a reminder that Fedora 23 is nearing its end of life. Approximately 4 (four) weeks from now Fedora will stop maintaining and issuing updates for Fedora 23. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '23'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 23 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
This bug appears to have been reported against 'rawhide' during the Fedora 26 development cycle. Changing version to '26'.
As this is an RFE that we've been already tracking in our pagure I'm closing this bug as "UPSTREAM". For more details, please, feel free to follow: https://pagure.io/SSSD/sssd/issue/1294 If, for some reason, there's the need to re-open this bug, feel free to do so.