Page 1 of 3 123 LastLast
Results 1 to 10 of 21

Thread: systemd needs too much time to boot system

  1. #1

    Default systemd needs too much time to boot system

    I have a fresh installation of openSUSE 12.2. The boot process takes way too long, there are several pauses during boot process.
    Code:
    # systemd-analyze 
    Startup finished in 4917ms (kernel) + 123483ms (userspace) = 128401ms
    # systemd-analyze blame
     56148ms network.service
     44788ms remount-rootfs.service
     10719ms systemd-modules-load.service
      8940ms systemd-vconsole-setup.service
      8310ms console-kit-daemon.service
      5789ms md.service
      5164ms plymouth-start.service
      3556ms var-lock.mount
      3531ms var-run.mount
      3299ms dev-hugepages.mount
      3267ms dev-mqueue.mount
    ...
    systemd claims that network.service took 56 seconds, but the logger calls that I have added in /etc/init.d/network show that the script only needed about 16 seconds from start to exit. What is systemd doing for 40 seconds?

    Although I have added "systemd.log_target=kmsg systemd.log_level=debug systemd.sysv_console=1" to the kernel command line, I still do not see any log messages of systemd like "network.service starting " and "network.service done". How can I get such simple log information?

  2. #2
    Join Date
    Mar 2010
    Location
    Austin - Texas
    Posts
    10,500
    Blog Entries
    48

    Smile Re: systemd needs too much time to boot system

    Quote Originally Posted by herbertmeier View Post
    I have a fresh installation of openSUSE 12.2. The boot process takes way too long, there are several pauses during boot process.
    Code:
    # systemd-analyze 
    Startup finished in 4917ms (kernel) + 123483ms (userspace) = 128401ms
    # systemd-analyze blame
     56148ms network.service
     44788ms remount-rootfs.service
     10719ms systemd-modules-load.service
      8940ms systemd-vconsole-setup.service
      8310ms console-kit-daemon.service
      5789ms md.service
      5164ms plymouth-start.service
      3556ms var-lock.mount
      3531ms var-run.mount
      3299ms dev-hugepages.mount
      3267ms dev-mqueue.mount
    ...
    systemd claims that network.service took 56 seconds, but the logger calls that I have added in /etc/init.d/network show that the script only needed about 16 seconds from start to exit. What is systemd doing for 40 seconds?

    Although I have added "systemd.log_target=kmsg systemd.log_level=debug systemd.sysv_console=1" to the kernel command line, I still do not see any log messages of systemd like "network.service starting " and "network.service done". How can I get such simple log information?
    So, we can only say that your mileage may vary, depending on the hardware that you use. I do use a SSD for my boot driver, but all of the times are much less than yours. I might ask if we could look at your boot.log file to see what it might say on startup. I have a bash script for log file viewing you can use:

    S.L.A.V.E. - SuSE Logfile Automated Viewer Engine - Version 2.60 - Blogs - openSUSE Forums

    Here is my composite time: Startup finished in 3107ms (kernel) + 42772ms (userspace) = 45880ms

    Thank You,
    Last edited by jdmcdaniel3; 23-Oct-2012 at 15:04.
    My Blog: https://forums.opensuse.org/blogs/jdmcdaniel3/

    Software efficiency halves every 18 months, thus compensating for Moore's Law

    Its James again from Austin, Texas

  3. #3
    Join Date
    Jun 2009
    Location
    Mangfall, Germany
    Posts
    1,145

    Default Re: systemd needs too much time to boot system

    In yast /etc/sysconfig/ Editor, search for 'wait' and have a look at the times allocated

    to speed boot up, on this PC,
    - WAIT_FOR_INTERFACES default is 30, changed to 10
    - DHCLIENT_WAIT_AT_BOOT default is 15, changed to 3

    boot times are hardware and services enabled dependent, on this PC
    Startup finished in 3240ms (kernel) + 18908ms (userspace) = 22148ms

    services taking longer than 1 second :-
    4245ms home.mount
    2614ms systemd-vconsole-setup.service
    2198ms NetworkManager.service
    1964ms localnet.service
    1735ms systemd-modules-load.service
    1563ms SuSEfirewall2_setup.service
    1064ms hddtemp.service
    1028ms xinetd.service

    Do you like Plymouth?

  4. #4

    Default Re: systemd needs too much time to boot system

    Are you sure that the boot.log would help? It just contains, which services were started (all have a OK) but no time information.

    The main thing I want to find out are the reasons for the delay of about 40 seconds, where nothing seems to be happening: No log message on console 1, 7 or 10 are printed during that time.

    The changes to the network configuration should not help (nevertheless I have changed the 30 to 10), as I do not use DHCP and according to the log output, the network init script takes (only) 16 seconds of the 56 seconds that are printed by systemd.

  5. #5

    Default Re: systemd needs too much time to boot system

    Quote Originally Posted by herbertmeier View Post
    Although I have added "systemd.log_target=kmsg systemd.log_level=debug systemd.sysv_console=1" to the kernel command line, I still do not see any log messages of systemd like "network.service starting " and "network.service done". How can I get such simple log information?
    Remove "quiet" kernel parameter. It causes systemd to suppress all status messages about services progress.

  6. #6
    Join Date
    Nov 2009
    Location
    Groningen, NL
    Posts
    188

    Default Re: systemd needs too much time to boot system

    I have/had the same problem, although the delays are smaller. About 40 seconds were shaved off when I disabled ntp.
    Method: Yast -> System -> /etc/sysconfig editor -> Network -> General -> NETCONFIG_NTP_POLICY : change from auto to ""
    (two double apostrophes).
    For setting the system clock I now use ntpdate manually - later to be transferred to a cronjob
    Not-starting Nepomuk reduces the delay after login by approx. 30 seconds.
    AMD Phenom II X2 555, 4 GB, 500 GB SATA, openSUSE-13.1 (64b), KDE 4.12.1

  7. #7

    Default Re: systemd needs too much time to boot system

    hws38 wrote:
    > I have/had the same problem, although the delays are smaller. About 40
    > seconds were shaved off when I disabled ntp.
    > Method: Yast -> System -> /etc/sysconfig editor -> Network -> General
    > -> NETCONFIG_NTP_POLICY : change from auto to ""
    > (two double apostrophes).
    > For setting the system clock I now use ntpdate manually - later to be
    > transferred to a cronjob


    IMHO, that's a bad idea; the normal NTP daemon works well. But there's
    no reason why NTP should be adding 40 secs to the boot time. That sounds
    like somthing to file in bugzilla.

    > Not-starting Nepomuk reduces the delay after login by approx. 30
    > seconds.
    >
    >


  8. #8

    Default Re: systemd needs too much time to boot system

    Quote Originally Posted by djh-novell View Post
    hBut there's
    no reason why NTP should be adding 40 secs to the boot time.
    As a guess - it tries to sync time during startup? Does setting NTPD_FORCE_SYNC_ON_STARTUP to "no" in /etc/sysconfig/ntp help?

  9. #9

    Default Re: systemd needs too much time to boot system

    Quote Originally Posted by arvidjaar View Post
    Remove "quiet" kernel parameter. It causes systemd to suppress all status messages about services progress.
    This was one of the first things I did, as I do not like any splash screen that hides error messages.

    It seems that a mkinitrd or one of the recent updates was needed to let systemd produce the debug messages. Additionally I completely removed plymouth. It looks like it is in some way related to the network startup that delays the boot process. Although the network init script returns an error (it did not do this before today), the interfaces are properly set up.

    Summary of the code block: network.service is started at time 24 and exits at time 92.

    Code:
    [    7.589679] systemd[1]: Installed new job network.service/start as 128
    [    7.589682] systemd[1]: Installed new job network-remotefs.service/start as 129
    ...
    [   24.646101] systemd[1]: About to execute: /etc/init.d/network start
    [   24.656432] systemd[1]: Forked /etc/init.d/network as 944
    [   24.656471] systemd[1]: network.service changed dead -> start
    ...
    [   27.247624] systemd[1]: systemd-logind.service changed start -> running
    [   27.247629] systemd[1]: Job systemd-logind.service/start finished, result=done
    [   38.000145] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   38.000158] systemd[1]: Running GC...
    [   38.002906] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   38.012318] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   49.501410] systemd[1]: Received SIGCHLD from PID 297 (systemd-readahe).
    [   49.501440] systemd[1]: Got SIGCHLD for process 297 (systemd-readahe)
    [   49.501465] systemd[1]: Child 297 died (code=exited, status=0/SUCCESS)
    [   49.501470] systemd[1]: Child 297 belongs to systemd-readahead-replay.service
    [   49.501486] systemd[1]: systemd-readahead-replay.service: main process exited, code=exited, status=0
    [   49.512044] systemd[1]: systemd-readahead-replay.service changed running -> exited
    [   49.512117] systemd[1]: Accepted connection on private bus.
    [   49.512238] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Agent.Released() on /org/freedesktop/systemd1/agent
    [   49.512288] systemd[1]: systemd-readahead-replay.service: cgroup is empty
    [   49.512323] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
    [   72.871572] systemd[1]: Got notification message for unit systemd-journald.service
    [   72.871581] systemd[1]: systemd-journald.service: Got message
    [   72.871590] systemd[1]: systemd-journald.service: got STATUS=Processing requests...
    [   83.397560] systemd[1]: Incoming traffic on syslog.socket
    [   83.397573] systemd[1]: syslog.socket changed listening -> running
    [   84.234789] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Activator.ActivationRequest() on /org/freedesktop/DBus
    [   84.234797] systemd[1]: Got D-Bus activation request for console-kit-daemon.service
    [   84.234995] systemd[1]: Trying to enqueue job console-kit-daemon.service/start/replace
    [   84.235353] systemd[1]: Installed new job console-kit-daemon.service/start as 226
    [   84.235358] systemd[1]: Enqueued job console-kit-daemon.service/start as 226
    [   84.235899] systemd[1]: About to execute: /usr/sbin/console-kit-daemon --no-daemon
    [   84.242137] systemd[1]: Forked /usr/sbin/console-kit-daemon as 1473
    [   84.242277] systemd[1]: console-kit-daemon.service changed dead -> start
    [   87.652978] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   87.657479] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   89.575234] systemd[1]: Got notification message for unit avahi-daemon.service
    [   89.575239] systemd[1]: avahi-daemon.service: Got message
    [   89.575244] systemd[1]: avahi-daemon.service: got STATUS=Registering host name hm.local
    [   89.577634] systemd[1]: Got notification message for unit avahi-daemon.service
    [   89.577638] systemd[1]: avahi-daemon.service: Got message
    [   89.577644] systemd[1]: avahi-daemon.service: got STATUS=Server startup complete. Host name is hm.local. Local service cookie is 3648052011.
    [   89.583164] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   89.694607] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   89.696101] systemd[1]: Got D-Bus request: org.freedesktop.DBus.NameOwnerChanged() on /org/freedesktop/DBus
    [   89.696108] systemd[1]: console-kit-daemon.service's D-Bus name org.freedesktop.ConsoleKit now registered by :1.5
    [   89.696175] systemd[1]: console-kit-daemon.service changed start -> running
    [   89.696180] systemd[1]: Job console-kit-daemon.service/start finished, result=done
    [   89.970370] atl1 0000:02:00.0: irq 45 for MSI/MSI-X
    [   89.970481] atl1 0000:02:00.0: eth0 link is up 100 Mbps full duplex
    [   90.012961] systemd[1]: Accepted connection on private bus.
    [   90.013175] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.LoadUnit() on /org/freedesktop/systemd1
    [   90.013250] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Properties.GetAll() on /org/freedesktop/systemd1/unit/graphical_2etarget
    [   90.013421] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
    [   90.106570] systemd[1]: Received SIGCHLD from PID 1768 (ifstatus-route).
    [   90.106590] systemd[1]: Got SIGCHLD for process 1768 (ifstatus-route)
    [   90.106627] systemd[1]: Child 1768 died (code=exited, status=1/FAILURE)
    [   90.195744] systemd[1]: Received SIGCHLD from PID 1838 (ifstatus-route).
    [   90.195765] systemd[1]: Got SIGCHLD for process 1838 (ifstatus-route)
    [   90.195800] systemd[1]: Child 1838 died (code=exited, status=1/FAILURE)
    [   90.293323] Bridge firewalling registered
    [   90.297193] device eth0 entered promiscuous mode
    [   90.302596] systemd[1]: sys-devices-virtual-net-br0.device changed dead -> plugged
    [   90.302892] br0: port 1(eth0) entered forwarding state
    [   90.302899] br0: port 1(eth0) entered forwarding state
    [   90.328365] systemd[1]: Received SIGCHLD from PID 1971 (ifup-route).
    [   90.328386] systemd[1]: Got SIGCHLD for process 1971 (ifup-route)
    [   90.328424] systemd[1]: Child 1971 died (code=exited, status=1/FAILURE)
    [   90.350652] systemd[1]: Accepted connection on private bus.
    [   90.350782] systemd[1]: Got D-Bus request: org.freedesktop.systemd1.Manager.LoadUnit() on /org/freedesktop/systemd1
    [   90.350857] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Properties.GetAll() on /org/freedesktop/systemd1/unit/graphical_2etarget
    [   90.351038] systemd[1]: Got D-Bus request: org.freedesktop.DBus.Local.Disconnected() on /org/freedesktop/DBus/Local
    [   92.783896] systemd[1]: Received SIGCHLD from PID 2273 (ifstatus-route).
    [   92.783917] systemd[1]: Got SIGCHLD for process 2273 (ifstatus-route)
    [   92.783952] systemd[1]: Child 2273 died (code=exited, status=1/FAILURE)
    [   92.837581] systemd[1]: Received SIGCHLD from PID 944 (network).
    [   92.837608] systemd[1]: Got SIGCHLD for process 944 (network)
    [   92.837674] systemd[1]: Child 944 died (code=exited, status=7/NOTRUNNING)
    [   92.837679] systemd[1]: Child 944 belongs to network.service
    [   92.837691] systemd[1]: network.service: control process exited, code=exited status=7
    [   92.837695] systemd[1]: network.service got final SIGCHLD for state start
    [   92.837709] systemd[1]: network.service changed start -> failed
    [   92.839105] systemd[1]: Job network.service/start finished, result=failed
    [   92.847304] systemd[1]: Unit network.service entered failed state.
    [   92.847360] systemd[1]: network.target changed dead -> active
    [   92.847366] systemd[1]: Job network.target/start finished, result=done
    [   92.847376] systemd[1]: remote-fs-pre.target changed dead -> active
    I searched for a way to force systemd to do one thing after the other (not everything in parallel), but I could not find any. The options in /etc/sysconfig/boot seem to be only used for the old init system.

    So my next step is to remove the br0 and enable debug in network config.

  10. #10

    Default Re: systemd needs too much time to boot system

    Quote Originally Posted by herbertmeier View Post
    So my next step is to remove the br0 and enable debug in network config.
    Why do you need a bridge (br0) at boot? Who wouldn't have this device if someone/something hadn't created a bridge. Did you install an hypervisor or something?

Page 1 of 3 123 LastLast

Tags for this Thread

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •