Bug 1820586 - sssd.service failed to start
Summary: sssd.service failed to start
Keywords:
Status: CLOSED WORKSFORME
Alias: None
Product: Fedora
Classification: Fedora
Component: sssd
Version: 32
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: Sumit Bose
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-04-03 12:23 UTC by ersen
Modified: 2020-05-26 17:59 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2020-05-22 05:16:12 UTC
Type: Bug


Attachments (Terms of Use)
requested file in #20 (337.70 KB, text/plain)
2020-04-06 12:28 UTC, ersen
no flags Details

Description ersen 2020-04-03 12:23:53 UTC
Description of problem:
sssd.service fails to start at Fedora 32.

Nis 03 12:45:30 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Start request repeated too quickly.
Nis 03 12:45:30 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 5.
Nis 03 12:45:30 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nis 03 12:45:30 localhost.localdomain sssd[1717]: Starting up
Nis 03 12:45:30 localhost.localdomain systemd[1]: Starting System Security Services Daemon...
Nis 03 12:45:30 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 4.
Nis 03 12:45:30 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nis 03 12:45:30 localhost.localdomain sssd[1679]: Starting up
Nis 03 12:45:30 localhost.localdomain systemd[1]: Starting System Security Services Daemon...
Nis 03 12:45:30 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 3.
Nis 03 12:45:29 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nis 03 12:45:29 localhost.localdomain sssd[1618]: Starting up
Nis 03 12:45:29 localhost.localdomain systemd[1]: Starting System Security Services Daemon...
Nis 03 12:45:29 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 2.
Nis 03 12:45:29 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nis 03 12:45:29 localhost.localdomain sssd[1510]: Starting up
Nis 03 12:45:29 localhost.localdomain systemd[1]: Starting System Security Services Daemon...
Nis 03 12:45:29 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 1.
Nis 03 12:45:29 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
Nis 03 12:45:29 localhost.localdomain systemd[1]: sssd.service: Main process exited, code=exited, status=4/NOPERMISSION
Nis 03 12:45:29 localhost.localdomain sssd[1440]: Starting up
Nis 03 12:45:28 localhost.localdomain systemd[1]: Starting System Security Services Daemon...


Version-Release number of selected component (if applicable):
sssd 2.2.3-13.fc32
systemd 245.4-1.fc32


How reproducible:
Always

Steps to Reproduce:
1. Boot the system
2. Check `systemctl status sssd.service`

Actual results: failed


Expected results: active (running)


Additional info:

Comment 1 Sumit Bose 2020-04-03 15:43:31 UTC
Hi,

so far I cannot reproduce the behavior. Can you share your /etc/sssd/sssd.conf? It might also help to understand what's wrong if you can add 'debug_level = 9' to the [sssd] section of sssd.conf and restart SSSD, /var/log/sssd/sssd.log should now contain more details.

bye,
Sumit

