Arch Linux

ziro360

Member

Registered: 2012-04-27

Posts: 30

[Solved] Increased boot time after update

Hi,

I normally have a between 20s to 30s boot time on SSD, but after the most recent update this as increased to 2 minutes.
The problem appears to be related to the upower service that takes almost 1 minute to load. Do you guys have any idea whats going on?

~|➜ sudo systemd-analyze
Startup finished in 1.735s (kernel) + 59.786s (userspace) = 1min 1.522s

~|➜ sudo systemd-analyze blame
         58.297s upower.service
           374ms run-media-walfire-Data.mount
           224ms dev-sdb1.device
            85ms systemd-logind.service
            79ms packagekit.service
            78ms user@1000.service
            71ms lm_sensors.service
            66ms alsa-restore.service
            66ms systemd-user-sessions.service
            61ms systemd-journald.service
...

~|➜ sudo 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.

graphical.target @59.786s
└─upower.service @1.489s +58.297s
  └─basic.target @1.485s
    └─sockets.target @1.485s
      └─dbus.socket @1.485s
        └─sysinit.target @1.485s
          └─systemd-backlight@backlight:acpi_video1.service @2.344s +2ms
            └─system-systemd\x2dbacklight.slice @385ms
              └─system.slice @88ms
                └─-.slice @78ms

Last edited by ziro360 (2016-04-26 19:18:33)

ewaller

Administrator

From: Pasadena, CA

Registered: 2009-07-13

Posts: 19,784

Re: [Solved] Increased boot time after update

Anything in the journal?

---

Nothing is too wonderful to be true, if it be consistent with the laws of nature -- Michael Faraday
Sometimes it is the people no one can imagine anything of who do the things no one can imagine. -- Alan Turing
---
How to Ask Questions the Smart Way

ziro360

Member

Registered: 2012-04-27

Posts: 30

Re: [Solved] Increased boot time after update

Anything in the journal?

There are some things about upower and libupower-glib timed out

Apr 26 09:13:25 machine dbus[584]: [system] Failed to activate service 'org.freedesktop.UPower': timed out
Apr 26 09:13:25 machine org.gnome.Shell.desktop[822]: (gnome-shell:822): libupower-glib-WARNING **: Couldn't connect to proxy: Error calling StartServiceByName for org.freedesktop.UPower: GDBus.Error:org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.UPower': timed out
Apr 26 09:13:25 machine kernel: gnome-shell[822]: segfault at 0 ip 00007f7d7d09a549 sp 00007ffd0f208ad0 error 4 in libupower-glib.so.3.0.1[7f7d7d089000+25000]
Apr 26 09:13:25 machine systemd[1]: Created slice system-systemd\x2dcoredump.slice.
Apr 26 09:13:25 machine systemd[1]: Started Process Core Dump (PID 965/UID 0).
Apr 26 09:13:25 machine gnome-session[813]: gnome-session-binary[813]: WARNING: Application 'org.gnome.Shell.desktop' killed by signal 11
Apr 26 09:13:25 machine gnome-session-binary[813]: WARNING: Application 'org.gnome.Shell.desktop' killed by signal 11
Apr 26 09:13:25 machine gnome-session-binary[813]: Unrecoverable failure in required component org.gnome.Shell.desktop
Apr 26 09:13:25 machine systemd-coredump[966]: Process 822 (gnome-shell) of user 120 dumped core.

Full journal from the first few minutes: https://www.dropbox.com/s/4wvod59ohz5c8m4/dump.txt?dl=0

Trilby

Inspector Parrot

Registered: 2011-11-29

Posts: 29,524

Website

Re: [Solved] Increased boot time after update

Is this actually a problem?  What is the wallclock time from the start of systemd to being in your desktop?  It looks like about 1.5 seconds.

---

"UNIX is simple and coherent..." - Dennis Ritchie, "GNU's Not UNIX" -  Richard Stallman

ziro360

Member

Registered: 2012-04-27

Posts: 30

Re: [Solved] Increased boot time after update

Is this actually a problem?  What is the wallclock time from the start of systemd to being in your desktop?  It looks like about 1.5 seconds.

It takes about 2 minutes from the grub to the login prompt, before the update it was 30s or less.

Trilby

Inspector Parrot

Registered: 2011-11-29

Posts: 29,524

Website

Re: [Solved] Increased boot time after update

Then there is something not listed in your systemd-analyze output.  It show 1.485s to the basic target which is when you'd have the login prompt.

---

"UNIX is simple and coherent..." - Dennis Ritchie, "GNU's Not UNIX" -  Richard Stallman

ziro360

Member

Registered: 2012-04-27

Posts: 30

Re: [Solved] Increased boot time after update

Then there is something not listed in your systemd-analyze output.  It show 1.485s to the basic target which is when you'd have the login prompt.

I'm using gdm so the login prompt is on the graphical.target and it takes 59.786s

With in total gives me a boot time of 1min 1.522s in that particular boot

Startup finished in 1.735s (kernel) + 59.786s (userspace) = 1min 1.522s

Trilby

Inspector Parrot

Registered: 2011-11-29

Posts: 29,524

Website

Re: [Solved] Increased boot time after update

Hmm, that may be a gdm specific thing.  X should start as soon as basic.target is reached.  It does for me.  Anything after basic.target can take as long as needed as it will run in parallel to your desktop session.  Perhaps gdm.service has a specific after= dependency on upower.

---

"UNIX is simple and coherent..." - Dennis Ritchie, "GNU's Not UNIX" -  Richard Stallman

ziro360

Member

Registered: 2012-04-27

Posts: 30

Re: [Solved] Increased boot time after update

Hmm, that may be a gdm specific thing.  X should start as soon as basic.target is reached.  It does for me.  Anything after basic.target can take as long as needed as it will run in parallel to your desktop session.  Perhaps gdm.service has a specific after= dependency on upower.

It looks like it. This error messages on the journal talk about a timeout and errors on the libupower-glib

Apr 26 09:13:25 machine dbus[584]: [system] Failed to activate service 'org.freedesktop.UPower': timed out
Apr 26 09:13:25 machine org.gnome.Shell.desktop[822]: (gnome-shell:822): libupower-glib-WARNING **: Couldn't connect to proxy: Error calling StartServiceByName for org.freedesktop.UPower: GDBus.Error:org.freedesktop.DBus.Error.TimedOut: Failed to activate service 'org.freedesktop.UPower': timed out
Apr 26 09:13:25 machine kernel: gnome-shell[822]: segfault at 0 ip 00007f7d7d09a549 sp 00007ffd0f208ad0 error 4 in libupower-glib.so.3.0.1[7f7d7d089000+25000]

ziro360

Member

Registered: 2012-04-27

Posts: 30

Re: [Solved] Increased boot time after update

Well, after a little of digging around i found that its was a problem with a mismatch between the versions of libupower, upower and gnome shell. So i reinstalled them all solved the issue from the looks of it. And from the looks of it this new kernel version also gave me a boot time boost because now from the grub to the login it takes only 4s

~|➜ sudo systemd-analyze      
Startup finished in 1.842s (kernel) + 2.621s (userspace) = 4.463s

Marking this as solved