[Solved] mandb increases boot time

judd1 · 2018-11-30 14:04:15

Hello, the time for man-db.service, is longer than the time it takes my system to boot completely to login.
man-db.service has been loading too much on the system boot for some time.
Running "sudo /usr/bin/mandb" I can go back to my normal start times after a reboot, searching the forum I did not find any clue, or I did it wrong.
This appears randomly, but annoying when one reviews the start times.

$ systemd-analyze time
Startup finished in 3.390s (firmware) + 5.000s (loader) + 1.965s (kernel) + 27.669s (userspace) = 38.025s
graphical.target reached after 1.474s in userspace

$ systemd-analyze blame | head
         26.822s man-db.service
           908ms systemd-backlight@backlight:intel_backlight.service
           645ms upower.service
           571ms udisks2.service
           552ms home.mount
           470ms dev-sdb2.device
           400ms ufw.service
           198ms NetworkManager.service
           189ms polkit.service
           173ms user@1000.service

$ dmesg | grep man-db
[   29.635408] audit: type=1130 audit(1543579438.284:68): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=man-db comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   29.635438] audit: type=1131 audit(1543579438.284:69): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=man-db comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'

After the restart, running $ sudo /usr/bin/mandb:

$ systemd-analyze time
Startup finished in 2.165s (firmware) + 1.732s (loader) + 1.971s (kernel) + 2.340s (userspace) = 8.210s
graphical.target reached after 1.492s in userspace

$ systemd-analyze blame | head
           887ms systemd-backlight@backlight:intel_backlight.service
           565ms upower.service
           483ms home.mount
           434ms dev-sdb2.device
           426ms ufw.service
           172ms user@1000.service
           157ms NetworkManager.service
           148ms polkit.service
           148ms systemd-udevd.service
           124ms bluetooth.service

dmesg: https://hastebin.com/raw/adimiqelux

/var/log/Xorg.0.log: https://hastebin.com/raw/gisadimohi

$ uname -rs
Linux 4.19.4-arch1-1-ARCH

WM: dwm

I can not find out what I missed ...

Thanks, as always !

Last edited by judd1 (2018-11-30 17:35:08)

loqs · 2018-11-30 14:30:11

There seem to be two related issues:
Why is man-db.service enabled instead of relying on man-db.timer?
Why is man-db.service taking 26.822 seconds?

judd1 · 2018-11-30 14:40:55

@loqs, thanks for the prompt response!

$ systemctl status man-db.timer
● man-db.timer - Daily man-db cache update
   Loaded: loaded (/usr/lib/systemd/system/man-db.timer; static; vendor preset: disabled)
   Active: active (waiting) since Fri 2018-11-30 11:06:33 -03; 45min ago
  Trigger: Sat 2018-12-01 00:00:00 -03; 12h left

nov 30 11:06:33 arch systemd[1]: Started Daily man-db cache update.

$ systemctl status man-db
● man-db.service - Update man-db cache
   Loaded: loaded (/usr/lib/systemd/system/man-db.service; static; vendor preset: disabled)
   Active: inactive (dead)

So, enabling man-db.timer would be the right thing to do?

Last edited by judd1 (2018-11-30 14:53:56)

loqs · 2018-11-30 15:04:52

man-db.timer should be being pulled in automatically

systemctl list-dependencies --reverse man-db.timer

I saw man-db.service in the output of systemd-analyze blame and assumed it was man-db.service being started directly rather than man-db.timer triggering on boot and then blocking the completion of multi-user.target.

judd1 · 2018-11-30 15:10:15

$ systemctl list-dependencies --reverse man-db.timer
man-db.timer
● └─multi-user.target
●   └─graphical.target

After the restart:

$ systemctl status man-db.timer
● man-db.timer - Daily man-db cache update
   Loaded: loaded (/usr/lib/systemd/system/man-db.timer; static; vendor preset: disabled)
   Active: active (waiting) since Fri 2018-11-30 12:15:58 -03; 1min 0s ago
  Trigger: Sat 2018-12-01 00:00:00 -03; 11h left

nov 30 12:15:58 arch systemd[1]: Started Daily man-db cache update.

$ systemd-analyze time
Startup finished in 2.167s (firmware) + 5.065s (loader) + 1.989s (kernel) + 1.573s (userspace) = 10.795s
graphical.target reached after 1.456s in userspace

$ systemd-analyze blame | head
          1.005s alsa-restore.service
           818ms systemd-backlight@backlight:intel_backlight.service
           672ms home.mount
           596ms upower.service
           466ms dev-sdb2.device
           299ms ufw.service
           199ms polkit.service
           174ms user@1000.service
           146ms NetworkManager.service
           132ms systemd-udevd.service

We will see in the following days how it behaves.
Thanks @loqs

Last edited by judd1 (2018-11-30 15:39:33)

Trilby · 2018-11-30 15:54:57

It *will* still run periodically. That's what it's supposed to do. It adds time to the total in systemd-analyze, but it doesn't add that time to how long it takes to get working in your desktop. Use `systemd-analyze critical-chain` if you really want.

judd1 · 2018-11-30 16:06:14

