[SOLVED] Slow boot because of long loader stage

Martijn600 · 12-10-2018, 01:45 AM

Recently I did a fresh install of Lubuntu 18.04 on my machine (Asus R417S, Duo Core, 2 GHz, 2 GB RAM). Before Ubuntu 16.04 was installed. In Lubuntu 18.04 boot time to get into login screen is over 30s, I am quite sure Ubuntu 16.04 was a lot faster.
Not being a Linux expert myself, hopefully someone can help on tracking down a cause for the long boot time.

The boot plot shows for the loader stage a long gray bar.

Code:

systemd-analyze
Startup finished in 5.603s (firmware) + 15.788s (loader) + 3.786s (kernel) + 5.643s (userspace) = 30.822s
graphical.target reached after 5.609s in userspace

Code:

systemd-analyze blame
      2.069s NetworkManager-wait-online.service
      1.734s dev-mmcblk0p2.device
      1.691s plymouth-start.service
      1.240s systemd-rfkill.service
       722ms systemd-journal-flush.service
...

Code:

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 "+" charaIter.

graphical.target @5.609s
└─multi-user.target @5.609s
  └─kerneloops.service @5.573s +35ms
    └─network-online.target @5.566s
      └─NetworkManager-wait-online.service @3.392s +2.174s
        └─NetworkManager.service @2.883s +497ms
          └─dbus.service @2.820s
            └─basic.target @2.735s
              └─sockets.target @2.735s
                └─cups.socket @2.735s
                  └─sysinit.target @2.726s
                    └─apparmor.service @2.226s +498ms
                      └─local-fs.target @2.203s
                        └─boot-efi.mount @2.151s +50ms
                          └─systemd-fsck@dev-disk-by\x2duuid-85B4\x2d7A39.servic
                            └─dev-disk-by\x2duuid-85B4\x2d7A39.device @1.992s

In my opinion, the most suspicuous lines in journalctl-b:

Code:

dec 07 22:29:05 asus-r417s systemd-gpt-auto-generator[224]: Failed to dissect: Input/output error
dec 07 22:29:05 asus-r417s systemd[217]: /lib/systemd/system-generators/systemd-gpt-auto-generator failed with exit status 1.

Code:

dec 07 22:29:11 asus-r417s lightdm[726]: PAM unable to dlopen(pam_gnome_keyring.so): /lib/security/pam_gnome_keyring.so: cannot open shared object file: No such file or di
dec 07 22:29:11 asus-r417s lightdm[726]: PAM adding faulty module: pam_gnome_keyring.so
dec 07 22:29:11 asus-r417s lightdm[726]: PAM unable to dlopen(pam_kwallet.so): /lib/security/pam_kwallet.so: cannot open shared object file: No such file or directory
dec 07 22:29:11 asus-r417s lightdm[726]: PAM adding faulty module: pam_kwallet.so
dec 07 22:29:11 asus-r417s lightdm[726]: PAM unable to dlopen(pam_kwallet5.so): /lib/security/pam_kwallet5.so: cannot open shared object file: No such file or directory
dec 07 22:29:11 asus-r417s lightdm[726]: PAM adding faulty module: pam_kwallet5.so

5 sec difference in journalctl-b:

Code:

dec 07 22:29:16 asus-r417s dbus-daemon[761]: [session uid=1000 pid=761] Successfully activated service 'com.canonical.indicator.sound-gtk2'
dec 07 22:29:21 asus-r417s pkexec[1006]: pam_unix(polkit-1:session): session opened for user root by (uid=1000)

Tried to disable pam gnome_keyring and kwallet stuff, but then I couldn't login at all (enabled it again my going to the terminal in login screen (Ctrl+Alt+F2).

whansard · 12-10-2018, 08:55 PM

have you played with making your own custom kernel, removing things you don't need? you can usually do that and even get by without an initramfs or initrd.

ondoho · 12-11-2018, 01:48 AM

Quote:

Originally Posted by Martijn600

The boot plot shows for the loader stage a long gray bar.

Code:

systemd-analyze
Startup finished in 5.603s (firmware) + 15.788s (loader) + 3.786s (kernel) + 5.643s (userspace) = 30.822s
graphical.target reached after 5.609s in userspace

what are those 15s?
it does not seem to reflect in any of the subsequent output you provided.

what you do:

read 'man systemd-analyze'
find out how to obtain more info about "(loader)"

30s isn't too bad for an oldish laptop with a spinning hard drive.

please use code tags for code; i showed you how to do it with the code above. or read my sig.

Martijn600 · 12-11-2018, 02:14 AM

