Bug 71721

Summary:	systemd-journald - 60 second pause in dracut, then systemd hangs at Init Default Target
Product:	systemd	Reporter:	James <james>
Component:	general	Assignee:	systemd-bugs
Status:	RESOLVED FIXED	QA Contact:	systemd-bugs
Severity:	normal
Priority:	medium
Version:	unspecified
Hardware:	x86 (IA32)
OS:	Linux (All)
Whiteboard:
i915 platform:		i915 features:

Description James 2013-11-18 06:44:59 UTC

Arch Linux
kernel 3.12.0-1-ARCH
dracut 034-1
systemd 208-2

Symptom: on boot with "systemd.log_level=debug", after log message"Started Journal Service", the booting-process pauses for exactly 60 seconds.  Then, at Init Default Target, after pivot, where systemd proper should start, after the log message "systemd-journald[43]: Received SIGTERM", the system hangs permanantly.

Circumstances: The pause and hang can be influenced by the "debug" and "systemd.log_target=<blah>" kernel command-line boot parameters.

With no "debug" and no "systemd.log_target=<blah>" parameter, the boot pauses and then hangs.

With "debug" and no "systemd.log_target=<blah>" parameter, the boot never pauses or hangs and seems to start normally.

With no "debug" and with any of "systemd.log_target=[journal|syslog|journal-or-kmsg|syslog-or-kmsg]", the boot will pause and then hang.

With no "debug" and with any of "systemd.log_target=[console|kmsg|null]", the boot does not pause or hang and seems to start normally.

The pause and hang seem to be related to systemd-journald.  Setting "debug" or setting "systemd.log_target=[console|kmsg|null]" acts as a work-around to the pause and hang.

With no "debug" and no "systemd.log_target=<blah>" parameter, where the boot would otherwise pause and then hang, using the kernel command-line boot parameter "init=/usr/bin/bash", the shell starts normally, and then running "/usr/lib/systemd/systemd --system" from the shell, all systemd-managed processes seem to start-up normally.

Hopefully, that's enough information to narrow-down the source of the problem.  Let me know if there is any easy way to expose more useful error messages during the pause or at the hang.

Comment 1 Kay Sievers 2013-11-18 13:45:12 UTC

Sounds like blocking in the filled-up log socket logic, but this should
not happen when systemd logs directly to the kernel. which is the default
for "debug" and no other specific log option.

A couple more details are here:

http://cgit.freedesktop.org/systemd/systemd/commit/?id=bd6d2963396061ed068c4c6c54d8104b59ba91dc

Comment 2 James 2013-11-18 15:06:54 UTC

Yes, for either "debug" and no other specific log option, or for an explicit "systemd.log_target=kmsg", there is no blocking and no hang, and operation seems normal.

So that works, except that it creates a "Heisenbug", where, like some "quantum event", the problem goes away when you try to observe it, with "debug".

If you want to do this kind of modified behavior with "debug", there should at least be very profuse and verbose and loud disclosure in the system log, saying that the underlying systemd behavior has been modified, and that the logging has been automatically - and not "silently" - changed, from "journal logging" to "kernel logging", and that "journal blocking behavior" will disappear as a result of this change.  Otherwise, systemd is going to be very mysterious and "un-discoverable", and debugging is going to be a PITA.

In the long run, it would seem to me, that "journal blocking" is not appropriate behavior.  Instead, perhaps, systemd-journald should throw a very loud warning message, and then continue.  Wasn't that the whole point of setting-up sockets with systemd, not slowing the boot process, because of any one misbehaving process?

Comment 3 Lennart Poettering 2017-09-14 11:03:55 UTC

Given this is 3 years old I am pretty sure this has been resolved since then. Closing.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.