Slow boot, "disk verification" during boot and pkgfile database update error

Ewsg · 19 December 2022 12:37

Hi there,

I am experiencing a strange issue here and would like to know if someone could help me please.

So, since some weeks my laptop started displaying an error during the boot, as below:

[FAILED] Failed to start pkgfile database update

Well, above this is displayed another data. Some kind of disk verification for /dev/sda3, as below:

/dev/sda3: clean, 432791/32915456 files, 10178783/131642880 blocks

I don’t know if both messages are related or if they are also related with the boot, wich is a bit slow.

Well, below are some outputs, I would love if someone could give me a hand.

systemd-analyze

Startup finished in 6.229s (firmware) + 2.103s (loader) + 6.500s (kernel) + 39.071s (userspace) = 53.904s 
graphical.target reached after 33.842s in userspace.

systemd-analyze blame

18.241s man-db.service
17.738s systemd-modules-load.service
15.286s systemd-journal-flush.service
 7.445s NetworkManager-wait-online.service
 5.779s systemd-fsck@dev-disk-by\x2duuid-7300d384\x2d1f79\x2d4d4d\x2d8a01\x2d563ac70b9105.service
 4.916s dev-sda3.device
 4.310s systemd-tmpfiles-clean.service
 3.397s user@1000.service
 3.307s systemd-backlight@backlight:intel_backlight.service
 3.244s systemd-rfkill.service
 3.225s ufw.service
 2.901s systemd-fsck@dev-disk-by\x2duuid-ACAC\x2d1729.service
 2.727s cups.service
 2.038s systemd-udevd.service
 1.942s polkit.service
 1.788s ModemManager.service
 1.727s bluetooth.service
 1.714s dbus.service
 1.647s accounts-daemon.service
 1.593s systemd-logind.service
 1.489s systemd-tmpfiles-setup.service
 1.253s NetworkManager.service
 1.149s udisks2.service
 1.071s systemd-tmpfiles-setup-dev.service
  909ms upower.service
  859ms lvm2-monitor.service
  858ms logrotate.service
  778ms boot-efi.mount
  771ms systemd-random-seed.service
  507ms pkgfile-update.service

systemd-analyze critical-chain

graphical.target @33.842s
└─multi-user.target @33.842s
  └─cups.service @31.113s +2.727s
    └─network.target @31.108s
      └─wpa_supplicant.service @32.807s +328ms
        └─dbus.service @28.132s +1.714s
          └─basic.target @28.028s
            └─sockets.target @28.028s
              └─dbus.socket @28.028s
                └─sysinit.target @27.966s
                  └─ufw.service @24.741s +3.225s
                    └─systemd-sysctl.service @24.519s +4ms
                      └─systemd-modules-load.service @6.777s +17.738s
                        └─systemd-journald.socket @6.588s
                          └─-.mount @6.448s
                            └─-.slice @6.456s

inxi

CPU: quad core Intel Core i7-7700HQ (-MT MCP-)
speed/min/max: 3132/800/3800 MHz Kernel: 5.15.81-1-MANJARO x86_64 Up: 3h 10m
Mem: 6085.7/15882.6 MiB (38.3%) Storage: 2.27 TiB (21.8% used) Procs: 303
Shell: Zsh inxi: 3.3.24

TriMoon · 19 December 2022 12:49

This is perfectly ok/normal…

This could be looked into but isn’t necessarily something to worry about because it could be due to unavailable network connection at that time…
To know if it is something that needs to be fixed it would be helpful to know which program (unit) actually printed that message…
(It is mentioned just before that text)

Slow boot can be cause by a lot of things, not necessarily due to that message but it could ofcourse.

Mirdarthos · 19 December 2022 12:54

Hi @Ewsg,

Please share the output of:

systemd-analyze blame

Ewsg · 19 December 2022 12:56

@TriMoon

Thank you very much!

Understood.

So, regarding the pkgfile database error, there’s no mention to a program or unit, unfortunately. Or, maybe I was not able to catch it.

@Mirdarthos

Thank you!

Here it goes:

