Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
boot delay after starting timers.target
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Desktop Environments
View previous topic :: View next topic  
Author Message
potuz
Guru
Guru


Joined: 30 Jan 2010
Posts: 378

PostPosted: Sat Jan 25, 2014 6:49 pm    Post subject: boot delay after starting timers.target Reply with quote

My system is a relatively fresh stable install, very lightweight (fvwm, no windows manager). Booting into multiuser.target. I see a delay of 9s-15s after starting timers. The relevant part of the log is:
Code:

#journalctl -b
...
Jan 25 14:20:58 birra systemd[1]: Listening on D-Bus System Message Bus Socket.
Jan 25 14:20:58 birra systemd[1]: Starting Sockets.
Jan 25 14:20:58 birra systemd[1]: Reached target Sockets.
Jan 25 14:20:58 birra systemd[1]: Starting Daily Cleanup of Temporary Directories.
Jan 25 14:20:58 birra systemd[1]: Started Daily Cleanup of Temporary Directories.
Jan 25 14:20:58 birra systemd[1]: Starting Timers.
Jan 25 14:21:12 birra systemd[1]: Reached target Timers.
Jan 25 14:21:12 birra systemd[1]: Started Manage Sound Card State (restore and store).
Jan 25 14:21:12 birra systemd[1]: Starting Restore Sound Card State...
Jan 25 14:21:12 birra systemd[1]: Starting Basic System.
Jan 25 14:21:12 birra systemd[1]: Reached target Basic System.
Jan 25 14:21:12 birra systemd[1]: Starting Wireless network connectivity (wlp1s0)...
Jan 25 14:21:12 birra systemd[1]: Starting fcron periodical command scheduler...
Jan 25 14:21:12 birra systemd[1]: Starting Login Service...
Jan 25 14:21:12 birra systemd[1]: Starting D-Bus System Message Bus...
Jan 25 14:21:12 birra systemd[1]: Started D-Bus System Message Bus.
...

Booting with log_level=debug for systemd I get something slightly more meaninful:
Code:

#journalctl -b
...
Jan 25 12:27:49 birra systemd[1]: Child 2011 belongs to systemd-update-utmp.service
Jan 25 12:27:49 birra systemd[1]: systemd-update-utmp.service: main process exited, code=exited, status=0/SUCCESS
Jan 25 12:27:49 birra systemd[1]: systemd-update-utmp.service changed start -> exited
Jan 25 12:27:49 birra systemd[1]: Job systemd-update-utmp.service/start finished, result=done
Jan 25 12:27:49 birra systemd[1]: Started Update UTMP about System Reboot/Shutdown.
Jan 25 12:28:05 birra systemd[1]: Closed jobs progress timerfd.
Jan 25 12:28:05 birra systemd[1]: Starting System Initialization.
Jan 25 12:28:05 birra systemd[1]: sysinit.target changed dead -> active
Jan 25 12:28:05 birra systemd[1]: Job sysinit.target/start finished, result=done
Jan 25 12:28:05 birra systemd[1]: Reached target System Initialization.
...

systemd-analyze plot gives this graph (on the log_level=debug boot) showing the delay on update-utmp.

systemd-analyze critical-chain and such do not show much:
Code:

# systemd-analyze
Startup finished in 2ms (firmware) + 5ms (loader) + 2.979s (kernel) + 27.680s (userspace) = 30.66
# systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

multi-user.target @27.680s
└─network-wireless@wlp1s0.service @17.130s +10.549s
  └─basic.target @17.127s
    └─timers.target @3.749s
      └─systemd-tmpfiles-clean.timer @3.749s
        └─sysinit.target @3.746s
          └─systemd-update-utmp.service @3.561s +183ms
            └─systemd-tmpfiles-setup.service @3.476s +81ms
              └─local-fs.target @3.473s
                └─home.mount @3.403s +68ms
                  └─dev-sda2.device @3.365s

# systemd-analyze blame
         10.549s network-wireless@wlp1s0.service
          4.203s systemd-suspend.service
          1.948s alsa-restore.service
          1.546s systemd-logind.service
           818ms user@1000.service
           510ms systemd-fsck-root.service
           491ms systemd-udev-trigger.service
           490ms kmod-static-nodes.service
           410ms systemd-tmpfiles-clean.service
           403ms dev-mqueue.mount
           402ms systemd-vconsole-setup.service
           373ms systemd-sysctl.service
           366ms dev-hugepages.mount
           361ms sys-kernel-debug.mount
           334ms sys-fs-fuse-connections.mount
           325ms fcron.service
           221ms systemd-remount-fs.service
           211ms systemd-user-sessions.service
           183ms systemd-update-utmp.service
           177ms systemd-journal-flush.service
           107ms systemd-tmpfiles-setup-dev.service
            81ms systemd-tmpfiles-setup.service
            81ms systemd-random-seed.service
            68ms home.mount
            36ms systemd-udevd.service
            31ms systemd-backlight@acpi_video0.service
            20ms tmp.mount
             8ms systemd-fsck@dev-sdb2.service
             5ms boot.mount

Of course waking up the wireless (network-wireless@.service manually executes wpa-supplicant+dhcpcd on the interface) is taking the most time in wake up, but the delay is clearly unrelated and in fact, disabling network-wireless@.service the delay is still there).
I found this thread in the arch forums with a similar problem. My tmpfiles are essentially the sames as the ones of that user with only
Code:
# cat /usr/lib/tmpfiles.d/*
d /run/saslauthd 0755 root root -
# New OpenRC versions replace /var/lock with a symlink to /run/lock.
# We just create that directory for now, just in case.
# Of course, it's not guaranteed that'll satisfy all relevant packages.

d /run/lock 0755 root root -
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

# See tmpfiles.d(5) for details

d /run/user 0755 root root ~10d
F /run/utmp 0664 root utmp -

f /var/log/wtmp 0664 root utmp -
f /var/log/btmp 0600 root utmp -

d /var/cache/man - - - 30d

d /run/systemd/ask-password 0755 root root -
d /run/systemd/seats 0755 root root -
d /run/systemd/sessions 0755 root root -
d /run/systemd/users 0755 root root -
d /run/systemd/machines 0755 root root -
d /run/systemd/shutdown 0755 root root -

F /run/nologin 0644 - - - "System is booting up. See pam_nologin(8)"

m /var/log/journal 2755 root systemd-journal - -
m /var/log/journal/%m 2755 root systemd-journal - -
m /run/log/journal 2755 root systemd-journal - -
m /run/log/journal/%m 2755 root systemd-journal - -
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

# See tmpfiles.d(5) for details

# Clear tmp directories separately, to make them easier to override
d /tmp 1777 root root 10d
d /var/tmp 1777 root root 30d

# Exclude namespace mountpoints created with PrivateTmp=yes
x /tmp/systemd-private-*
x /var/tmp/systemd-private-*
X /tmp/systemd-private-*/tmp
X /var/tmp/systemd-private-*/tmp
#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.

# See tmpfiles.d(5) for details

# Make sure these are created by default so that nobody else can
d /tmp/.X11-unix 1777 root root 10d
d /tmp/.ICE-unix 1777 root root 10d
d /tmp/.XIM-unix 1777 root root 10d
d /tmp/.font-unix 1777 root root 10d
d /tmp/.Test-unix 1777 root root 10d

# Unlink the X11 lock files
r /tmp/.X[0-9]*-lock

Does anyone here know where should I start looking for a way to debug this?
Thanks,
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Desktop Environments All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum