Fedora Linux Support Community & Resources Center
  #1  
Old 14th November 2011, 11:03 PM
chrisham Offline
Registered User
 
Join Date: Nov 2011
Posts: 10
linuxfirefox
Exclamation [SOLVED] systemd hang during startup (Fedora15/16)

I'm seeing a hang of systemd during bootup - I believe it started some time around my update to the 2.6.40 kernel on Fedora15. But since my system usually runs 24/7 I'm not really sure wich update caused the problem.

I then updated to F16, in the hope that this would somehow cure the problem, but no luck so far.

Symptoms:
- During bootup, first everything seems fine, but then all activity dies down and the boot process just sits there and does nothing for several minutes
- If I wait patiently, I finally get to the graphical login, but logging in is impossible: after entering my password, the system just sits there and does nothing again. After some time, the login prompt reappears
- Also, logging in on a TTY is impossible as well: after one minute, the login times out and drops me at the login prompt again.
- I can work around the blockage with 'Alt+SysRq+e' - killing all processes except init. Graphical login is spawned again, and suddenly, login is possible again (on TTY as well) - I can then manually restart all the missing services, and get back to a working system ...
- ... but upon next reboot, the same thing happens all over again

To me, this looks like some part of the systemd bootup is hanging, and thus blocking all further activity depending on this part. The restart forced by SysRq+e somehow clears the blockage, and gets things going again. Unfortunately, due to the asynchronous nature of the systemd boot, I cannot figure out which part is causing the hang.

I booted up with log.level set to debug, and had a look at dmesg. I believe this excerpt shows where things start going sideways (complete dmesg attached), and to me things seem to point to the ttyX.services hanging - but beyond this, I cannot see a further path for analysis.

Code:
[...]
[   29.856366] systemd[1]: Received SIGRTMIN+20 from PID 166 (plymouthd).
[   29.856369] systemd[1]: Enabling showing of status.
[   29.856470] systemd[1]: Running GC...
[   45.994458] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   45.994892] systemd[1]: Failed to load configuration for autovt@tty2.service: File exists
[   45.994901] systemd[1]: Trying to enqueue job autovt@tty2.service/start/fail
[   50.990169] systemd-logind[1027]: Failed to start unit: Unit autovt@tty2.service failed to load: File exists. See system logs and 'systemctl status autovt@tty2.service' for details.
[   50.993778] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   50.993887] systemd[1]: Failed to load configuration for autovt@tty5.service: File exists
[   50.993895] systemd[1]: Trying to enqueue job autovt@tty5.service/start/fail
[   50.994178] systemd-logind[1027]: Failed to start unit: Unit autovt@tty5.service failed to load: File exists. See system logs and 'systemctl status autovt@tty5.service' for details.
[   51.416940] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   51.417046] systemd[1]: Failed to load configuration for autovt@tty6.service: File exists
[   51.417055] systemd[1]: Trying to enqueue job autovt@tty6.service/start/fail
[   51.417366] systemd-logind[1027]: Failed to start unit: Unit autovt@tty6.service failed to load: File exists. See system logs and 'systemctl status autovt@tty6.service' for details.
[   52.263864] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   52.263883] systemd[1]: Trying to enqueue job autovt@tty5.service/start/fail
[   52.264163] systemd-logind[1027]: Failed to start unit: Unit autovt@tty5.service failed to load: File exists. See system logs and 'systemctl status autovt@tty5.service' for details.
[   66.202683] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   66.202815] systemd[1]: Failed to load configuration for autovt@tty4.service: File exists
[   66.202823] systemd[1]: Trying to enqueue job autovt@tty4.service/start/fail
[   66.203037] systemd-logind[1027]: Failed to start unit: Unit autovt@tty4.service failed to load: File exists. See system logs and 'systemctl status autovt@tty4.service' for details.
[   84.576682] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[   84.576795] systemd[1]: Failed to load configuration for autovt@tty3.service: File exists
[   84.576803] systemd[1]: Trying to enqueue job autovt@tty3.service/start/fail
[   84.577014] systemd-logind[1027]: Failed to start unit: Unit autovt@tty3.service failed to load: File exists. See system logs and 'systemctl status autovt@tty3.service' for details.
[   85.615688] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.StartUnit() on /org/freedesktop/systemd1
[...]
The corresponding part of /var/log/messages looks like this:
Code:
[...]
Nov 14 00:47:45 calvin [   14.972323] smartd[992]: Device: /dev/sdb [SAT], found in smartd database: S
AMSUNG SpinPoint T166
Nov 14 00:47:45 calvin [   15.066964] avahi-daemon[1005]: Found user 'avahi' (UID 498) and group 'avah
i' (GID 494).
Nov 14 00:47:45 calvin [   15.067044] avahi-daemon[1005]: Successfully dropped root privileges.
Nov 14 00:47:45 calvin [   15.067239] avahi-daemon[1005]: avahi-daemon 0.6.30 starting up.
Nov 14 00:47:45 calvin [   15.249624] NetworkManager[998]: <info> NetworkManager (version 0.9.1.90-5.g
it20110927.fc16) is starting...
Nov 14 00:47:45 calvin [   15.249631] NetworkManager[998]: <info> Read config file /etc/NetworkManager
/NetworkManager.conf
Nov 14 00:47:45 calvin [   15.250454] NetworkManager[998]: NetworkManager[998]: <info> NetworkManager 
(version 0.9.1.90-5.git20110927.fc16) is starting...
Nov 14 00:47:45 calvin [   15.250469] NetworkManager[998]: NetworkManager[998]: <info> Read config fil
e /etc/NetworkManager/NetworkManager.conf
Nov 14 00:47:45 calvin [   15.252405] ntpd[1002]: 0.0.0.0 c016 06 restart
Nov 14 00:47:45 calvin [   15.252412] ntpd[1002]: 0.0.0.0 c012 02 freq_set kernel 3.231 PPM
Nov 14 00:47:45 calvin [   15.411691] smartd[992]: Device: /dev/sdb [SAT], is SMART capable. Adding to
 "monitor" list.
Nov 14 00:47:45 calvin [   15.417740] dbus-daemon[1040]: dbus[1040]: avc:  netlink poll: error 4
Nov 14 00:47:45 calvin [   15.417747] dbus[1040]: avc:  netlink poll: error 4
Nov 14 00:47:45 calvin [   15.418296] smartd[992]: Device: /dev/sdc, type changed from 'scsi' to 'sat'
Nov 14 00:47:45 calvin [   15.418306] smartd[992]: Device: /dev/sdc [SAT], opened
Nov 14 00:47:45 calvin [   15.422449] avahi-daemon[1005]: Successfully called chroot().
Nov 14 00:47:45 calvin [   15.422457] avahi-daemon[1005]: Successfully dropped remaining capabilities.
Nov 14 00:47:45 calvin [   15.422948] avahi-daemon[1005]: Loading service file /services/ssh.service.
Nov 14 00:47:45 calvin [   15.422954] avahi-daemon[1005]: Loading service file /services/udisks.service.
Nov 14 00:47:45 calvin [   15.422966] systemd-logind[1027]: New seat seat0.
Nov 14 00:47:45 calvin [   15.423046] avahi-daemon[1005]: Network interface enumeration completed.
Nov 14 00:47:45 calvin [   15.423130] avahi-daemon[1005]: Registering HINFO record with values 'X86_64'/'LINUX'.
Nov 14 00:47:45 calvin [   15.423210] avahi-daemon[1005]: Server startup complete. Host name is calvin.local. Local service cookie is 962166671.
Nov 14 00:47:45 calvin [   15.423258] avahi-daemon[1005]: Service "calvin" (/services/udisks.service) successfully established.
Nov 14 00:47:45 calvin [   15.423263] avahi-daemon[1005]: Service "calvin" (/services/ssh.service) successfully established.
Nov 14 00:47:45 calvin [   15.424892] smartd[992]: Device: /dev/sdc [SAT], SAMSUNG HD502IJ, S/N:S13TJ1CQ400922, WWN:5-0000f, FW:1AA01110, 500 GB
Nov 14 00:47:45 calvin [   15.426473] smartd[992]: Device: /dev/sdc [SAT], found in smartd database: SAMSUNG SpinPoint F1 DT
Nov 14 00:47:45 calvin [   15.473955] mcelog[1052]: mcelog: Unsupported new Family 6 Model 1e CPU: only decoding architectural errors
Nov 14 00:47:45 calvin [   15.502089] smartd[992]: Device: /dev/sdc [SAT], is SMART capable. Adding to "monitor" list.
Nov 14 00:47:45 calvin [   15.504355] smartd[992]: Device: /dev/sdd, type changed from 'scsi' to 'sat'
Nov 14 00:47:45 calvin [   15.504411] smartd[992]: Device: /dev/sdd [SAT], opened
Nov 14 00:47:45 calvin [   15.506543] smartd[992]: Device: /dev/sdd [SAT], SAMSUNG HD501LJ, S/N:S0MUJDWPC09184, WWN:5-0000f0-0dbc09184, FW:CR100-12, 500 GB
Nov 14 00:47:45 calvin [   15.509135] smartd[992]: Device: /dev/sdd [SAT], found in smartd database: SAMSUNG SpinPoint T166
Nov 14 00:47:45 calvin kernel: : [   15.582061] syslog-ng (1056): Attempt to access syslog with CAP_SYS_ADMIN but no CAP_SYSLOG (deprecated).
Nov 14 00:48:20 calvin [   50.990169] systemd-logind[1027]: Failed to start unit: Unit autovt@tty2.service failed to load: File exists. See system logs and 'systemctl status autovt@tty2.service' for details.
Nov 14 00:48:20 calvin [   50.994178] systemd-logind[1027]: Failed to start unit: Unit autovt@tty5.service failed to load: File exists. See system logs and 'systemctl status autovt@tty5.service' for details.
[...]
I also attached /var/log/boot.log - the only thing that sticks out to me is NetworkManager failing - but I cannot tell if this is cause or effect.

Could anybody please point me in the direction of further useful things to do, or pieces of information I forgot to provide?

Thanks,

-chris


----------------------
SOLVED

Pls. see below
Attached Files
File Type: log boot.log (6.7 KB, 71 views)
File Type: log systemd_dmsg.log (229.0 KB, 76 views)

Last edited by chrisham; 6th December 2011 at 11:51 PM. Reason: Finally found the solution ...
Reply With Quote
  #2  
Old 16th November 2011, 08:08 PM
chrisham Offline
Registered User
 
Join Date: Nov 2011
Posts: 10
linuxfirefox
Re: systemd hang during startup (Fedora15/16)

The problem 'disappeared' after todays update to kernel 3.1.1-1 together with the corresponding NVIDIA driver from RPMfusion. Booting into the new kernel went through witout any hangups, no failed services, no 'quiet waits' during the boot process.

Still, having this problem just disappear without any analysis or understanding of what caused the problem in the first place leaves a bit of a bad feeling.

So, if anyone can still shed some light onto what might have caused the problem, I'd be grateful.
Reply With Quote
  #3  
Old 17th November 2011, 09:03 PM
chrisham Offline
Registered User
 
Join Date: Nov 2011
Posts: 10
linuxfirefox
Re: systemd hang during startup (Fedora15/16)

And here we go again - after another reboot it turns out the problem is still there.

Again a hang during boot, 'Alt+SysRq+e' gets things going again ... I still need help figuring out where to look for a real solution.
Reply With Quote
  #4  
Old 6th December 2011, 11:49 PM
chrisham Offline
Registered User
 
Join Date: Nov 2011
Posts: 10
linuxfirefox
[SOLVED] Re: systemd hang during startup (Fedora15/16)

OK - after much suffering I finally found a solution for my problem:

It turns out that systemd does not agree with syslog-ng

Fedora offers the choice between three logging daemons: sysklogd, syslog-ng and rsyslog. My system has been updated (without ever reinstalling) all the way from the early pre-Fedora (Redhat) days - somewhere along the line, I must have switched from the original sysklogd to syslog-ng. This was then propagated through all the updates, just waiting to fail as soon as systemd was introduced, and a certain change made it into syslog-ng.

Unfortunately, I cannot find the Web page anymore that finally pointed me in the right directions. However, after replacing syslog-ng with rsyslog, my boot immediately went all the way through to the KDM start screen - everything seems alright now.
Reply With Quote
  #5  
Old 19th February 2012, 03:46 AM
Ernst0 Offline
Registered User
 
Join Date: Mar 2009
Location: Northern California
Posts: 89
linuxfedorafirefox
Re: systemd hang during startup (Fedora15/16)

I have this problem and I can stand all the hand holding anyone cares to offer.

I just followed the installation of the NVIDIA files as directed in that thread.

What do I do to change this? This is a fresh install from the F16 Gnome distro plus the updates and NVIDIA.

I appreciate the help.

I don't know if it is related but the encrypted file system reports corruption every time software is installed or updates. It is rebuilding the files and directories right now. I figure the new repair is not like the old fsck

Last edited by Ernst0; 19th February 2012 at 03:49 AM.
Reply With Quote
Reply

Tags
fedora15 or 16, hang, startup, systemd

Thread Tools Search this Thread
Search this Thread:

Advanced Search
Display Modes

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off

Forum Jump

Similar Threads
Thread Thread Starter Forum Replies Last Post
Analyze the startup time of your OS with systemd salemeni Guides & Solutions (No Questions) 3 17th August 2011 06:28 PM
systemd exec 203 failed service startup (a non-starter, so to speak) m1boli Using Fedora 0 29th June 2011 02:10 AM
Fedora15 Desktops and Systemd hal8000b Using Fedora 4 31st May 2011 01:31 AM
FC3 Startup Hang nupe494 EOL (End Of Life) Versions 8 27th August 2005 12:35 AM


Current GMT-time: 11:18 (Monday, 01-09-2014)

TopSubscribe to XML RSS for all Threads in all ForumsFedoraForumDotOrg Archive
logo

All trademarks, and forum posts in this site are property of their respective owner(s).
FedoraForum.org is privately owned and is not directly sponsored by the Fedora Project or Red Hat, Inc.

Privacy Policy | Term of Use | Posting Guidelines | Archive | Contact Us | Founding Members

Powered by vBulletin® Copyright ©2000 - 2012, vBulletin Solutions, Inc.

FedoraForum is Powered by RedHat