18.241s man-db.service
17.738s systemd-modules-load.service
15.286s systemd-journal-flush.service
 7.445s NetworkManager-wait-online.service
 5.779s systemd-fsck@dev-disk-by\x2duuid-7300d384\x2d1f79\x2d4d4d\x2d8a01\x2d563ac70b9105.service
 4.916s dev-sda3.device
 4.310s systemd-tmpfiles-clean.service
 3.397s user@1000.service
 3.307s systemd-backlight@backlight:intel_backlight.service
 3.244s systemd-rfkill.service
 3.225s ufw.service
 2.901s systemd-fsck@dev-disk-by\x2duuid-ACAC\x2d1729.service
 2.727s cups.service
 2.038s systemd-udevd.service
 1.942s polkit.service
 1.788s ModemManager.service
 1.727s bluetooth.service
 1.714s dbus.service
 1.647s accounts-daemon.service
 1.593s systemd-logind.service
 1.489s systemd-tmpfiles-setup.service
 1.253s NetworkManager.service
 1.149s udisks2.service
 1.071s systemd-tmpfiles-setup-dev.service
  909ms upower.service
  859ms lvm2-monitor.service
  858ms logrotate.service
  778ms boot-efi.mount
  771ms systemd-random-seed.service
  507ms pkgfile-update.service

TriMoon · 19 December 2022 12:59

Please try journalctl --grep “Failed to start pkgfile database update”

NGr · 19 December 2022 13:06

I’ve had the pkgfile database update error. I solved it in the following post:

Mirdarthos · 19 December 2022 13:08

I doubt this would be the cause of a slow startup, directly. However, it could very well be an dependency.

The pkgfile-update.timer triggers the startup of pkgfile-update.service which has a dependency of network-online.target. So, the next step would be to check that service:

systemd-analyze critical-chain network-online.target

Also, while you’re at it,

…these all seem a tad long, depending on your computer’s specification, of course. so please also provide the output for:

systemd-analyze critical-chain man-db.service

systemd-analyze critical-chain systemd-modules-load.service

…and…

systemd-analyze critical-chain systemd-journal-flush.service

TriMoon · 19 December 2022 13:24

It could be if that service tries to retrieve data from the internet, which it can’t reach at that moment, and exits due to a time-out
Hence why the solution @NGr linked to fixes it by waiting for the nss-lookup.target before attempting to start…
systemd.special.html#nss-lookup.target

Unable to reach can be both network connection related as in IP-connection, but also DNS resolving…

Mirdarthos · 19 December 2022 13:27

Fair enough. I meant direct cause. That’s why I suggested inspecting it’s dependencies. Because that’s more indirect.

TriMoon · 19 December 2022 13:28

Well… the OP did say (s)he is using a laptop, which probably means WiFi connection, which also means slow to setup…
“All indirect stuff can affect the total” especially when they are sequential

Mirdarthos · 19 December 2022 13:30

Just changed my wording.

Ewsg · 19 December 2022 13:33

@NGr ,

Great, I’ll take a look!

@Mirdarthos

Below is the output of systemd-analyze critical-chain network-online.target:

network-online.target @38.559s
└─NetworkManager-wait-online.service @31.111s +7.445s
  └─NetworkManager.service @29.853s +1.253s
    └─dbus.service @28.132s +1.714s
      └─basic.target @28.028s
        └─sockets.target @28.028s
          └─dbus.socket @28.028s
            └─sysinit.target @27.966s
              └─ufw.service @24.741s +3.225s
                └─systemd-sysctl.service @24.519s +4ms
                  └─systemd-modules-load.service @6.777s +17.738s
                    └─systemd-journald.socket @6.588s
                      └─-.mount @6.448s
                        └─-.slice @6.456s

systemd-analyze critical-chain man-db.service

an-db.service +18.241s
└─basic.target @28.028s
  └─sockets.target @28.028s
    └─dbus.socket @28.028s
      └─sysinit.target @27.966s
        └─ufw.service @24.741s +3.225s
          └─systemd-sysctl.service @24.519s +4ms
            └─systemd-modules-load.service @6.777s +17.738s
              └─systemd-journald.socket @6.588s
                └─-.mount @6.448s
                  └─-.slice @6.456s

systemd-analyze critical-chain systemd-modules-load.service

systemd-modules-load.service +17.738s
└─systemd-journald.socket @6.588s
  └─-.mount @6.448s
    └─-.slice @6.456s

systemd-analyze critical-chain systemd-journal-flush.service

systemd-journal-flush.service +15.286s
└─systemd-journald.service @7.909s +111ms
  └─systemd-journald.socket @6.588s
    └─-.mount @6.448s
      └─-.slice @6.456s

@TriMoon

I will try. Many thanks.

Mirdarthos · 19 December 2022 13:48

That won’t work. Just tried it, to make sure. It should be:

journalctl --grep 'Failed to start pkgfile database update'

Single quotes, and not double quotes.

Ewsg · 19 December 2022 13:56

Ah, ok, Understood.

Here it goes:

-- Boot 13e07107a0da42bcb1cc6600ad0b6b36 --
dez 10 08:09:12 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot bc0cb2995ead4103b06fca767a7c364b --
-- Boot d2c1d6fbf8d04d13afdd7ba63f7ce403 --
-- Boot 1b25e27f0a32416c9119310067dd8690 --
dez 11 08:42:25 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 945dcc9c2fcd440aabd770e399eaedff --
-- Boot b87caa78c3024bb8af92e5230dfd1691 --
dez 12 10:10:02 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot cfcf10328d274bb2b63d1e9aac13562b --
dez 13 07:12:59 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 5fac85de6e3940d59f0bdd62772d11d8 --
-- Boot aa06ad5ee3f14a8b8fbe424722d0d9cd --
dez 14 06:07:39 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 6646807bf56640b483022f42bc053ce0 --
dez 15 06:00:05 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 1653584a4bbc4373b633c4d62268e996 --
dez 16 06:11:16 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 2ac72447232b47f8bbe8efba7e2a1bb4 --
dez 17 19:03:47 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot 2af9c4f95d5f487baba3663f34b09545 --
dez 18 10:53:53 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.
-- Boot a009ee861991473bb6764004467e71e2 --
-- Boot 473806c75ae1446982550bd4594ba406 --
dez 19 06:27:28 ewsg-manjaro-lnx systemd[1]: Failed to start pkgfile database update.

Mirdarthos · 19 December 2022 14:00

As you can see, this had been a longtime failure. It might not be related directly.

So, I’d advise you to go with @NGr’s advice.

Ewsg · 19 December 2022 14:09

Yes, you are right. I’ll stick to that topic.

Thank you very much.

TriMoon · 19 December 2022 14:16

It worked for me, maybe it didnt due to the quotes on the forum, ahh well

That shows it is generated by systemd with PID 1, so yea it’s most likely at boot…
The solution by NGr will most likely prevent that message…

Mirdarthos · 19 December 2022 14:23

This was for me:

$ journalctl --grep “Failed to start pkgfile database update”
Failed to add match 'to': Invalid argument

vs.

$ journalctl --grep 'Failed to start pkgfile database update'
[...]
Oct 26 10:06:24 Mirdarthos-PC systemd[1]: Failed to start pkgfile database update.
[...]

TriMoon · 19 December 2022 14:27

journalctl --grep "Failed to start pkgfile database update"
-- Boot b622df906511495badd8a7d7ca44ab21 --
-- Boot f62bf233e42f472dab1ac79da0f41d3e --
-- Boot 85071bd379b14a83a7f156ee966ae9f3 --
-- Boot 8bdc909cf94d4f41ad098b0fe3271cc9 --
-- Boot 101a6e811be24db6963bd2c3c62697ab --
-- Boot de8fdc0676fa425ca7f5b09adb577bbf --
-- Boot 4c036942437a4707b4a85cc7ca4e9037 --
-- Boot dae921df29a44b778a30d2d858b9a96e --
-- Boot 1583b1633d2c4859888b4d4694510b71 --
-- Boot 169097b3d2564937be81eb6f237777b3 --
-- Boot 5970c67649af441f8e968e3786c98020 --
-- No entries --

Quotes
I use multiple keyboard locales, maybe it slipped

Mirdarthos · 19 December 2022 14:29

Could it be because we use different shells?

$ echo $SHELL
/usr/bin/zsh