Arch Linux

julesm

Member

Registered: 2014-07-29

Posts: 70

[SOLVED] Suddenly slower boot (since last update)

Since yesterday's update my boot time has suddenly slowed and I'm trying to troubleshoot why. I would be extremely grateful if anyone could give me a pointer in the right direction as to what could be the culprit.

Here's my systemd-analyze blame:

13.037s systemd-journald.service
6.120s NetworkManager.service
4.361s systemd-fsck@dev-disk-by\x2duuid-798097bd\x2dcdcb\x2d4610\x2dbacf\x2d39dcc8642e5f.service
3.643s lvm2-pvscan@254:0.service
3.500s iptables.service
1.993s systemd-fsck@dev-disk-by\x2duuid-e08e6ce4\x2dee3d\x2d4fdc\x2d8271\x2d8b19f1ddfa31.service
1.964s upower.service
1.882s systemd-logind.service
1.879s alsa-restore.service
1.509s wpa_supplicant.service
1.467s systemd-vconsole-setup.service
1.408s boot.mount
1.391s systemd-rfkill@rfkill0.service
1.377s dev-disk-by\x2duuid-7d5d6aec\x2d72e5\x2d4de4\x2db168\x2d8525b0f7d3e2.swap
1.271s systemd-journal-flush.service
1.171s systemd-udevd.service
1.153s systemd-remount-fs.service
1.121s dev-hugepages.mount
1.013s sys-kernel-debug.mount
984ms dev-mqueue.mount
982ms tmp.mount
914ms colord.service
816ms home.mount
719ms systemd-tmpfiles-clean.service
672ms polkit.service
605ms systemd-random-seed.service
572ms systemd-rfkill@rfkill1.service
562ms systemd-modules-load.service
550ms systemd-backlight@backlight:nv_backlight.service
543ms systemd-tmpfiles-setup-dev.service
428ms systemd-user-sessions.service
427ms sys-kernel-config.mount
416ms user@1000.service
402ms udisks2.service
370ms systemd-udev-trigger.service
270ms systemd-sysctl.service
269ms systemd-rfkill@rfkill2.service
190ms avahi-daemon.service
174ms ntpd.service
120ms kmod-static-nodes.service
106ms rtkit-daemon.service
99ms systemd-tmpfiles-setup.service
95ms systemd-update-utmp.service
18ms systemd-rfkill@rfkill3.service
1ms sys-fs-fuse-connections.mount

I've checked and no systemd services have entered in a failed state.

$ systemctl --failed
0 loaded units listed.

My systemd-analyze critical-chain gives this:

graphical.target @21.915s
└─multi-user.target @21.915s
  └─NetworkManager.service @15.795s +6.120s
    └─basic.target @15.794s
      └─timers.target @15.793s
        └─systemd-tmpfiles-clean.timer @15.793s
          └─sysinit.target @15.750s
            └─systemd-update-utmp.service @15.654s +95ms
              └─systemd-tmpfiles-setup.service @15.553s +99ms
                └─systemd-journal-flush.service @14.281s +1.271s
                  └─systemd-journald.service @1.242s +13.037s
                    └─system.slice @1.100s
                      └─-.slice @1.099s