Comment 2 Lukas Slebodnik 2020-04-03 16:05:52 UTC
(In reply to ersen from comment #0)
> Description of problem:
> sssd.service fails to start at Fedora 32.
> 
> Nis 03 12:45:30 localhost.localdomain systemd[1]: Failed to start System
> Security Services Daemon.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Failed with
> result 'exit-code'.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Start
> request repeated too quickly.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: Stopped System Security
> Services Daemon.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Scheduled
> restart job, restart counter is at 5.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: Failed to start System
> Security Services Daemon.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Failed with
> result 'exit-code'.
> Nis 03 12:45:30 localhost.localdomain systemd[1]: sssd.service: Main process
> exited, code=exited, status=4/NOPERMISSION

Return code 4 is returned in case of issues with configuration.
Maybe you have wrong permissions on /etc/sssd/sssd.conf or files in /etc/sssd/conf.d/

It has to be "600" read/write to owner

Comment 3 ersen 2020-04-03 16:07:47 UTC
I don't have a "sssd.conf" file in the "/etc/sssd" directory. I have 2 directory in the "/etc/sssd" directory, "conf.d" and "pki", both are empty. This is a system upgraded from fedora 31 to 32 using system-upgrade plugin.

Comment 4 Lukas Slebodnik 2020-04-03 16:10:34 UTC
(In reply to ersen from comment #3)
> I don't have a "sssd.conf" file in the "/etc/sssd" directory. I have 2
> directory in the "/etc/sssd" directory, "conf.d" and "pki", both are empty.
> This is a system upgraded from fedora 31 to 32 using system-upgrade plugin.

can you see some AVCs?

Which version of sssd and libldb did you have on f31 and which versions do you have now?

Comment 5 Lukas Slebodnik 2020-04-03 16:11:09 UTC
(In reply to Lukas Slebodnik from comment #4)
> (In reply to ersen from comment #3)
> > I don't have a "sssd.conf" file in the "/etc/sssd" directory. I have 2
> > directory in the "/etc/sssd" directory, "conf.d" and "pki", both are empty.
> > This is a system upgraded from fedora 31 to 32 using system-upgrade plugin.
> 
> can you see some AVCs?
> 
> Which version of sssd and libldb did you have on f31 and which versions do
> you have now?

you might have just sssd-common on your system instead of sssd package

Comment 6 ersen 2020-04-03 16:16:41 UTC
packages I have now:
libldb.x86_64                                                                                                          2.1.1-1.fc32                                                                                            @fedora        
sssd.x86_64                                                                                                            2.2.3-13.fc32                                                                                           @fedora        
sssd-ad.x86_64                                                                                                         2.2.3-13.fc32                                                                                           @fedora        
sssd-client.x86_64                                                                                                     2.2.3-13.fc32                                                                                           @fedora        
sssd-common.x86_64                                                                                                     2.2.3-13.fc32                                                                                           @fedora        
sssd-common-pac.x86_64                                                                                                 2.2.3-13.fc32                                                                                           @fedora        
sssd-ipa.x86_64                                                                                                        2.2.3-13.fc32                                                                                           @fedora        
sssd-kcm.x86_64                                                                                                        2.2.3-13.fc32                                                                                           @fedora        
sssd-krb5.x86_64                                                                                                       2.2.3-13.fc32                                                                                           @fedora        
sssd-krb5-common.x86_64                                                                                                2.2.3-13.fc32                                                                                           @fedora        
sssd-ldap.x86_64                                                                                                       2.2.3-13.fc32                                                                                           @fedora        
sssd-nfs-idmap.x86_64                                                                                                  2.2.3-13.fc32                                                                                           @fedora        
sssd-proxy.x86_64                                                                                                      2.2.3-13.fc32                                                                                           @fedora        

I had 2.2.3-13.fc31.x86_64 before upgrade.

Comment 7 Lukas Slebodnik 2020-04-03 17:28:40 UTC
(In reply to ersen from comment #6)
> packages I have now:
> libldb.x86_64                                                               
> 2.1.1-1.fc32                                                                
> @fedora        
> sssd.x86_64                                                                 
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-ad.x86_64                                                              
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-client.x86_64                                                          
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-common.x86_64                                                          
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-common-pac.x86_64                                                      
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-ipa.x86_64                                                             
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-kcm.x86_64                                                             
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-krb5.x86_64                                                            
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-krb5-common.x86_64                                                     
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-ldap.x86_64                                                            
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-nfs-idmap.x86_64                                                       
> 2.2.3-13.fc32                                                               
> @fedora        
> sssd-proxy.x86_64                                                           
> 2.2.3-13.fc32                                                               
> @fedora        
> 
> I had 2.2.3-13.fc31.x86_64 before upgrade.

I tried https://docs.fedoraproject.org/en-US/quick-docs/dnf-system-upgrade/ as well with minimal f31
and I was not able to reproduce failure. And I cannot see any AVCs either.

Can you see some AVCs? can you see something in /var/log/sssd/sssd.log?

Comment 8 ersen 2020-04-03 17:45:53 UTC
/var/log/sssd/sssd.log:

(Thu Apr  2 13:01:35 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 13:01:36 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 13:01:37 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 13:01:39 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 13:01:43 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 15:04:00 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 15:04:01 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 15:04:01 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 15:04:02 2020) [sssd] [main] (0x0010): No domains configured.
(Thu Apr  2 15:04:03 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 09:46:43 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 09:46:44 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 09:46:45 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 09:46:46 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 09:46:46 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 10:39:11 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 10:39:13 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 10:39:13 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 10:39:14 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 10:39:15 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 12:45:29 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 12:45:29 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 12:45:29 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 12:45:30 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 12:45:30 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 18:55:00 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 18:55:01 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 18:55:02 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 18:55:03 2020) [sssd] [main] (0x0010): No domains configured.
(Fri Apr  3 18:55:03 2020) [sssd] [main] (0x0010): No domains configured.


I see these errors in the "audit.log":
type=SERVICE_START msg=audit(1585929303.705:149): pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sssd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'UID="root" AUID="unset"

Comment 9 Lukas Slebodnik 2020-04-03 18:16:46 UTC
IIRC similar bug was already reported somewhere and it seems that bug was introduced somewhere in sssd >= 2.1.0.
But do not remember whether somebody was able to reliably the reproduce the bug.

workaround:
Remove /var/lib/sss/db/config.ldb and everything should work without any problem after restart of sssd.

Comment 10 ersen 2020-04-03 18:29:29 UTC
Removed the file, reboot and it failed again. Output of "journalctl -xe":

-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- An ExecStart= process belonging to unit sssd.service has exited.
-- 
-- The process' exit code is 'exited' and its exit status is 4.
Nis 03 21:24:45 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The unit sssd.service has entered the 'failed' state with result 'exit-code'.
Nis 03 21:24:45 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
-- Subject: A start job for unit sssd.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit sssd.service has finished with a failure.
-- 
-- The job identifier is 4632 and the job result is failed.
Nis 03 21:24:45 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sssd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Nis 03 21:24:45 localhost.localdomain systemd[1]: sssd.service: Scheduled restart job, restart counter is at 5.
-- Subject: Automatic restarting of a unit has been scheduled
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Automatic restarting of the unit sssd.service has been scheduled, as the result for
-- the configured Restart= setting for the unit.
Nis 03 21:24:45 localhost.localdomain systemd[1]: Stopped System Security Services Daemon.
-- Subject: A stop job for unit sssd.service has finished
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A stop job for unit sssd.service has finished.
-- 
-- The job identifier is 4718 and the job result is done.
Nis 03 21:24:45 localhost.localdomain audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sssd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Nis 03 21:24:45 localhost.localdomain audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=sssd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=successs'
Nis 03 21:24:45 localhost.localdomain systemd[1]: sssd.service: Start request repeated too quickly.
Nis 03 21:24:45 localhost.localdomain systemd[1]: sssd.service: Failed with result 'exit-code'.
-- Subject: Unit failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The unit sssd.service has entered the 'failed' state with result 'exit-code'.
Nis 03 21:24:45 localhost.localdomain systemd[1]: Failed to start System Security Services Daemon.
-- Subject: A start job for unit sssd.service has failed
-- Defined-By: systemd
-- Support: https://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- A start job for unit sssd.service has finished with a failure.
-- 
-- The job identifier is 4718 and the job result is failed.

Comment 11 Lukas Slebodnik 2020-04-03 20:46:14 UTC
I wrote:

> workaround:
> Remove /var/lib/sss/db/config.ldb and everything should work without any problem after restart of sssd.

restart sssd and not reboot :-)

and workaround is not a permanent solution.

Comment 12 ersen 2020-04-03 21:18:25 UTC
I tried both. First rebooted after removing the file and sssd failed to start. Then removed the file again, tried to restart sssd and it failed.

Comment 13 Lukas Slebodnik 2020-04-03 21:45:25 UTC
(In reply to ersen from comment #12)
> I tried both. First rebooted after removing the file and sssd failed to
> start. Then removed the file again, tried to restart sssd and it failed.

that's weird.

Could yo provide output of following commands?

find /etc/sssd
find /var/lib/sss/
rm -f /var/lib/sss/db/config.ldb /var/log/sssd/*
systemctl restart sssd
# provide log files from /var/log/sssd/
# but just in case of failure
find /var/lib/sss/

Comment 14 ersen 2020-04-03 21:56:58 UTC
find /etc/sssd:

/etc/sssd
/etc/sssd/conf.d
/etc/sssd/pki


find /var/lib/sss/:

/var/lib/sss/
/var/lib/sss/db
/var/lib/sss/db/cache_implicit_files.ldb
/var/lib/sss/db/timestamps_implicit_files.ldb
/var/lib/sss/db/config.ldb
/var/lib/sss/deskprofile
/var/lib/sss/gpo_cache
/var/lib/sss/mc
/var/lib/sss/pipes
/var/lib/sss/pipes/private
/var/lib/sss/pubconf
/var/lib/sss/pubconf/krb5.include.d
/var/lib/sss/secrets
/var/lib/sss/secrets/secrets.ldb
/var/lib/sss/secrets/.secrets.mkey
/var/lib/sss/keytabs


After removing said files and trying to restart sssd it failed with message:

Job for sssd.service failed because the control process exited with error code.
See "systemctl status sssd.service" and "journalctl -xe" for details.


Content of /var/log/sssd/sssd.log after failure:

(Sat Apr  4 00:52:20 2020) [sssd] [main] (0x0010): No domains configured.
(Sat Apr  4 00:52:21 2020) [sssd] [main] (0x0010): No domains configured.
(Sat Apr  4 00:52:21 2020) [sssd] [main] (0x0010): No domains configured.
(Sat Apr  4 00:52:22 2020) [sssd] [main] (0x0010): No domains configured.
(Sat Apr  4 00:52:22 2020) [sssd] [main] (0x0010): No domains configured.

find /var/lib/sss/:

/var/lib/sss/
/var/lib/sss/db
/var/lib/sss/db/cache_implicit_files.ldb
/var/lib/sss/db/timestamps_implicit_files.ldb
/var/lib/sss/db/config.ldb
/var/lib/sss/deskprofile
/var/lib/sss/gpo_cache
/var/lib/sss/mc
/var/lib/sss/pipes
/var/lib/sss/pipes/private
/var/lib/sss/pubconf
/var/lib/sss/pubconf/krb5.include.d
/var/lib/sss/secrets
/var/lib/sss/secrets/secrets.ldb
/var/lib/sss/secrets/.secrets.mkey
/var/lib/sss/keytabs

Comment 15 Lukas Slebodnik 2020-04-03 23:17:24 UTC
I think the best would be to run daemon manually with high debug level.
(otherwise you would need to create sssd.conf to increase debug level)
and you do not have any. 

I hope it will help reveal why we cannot reprduce bug locally and why removing /var/lib/sss/db/config.ldb
does not work for you

sh# /usr/sbin/sssd -i -d9

Comment 16 ersen 2020-04-04 04:34:01 UTC
(Sat Apr  4 07:26:31:911982 2020) [sssd] [check_file] (0x0400): lstat for [/var/run/sssd.pid] failed: [2][No such file or directory].                                                                                                         
(Sat Apr  4 07:26:31:912096 2020) [sssd] [check_file] (0x0400): lstat for [/var/run/nscd/socket] failed: [2][No such file or directory].                                                                                                      
(Sat Apr  4 07:26:31:917736 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ec80                                                                                                                                  
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:917812 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50                                                                                                                                   
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:917838 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:917922 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"                                                                                                                               
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:917951 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:917996 2020) [sssd] [ldb] (0x0400): server_sort:Unable to register control with rootdse!                                                                                                                                 
(Sat Apr  4 07:26:31:918045 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ec80                                                                                                                                  
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918077 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50                                                                                                                                   
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918090 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918115 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"                                                                                                                               
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918138 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918194 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ec80                                                                                                                                  
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918210 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50                                                                                                                                   
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918222 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918249 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"                                                                                                                               
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918272 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_callback"                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:918424 2020) [sssd] [sss_ini_open] (0x0400): No /etc/sssd/sssd.conf.                                                                                                                                                     
(Sat Apr  4 07:26:31:920279 2020) [sssd] [confdb_ldif_from_ini_file] (0x0100): Value of config_file_version option not found. Assumed to be version 2.                                                                                        
(Sat Apr  4 07:26:31:920316 2020) [sssd] [sss_confdb_create_ldif] (0x0400): Processing config section [sssd]                                                                                                                                  
(Sat Apr  4 07:26:31:920331 2020) [sssd] [sss_confdb_create_ldif] (0x0400): Processing attribute [services]                                                                                                                                   
(Sat Apr  4 07:26:31:920356 2020) [sssd] [sss_confdb_create_ldif] (0x4000): services: nss

(Sat Apr  4 07:26:31:920377 2020) [sssd] [sss_confdb_create_ldif] (0x4000): Section dn                                                                                                                                                        
dn: cn=sssd,cn=config                                                                                                                                                                                                                         
cn: sssd                                                                                                                                                                                                                                      
services: nss                                                                                                                                                                                                                                 
                                                                                                                                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:920430 2020) [sssd] [confdb_init_db] (0x0100): LDIF file to import:                                                                                                                                                      
dn: cn=config                                                                                                                                                                                                                                 
version: 2                                                                                                                                                                                                                                    
                                                                                                                                                                                                                                              
dn: cn=sssd,cn=config                                                                                                                                                                                                                         
cn: sssd                                                                                                                                                                                                                                      
services: nss


(Sat Apr  4 07:26:31:920450 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Sat Apr  4 07:26:31:920619 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:31:920639 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:31:920655 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:920695 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:920713 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:920736 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:920751 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d563980

(Sat Apr  4 07:26:31:920766 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:31:920778 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:31:920841 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:920859 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:31:920874 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:920895 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:920909 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:31:920920 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:31:920932 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:920961 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:920987 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921000 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921020 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921033 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510                                                                                                                                  
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921048 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070                                                                                                                                   
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921061 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921098 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"                                                                                                                               
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921121 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921134 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)                                                                                                                                                  
(Sat Apr  4 07:26:31:921161 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)                                                                                                                                                   
(Sat Apr  4 07:26:31:921188 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d563980                                                                                                                                  

(Sat Apr  4 07:26:31:921205 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:31:921217 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921241 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:921259 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921270 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921294 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921311 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:31:921326 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:31:921338 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921367 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:921384 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921429 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921458 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:31:921475 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:31:921487 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921508 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:31:921521 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921549 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 1)
(Sat Apr  4 07:26:31:921563 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d563980

(Sat Apr  4 07:26:31:921574 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:31:921585 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d563980 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:31:921616 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"                                                                                                                               

(Sat Apr  4 07:26:31:921630 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:31:921642 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 1)
(Sat Apr  4 07:26:32:371179 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Sat Apr  4 07:26:32:416368 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32:416469 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:32:416504 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:416571 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:416597 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:416667 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d563980

(Sat Apr  4 07:26:32:416698 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:32:416722 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:32:416765 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:416788 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:32:416854 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10

(Sat Apr  4 07:26:32:416880 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d563980

(Sat Apr  4 07:26:32:416902 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:416942 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:416965 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:417018 2020) [sssd] [add_implicit_services] (0x0040): No domains configured!
(Sat Apr  4 07:26:32:417042 2020) [sssd] [get_monitor_config] (0x0040): Failed to add implicit configured services. Some functionality might be missing
(Sat Apr  4 07:26:32:417103 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d5581e0

(Sat Apr  4 07:26:32:417127 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54eb10

(Sat Apr  4 07:26:32:417150 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d5581e0 "ldb_kv_callback"

(Sat Apr  4 07:26:32:417189 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:417212 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418339 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d564070                                                                                                                                  
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:32:418415 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d5581e0                                                                                                                                   

(Sat Apr  4 07:26:32:418441 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418484 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:418507 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418559 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32:418588 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:32:418618 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418716 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:418740 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418795 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32:418819 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:32:418844 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418883 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:418907 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:418957 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d563980

(Sat Apr  4 07:26:32:418981 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:32:419014 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:32:419051 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:419098 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_callback"

(Sat Apr  4 07:26:32:419139 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Sat Apr  4 07:26:32:419229 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10

(Sat Apr  4 07:26:32:419256 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d563980

(Sat Apr  4 07:26:32:419283 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:419357 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:419405 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:446072 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 0)                                                                                                                                                  
(Sat Apr  4 07:26:32:499810 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10                                                                                                                                  

(Sat Apr  4 07:26:32:499915 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d563980

(Sat Apr  4 07:26:32:499985 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:500105 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d563980 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:500145 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:500212 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d5581e0

(Sat Apr  4 07:26:32:500227 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54eb10

(Sat Apr  4 07:26:32:500254 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d5581e0 "ldb_kv_callback"

(Sat Apr  4 07:26:32:500279 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:500293 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_callback"

(Sat Apr  4 07:26:32:500316 2020) [sssd] [ldb] (0x4000): start ldb transaction (nesting: 0)
(Sat Apr  4 07:26:32:500440 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d564070

(Sat Apr  4 07:26:32:500478 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d5581e0

(Sat Apr  4 07:26:32:500493 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:500559 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:500602 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:522314 2020) [sssd] [ldb] (0x4000): commit ldb transaction (nesting: 0)
(Sat Apr  4 07:26:32:574854 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d564070

(Sat Apr  4 07:26:32:574925 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d5581e0

(Sat Apr  4 07:26:32:574947 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575015 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:575039 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575093 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32:575129 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:32:575148 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575177 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:575196 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575219 2020) [sssd] [confdb_expand_app_domains] (0x2000): implicit_files is not an app domain
(Sat Apr  4 07:26:32:575255 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32:575274 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d564070

(Sat Apr  4 07:26:32:575291 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575323 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d564070 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:575343 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575472 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ec80

(Sat Apr  4 07:26:32:575512 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d558510

(Sat Apr  4 07:26:32:575549 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ec80 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575653 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:575691 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575770 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:575811 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:575857 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575903 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:575932 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:575980 2020) [sssd] [confdb_get_domain_internal] (0x0400): No enumeration for [implicit_files]!
(Sat Apr  4 07:26:32:576043 2020) [sssd] [confdb_get_domain_internal] (0x0400): Please note that when enumeration is disabled `getent passwd` does not return all users by design. See sssd.conf man page for more detailed information
(Sat Apr  4 07:26:32:576114 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:576151 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:576194 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:576254 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:576287 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:576379 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10

(Sat Apr  4 07:26:32:576449 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50

(Sat Apr  4 07:26:32:576496 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"                                                                                                                                 
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:32:576582 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"                                                                                                                               
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:32:576632 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"                                                                                                                              
                                                                                                                                                                                                                                              
(Sat Apr  4 07:26:32:576681 2020) [sssd] [confdb_get_domain_internal] (0x1000): pwd_expiration_warning is -1                                                                                                                                  
(Sat Apr  4 07:26:32:576770 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10

(Sat Apr  4 07:26:32:576823 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50

(Sat Apr  4 07:26:32:576865 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:576932 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:577019 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:577117 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54eb10

(Sat Apr  4 07:26:32:577158 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ed50

(Sat Apr  4 07:26:32:577198 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:577243 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:577283 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54eb10 "ldb_kv_callback"

(Sat Apr  4 07:26:32:577599 2020) [sssd] [become_user] (0x0200): Trying to become user [0][0].
(Sat Apr  4 07:26:32:577642 2020) [sssd] [become_user] (0x0200): Already user [0].
(Sat Apr  4 07:26:32:577957 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:578004 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:578040 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578085 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:578114 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578163 2020) [sssd] [ldb] (0x0400): server_sort:Unable to register control with rootdse!
(Sat Apr  4 07:26:32:578234 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:578277 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:578305 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578354 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:578427 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578514 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:578561 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:578601 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578663 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:578696 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578777 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32:578820 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32:578869 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32:578917 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32:578960 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d54ed50

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d54ec80

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ec80 "ldb_kv_timeout"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d54ed50 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_callback": 0x55a11d558510

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Added timed event "ldb_kv_timeout": 0x55a11d5581e0

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Running timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d5581e0 "ldb_kv_timeout"

(Sat Apr  4 07:26:32 2020) [sssd] [ldb] (0x4000): Destroying timer event 0x55a11d558510 "ldb_kv_callback"

(Sat Apr  4 07:26:32 2020) [sssd] [confdb_get_domains] (0x0080): No domains configured, fatal error!
(Sat Apr  4 07:26:32 2020) [sssd] [main] (0x0010): No domains configured.

Comment 17 Lukas Slebodnik 2020-04-04 19:31:15 UTC
Could you try?

sh# echo -e '[sssd]\nservices=nss' > /etc/sssd/sssd.conf ; chmod 600 /etc/sssd/sssd.conf
sh# systemctl restart sssd

Comment 18 ersen 2020-04-04 21:22:48 UTC
It failed with same errors.

Comment 19 Lukas Slebodnik 2020-04-06 10:10:30 UTC
(In reply to ersen from comment #18)
> It failed with same errors.

Sorry, I am out of ideas. And cannot reproduce the bug myself.

Maybe fedora package maintainers can prepare some testing build for you with extra debug messages.

Comment 20 Sumit Bose 2020-04-06 11:37:21 UTC
Hi,

can you run

    rm -f /var/lib/sss/db/config.ldb
    strace -ff -o /tmp/strace_sssd -s 1024 /usr/sbin/sssd -i -d9

and attach the /tmp/strace_sssd* files to this case and either the output of

     ldbsearch -H /var/lib/sss/db/config.ldb

(ldbsearch is included in the ldb-tools package) or just the plain /var/lib/sss/db/config.ldb. It looks like there is at least an issue with the lastUpdate attribute, but I'm not sure if this might cause the startup failure you are seeing.

Does it make a different if you remove the whole content of /var/lib/sss/db like e.g. 'rm -f /var/lib/sss/db/*' ?

bye,
Sumit

Comment 21 Lukas Slebodnik 2020-04-06 11:53:31 UTC
(In reply to Sumit Bose from comment #20)
> Hi,
> 
> can you run
> 
>     rm -f /var/lib/sss/db/config.ldb
>     strace -ff -o /tmp/strace_sssd -s 1024 /usr/sbin/sssd -i -d9
> 
> and attach the /tmp/strace_sssd* files to this case and either the output of
> 
>      ldbsearch -H /var/lib/sss/db/config.ldb
> 
> (ldbsearch is included in the ldb-tools package) or just the plain
> /var/lib/sss/db/config.ldb. It looks like there is at least an issue with
> the lastUpdate attribute, but I'm not sure if this might cause the startup
> failure you are seeing.
> 

the bug/regression with lastUpdate attribute is "fixed" by 

sh# echo -e '[sssd]\nservices=nss' > /etc/sssd/sssd.conf ; chmod 600 /etc/sssd/sssd.conf
sh# systemctl restart sssd

But it still does not work based on comment 18

Comment 22 ersen 2020-04-06 12:28:30 UTC
Created attachment 1676578 [details]
requested file in #20

It failed after after "rm -f /var/lib/sss/db/*"

Comment 23 ersen 2020-04-06 12:33:44 UTC
output of `ldbsearch -H /var/lib/sss/db/config.ldb`:

server_sort:Unable to register control with rootdse!
# record 1
dn: cn=sssd,cn=config
cn: sssd
services: nss
domains: implicit_files
distinguishedName: cn=sssd,cn=config

# record 2
dn: cn=config
version: 2
lastUpdate: 1586028928
distinguishedName: cn=config

# record 3
dn: cn=implicit_files,cn=domain,cn=config
cn: implicit_files
id_provider: files
distinguishedName: cn=implicit_files,cn=domain,cn=config

# returned 3 records
# 3 entries
# 0 referrals

Comment 24 Lukas Slebodnik 2020-04-06 16:07:11 UTC
(In reply to ersen from comment #23)
> output of `ldbsearch -H /var/lib/sss/db/config.ldb`:
> 
> server_sort:Unable to register control with rootdse!
> # record 1
> dn: cn=sssd,cn=config
> cn: sssd
> services: nss
> domains: implicit_files
> distinguishedName: cn=sssd,cn=config
> 
> # record 2
> dn: cn=config
> version: 2
> lastUpdate: 1586028928
> distinguishedName: cn=config
> 
> # record 3
> dn: cn=implicit_files,cn=domain,cn=config
> cn: implicit_files
> id_provider: files
> distinguishedName: cn=implicit_files,cn=domain,cn=config
> 
> # returned 3 records
> # 3 entries
> # 0 referrals


It the same as on my machine. And it works for me without any problem.

sh-5.0# systemctl stop sssd
sh-5.0# 
sh-5.0# 
sh-5.0# rm -f /var/lib/sss/db/*
sh-5.0# systemctl start sssd
sh-5.0# ldbsearch -H /var/lib/sss/db/config.ldb
server_sort:Unable to register control with rootdse!
# record 1
dn: cn=sssd,cn=config
cn: sssd
services: nss
domains: implicit_files
distinguishedName: cn=sssd,cn=config

# record 2
dn: cn=config
version: 2
lastUpdate: 1586028928
distinguishedName: cn=config

# record 3
dn: cn=implicit_files,cn=domain,cn=config
cn: implicit_files
id_provider: files
distinguishedName: cn=implicit_files,cn=domain,cn=config

# returned 3 records
# 3 entries
# 0 referrals

sh-5.0# systemctl status sssd
● sssd.service - System Security Services Daemon
     Loaded: loaded (/usr/lib/systemd/system/sssd.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2020-04-06 12:04:43 EDT; 14s ago
   Main PID: 12021 (sssd)
      Tasks: 3 (limit: 4680)
     Memory: 31.7M
        CPU: 135ms
     CGroup: /system.slice/sssd.service
             ├─12021 /usr/sbin/sssd -i --logger=files
             ├─12022 /usr/libexec/sssd/sssd_be --domain implicit_files --uid 0 --gid 0 --logger=files
             └─12023 /usr/libexec/sssd/sssd_nss --uid 0 --gid 0 --logger=files

Apr 06 12:04:42 localhost systemd[1]: Starting System Security Services Daemon...
Apr 06 12:04:42 localhost sssd[12021]: Starting up
Apr 06 12:04:42 localhost sssd[be[implicit_files]][12022]: Starting up
Apr 06 12:04:43 localhost sssd[nss][12023]: Starting up
Apr 06 12:04:43 localhost systemd[1]: Started System Security Services Daemon.

Comment 25 Lukas Slebodnik 2020-04-06 16:08:10 UTC
Are you able to reproduce bug also on another machine/VM/... ?

Comment 26 ersen 2020-04-06 16:52:14 UTC
I have a bare metal Fedora 31 installation, sssd working fine:

libldb.x86_64         2.0.9-1.fc31
sssd.x86_64           2.2.3-13.fc31
systemd.x86_64        243.8-1.fc31


Fedora VM which is installed as 31 using netinstall and upgraded to 32 after that, sssd fails:

libldb.x86_64         2.1.1-1.fc32         
sssd.x86_64           2.2.3-13.fc32         
systemd.x86_64        245.4-1.fc32

Comment 27 ersen 2020-05-22 05:16:12 UTC
I had a fresh installation and didn't encounter this bug again. Don't know what caused that though. Closing this.

Comment 28 matrax41 2020-05-23 16:27:50 UTC
I have the same problem. And I realized that it was due to the language preference. I use Fedora in Turkish. It worked when I forced the SSSD service to work in English.

Comment 29 Simo Sorce 2020-05-26 12:26:42 UTC
What LANG string do you have in that case ?

Comment 30 Sumit Bose 2020-05-26 13:07:23 UTC
(In reply to Simo Sorce from comment #29)
> What LANG string do you have in that case ?

Hi,

it's tr_TR.UTF-8 and it's a libldb issue, see https://lists.samba.org/archive/samba-technical/2019-December/134659.html for details. To cut is short in tr_TR.UTF-8 and upper-case 'i' has a dot on top while a lower-case 'I' has no dot on top.

bye,
Sumit

Comment 31 ersen 2020-05-26 13:24:00 UTC
My failing system also had "tr_TR.UTF-8" locale, and the one which does not fail had "en_US.UTF-8" locale. My current system also have "en_US.UTF-8" locale and sssd works fine.

Comment 32 Simo Sorce 2020-05-26 16:35:27 UTC
very odd, so the issue seems to be that in tr_TR.utf-8 lower1 -> Upper -> lower2 is not a symmetrical operation and yields lower1 != lower2 ?

Comment 33 Sumit Bose 2020-05-26 17:59:15 UTC
(In reply to Simo Sorce from comment #32)
> very odd, so the issue seems to be that in tr_TR.utf-8 lower1 -> Upper ->
> lower2 is not a symmetrical operation and yields lower1 != lower2 ?

no, see thread on samba-technical, with tr_TR.UTF-8 strcasecmp("i", "I") != 0.

bye,
Sumit


Note You need to log in before you can comment on or make changes to this bug.