Booting taking far too long

Hello dear friends
I am having trouble while trying to understand reason why is my laptop booting very slowly
Startup finished in 3.800s (kernel) + 4.176s (initrd) + ***2min 18.763s *(userspace) = 2min 26.739s
, Laptop is new HP Pavilion E15 . It started to happen recently , but first days it was normal .
So I am wandering what is the problem and how to solve it (any article ,guidance about topic ) .
Thanks in advance
:):):slight_smile:

Hi
You need to use the following two commands too see what is happening;


systemd-analyze blame
systemd-analyze critical-chain

Maybe some maintenance job, fstrim, purge kernels…

If it’s postfix, then your probably only using ipv4 and the /etc/postfix/main.cf needs the inet_protocols (~line 676) set to = ipv4 and save the file.

You could also check the SMART status of the hard disk – in particular its health:

 # smartctl --health /dev/sda

If the disk isn’t at /dev/sda then use “smartctl --scan” to search.

Thank you for response .
Here is the output
from -----

systemd-analyze blame

    1min 10.375s systemd-journal-flush.service
         40.679s docker.service
         24.600s mysql.service
         23.343s libvirtd.service
         13.052s SuSEfirewall2_init.service
         12.833s display-manager.service
         12.418s postfix.service
         12.359s ModemManager.service
         10.920s polkit.service
          7.757s apparmor.service
          7.227s teamviewerd.service
          7.203s SuSEfirewall2.service
          6.032s NetworkManager-wait-online.service
          4.445s colord.service
          4.288s dev-sda6.device
          1.552s systemd-fsck@dev-disk-by\x2duuid-e958a10f\x2dcbc0\x2d4b31\x2d8b92\x2ddd8e4e07efa8.service
          1.425s pullin-bcm43xx-firmware.service
          1.348s home.mount
          1.287s iscsi.service
          1.284s rc-local.service
          1.284s nscd.service
          1.118s bluetooth.service
          1.117s avahi-daemon.service
           945ms accounts-daemon.service
           873ms systemd-udevd.service
           778ms usr-local.mount
           671ms var-log.mount
           664ms opt.mount
           661ms srv.mount
           659ms var-crash.mount
           651ms var-opt.mount
           650ms var-lib-pgsql.mount
           646ms tmp.mount
           646ms systemd-remount-fs.service
           641ms var-tmp.mount
           634ms var-lib-libvirt-images.mount
           632ms var-cache.mount
           615ms boot-grub2-x86_64\x2defi.mount
           593ms sys-kernel-debug.mount
           591ms dev-hugepages.mount
           589ms dev-mqueue.mount
           561ms var-lib-named.mount
           539ms plymouth-read-write.service
           504ms boot-grub2-i386\x2dpc.mount
           496ms systemd-journald.service
           492ms var-lib-mysql.mount
           484ms \x2esnapshots.mount
           427ms apache2.service
           423ms systemd-udev-root-symlink.service
           392ms var-spool.mount
           389ms var-lib-mailman.mount
           388ms NetworkManager.service
           367ms systemd-modules-load.service
           356ms systemd-sysctl.service
           309ms var-lib-mariadb.mount
           299ms systemd-tmpfiles-setup.service
           275ms var-lib-machines.mount
           272ms rtkit-daemon.service
           200ms auditd.service
           176ms systemd-user-sessions.service
           170ms systemd-random-seed.service
           166ms systemd-logind.service
           146ms systemd-tmpfiles-setup-dev.service
           134ms user@1000.service
           132ms upower.service
           129ms dracut-shutdown.service
           109ms wpa_supplicant.service
            96ms systemd-backlight@backlight:intel_backlight.service
            93ms systemd-vconsole-setup.service
            85ms systemd-fsck-root.service
            81ms udisks2.service
            63ms systemd-udev-trigger.service
            53ms dev-disk-by\x2duuid-667c3dac\x2de702\x2d41ab\x2da7ce\x2d3dd606232268.swap
            42ms plymouth-start.service
            35ms systemd-update-utmp.service
            18ms sys-fs-fuse-connections.mount
            14ms alsa-restore.service
            10ms systemd-update-utmp-runlevel.service
             6ms kmod-static-nodes.service
             6ms systemd-tmpfiles-clean.service
             1ms systemd-rfkill.service


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 @2min 18.741s
└─multi-user.target @2min 18.740s
  └─docker.service @1min 38.061s +40.679s
    └─network.target @1min 38.032s
      └─wpa_supplicant.service @1min 32.551s +109ms
        └─basic.target @1min 18.444s
          └─sockets.target @1min 18.444s
            └─virtlogd.socket @1min 18.444s
              └─sysinit.target @1min 18.444s
                └─systemd-update-utmp.service @1min 18.407s +35ms
                  └─systemd-tmpfiles-setup.service @1min 18.075s +299ms
                    └─systemd-journal-flush.service @7.687s +1min 10.375s
                      └─var-log.mount @6.923s +671ms
                        └─dev-disk-by\x2duuid-6c00ae47\x2d8ad7\x2d4601\x2dac42\x2dbfaebad2e5d8.device @6.906s


