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.
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"
“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.
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.
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
[FONT=monospace]**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:~ #**
[/FONT]
[FONT=monospace][FONT=monospace]**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:~ #**[/FONT][/FONT]
[FONT=monospace]**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:~ #**[/FONT]
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 –
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?
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.
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 …