Bug 1400190

Summary:	Unable to restart service
Product:	Red Hat Enterprise Linux 7	Reporter:	Branislav Náter <bnater>
Component:	systemd	Assignee:	systemd-maint
Status:	CLOSED CURRENTRELEASE	QA Contact:	qe-baseos-daemons
Severity:	urgent	Docs Contact:
Priority:	urgent
Version:	7.3	CC:	apmukher, ccheney, hasuzuki, kwalker, systemd-maint-list
Target Milestone:	rc
Target Release:	---
Hardware:	All
OS:	All
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2019-06-20 19:56:17 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:

Description Branislav Náter 2016-11-30 16:36:50 UTC

Description of problem:
I've hit this while trying to restart NetworkManager but occur also on other services (firewalld, cups, network). I will add more logs when issue occur again.

Version-Release number of selected component (if applicable):
systemd-219-30.el7_3.6.x86_64
polkit-0.112-9.el7.x86_64
dbus-1.6.12-17.el7.x86_64
selinux-policy-3.13.1-102.el7_3.4.noarch
kernel-3.10.0-506.el7.x86_64

How reproducible:

Steps to Reproduce:
1. # systemctl restart network.service

Actual results (after timeout):

** (pkttyagent:8372): WARNING **: Unable to register authentication agent: Timeout was reached
Error registering authentication agent: Timeout was reached (g-io-error-quark, 24)
Failed to restart network.service: Connection timed out$
See system logs and 'systemctl status network.service' for details.

Expected results:
service is restarted

Additional info:
/var/log/messages during systemctl restart shows:
Nov 30 13:47:52 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:47:54 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:47:55 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:47:56 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:47:58 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:47:59 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:00 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:02 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:03 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:04 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:05 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:07 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:08 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:09 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:11 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:12 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:13 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:15 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:48:16 gringo systemd: Looping too fast. Throttling execution a little.
Nov 30 13:50:00 gringo systemd: Received SIGRTMIN+22 from PID 5716 (bash).

Comment 1 Branislav Náter 2016-11-30 19:14:25 UTC

Issue appeared again (systemctl restart cups), journalctl output with level debug:

Nov 30 20:10:13 gringo.brq.redhat.com systemd[1]: Setting log level to debug.
Nov 30 20:10:13 gringo.brq.redhat.com systemd[1]: Got notification message for unit systemd-journald.service
Nov 30 20:10:13 gringo.brq.redhat.com systemd[1]: systemd-journald.service: Got notification message from PID 857 (WATCHDOG=1)
Nov 30 20:10:13 gringo.brq.redhat.com systemd[1]: systemd-journald.service: got WATCHDOG=1
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: Got unexpected auxiliary data with level=1 and type=2
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: Accepted new private connection.
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: Got notification message for unit systemd-logind.service
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: systemd-logind.service: Got notification message from PID 1254 (WATCHDOG=1)
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: systemd-logind.service: got WATCHDOG=1
Nov 30 20:10:26 gringo.brq.redhat.com systemd[1]: Got message type=signal sender=org.freedesktop.DBus destination=n/a object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameOwnerChanged cookie=562 reply_cookie=0 error=n/a
Nov 30 20:10:51 gringo.brq.redhat.com systemd[1]: Event source 'bus-time' returned error, disabling: Connection timed out
Nov 30 20:10:51 gringo.brq.redhat.com systemd[1]: Event source 'bus-time' returned error, disabling: Connection timed out

<snip> (billion of such lines)

Nov 30 20:10:51 gringo.brq.redhat.com systemd[1]: Event source 'bus-time' returned error, disabling: Connection timed out
Nov 30 20:10:51 gringo.brq.redhat.com systemd[1]: Event source 'bus-time' returned error, disabling: Connection timed out
Nov 30 20:11:38 gringo.brq.redhat.com systemd-journal[857]: Suppressed 820768 messages from /
Nov 30 20:11:38 gringo.brq.redhat.com systemd[1]: Got message type=signal sender=org.freedesktop.DBus destination=n/a object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameOwnerChanged cookie=564 reply_cookie=0 error=n/a
Nov 30 20:11:38 gringo.brq.redhat.com systemd[1]: Received SIGCHLD from PID 12961 (abrt-dbus).
Nov 30 20:11:38 gringo.brq.redhat.com systemd[1]: Child 12961 (abrt-dbus) died (code=exited, status=0/SUCCESS)
Nov 30 20:11:38 gringo.brq.redhat.com systemd[1]: Got message type=signal sender=org.freedesktop.DBus destination=n/a object=/org/freedesktop/DBus interface=org.freedesktop.DBus member=NameOwnerChanged cookie=565 reply_cookie=0 error=n/a
Nov 30 20:12:14 gringo.brq.redhat.com systemd[1]: Got notification message for unit systemd-journald.service
Nov 30 20:12:14 gringo.brq.redhat.com systemd[1]: systemd-journald.service: Got notification message from PID 857 (WATCHDOG=1)
Nov 30 20:12:14 gringo.brq.redhat.com systemd[1]: systemd-journald.service: got WATCHDOG=1

Comment 3 Branislav Náter 2016-12-01 14:09:55 UTC

Looks like killing sssd process unblocks systemd. sssd-1.14.0.-43.el7 is installed.

Comment 8 Kyle Walker 2019-06-20 19:56:17 UTC

Unfortunately, this particular message and behaviour is a common path for a few underlying failures. Based on the reported version being before quite a few of these instances being addressed, I am going to mark this as CURRENTRELEASE.

However, in the event, that a further instance is encountered with later revisions of systemd please open a further bug report and mention this bug report.