Page 1 of 2 12 LastLast
Results 1 to 10 of 11

Thread: S*L*O*W Boot

  1. #1

    Default S*L*O*W Boot

    After a recent update, the system is very slow to boot. Once it's up and running, a restart is fairly quick. Here is a snippet from the system log (var/log/messages) showing a seven minute gap in activity, but I have no idea how to do any further diagnosis.

    Code:
    2021-12-12T08:53:18.006377-08:00 linux-vjgc systemd[1]: Removed slice User Slice of UID 0.
     2021-12-12T08:53:24.005503-08:00 linux-vjgc systemd[1]: systemd-hostnamed.service: Succeeded.
     2021-12-12T08:53:27.805560-08:00 linux-vjgc systemd[1]: systemd-localed.service: Succeeded.
     2021-12-12T09:00:24.926106-08:00 linux-vjgc sddm-greeter[2546]: Reading from "/usr/share/xsessions/plasma5.desktop"
     2021-12-12T09:00:24.926355-08:00 linux-vjgc sddm[2492]: Message received from greeter: Login
     2021-12-12T09:00:24.926424-08:00 linux-vjgc sddm[2492]: Reading from "/usr/share/xsessions/plasma5.desktop"
     2021-12-12T09:00:24.927416-08:00 linux-vjgc sddm[2492]: Reading from "/usr/share/xsessions/plasma5.desktop"
    Where do I go from here?

  2. #2

    Default Re: S*L*O*W Boot

    Check your CPU speed with
    Code:
    lscpu
    and see if your current speed is set at the minimum. That happened to me once and caused everything to slow to a crawl.

  3. #3
    Join Date
    Feb 2010
    Location
    Germany
    Posts
    5,127

    Default Re: S*L*O*W Boot

    Quote Originally Posted by m1bliss View Post
    Where do I go from here?
    Please use the following analysis tools –
    • “systemd-analyze” → “systemd-analyze blame” → “systemd-analyze critical-chain”
    • “journalctl --boot=0 --output=short-monotonic --no-hostname” – use “--list-boots” to work out which Boot took longer and then use that Offset for the “--boot=” parameter.

    If your system partition is using a Btrfs file system then –
    • “systemctl start btrfs-balance.service” and, when that service finishes (check with “systemctl status btrfs-balance.service”), start the “btrfs-scrub.service”.

    Another culprit could be the “backup-rpmdb.service” – check in the systemd Journal for instances when the RPM Database was backed up and, for the time needed for the backups to complete.
    Yet another culprit for non-Btrfs system partitions, could be a “fsck” file system check which automatically kicked during that boot.

  4. #4

    Default Re: S*L*O*W Boot

    Many thanks for that.

    systemd-analyze options all returned a few seconds.

    systemctl commands completed successfully

    journalctl -b yielded something like what I posted above, but is this perhaps the RPM backup you referenced, or something else? What is that IP? Whois indicates INOC LLC, but what is this for? Seems very strange to me.

    Code:
    Dec 15 16:41:01 linux-vjgc systemd[1]: systemd-hostnamed.service: Succeeded.
    Dec 15 16:41:05 linux-vjgc systemd[1]: systemd-localed.service: Succeeded.
    Dec 15 16:42:53 linux-vjgc chronyd[1408]: Selected source 64.246.132.14
    Dec 15 16:45:17 linux-vjgc systemd[1]: Starting Backup /etc/sysconfig directory...
    Dec 15 16:45:17 linux-vjgc systemd[1]: backup-sysconfig.service: Succeeded.
    Dec 15 16:45:17 linux-vjgc systemd[1]: Finished Backup /etc/sysconfig directory.
    Dec 15 16:48:57 linux-vjgc sddm-greeter[1991]: Reading from "/usr/share/xsessions/plasma5.desktop"
    Dec 15 16:48:57 linux-vjgc sddm[1938]: Message received from greeter: Login

  5. #5
    Join Date
    Jan 2014
    Location
    Erlangen
    Posts
    4,352
    Blog Entries
    5

    Default Re: S*L*O*W Boot

    System assembled with budget components in February 2014:
    Code:
    i3-4130:~ # inxi -CDSm                     
    System:    Host: i3-4130 Kernel: 5.15.7-1-default x86_64 bits: 64 Console: pty pts/1 Distro: openSUSE Tumbleweed 20211213 
    Memory:    RAM:total: 15.29 GiB used: 2.77 GiB (18.1%) 
               Array-1:capacity: 32 GiB slots: 4 EC: None 
               Device-1: ChannelA-DIMM0 size: No Module Installed 
               Device-2: ChannelA-DIMM1 size: 8 GiB speed: 1600 MT/s 
               Device-3: ChannelB-DIMM0 size: No Module Installed 
               Device-4: ChannelB-DIMM1 size: 8 GiB speed: 1600 MT/s 
    CPU:       Info: Dual Core model: Intel Core i3-4130 bits: 64 type: MT MCP cache:L2: 3 MiB 
               Speed: 800 MHz min/max: 800/3400 MHz Core speeds (MHz):1: 800 2: 800 3: 801 4: 801 
    Drives:    Local Storage:total: 232.89 GiB used: 23.33 GiB (10.0%) 
               ID-1: /dev/sda vendor: Crucial model: CT250MX500SSD1 size: 232.89 GiB 
    i3-4130:~ #
    Code:
    i3-4130:~ # systemd-analyze 
    Startup finished in 3.793s (firmware) + 674ms (loader) + 704ms (kernel) + 1.870s (initrd) + 2.155s (userspace) = 9.197s  
    graphical.target reached after 2.147s in userspace 
    i3-4130:~ #
    Code:
    i3-4130:~ # systemd-analyze critical-chain                                         
    The time when unit became active or started is printed after the "@" character. 
    The time the unit took to start is printed after the "+" character. 
    
    graphical.target @2.147s 
    └─display-manager.service @1.502s +644ms
      └─apache2.service @1.225s +275ms
        └─time-sync.target @1.214s 
          └─chronyd.service @1.066s +147ms
            └─nss-lookup.target @1.054s 
              └─systemd-resolved.service @752ms +301ms
                └─systemd-networkd.service @637ms +113ms
                  └─systemd-udevd.service @454ms +164ms
                    └─systemd-tmpfiles-setup-dev.service @426ms +13ms
                      └─kmod-static-nodes.service @377ms +41ms
                        └─systemd-journald.socket 
                          └─system.slice 
                            └─-.slice 
    i3-4130:~ #

    Targets reached:
    Code:
    i3-4130:~ # journalctl -b -u init.scope -g Reached -o short-monotonic         
    -- Journal begins at Tue 2021-12-14 08:03:01 CET, ends at Thu 2021-12-16 04:26:29 CET. -- 
    [    1.893171] i3-4130 systemd[1]: Reached target System Initialization. 
    [    1.893519] i3-4130 systemd[1]: Reached target Path Units. 
    [    1.893555] i3-4130 systemd[1]: Reached target Basic System. 
    [    2.049785] i3-4130 systemd[1]: Reached target Initrd Root Device. 
    [    2.211142] i3-4130 systemd[1]: Reached target Preparation for Remote File Systems. 
    [    2.211192] i3-4130 systemd[1]: Reached target Remote File Systems. 
    [    2.252410] i3-4130 systemd[1]: Reached target Initrd Root File System. 
    [    2.385736] i3-4130 systemd[1]: Reached target Initrd File Systems. 
    [    2.385767] i3-4130 systemd[1]: Reached target Initrd Default Target. 
    [    2.421338] i3-4130 systemd[1]: Reached target Switch Root. 
    [    3.015128] i3-4130 systemd[1]: Reached target Preparation for Local File Systems. 
    [    3.045585] i3-4130 systemd[1]: Reached target Local File Systems. 
    [    3.194197] i3-4130 systemd[1]: Reached target System Initialization. 
    [    3.195293] i3-4130 systemd[1]: Reached target Path Units. 
    [    3.195564] i3-4130 systemd[1]: Reached target Socket Units. 
    [    3.195653] i3-4130 systemd[1]: Reached target Basic System. 
    [    3.629421] i3-4130 systemd[1]: Reached target Network. 
    [    3.629564] i3-4130 systemd[1]: Reached target Host and Network Name Lookups. 
    [    3.792364] i3-4130 systemd[1]: Reached target System Time Synchronized. 
    [    3.800047] i3-4130 systemd[1]: Reached target Timer Units. 
    [    4.061079] i3-4130 systemd[1]: Reached target Sound Card. 
    [    4.083619] i3-4130 systemd[1]: Reached target Login Prompts. 
    [    4.382692] i3-4130 systemd[1]: Reached target Multi-User System. 
    [    4.722062] i3-4130 systemd[1]: Reached target Graphical Interface. 
    i3-4130:~ #

    Services started:

    Code:
    i3-4130:~ # journalctl -b -u init.scope -g Started -o short-monotonic  
    -- Journal begins at Tue 2021-12-14 08:03:01 CET, ends at Thu 2021-12-16 04:26:29 CET. -- 
    [    1.831728] i3-4130 systemd[1]: Started Rule-based Manager for Device Events and Files. 
    [    1.893441] i3-4130 systemd[1]: Started Dispatch Password Requests to Console Directory Watch. 
    [    3.193789] i3-4130 systemd[1]: Started Rule-based Manager for Device Events and Files. 
    [    3.194311] i3-4130 systemd[1]: Started Watch /etc/sysconfig/btrfsmaintenance. 
    [    3.194787] i3-4130 systemd[1]: Started Watch for changes in CA certificates. 
    [    3.194915] i3-4130 systemd[1]: Started Watch for changes in issue snippets. 
    [    3.195017] i3-4130 systemd[1]: Started Watch for changes in smartmontools sysconfig file. 
    [    3.195101] i3-4130 systemd[1]: Started Daily Cleanup of Snapper Snapshots. 
    [    3.195197] i3-4130 systemd[1]: Started Daily Cleanup of Temporary Directories. 
    [    3.197378] i3-4130 systemd[1]: Started D-Bus System Message Bus. 
    [    3.200804] i3-4130 systemd[1]: Started irqbalance daemon. 
    [    3.265244] i3-4130 systemd[1]: Started Machine Check Exception Logging Daemon. 
    [    3.325577] i3-4130 systemd[1]: Started Network Configuration. 
    [    3.355779] i3-4130 systemd[1]: Started User Login Management. 
    [    3.593521] i3-4130 systemd[1]: Started Entropy Daemon based on the HAVEGE algorithm. 
    [    3.629004] i3-4130 systemd[1]: Started Network Name Resolution. 
    [    3.792207] i3-4130 systemd[1]: Started NTP client/server. 
    [    3.792479] i3-4130 systemd[1]: Started Backup of RPM database. 
    [    3.792586] i3-4130 systemd[1]: Started Backup of /etc/sysconfig. 
    [    3.792671] i3-4130 systemd[1]: Started Balance block groups on a btrfs filesystem. 
    [    3.792752] i3-4130 systemd[1]: Started Defragment file data and/or directory metadata. 
    [    3.792822] i3-4130 systemd[1]: Started Scrub btrfs filesystem, verify block checksums. 
    [    3.792904] i3-4130 systemd[1]: Started Discard unused blocks on a mounted filesystem. 
    [    3.792978] i3-4130 systemd[1]: Started Check if mainboard battery is Ok. 
    [    3.793053] i3-4130 systemd[1]: Started Discard unused blocks once a week. 
    [    3.793127] i3-4130 systemd[1]: Started Daily rotation of log files. 
    [    3.799749] i3-4130 systemd[1]: Started Daily man-db regeneration. 
    [    3.799943] i3-4130 systemd[1]: Started Timeline of Snapper Snapshots. 
    [    3.985710] i3-4130 systemd[1]: Started Load/Save RF Kill Switch Status. 
    [    4.010558] i3-4130 systemd[1]: Started WPA Supplicant daemon (interface wlan0). 
    [    4.075892] i3-4130 systemd[1]: Started The Apache Webserver. 
    [    4.083325] i3-4130 systemd[1]: Started Getty on tty1. 
    [    4.195974] i3-4130 systemd[1]: Started Locale Service. 
    [    4.380576] i3-4130 systemd[1]: Started Postfix Mail Transport Agent. 
    [    4.382568] i3-4130 systemd[1]: Started Command Scheduler. 
    [    4.721732] i3-4130 systemd[1]: Started X Display Manager. 
    [    5.278977] i3-4130 systemd[1]: Started User Manager for UID 1000. 
    [    5.279057] i3-4130 systemd[1]: Started Session 1 of User karl. 
    [    5.980675] i3-4130 systemd[1]: Started Timeline of Snapper Snapshots. 
    [    6.068346] i3-4130 systemd[1]: Started DBus interface for snapper. 
    [    7.045943] i3-4130 systemd[1]: Started Authorization Manager. 
    [    7.099993] i3-4130 systemd[1]: Started Disk Manager. 
    [    7.188930] i3-4130 systemd[1]: Started Daemon for power management. 
    [   10.149832] i3-4130 systemd[1]: Started RealtimeKit Scheduling Policy Service. 
    i3-4130:~ #
    openSUSE Tumbleweed, KDE Plasma, Blogs/KeepItSimple, i7-6700K (2016), i5-8250U (2018), AMD Ryzen 5 3400G (2020), 5600X, 5700U (2022)

  6. #6
    Join Date
    Feb 2010
    Location
    Germany
    Posts
    5,127

    Default Re: S*L*O*W Boot

    Quote Originally Posted by m1bliss View Post
    is this perhaps the RPM backup you referenced,
    The systemd Backup RPM Database often needs about 20 seconds on systems with a mixture of user and developer packages installed – here some times for the case that the Service was started manually –
    Code:
    [ 9154.536982] systemd[1]: Starting Backup RPM database...
    [ 9173.086776] systemd[1]: backup-rpmdb.service: Succeeded.
    [ 9173.087386] systemd[1]: Finished Backup RPM database.
     .
     .
     .
    [ 1868.703537] systemd[1]: Starting Backup RPM database...
    [ 1889.058925] systemd[1]: backup-rpmdb.service: Succeeded.
    [ 1889.059739] systemd[1]: Finished Backup RPM database.
    But, if the Timer kicks in shortly after a boot and, there isn't anything to backup, it needs about 1¼ second –
    Code:
    [  221.125983] systemd[1]: Starting Backup RPM database...
    [  222.382725] systemd[1]: backup-rpmdb.service: Succeeded.
    [  222.383212] systemd[1]: Finished Backup RPM database.

  7. #7

    Default Re: S*L*O*W Boot

    I think I'm about to give up on this machine. If I turn it off and disconnect the power, within five minutes it will start up again in about 40s. But after an hour, it's back to taking ten to fifteen minutes. That suggested a problem with the CMOS battery to me, but replacing it had no effect.

    It's a bit of a strange setup: it's a Dell XPS with a 328GB mSATA drive where the system is installed, with two disc drives, sdc, sda, and sdb respectively. I could not install the system on the mSATA drive (sdc) without disconnecting the disc drives first. I probably should have done the same thing when I upgraded to 15.3, but I didn't, so maybe there is something that the system is waiting for from the disc drives that doesn't show up in the logs. But what is it that decays after five minutes?

    Guess I'll get to see how good my backups are ...

  8. #8
    Join Date
    Apr 2011
    Location
    Texas USA
    Posts
    524

    Default Re: S*L*O*W Boot

    I have been finding that long boots and shutdowns are strongly affected by the "mlocate" file search service. In a "systemd determine blame listing" it took 3min and 15 seconds. for mlocate.service to run. That is strange for if I run the "updatedb" portion of mlocate that usually only takes a minute or so.

    Check if you are running mlocate. If not, this is a mute point. If so, you might not want it to start upon boot and start manually when you need it if the boot times are important to you.

    This might help understand some of the problem.

    tom kosvic

  9. #9

    Default Re: S*L*O*W Boot

    Quote Originally Posted by tckosvic View Post
    Check if you are running mlocate. If not, this is a mute point.
    Thanks for the suggestion, but mlocate is not listed in system activity, so I guess that's a mute point.

    I'm just going to ditch this system, it's been nothing but a pain. I reinstalled LEAP to a regular disc, but login is still slow.

    The bright spot is that restore from backup worked fine, so I just need to find a new box ....

  10. #10

    Default Re: S*L*O*W Boot

    After endless parts swapping and diddling with this system, it turned out that the issue was the monitor. I always thought of monitors as passive components, but I guess that's not the case. With a different monitor, all is well ....

Page 1 of 2 12 LastLast

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •