Bug 737917

Summary: very slow boot with systemd
Product: [openSUSE] openSUSE 12.1 Reporter: Wolfgang Rosenauer <wolfgang>
Component: BasesystemAssignee: Frederic Crozat <fcrozat>
Status: RESOLVED FIXED QA Contact: E-mail List <qa-bugs>
Severity: Normal    
Priority: P5 - None    
Version: Final   
Target Milestone: ---   
Hardware: x86-64   
OS: Other   
Whiteboard:
Found By: --- Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: bootgraph
bootgraph2

Description Wolfgang Rosenauer 2011-12-20 21:59:28 UTC
Sorry that I cannot add much initial information but I don't know how to diagnose anything in systemd.

My 11.4 boots to kdm within 25 seconds
12.1 with systemd needs 51 seconds to show me KDM on the same hardware.
Comment 1 Wolfgang Rosenauer 2011-12-21 10:49:46 UTC
There are not many services as it's a desktop machine so basically no server daemons started and the services in 11.4 and 12.1 are basically the same.

Please let me know which information is needed and how to get it.
Comment 2 Frederic Crozat 2011-12-21 11:48:08 UTC
first, install systemd update from home:fcrozat:systemd / systemd (it fixes some issues there).

Second, check dmesg to see if there is any timeout appearing (you might want to boot with systemd.log_level=debug systemd.log_target=kmsg to get a debug trace in dmesg).

Third, try to run :
systemd-analyze blame (to find which service is taking a lot of time)
systemd-analyze plot > boot.svg to see a bootchart of your system booting.
Comment 3 Wolfgang Rosenauer 2011-12-21 12:19:56 UTC
From dmesg:
[   12.920959] udev-configure-printer[860]: failed to connect to CUPS server; giving up
[   12.921502] systemd[1]: Received SIGCHLD from PID 860 (udev-configure-).
[   12.921525] systemd[1]: Got SIGCHLD for process 860 (udev-configure-)
[   12.921567] systemd[1]: Child 860 died (code=exited, status=1/FAILURE)
[   42.720184] usblp0: removed
[   42.720575] systemd[1]: dev-usblp0.device changed plugged -> dead
[   42.720597] systemd[1]: dev-usb-lp0.device changed plugged -> dead
[   42.720607] systemd[1]: sys-devices-pci0000:00-0000:00:13.5-usb1-1\x2d4-1\x2d4:1.1-usb-lp0.device changed plugged -> dead

Looks like a jump here.

Hygiea:~ # systemd-analyze blame
 37893ms storage-after-cryptsetup.service
 37290ms lvm.service
  6911ms md.service
  5443ms ntp.service
  2551ms localnet.service
  2003ms var-run.mount
  1949ms var-lock.mount
  1928ms dev-mqueue.mount
  1901ms dev-hugepages.mount
  1886ms sys-kernel-security.mount
  1865ms sys-kernel-debug.mount
  1844ms bootsplash-startup.service
  1835ms systemd-vconsole-setup.service
  1759ms media.mount
  1701ms remount-rootfs.service
  1401ms systemd-remount-api-vfs.service
  1163ms network.service
  1029ms bootsplash-quit.service
   658ms systemd-logind.service
   645ms systemd-readahead-replay.service
   592ms syslog.service
   454ms systemd-sysctl.service
   427ms systemd-readahead-collect.service
   404ms purge-kernels.service
   390ms rc-local.service
   381ms cpufreq.service
   370ms microcode.ctl.service
   368ms systemd-user-sessions.service
   349ms fbset.service
   300ms console-kit-log-system-start.service
   274ms cycle.service
   273ms network-remotefs.service
   164ms udev-trigger.service
   146ms xdm.service
   117ms udev.service
   106ms haveged.service
[some more under 100ms]

I do not have any crypto partition and no LVM.
I got a softraid on the machine but it's not used from 12.1 yet.
Comment 4 Wolfgang Rosenauer 2011-12-21 12:20:31 UTC
Created attachment 468484 [details]
bootgraph
Comment 5 Frederic Crozat 2011-12-21 14:07:47 UTC
cryptsetup / lvm taking time should be fixed with pending maintenance update for systemd in home:fcrozat:systemd / systemd. Please install this package and check again.

I'd suggest opening a bug against system-config-printer which should wait for cups to appear (I guess).

ntp is also taking a lot of time to startup..
Comment 6 Wolfgang Rosenauer 2011-12-21 16:27:03 UTC
after systemd update:

Hygiea:~ # systemd-analyze blame
  7664ms md.service
  6468ms remount-rootfs.service
  5986ms var-run.mount
  5944ms var-lock.mount
  5925ms dev-mqueue.mount
  5903ms dev-hugepages.mount
  5883ms sys-kernel-security.mount
  5865ms sys-kernel-debug.mount
  5731ms media.mount
  5692ms systemd-remount-api-vfs.service
  3392ms cycle.service
  3322ms udev-trigger.service
  3230ms bootsplash-startup.service
  3159ms udev.service
  3089ms localnet.service
  2593ms systemd-vconsole-setup.service
  2353ms ntp.service
  1549ms network.service
  1126ms systemd-tmpfiles-setup.service
  1023ms bootsplash-quit.service
   461ms systemd-logind.service
   394ms syslog.service
   393ms network-remotefs.service
   352ms systemd-readahead-collect.service
   331ms mcelog.service
   320ms systemd-readahead-replay.service
   274ms sshd.service
   220ms purge-kernels.service
   210ms rc-local.service
   199ms cpufreq.service
   192ms microcode.ctl.service
   186ms systemd-user-sessions.service
   171ms fbset.service
   147ms console-kit-log-system-start.service
   142ms xdm.service
   115ms systemd-sysctl.service
   108ms pcscd.service
   108ms haveged.service                                                        
   105ms cups.service
   101ms avahi-daemon.service                                            
    69ms nscd.service                                                         
    67ms dbus.service                                                         
    50ms console-kit-daemon.service
    37ms acpid.service
    34ms splash.service                                                         
    26ms splash_early.service
     0ms sys-fs-fuse-connections.mount
Comment 7 Wolfgang Rosenauer 2011-12-21 16:28:16 UTC
Created attachment 468527 [details]
bootgraph2

New bootgraph. The printer issue is gone apparently?
Anything looks out of tolerance here? Still NTP?
Comment 8 Frederic Crozat 2012-01-03 12:41:29 UTC
md.service is taking a lot of time but I'm guessing you have MD RAID on your system ?

for NTP, I can't really say if it is normal for it to take so much time or not.
Comment 9 Wolfgang Rosenauer 2012-01-03 16:49:24 UTC
I run one MD RAID on the system, yes. I also cannot tell about NTP but I wouldn't expect it to take much time.
As the biggest issues are gone with the update and we are basically at the same time of booting as with sysvinit feel free to either close this bug as fixed with the (upcoming?) update or let someone check about NTP.
Comment 10 Frederic Crozat 2012-01-03 16:54:15 UTC
let's close it as fixed then .