ls -l /etc/systemd/system/* gives this:

lrwxrwxrwx 1 root root   46 Jun 24 17:08 /etc/systemd/system/dbus-org.freedesktop.NetworkManager.service -> /usr/lib/systemd/system/NetworkManager.service
lrwxrwxrwx 1 root root   57 Jun 24 17:08 /etc/systemd/system/dbus-org.freedesktop.nm-dispatcher.service -> /usr/lib/systemd/system/NetworkManager-dispatcher.service

/etc/systemd/system/getty.target.wants:
total 0
lrwxrwxrwx 1 root root 38 Jun 24 16:10 getty@tty1.service -> /usr/lib/systemd/system/getty@.service

/etc/systemd/system/getty@tty1.service.d:
total 4
-rw-r--r-- 1 root root 89 Jul 31 08:17 autologin.conf

/etc/systemd/system/multi-user.target.wants:
total 0
lrwxrwxrwx 1 root root 33 Jun 25 07:35 cups.path -> /usr/lib/systemd/system/cups.path
lrwxrwxrwx 1 root root 40 Jul  2 09:37 iptables.service -> /usr/lib/systemd/system/iptables.service
lrwxrwxrwx 1 root root 46 Jun 24 17:08 NetworkManager.service -> /usr/lib/systemd/system/NetworkManager.service
lrwxrwxrwx 1 root root 43 Nov  1 09:40 org.cups.cupsd.path -> /usr/lib/systemd/system/org.cups.cupsd.path
lrwxrwxrwx 1 root root 51 Nov  9 22:22 remote-fs.target -> ../../../../usr/lib/systemd/system/remote-fs.target

/etc/systemd/system/printer.target.wants:
total 0
lrwxrwxrwx 1 root root 46 Nov  1 09:40 org.cups.cupsd.service -> /usr/lib/systemd/system/org.cups.cupsd.service

/etc/systemd/system/sockets.target.wants:
total 0
lrwxrwxrwx 1 root root 35 Jun 25 07:35 cups.socket -> /usr/lib/systemd/system/cups.socket
lrwxrwxrwx 1 root root 45 Nov  1 09:40 org.cups.cupsd.socket -> /usr/lib/systemd/system/org.cups.cupsd.socket

/etc/systemd/system/sysinit.target.wants:
total 0

Many thanks for any assistance.

Cheers,
Jules

Last edited by julesm (2014-11-12 21:50:38)

Fuxino

Member

From: Slovakia

Registered: 2014-09-26

Posts: 179

Re: [SOLVED] Suddenly slower boot (since last update)

I have a similar issue. For me what's taking long is the systemd-journal-flush.service.

It started after I update the system with 'pacman -Syu':

[2014-11-11 18:32] [PACMAN] Running 'pacman -Syu'
[2014-11-11 18:32] [PACMAN] synchronizing package lists
[2014-11-11 18:33] [PACMAN] starting full system upgrade
[2014-11-11 18:33] [PACMAN] upgraded kmod (18-1 -> 18-2)
[2014-11-11 18:33] [PACMAN] upgraded libsystemd (216-3 -> 217-6)
[2014-11-11 18:33] [PACMAN] upgraded protobuf (2.6.0-3 -> 2.6.1-1)
[2014-11-11 18:33] [PACMAN] installed lz4 (123-1)
[2014-11-11 18:33] [PACMAN] upgraded systemd (216-3 -> 217-6)
[2014-11-11 18:33] [PACMAN] upgraded systemd-sysvcompat (216-3 -> 217-6)

systemd-analyze blame:

10.996s systemd-journal-flush.service
2.741s polkit.service
2.688s systemd-fsck@dev-disk-by\x2duuid-634cb882\x2dd1a
2.513s user@1000.service
2.085s netctl-auto@wlp7s0.service
2.078s laptop-powersave.service
1.905s lvm2-pvscan@8:2.service
1.774s systemd-vconsole-setup.service
1.480s systemd-fsck@dev-disk-by\x2duuid-252aa34b\x2dabf
1.329s systemd-udev-settle.service
1.254s alsa-restore.service
1.222s systemd-logind.service
1.216s brcms_suppression.service
1.210s iptables.service
1.203s systemd-modules-load.service
702ms systemd-journald.service
655ms systemd-binfmt.service
647ms systemd-tmpfiles-setup-dev.service
609ms systemd-remount-fs.service
607ms sys-kernel-debug.mount
527ms dev-mqueue.mount
508ms systemd-udevd.service
498ms dev-hugepages.mount
455ms var.mount
447ms systemd-sysctl.service
383ms systemd-udev-trigger.service
364ms boot.mount
357ms kmod-static-nodes.service
339ms home.mount
285ms systemd-rfkill@rfkill2.service
285ms systemd-random-seed.service
276ms systemd-rfkill@rfkill1.service
273ms systemd-rfkill@rfkill0.service
213ms systemd-tmpfiles-setup.service
172ms avahi-daemon.service
157ms systemd-tmpfiles-clean.service
144ms tmp.mount
136ms dev-disk-by\x2duuid-c68208bd\x2dcf7b\x2d4cfd\x2da2c6\x2d4ad4a0c6cd35.swap
125ms proc-sys-fs-binfmt_misc.mount
42ms systemd-user-sessions.service
37ms systemd-update-utmp.service
10ms var-lib-mysqltmp.mount
7ms home-fuxino-.cache.mount
6ms sys-kernel-config.mount

systemd-analyze critical-chain:

multi-user.target @22.399s
└─laptop-powersave.service @20.319s +2.078s
  └─acpid.service @20.316s
    └─basic.target @20.254s
      └─timers.target @20.252s
        └─systemd-tmpfiles-clean.timer @20.252s
          └─sysinit.target @20.249s
            └─systemd-update-utmp.service @20.211s +37ms
              └─systemd-tmpfiles-setup.service @19.995s +213ms
                └─systemd-journal-flush.service @8.995s +10.996s
                  └─var.mount @8.445s +455ms
                    └─dev-disk-by\x2duuid-d96a976c\x2dcaa6\x2d4c19\x2d9ef4\x2d8efd7bfdfbd2.device @8.443s

ooo

Member

Registered: 2013-04-10

Posts: 1,638

Re: [SOLVED] Suddenly slower boot (since last update)

did you try limiting journal size?
it's not uncommon that it will slow down your boot, as it grows bigger and gets fragmented on your hard drive over time.

julesm

Member

Registered: 2014-07-29

Posts: 70

Re: [SOLVED] Suddenly slower boot (since last update)

Many thanks, ooo! I set the SystemMaxUse to 50M, cleared out the existing journal log and all's well and speedy once again!

Thanks again!

Jules