[Freeipa-users] sssd.service start operation timed out

[Harald Dunkel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Hi folks,

If I reboot my LXC server, then sssd doesn't come up in some containers.
The logfile of an affected host shows

- -- Reboot --
Feb 27 17:17:23 lxc1.example.com systemd[1]: Starting System Security Services Daemon...
Feb 27 17:17:53 lxc1.example.com sssd[392]: Starting up
Feb 27 17:17:54 lxc1.example.com sssd[be[471]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[485]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[487]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[486]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[484]: Starting up
Feb 27 17:18:00 lxc1.example.com sssd[488]: Starting up
Feb 27 17:18:13 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:13 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:15 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:15 lxc1.example.com sssd_be[471]: GSSAPI client step 2
Feb 27 17:18:53 lxc1.example.com systemd[1]: sssd.service start operation timed out. Terminating.
Feb 27 17:18:53 lxc1.example.com sssd[485]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[484]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[488]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[be[471]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[487]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[486]: Shutting down
Feb 27 17:18:53 lxc1.example.com systemd[1]: Failed to start System Security Services Daemon.
Feb 27 17:18:53 lxc1.example.com systemd[1]: Unit sssd.service entered failed state.

Shouldn't it keep on trying, or retry after a few minutes?

sssd is version 1.12.5. Google doesn't mention this problem, so I
wonder what is happening here?


Every insightful comment is highly appreciated
Harri
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBCAAGBQJW6ElpAAoJEAqeKp5m04HL5kEH/03uUy+kyoLqrDpndZALEX0f
3XHFZryUNaJTUjQwtKe6tywmaKWcreQwZamwAFNxEQloGzhXiseAJ5LFNoP1KNuk
qDdYji4cpRczpP1E7TvNdKahqEXCSeUSLEKzreR9ZYfQb+/pxlFxR/yTvIPlZhMG
Wg1ckXfKh4jDfR5PTR1FdmdzvGCOg/GUhjQs1av+jJ0OQhSnQyfDFJOXM0HfyQv2
sDh6wNL2SAlQ9rPtLxF9mBLYkgZK9ibQ8uhA2FuF5noeuie/za5SouqlwlnWy/Ji
8NOgrmKB+nSAfcmeGB26aosHqaFoKX/mgrcYAbCwDFNnZXzBEEumWmlULKH5h8w=
=gPWc
-----END PGP SIGNATURE-----

[Jakub Hrozek]

Post by Harald Dunkel
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256
Hi folks,
If I reboot my LXC server, then sssd doesn't come up in some containers.
The logfile of an affected host shows
- -- Reboot --
Feb 27 17:17:23 lxc1.example.com systemd[1]: Starting System Security Services Daemon...
Feb 27 17:17:53 lxc1.example.com sssd[392]: Starting up
Feb 27 17:17:54 lxc1.example.com sssd[be[471]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[485]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[487]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[486]: Starting up
Feb 27 17:17:59 lxc1.example.com sssd[484]: Starting up
Feb 27 17:18:00 lxc1.example.com sssd[488]: Starting up
Feb 27 17:18:13 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:13 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:15 lxc1.example.com sssd_be[471]: GSSAPI client step 1
Feb 27 17:18:15 lxc1.example.com sssd_be[471]: GSSAPI client step 2
Feb 27 17:18:53 lxc1.example.com systemd[1]: sssd.service start operation timed out. Terminating.
Feb 27 17:18:53 lxc1.example.com sssd[485]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[484]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[488]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[be[471]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[487]: Shutting down
Feb 27 17:18:53 lxc1.example.com sssd[486]: Shutting down
Feb 27 17:18:53 lxc1.example.com systemd[1]: Failed to start System Security Services Daemon.
Feb 27 17:18:53 lxc1.example.com systemd[1]: Unit sssd.service entered failed state.
Shouldn't it keep on trying, or retry after a few minutes?

We don't have any such functionality..

Post by Harald Dunkel
sssd is version 1.12.5. Google doesn't mention this problem, so I
wonder what is happening here?

I would suggest to look into the sssd logs..

[Harald Dunkel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Post by Jakub Hrozek

Post by Harald Dunkel
-----BEGIN PGP SIGNED MESSAGE-----
Shouldn't it keep on trying, or retry after a few minutes?

We don't have any such functionality..

Understood. Obviously the dependencies and parameters listed
in sssd.service are not sufficient to guarantee a smooth
system startup for sssd. Except for sssd the system booted
fine, so I wonder what is different with sssd?

Post by Jakub Hrozek

Post by Harald Dunkel
sssd is version 1.12.5. Google doesn't mention this problem, so I wonder what is happening here?

I would suggest to look into the sssd logs..

I did, of course. There was no error message except

(Sat Feb 27 17:18:53 2016) [sssd] [monitor_cleanup] (0x0010): Error removing pidfile! (2 [No such file or directory])

Looking at the time entry it seems this message came up after
the timeout.


Regards
Harri

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBCAAGBQJW6GzuAAoJEAqeKp5m04HLFbcH/0+xuE1/f9T1L6mLGVWNKdBL
KKlv4siSHYgF9gUsbaqyDYGpoO6wKeFnj9sFMtD92TX5+JrXttkqTS9VRzIoY3kx
w4lchG83gKqTM10/tjjPHT4eLEviUg9C/AW+JfLUa85wG/hm507JSyYSgF1btRco
Wp6qWlg5D6yaaZdRmJsuqBGotFmaIG88SfXLYxCuJsqnbZi2VA8s3lGkB+wfWHSQ
sztI4uFCvgJjLwCRiwHRPvp5gv1SdOIY04A7du6IFGtaR4+UhNpRn8vev4MWeh8I
uRIhfrbmmO/E+WgcyEIX4C6YqUR7gAMB8/7qNV7Wd9WsZxcLAiXZWqFo5Wh6BJU=
=9CwW
-----END PGP SIGNATURE-----

[Jakub Hrozek]

Post by Harald Dunkel
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Post by Jakub Hrozek

Post by Harald Dunkel
-----BEGIN PGP SIGNED MESSAGE-----
Shouldn't it keep on trying, or retry after a few minutes?

We don't have any such functionality..

Understood. Obviously the dependencies and parameters listed
in sssd.service are not sufficient to guarantee a smooth
system startup for sssd. Except for sssd the system booted
fine, so I wonder what is different with sssd?

If you can reproduce the issue, it would be nice to increase the
debug_level a bit so that the debug logs are more verbose..

[Harald Dunkel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Hi Jakub,

If you can reproduce the issue, it would be nice to increase the debug_level a bit so that the debug logs are more verbose..

Using debug level 9 I got

(Wed Mar 16 13:24:57 2016) [sssd] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c2a0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c360
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c2a0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c360 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c2a0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): no modules required by the db
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): No modules specified for this database
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c2d0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c390
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c2d0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c390 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c2d0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c4e0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c5a0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c4e0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c5a0 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c4e0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for example.com: /var/lib/sss/db/cache_example.com.ldb
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dbe0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3dca0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dbe0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3dca0 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dbe0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x0400): asq: Unable to register control with rootdse!
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dd80
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3de40
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dd80 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3de40 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dd80 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dfd0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3e090
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dfd0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3e090 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dfd0 "ltdb_callback"
(Wed Mar 16 13:25:04 2016) [sssd] [sbus_new_server] (0x0400): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-monitor,guid=d5f35f30568405c90a0fc9e756e950a0
(Wed Mar 16 13:25:05 2016) [sssd] [sbus_add_watch] (0x2000): 0xb3e070/0xb3dda0 (14), R/- (enabled)
(Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between service pings for [example.com]: [10]
(Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between SIGTERM and SIGKILL for [example.com]: [60]
(Wed Mar 16 13:25:05 2016) [sssd] [start_service] (0x0100): Queueing service example.com for startup
(Wed Mar 16 13:25:06 2016) [sssd] [monitor_quit_signal] (0x2000): Received shutdown command
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit_signal] (0x0040): Monitor received Terminated: terminating children
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0040): Returned with: 0
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Terminating [example.com][474]
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Child [example.com] terminated with a signal
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_cleanup] (0x0010): Error removing pidfile! (2 [No such file or directory])
(Wed Mar 16 13:25:08 2016) [sssd] [sbus_remove_watch] (0x2000): 0xb3e070/0xb3dda0


daemon.log shows
:
Mar 16 13:16:57 lxc10 systemd[1]: Stopping Getty on tty1...
Mar 16 13:16:57 lxc10 systemd[1]: Stopping Getty on tty4...
Mar 16 13:16:57 lxc10 systemd[1]: Stopping Container Getty on /dev/pts/3...
Mar 16 13:16:57 lxc10 systemd[1]: Stopping Container Getty on /dev/pts/2...
Mar 16 13:24:28 lxc10 systemd[1]: Started Remount Root and Kernel File Systems.
Mar 16 13:24:28 lxc10 systemd[1]: Started Various fixups to make systemd work better on Debian.
Mar 16 13:24:28 lxc10 systemd[1]: Starting Load/Save Random Seed...
Mar 16 13:24:28 lxc10 systemd[1]: Starting Local File Systems (Pre).
:
Mar 16 13:24:28 lxc10 systemd[1]: Started System Logging Service.
Mar 16 13:24:41 lxc10 exim4[189]: Starting MTA: exim4.
Mar 16 13:24:41 lxc10 systemd[1]: Started LSB: exim Mail Transport Agent.
Mar 16 13:24:43 lxc10 dbus[191]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30000ms)
Mar 16 13:24:57 lxc10 sssd: Starting up
Mar 16 13:25:06 lxc10 systemd[1]: sssd.service start operation timed out. Terminating.
Mar 16 13:25:06 lxc10 systemd[1]: Failed to start System Security Services Daemon.
Mar 16 13:25:06 lxc10 systemd[1]: Unit sssd.service entered failed state.
Mar 16 13:25:06 lxc10 systemd[1]: Starting User and Group Name Lookups.
Mar 16 13:25:06 lxc10 systemd[1]: Reached target User and Group Name Lookups.
Mar 16 13:25:06 lxc10 systemd[1]: Starting Login Service...
Mar 16 13:25:06 lxc10 systemd[1]: Starting Permit User Sessions...
:

Does this help?


Regards
Harri

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBCAAGBQJW6WAAAAoJEAqeKp5m04HLcLwIAIU6Mjg3aTe6CHDdOUi6Nvt7
EBMDrmAS5nXV5CM/CiQc7JitUQPTmwhjTTOERUXu2o3f1L9LLwC2zTLbB0oLnqBX
ZNCZ/tjrMZBSSO6jAxmfcRlBOemsVinNFBavtpxQSvwoZ9wokUe1GI2NxBgL2kKR
fdEOUGOlgnglXlPY25cILDaoQ9yaw+LJY+Vmu5NJ73cnkfejYVnMJYtcYjFQhPSx
0zuQspROQAJCFmXWj7VH5MTysfuVjjn0GWbGfJIOXw+/1LKdIuebgG8TACXZItXR
1S3P4VU7c5DR0a7vqohCrGDRwBZDDMg4FhKPel9rkyUwHpN4ur9EZscq8N8FJDY=
=9uIf
-----END PGP SIGNATURE-----

[Lukas Slebodnik]

Post by Harald Dunkel
Hi Jakub,

If you can reproduce the issue, it would be nice to increase the debug_level a bit so that the debug logs are more verbose..

Using debug level 9 I got
(Wed Mar 16 13:24:57 2016) [sssd] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c2a0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c360
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c2a0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c360 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c2a0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): no modules required by the db
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): No modules specified for this database
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c2d0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c390
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c2d0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c390 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c2d0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3c4e0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3c5a0
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3c4e0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3c5a0 "ltdb_timeout"
(Wed Mar 16 13:25:00 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3c4e0 "ltdb_callback"
(Wed Mar 16 13:25:00 2016) [sssd] [sysdb_domain_init_internal] (0x0200): DB File for example.com: /var/lib/sss/db/cache_example.com.ldb
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dbe0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3dca0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dbe0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3dca0 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dbe0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x0400): asq: Unable to register control with rootdse!
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dd80
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3de40
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dd80 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3de40 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dd80 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_callback": 0xb3dfd0
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Added timed event "ltdb_timeout": 0xb3e090
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Running timer event 0xb3dfd0 "ltdb_callback"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Destroying timer event 0xb3e090 "ltdb_timeout"
(Wed Mar 16 13:25:01 2016) [sssd] [ldb] (0x4000): Ending timer event 0xb3dfd0 "ltdb_callback"
(Wed Mar 16 13:25:04 2016) [sssd] [sbus_new_server] (0x0400): D-BUS Server listening on unix:path=/var/lib/sss/pipes/private/sbus-monitor,guid=d5f35f30568405c90a0fc9e756e950a0
(Wed Mar 16 13:25:05 2016) [sssd] [sbus_add_watch] (0x2000): 0xb3e070/0xb3dda0 (14), R/- (enabled)
(Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between service pings for [example.com]: [10]
(Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between SIGTERM and SIGKILL for [example.com]: [60]
(Wed Mar 16 13:25:05 2016) [sssd] [start_service] (0x0100): Queueing service example.com for startup

^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
sssd should spawn
child processes
here.

Post by Harald Dunkel
(Wed Mar 16 13:25:06 2016) [sssd] [monitor_quit_signal] (0x2000): Received shutdown command

^^^^^^^^^^^^^^^^^^^^^^^^^
After a second, sssd got
signal for shutdown.

Post by Harald Dunkel
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit_signal] (0x0040): Monitor received Terminated: terminating children

^^^^^^^^^^
SIGTERM

Post by Harald Dunkel
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0040): Returned with: 0
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Terminating [example.com][474]
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Child [example.com] terminated with a signal
(Wed Mar 16 13:25:08 2016) [sssd] [monitor_cleanup] (0x0010): Error removing pidfile! (2 [No such file or directory])
(Wed Mar 16 13:25:08 2016) [sssd] [sbus_remove_watch] (0x2000): 0xb3e070/0xb3dda0