Trilby wrote:

It *will* still run periodically. That's what it's supposed to do. It adds time to the total in systemd-analyze, but it doesn't add that time to how long it takes to get working in your desktop. Use `systemd-analyze critical-chain` if you really want.

I get it.

I know that command, I really forgot it, since I concentrate exclusively on the increase of mandb in the beginning.

]$ 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 @1.460s
└─upower.service @847ms +612ms
  └─basic.target @846ms
    └─sockets.target @846ms
      └─dbus.socket @846ms
        └─sysinit.target @846ms
          └─haveged.service @805ms +40ms
            └─systemd-tmpfiles-setup.service @776ms +26ms
              └─local-fs.target @775ms
                └─boot-efi.mount @706ms +68ms
                  └─dev-disk-by\x2duuid-CC71\x2d27DA.device @690ms

Gracias @Trilby

eschwartz · 2018-11-30 16:09:33

But systemd-analyze is a lie. Or rather, it is notorious for being completely misunderstood. I highly doubt the man-db service is holding up your boot process no matter how long it takes, because nothing else will depend on it being started...

"systemd-analyze blame prints a list of all running units, ordered by the time they took to initialize." This says *nothing* about whether the units in question are part of the boot process. Nevertheless, it's highly common for people to look at the output of this and assume at complete random that every unit is part of the boot process, and that causing any given unit to finish faster will thereby also cause their boot to be faster.

Also keep in mind, the timer in question is designed to trigger once per day, at a completely random point in time during that day. It's exceedingly unlikely that it is always being started every time you boot, the very instant you boot...

judd1 · 2018-11-30 16:37:17

eschwartz wrote:

But systemd-analyze is a lie. Or rather, it is notorious for being completely misunderstood. I highly doubt the man-db service is holding up your boot process no matter how long it takes, because nothing else will depend on it being started...

What you say I've noticed and it's real if, sometimes it's just a matter of number of seconds ...and not focusing on the start of the system.

eschwartz wrote:

"systemd-analyze blame prints a list of all running units, ordered by the time they took to initialize." This says *nothing* about whether the units in question are part of the boot process. Nevertheless, it's highly common for people to look at the output of this and assume at complete random that every unit is part of the boot process, and that causing any given unit to finish faster will thereby also cause their boot to be faster.

I understand.

eschwartz wrote:

Also keep in mind, the timer in question is designed to trigger once per day, at a completely random point in time during that day. It's exceedingly unlikely that it is always being started every time you boot, the very instant you boot...

I did not know that randomly in the day is activated.

@eschwartz, Without many prerogatives on my part, I can understand what you are saying.
Thanks for the info.

Last edited by judd1 (2018-11-30 16:47:19)

Trilby · 2018-11-30 16:46:02

judd1 wrote:

What you say I've noticed and it's real if, sometimes it's just a matter of number of seconds ...and not focusing on the start of the system.

I can't parse that sentence at all. Are there typos? But the mandb service should does not delay startup for it's duration.

Depending on your hardware, it can take a notable chunk of cpu resources while it works, and if this happens to occur while other boot processes are also vying for cpu resources, it *might* slow down boot by a small percentage. But I don't think that's what this thread is about. Are you actually observing problems, or are you just unhappy with the systemd-analyze output? If the latter, the solution is simple: ignore it - it does not mean what you thought it means.

judd1 · 2018-11-30 16:56:10

Maybe it's the translation of my bad English translated by google.

>What you say I've noticed and it's real if, sometimes it's just a matter of number of seconds ...and not focusing on the start of the system.

The system works like silk, I do not see problems about it, not at all.
Just as you say, I'm not happy with the analysis of the system at startup.

I'm sorry, I try to learn every day, sometimes I do not achieve it that much.

Also, I read and reread your messages and they are very helpful to me.
I am going to make it !

Last edited by judd1 (2018-11-30 17:04:28)

Trilby · 2018-11-30 17:26:48

judd1 wrote:

The system works like silk, I do not see problems about it, not at all.
Just as you say, I'm not happy with the analysis of the system at startup.

Thanks. That makes more sense. Do you feel that this thread is SOLVED then?

Arch Linux

#1 2018-11-30 14:04:15

[Solved] mandb increases boot time

#2 2018-11-30 14:30:11

Re: [Solved] mandb increases boot time

#3 2018-11-30 14:40:55

Re: [Solved] mandb increases boot time

#4 2018-11-30 15:04:52

Re: [Solved] mandb increases boot time

#5 2018-11-30 15:10:15

Re: [Solved] mandb increases boot time

#6 2018-11-30 15:54:57

Re: [Solved] mandb increases boot time

#7 2018-11-30 16:06:14

Re: [Solved] mandb increases boot time

#8 2018-11-30 16:09:33

Re: [Solved] mandb increases boot time

#9 2018-11-30 16:37:17

Re: [Solved] mandb increases boot time

#10 2018-11-30 16:46:02

Re: [Solved] mandb increases boot time

#11 2018-11-30 16:56:10

Re: [Solved] mandb increases boot time

#12 2018-11-30 17:26:48

Re: [Solved] mandb increases boot time

Board footer