whansard, thank you for your suggestion. I may try if I can figure out how to build my own custom kernel.
Could I not get some clues from some logs which modules take most time boot?

ondoho, thanks for you suggestions.
I inserted code tags in my original post.
Btw the laptop has a SSD hard disk. Laptop is a cheap laptop that was brand new in July 2016. Unfortunately RAM is integrated without any additional memory slot, as such I cannot extend RAM.
Finding out how to obtain more info about "(loader)" was exactly the reason that I posted this question on this forum.
Regarding my level of Linux-experience I could start the thread in the Newbie forum instead.

Once again, thanks for your help.

syg00 · 12-11-2018, 02:38 AM

What's the grub timeout ?.

ondoho · 12-12-2018, 01:05 AM

i still fail to understand the output of your "systemd-analyze" (which is the same as "systemd-analyze time").
on my system it looks very different, both the (firmware) and (loader) stage are absent.

your other output suggests that
- either no single service is responsible for the 15s delay
- or it is something that happens before systemd even starts, very early boot.

with these things in mind, go again through "journalctl -b" (nice timestamps) and "dmesg" (not so nice timestamps).

Martijn600 · 12-12-2018, 01:28 AM

I decreased the value of grub timeout. It didn't help, probably because the laptop is a single-boot system.

When I have time I may try to configure my own kernel to speed up the phase of loading the kernel into memory https://en.wikipedia.org/wiki/Linux_startup_process#Overview (step 2). I don't expect to have time for it soon. Moreover it seems a little too complex for a delay of max about 10 s and my Linux knowledge.

Once again, thanks for the suggestions.

ondoho · 12-14-2018, 12:23 AM

Quote:

Originally Posted by Martijn600

When I have time I may try to configure my own kernel
(...)
Moreover it seems a little too complex for a delay of max about 10 s and my Linux knowledge.

i guess this is in reply to whansard's suggestion.
Maybe there's some firmware taking extremely long to load (or fail to do so) during early boot.
Maybe whansard thought the best way to deal with that is to copile your own kernel.
But I think, once you know what the holdup is, it would be fairly simple to fix it.

Once again, more information is required. 'dmesg' probably will be your friend.
also possible: temporarily disable the gui, and look at the console output.

Martijn600 · 12-15-2018, 02:11 AM

-I should have mentioned that I already checked dmesg, which doesn't give me a clue either.
Its log spans 9.4s, with highest difference among two subsequent lines about 1.8s.

Code:

...
[    0.299872] PCI: CLS 64 bytes, default 64
[    0.299872] Unpacking initramfs...
[    2.004757] Freeing initrd memory: 54332K
[    2.004964] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x171024fa93b, max_idle_ns: 440795253189 ns
...
[    7.500407] random: 7 urandom warning(s) missed due to ratelimiting
[    7.626803] IPv6: ADDRCONF(NETDEV_UP): wlp2s0: link is not ready
[    9.401764] r8169 0000:03:00.2 enp3s0f2: link up
[    9.401781] IPv6: ADDRCONF(NETDEV_CHANGE): enp3s0f2: link becomes ready

Problem might be in the gap between the 15s loader time and 9.4 in dmesg, i.e. when nothing is logged in dmesg?

-I already checked journalctl -b, most suspicuous lines to me were errors of lightdm and 5 sec lag before opening session (see first post).

-I disabled the GUI (systemctl set-default multi-user.target), but still no console output while booting.
Do I have to enable console output with something like dmesg -n <level>?

Once again, thanks for your suggestions!

whansard · 12-19-2018, 05:22 AM

Quote:

Originally Posted by ondoho

i guess this is in reply to whansard's suggestion.

Maybe whansard thought the best way to deal with that is to copile your own kernel.

no, i certainly didn't think that was the best thing to do, just something to do. having a very trimmed down kernel and no initrd make for fast boot times, and i'm sure you know that. i also thought that maybe the kernel probing for hardware that isn't there might be causing the hangup, if he can't find what it is doing it.

Martijn600 · 12-22-2018, 12:53 AM

After executing apt-get dist-upgrade, boot time improved significantly (7s faster).

Before dist-upgrade:

Code:

uname -rsm
Linux 4.15.0-42-generic x86_64

And loader phase always about 15.5s

After dist-upgrade:

Code:

uname -rsm
Linux 4.15.0-43-generic x86_64

systemd-analyze
Startup finished in 5.582s (firmware) + 8.071s (loader) + 3.934s (kernel) + 5.622s (userspace) = 23.210s
graphical.target reached after 5.562s in userspace

Thanks for your help!