It does not look like problem in sssd.

LS

[Harald Dunkel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

(Wed Mar 16 13:25:05 2016) [sssd] [sbus_add_watch] (0x2000): 0xb3e070/0xb3dda0 (14), R/- (enabled) (Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between service pings for [example.com]: [10] (Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between
SIGTERM and SIGKILL for [example.com]: [60] (Wed Mar 16 13:25:05 2016) [sssd] [start_service] (0x0100): Queueing service example.com for startup

^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ sssd should spawn child processes here.

(Wed Mar 16 13:25:06 2016) [sssd] [monitor_quit_signal] (0x2000): Received shutdown command

^^^^^^^^^^^^^^^^^^^^^^^^^ After a second, sssd got signal for shutdown.

(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit_signal] (0x0040): Monitor received Terminated: terminating children

^^^^^^^^^^ SIGTERM

(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0040): Returned with: 0 (Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Terminating [example.com][474] (Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Child [example.com] terminated with a signal (Wed Mar 16 13:25:08
2016) [sssd] [monitor_cleanup] (0x0010): Error removing pidfile! (2 [No such file or directory]) (Wed Mar 16 13:25:08 2016) [sssd] [sbus_remove_watch] (0x2000): 0xb3e070/0xb3dda0

It does not look like problem in sssd.

Are you sure? Then why doesn't it "spawn child processes here"?

I would guess the SIGTERM was either sent by systemd or sssd's
startup script? Since freeipa doesn't work with anything else
but systemd its a little bit cheap now to say "not my problem",
is it?


Regards
Harri

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBCAAGBQJW7R4AAAoJEAqeKp5m04HLtY0H/2+96DjhCx873/koFhQm+nZo
OLnsBbZd6O1ujFHHMYbtUelavHTGkKuClne5oojEfMle7YxuhgSmZdHQ8JC/b6AH
mIR6W9dxDNsYB9ChXL1+BCGYr9RAq4G/dYymnvfSE1HlDEQ+mWTt9vhjD4p5za79
ldetXkHnGus25F1z7nNGONYtYDDmeRaqrBxuWblKTKCA6zRwfFjtOP+/Zr3D5/fG
PkC2t7nciocFJIhPvEsfrV+5y1fGHfNS8JJ+aW2rFx70OvGIN+fcWF9q/yv6ibd4
MAg9R0ZigLgtqIS+o//c7BeL3yjInu6Pw5Ns16u8M832HDhDzCQsCffhdeX8n+A=
=9yfe
-----END PGP SIGNATURE-----

[Lukas Slebodnik]

Post by Harald Dunkel

(Wed Mar 16 13:25:05 2016) [sssd] [sbus_add_watch] (0x2000): 0xb3e070/0xb3dda0 (14), R/- (enabled) (Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between service pings for [example.com]: [10] (Wed Mar 16 13:25:05 2016) [sssd] [get_ping_config] (0x0100): Time between
SIGTERM and SIGKILL for [example.com]: [60] (Wed Mar 16 13:25:05 2016) [sssd] [start_service] (0x0100): Queueing service example.com for startup

^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ sssd should spawn child processes here.

(Wed Mar 16 13:25:06 2016) [sssd] [monitor_quit_signal] (0x2000): Received shutdown command

^^^^^^^^^^^^^^^^^^^^^^^^^ After a second, sssd got signal for shutdown.

(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit_signal] (0x0040): Monitor received Terminated: terminating children

^^^^^^^^^^ SIGTERM

(Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0040): Returned with: 0 (Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Terminating [example.com][474] (Wed Mar 16 13:25:08 2016) [sssd] [monitor_quit] (0x0020): Child [example.com] terminated with a signal (Wed Mar 16 13:25:08
2016) [sssd] [monitor_cleanup] (0x0010): Error removing pidfile! (2 [No such file or directory]) (Wed Mar 16 13:25:08 2016) [sssd] [sbus_remove_watch] (0x2000): 0xb3e070/0xb3dda0

It does not look like problem in sssd.

Are you sure? Then why doesn't it "spawn child processes here"?

Logs are from main process. If the main progess get a signal
for shutdown then it cannot continue with "spawning child processes".
sssd has to shutdown.

Post by Harald Dunkel
I would guess the SIGTERM was either sent by systemd or sssd's
startup script?

What do you mean by sssd's startup script?

You either have systemd or upstart/sysv
and you should know which initsystem do you use.

sssd does not send SIGTERM to itself therefore
signal had to be send from somewhere else.
So it's not a problem of sssd.

Post by Harald Dunkel
Since freeipa doesn't work with anything else
but systemd its a little bit cheap now to say "not my problem",
is it?

"freeipa-server" doesn't work with anything else but systemd.
and freeipa-client just configure sssd and few other services.

But sssd itself can run without systemd.

LS

[Harald Dunkel]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Hi Lukas,

Since freeipa doesn't work with anything else but systemd its a little bit cheap now to say "not my problem", is it?

"freeipa-server" doesn't work with anything else but systemd. and freeipa-client just configure sssd and few other services.

Without systemd:

***@lxc31:~# ipa-client-install
Traceback (most recent call last):
File "/usr/sbin/ipa-client-install", line 2790, in <module>
sys.exit(main())
File "/usr/sbin/ipa-client-install", line 2771, in main
rval = install(options, env, fstore, statestore)
File "/usr/sbin/ipa-client-install", line 2006, in install
ipaclient.ntpconf.check_timedate_services()
File "/usr/lib/python2.7/dist-packages/ipaclient/ntpconf.py", line 183, in check_timedate_services
if instance.is_enabled() or instance.is_running():
File "/usr/lib/python2.7/dist-packages/ipaplatform/base/services.py", line 321, in is_enabled
self.service_instance(instance_name)])
File "/usr/lib/python2.7/dist-packages/ipapython/ipautil.py", line 321, in run
preexec_fn=preexec_fn)
File "/usr/lib/python2.7/subprocess.py", line 710, in __init__
errread, errwrite)
File "/usr/lib/python2.7/subprocess.py", line 1335, in _execute_child
raise child_exception
OSError: [Errno 2] No such file or directory


Of course I understand that writing portable software is a
difficult task, but is this restriction really necessary, if
ipa client support is about "just configure sssd and a few
other services"? Currently I have to install systemd to make
ipa-client-install work, and later I can move back to sysvinit
to support HA services.

You have to admit that this is weird.



Regards
Harri

-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2

iQEcBAEBCAAGBQJW7pDyAAoJEAqeKp5m04HLcYQIAJLxFHxVSGMhHz791iZUgGCX
qBNIP1JI8QmADgS0G0FZZx/s94Gb0iLrH/64aFGYDFdQAC1HZex6DkOxzSfADJlD
JSWU6cTAIw0ktGJpj05oJCQXU2VMCg5PswyPnY4rwOqKlVnb5zQrD6yk6alkhz37
p7lSbgtzj6MkfwkVBNlb9epJFQEzGZYVOC8tfNQhVOmDgnlBBDVcsUSxASQlXr2G
7ASxOKwukWCIrP62jIwamIstg9n8TUkI95avkvwh5DvitBBADQxDA/GmF2VZG8NG
Ohy0ONrzZHXML2cB3Rvwab20rXUcwv2vypmgGP4QE9bOezNw89ZROtx1MsiqOn0=
=64Gt
-----END PGP SIGNATURE-----

[Lukas Slebodnik]

Post by Harald Dunkel
Hi Lukas,

Since freeipa doesn't work with anything else but systemd its a little bit cheap now to say "not my problem", is it?

"freeipa-server" doesn't work with anything else but systemd. and freeipa-client just configure sssd and few other services.

File "/usr/sbin/ipa-client-install", line 2790, in <module>
sys.exit(main())
File "/usr/sbin/ipa-client-install", line 2771, in main
rval = install(options, env, fstore, statestore)
File "/usr/sbin/ipa-client-install", line 2006, in install
ipaclient.ntpconf.check_timedate_services()
File "/usr/lib/python2.7/dist-packages/ipaclient/ntpconf.py", line 183, in check_timedate_services
File "/usr/lib/python2.7/dist-packages/ipaplatform/base/services.py", line 321, in is_enabled
self.service_instance(instance_name)])
File "/usr/lib/python2.7/dist-packages/ipapython/ipautil.py", line 321, in run
preexec_fn=preexec_fn)
File "/usr/lib/python2.7/subprocess.py", line 710, in __init__
errread, errwrite)
File "/usr/lib/python2.7/subprocess.py", line 1335, in _execute_child
raise child_exception
OSError: [Errno 2] No such file or directory
Of course I understand that writing portable software is a
difficult task, but is this restriction really necessary, if
ipa client support is about "just configure sssd and a few
other services"? Currently I have to install systemd to make
ipa-client-install work, and later I can move back to sysvinit
to support HA services.

But it's not problem of sssd. And it's not related to you issue with
LXC containers.

It's problem of ipa-client-install

Feel free to send patches which make freeipa-client more portable
http://www.freeipa.org/page/Contribute/Code

LS