Discussion:
Why on 1st run does pacman -Qi take so long? (15 seconds waiting for Qi?)
(too old to reply)
David C. Rankin
2018-06-02 11:05:05 UTC
Permalink
Raw Message
This is new, after the latest pacman update along with 4.6.13, when running

$ pacman -Qi somepackage

for the first time it takes 15 seconds for any response. E.g.,

$ time pmqi colord
Name : colord
Version : 1.4.3-1
Description : System daemon for managing color devices
Architecture : x86_64
URL : https://www.freedesktop.org/software/colord
Licenses : GPL2
Groups : None
Provides : None
Depends On : lcms2 libgusb polkit sqlite systemd dconf dbus
libgudev shared-mime-info
Optional Deps : argyllcms: color profiling
colord-sane: SANE support
Required By : gtk3
Optional For : cups
Conflicts With : None
Replaces : shared-color-profiles
Installed Size : 6.60 MiB
Packager : Jan Alexander Steffens (heftig) <***@gmail.com>
Build Date : Sat 21 Apr 2018 02:58:03 PM CDT
Install Date : Sun 22 Apr 2018 09:59:37 PM CDT
Install Reason : Installed as a dependency for another package
Install Script : No
Validated By : Signature


real 0m15.083s
user 0m0.011s
sys 0m0.194s

That's 15 seconds waiting for something that wasn't there before?

Subsequent -Qi queries are against near instantaneous as they have always been.

Is there something new that causes some type of handshake or authentication
that takes time to establish on 1st call.
--
David C. Rankin, J.D.,P.E.
Ralph Corderoy
2018-06-02 11:28:49 UTC
Permalink
Raw Message
Hi David,
Post by David C. Rankin
This is new, after the latest pacman update along with 4.6.13, when running
$ pacman -Qi somepackage
for the first time it takes 15 seconds for any response.
I've always found it sluggish if its data isn't cached in RAM.
`vmstat 1' shows one core is pegged out waiting for I/O; the `wa'
column.

The I/O is the reading of 814 /var/lib/pacman/local/*/desc.

$ LC_ALL=C strace -c pacman -Qi ed
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
50.40 0.157668 185 853 openat
35.51 0.111096 67 1670 read
6.27 0.019606 23 853 close
5.48 0.017140 20 856 fstat
0.76 0.002383 34 70 mmap

First run of `\time -v pacman -Qi ed' v. second, boring lines deleted.

Command being timed "pacman -Qi ed" "pacman -Qi ed"
User time (seconds) 0.10 0.06
System time (seconds) 0.29 0.02
Percent of CPU this job got 2% 96%
Elapsed (wall clock) time 0:14.70 0:00.08
Voluntary context switches 1786 0
Involuntary context switches 26 16
File system inputs 34768 0
File system outputs 0 0
--
Cheers, Ralph.
https://plus.google.com/+RalphCorderoy
Loading...