smartctl --health /dev/sda

smartctl 6.2 2013-11-07 r3856 [x86_64-linux-4.4.36-8-default] (SUSE RPM)
Copyright (C) 2002-13, Bruce Allen, Christian Franke, www.smartmontools.org

=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED


Hopefully this makes sense

Hi, I see two suspects worth analyzing:

  1. docker.service @1min 38.061s +40.679s
  2. systemd-journal-flush.service @7.687s +1min 10.375s

While I know nothing about the first, the latter is likely due to large or highly fragmented journal files and/or slow disk.
I had similar problems with BTRFS on small/slow laptop disks.
To see if that is your case, please see the result of:


journalctl -b |grep "Time spent on flushing"

and possibly the lines of the journal near that time in the boot process.
Then look at the files in the /var/log/journal/<a long number unique to your system> if they are larger than, say 100 MB each or if they show something else unusual.
If that is your case too, you can edit the journal settings in a way to limit the offence…

Thanks for response
Here is the output

Jan 27 19:25:12 l-fbxy systemd-journald[445]: Time spent on flushing to /var is 52.043998s for 972 entries.

MYSTIC why docker would take so long .???

Friend, you have a problem here… this is what I got out of a fairly slow 120GB disk after tuning:


nov 30 18:24:20 linux-a2yg systemd-journal[353]: Permanent journal is using 180.5M (max allowed 160.0M, trying to leave 1.5G free of 1.1G available → current limit 180.5M).
nov 30 18:24:20 linux-a2yg systemd-journal[353]: Time spent on flushing to /var is 50.076ms for 1134 entries.

If you don’t have special requirements for keeping long journals, you may edit /etc/systemd/journald.conf adding or uncommenting the following two lines:


SystemMaxUse=160M
SystemMaxFileSize=24M

Feel free to experiment with (slightly) larger numbers if you need a deeper journal history…
I don’t know if this is an option for you, but the EXT4 filesystem seem less prone to this slowdown.
As a benchmark, this is what I get out of an SSD with EXT4:


Jan 27 09:10:27 LT_B systemd-journald[402]: System journal (/var/log/journal/) is currently using 720.0M.
                                            Maximum allowed usage is set to 2.4G.
                                            Leaving at least 3.6G free (of currently available 8.5G of space).
                                            Enforced usage limit is thus 2.4G, of which 1.7G are still available.
Jan 27 09:10:27 LT_B systemd-journald[402]: Time spent on flushing to /var is 86.401ms for 960 entries.

Thanks for response )))
I tried what you advised me( set size in /etc/systemd/journald.conf ) , but it does not seem to work !
Any help ???

Please show the results of the following commands:


journalctl -b --unit systemd-journald

ls -l /var/log/journal/<insert the long folder name unique to your system here> |grep -e user-100[0-9].journal -e system.journal

I am sorry I can’t reply now , seems laptop wired connections is not working , I will reply you tomorrow as soon as I get wireless connection .)))))
but I just did what you asked and it seems a lot of stuff is going on
Here is

journalctl -b --unit systemd-journald
 Runtime journal (/run/log/journal/) is currently using 8.0M.
          Maximum allowed usage is **set to 395.8M **
          Leaving at least 593.7M free (of currently available 3.8G of space) .  Enforced usage limit is thus 395.8M,of which 387.8M are still available
          Journal started
          System journal (/var/log/journal/) is currently using 64.0M
          Maximum allowed usage is **set to 160.8M 
          **Leaving at least 4.0G free (of currently available 16.2G of space) .   Enforced usage limit is thus 160.0M which 96.0M are still available
          
          Time spent on flushing to /var is 26.455447s for 945 entries. 

and the output of the second command (sorry for inconvenient way of code turned out wired connection on my laptop is not working so i copy and paste manually)

-rw-r----- 1 root systemd-journal 58720256 Jan 28 22:05 **system.journal**

No problem to me, I’m just sitting and waiting for replies to pop up :wink:

Here is

journalctl -b --unit systemd-journald
 Runtime journal (/run/log/journal/) is currently using 8.0M.
          Maximum allowed usage is **set to 395.8M **
          Leaving at least 593.7M free (of currently available 3.8G of space) .  Enforced usage limit is thus 395.8M,of which 387.8M are still available
          Journal started
          System journal (/var/log/journal/) is currently using 64.0M
          Maximum allowed usage is **set to 160.8M    <<<<<<OK
          **Leaving at least 4.0G free (of currently available 16.2G of space) .   Enforced usage limit is thus 160.0M which 96.0M are still available <OK
          
          Time spent on flushing to /var is 26.455447s for 945 entries. 

At least you are down from 52 to 26 seconds… but that is still too much IMHO.

and the output of the second command (sorry for inconvenient way of code turned out wired connection on my laptop is not working so i copy and paste manually)

-rw-r----- 1 root systemd-journal 58720256 Jan 28 22:05 **system.journal**

I see system.journal at about 58 MB: that is inconsistent with a SystemMaxFileSize=24M in /etc/systemd/journald.conf.
Maybe you used a different setting? Or the system just needs a few more reboots to cycle the archived journals?

I see no “user-xxxx.journal” in your output: do you have non-default user numbers (e.g. your current user number is not in 1000 to 1009)?
If so please adjust the command to show at least the last user-xxxx.journal file: that should be below 25MB (unless you used a different setting, of course).

Please also check that your disk is not clogged by other processes at the time of journal flushing, maybe the root problem is somewhere else…

speaking of root problem, why not disable docker, and see if it is also causing the journal issue. (ie since docker itself is taking so long maybe it is spewing msgs of occupying io)?

Just turned it on nad already 5 minutes it is booting !!!
OS is not loading
Already 20 minutes and it is still loading seems it will not work and will load all day
any tips?

Already an hour since I turned it on and still loading !!!

Reboot, at the GRUB menu screen press “E” to edit the kernel command line.
Look for a line beginning with “linuxefi” or “linux”; at the end delete the two options “splash=silent quiet” and add “3” to boot to a command line.
Press F10 to boot, at least you shall see where it stops and see if it is still a journal problem or something else.

Hello again , I managed to turn it on after I have disabled the docker service and now seems everything works fine (surprisingly )
here is the output from my journal.conf

# Entries in this file show the compile time defaults.
# You can change settings by editing this file.
# Defaults can be restored by simply deleting this file.
#
# See journald.conf(5) for details.

[Journal]
#Storage=auto
#Compress=yes
#Seal=yes
#SplitMode=uid
#SyncIntervalSec=5m
#RateLimitInterval=30s
#RateLimitBurst=1000
SystemMaxUse=160M
#SystemKeepFree=
SystemMaxFileSize=24
#SystemMaxFiles=100
#RuntimeMaxUse=
#RuntimeKeepFree=
#RuntimeMaxFileSize=
#RuntimeMaxFiles=100
#MaxRetentionSec=
#MaxFileSec=1month
#ForwardToSyslog=yes
#ForwardToKMsg=no
#ForwardToConsole=no
#ForwardToWall=yes
#TTYPath=/dev/console
#MaxLevelStore=debug
#MaxLevelSyslog=debug
#MaxLevelKMsg=notice
#MaxLevelConsole=info
#MaxLevelWall=emerg


so is it really docker ?? why?

Nice to read that, so at least the journal flushing problem is out of the way.
You may keep that setting unless you need deeper journals for debugging; or you may restore the defaults (simply deleting /etc/systemd/journald.conf) or try higher settings as long as the time spent on flushing the journal to disk remains below a couple of seconds.
Please remember that changes are really applied only when journal files are actually extended beyond the limits, so normally it might take several reboot cycles before seeing any noticeable effect.

Leaving the keyboard to Docker experts and going to stand by :wink: