This service will be undergoing maintenance at 20:00 UTC, 2017-04-03. It is expected to last about 30 minutes
Bug 1279538 - [perf] dnf repoquery --resolve is extremely slow
[perf] dnf repoquery --resolve is extremely slow
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: dnf-plugins-core (Show other bugs)
23
Unspecified Unspecified
urgent Severity urgent
: ---
: ---
Assigned To: Michael Mráka
Fedora Extras Quality Assurance
:
: 1285360 1296657 (view as bug list)
Depends On:
Blocks: 1275275
  Show dependency treegraph
 
Reported: 2015-11-09 11:52 EST by Christian Dersch
Modified: 2016-05-21 22:24 EDT (History)
22 users (show)

See Also:
Fixed In Version: dnf-plugins-core-0.1.21-1.fc23
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-05-21 22:24:38 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
strace of dnf --requires --resolve gnome-terminal (6.86 MB, text/plain)
2015-12-22 12:16 EST, Dominique Brazziel
no flags Details

  None (edit)
Description Christian Dersch 2015-11-09 11:52:54 EST
Description of problem: dnf repoquery is extremely slow compared to older "repoquery" command. Also while running dnf creates a very high cpu load for whole time.


Version-Release number of selected component (if applicable): 1.1.3
  Installed: dnf-0:1.1.3-1.fc22.noarch at 2015-10-26 07:43
  Built    : Fedora Project at 2015-10-14 16:53


How reproducible: always


Steps to Reproduce: Execute following commands
1. time repoquery -q -C --requires --resolve vtk.x86_64
2. time dnf repoquery -q -C --requires --resolve vtk.x86_64
3. Compare times

Actual results: dnf repoquery is about 2 magnitues slower than old repoquery


Expected results: Both need approx. the same time


Additional info: in combination with a bug in fedora-review (https://bugzilla.redhat.com/1275275) reviewing becomes a very tedious process :(
Comment 1 Honza Silhan 2015-11-18 08:27:59 EST
Thanks for the report.
Comment 2 Christian Dersch 2015-11-26 04:06:27 EST
*** Bug 1285360 has been marked as a duplicate of this bug. ***
Comment 3 Alec Leamas 2015-11-26 04:25:22 EST
The timing is really bad, and the description "extremely slow" is IMHO justified. See figures in bug #1285360.

Adding Tim Lauridsen to cc:, see bug #1156487
Comment 4 Alec Leamas 2015-11-27 08:32:49 EST
After a  night's sleep I'm raising the priority/severity and resets "extremely slow" in the heading. 

This is justified by differences like 3 seconds using yum vs 2 minutes using dnf. This is just not performance, it's a blocking error in many contexts. We have reports about single --resolve queries taking "hours".

This performance is so bad that it typically makes fedora-review run 2-3 times slower than using using yum - and then f-r has both built and installed a package in a mock chroot. I will be forced to mention this bug in upcoming fedora-review release notes with hints how to avoid the checks invoking --resolve, which in turn means that directory ownership needs to be checked manually instead. Which no doubt occasionally will fail.

Taken together, I feel this motivates a higher priority than just a "slow performance" would indicate.
Comment 5 Piotr Popieluch 2015-11-27 08:41:03 EST
I agree with Alec on prio. For me waiting > 1 hour on f-r makes reviewing new packages unworkable.
Comment 6 Antonio Trande 2015-11-27 08:45:32 EST
(In reply to Alec Leamas from comment #4)
> After a  night's sleep I'm raising the priority/severity and resets
> "extremely slow" in the heading. 
> 
> This is justified by differences like 3 seconds using yum vs 2 minutes using
> dnf. This is just not performance, it's a blocking error in many contexts.
> We have reports about single --resolve queries taking "hours".
> 
> This performance is so bad that it typically makes fedora-review run 2-3
> times slower than using using yum - and then f-r has both built and
> installed a package in a mock chroot. I will be forced to mention this bug
> in upcoming fedora-review release notes with hints how to avoid the checks
> invoking --resolve, which in turn means that directory ownership needs to be
> checked manually instead. Which no doubt occasionally will fail.
> 
> Taken together, I feel this motivates a higher priority than just a "slow
> performance" would indicate.

+1
Comment 7 Dominique Brazziel 2015-12-22 12:16 EST
Created attachment 1108674 [details]
strace of dnf --requires --resolve gnome-terminal
Comment 8 Dominique Brazziel 2015-12-22 12:18:08 EST
As soon as I remove '--resolve' from 'dnf repoquery --requires --resolve <pkgname>' the command returns results almost instantaneously.
Comment 9 Tim Lauridsen 2015-12-23 04:12:13 EST
I dont have a clue why this is so slow

It must be some performance issue in hawkey, the code in the plugin is
just a call to a hawkey filter().

            query = self.filter_repo_arch(
                self.opts, self.base.sack.query().available())
            providers = query.filter(provides__glob=list(pkgs))
Comment 11 Alec Leamas 2015-12-23 05:48:37 EST
@tim: perhaps you could construct a test case without fedora-review for this issue? If the issue is still there, I guess we should re-assign this bug to the hawkey package?
Comment 12 Tom Hughes 2015-12-23 06:04:22 EST
There's nothing complicated about a non fedora-review test case - it's all there in the initial report. Compare this:

% time dnf repoquery -q -C --requires vtk.x86_64 
hdf5 = 1.8.15
<snipped>
rtld(GNU_HASH)
0.78user 0.09system 0:00.92elapsed 94%CPU (0avgtext+0avgdata 110756maxresident)k
0inputs+3120outputs (0major+45817minor)pagefaults 0swaps

and this:

% time dnf repoquery -q -C --requires --resolve vtk.x86_64
R-core-0:3.2.3-1.fc23.x86_64
<snipped>
zlib-0:1.2.8-9.fc23.x86_64
292.60user 2.42system 4:59.87elapsed 98%CPU (0avgtext+0avgdata 137040maxresident)k
191744inputs+25600outputs (24major+61131minor)pagefaults 0swaps

So adding --resolve takes us from just under a second to almost five minutes.
Comment 13 Alec Leamas 2015-12-23 07:44:53 EST
Indeed, I was clear as mud, sorry for that. What I mean is to construct a testcase in python modeled from the code in comment #10, bypassing the dnf plugin code. If we could reproduce it this way the bug belongs to the hawkey package and not dnf-plugins-core which perhaps could give this some more attention (?)
Comment 14 Honza Silhan 2016-01-11 08:11:46 EST
*** Bug 1296657 has been marked as a duplicate of this bug. ***
Comment 15 Lukas Slebodnik 2016-02-01 08:54:44 EST
I hit this bug as well
The repoquery from yum-utils is 500x faster then dnf plugin.
As a result of this fedora-review is unusable.

[root@host ~]# dnf makecache
Metadata cache created.

[root@host ~]# yum-deprecated makecache
Yum command has been deprecated, use dnf instead.
See 'man dnf' and 'man yum2dnf' for more information.

Metadata Cache Created 

[root@host ~]# time dnf repoquery -q -C --requires --resolve krb5-libs
bash-0:4.3.42-3.fc23.x86_64
coreutils-0:8.24-5.fc23.x86_64
crypto-policies-0:20151104-1.gitf1cba5f.fc23.noarch
gawk-0:4.1.3-2.fc23.x86_64
glibc-0:2.22-7.fc23.i686
glibc-0:2.22-7.fc23.x86_64
grep-0:2.22-6.fc23.x86_64
keyutils-libs-0:1.5.9-7.fc23.i686
keyutils-libs-0:1.5.9-7.fc23.x86_64
krb5-libs-0:1.14-7.fc23.i686
krb5-libs-0:1.14-7.fc23.x86_64
libcom_err-0:1.42.13-3.fc23.i686
libcom_err-0:1.42.13-3.fc23.x86_64
libselinux-0:2.4-4.fc23.i686
libselinux-0:2.4-4.fc23.x86_64
libverto-0:0.2.6-5.fc23.i686
libverto-0:0.2.6-5.fc23.x86_64
openssl-libs-1:1.0.2f-1.fc23.i686
openssl-libs-1:1.0.2f-1.fc23.x86_64
sed-0:4.2.2-11.fc23.x86_64

real    2m0.112s
user    1m59.373s
sys     0m0.872s


[root@host ~]# time repoquery -q -C --requires --resolve krb5-libs

Yum-utils package has been deprecated, use dnf instead.
See 'man yum2dnf' for more information.


bash-0:4.3.42-3.fc23.x86_64
libselinux-0:2.4-4.fc23.x86_64
keyutils-libs-0:1.5.9-7.fc23.x86_64
crypto-policies-0:20150518-3.gitffe885e.fc23.noarch
coreutils-0:8.24-5.fc23.x86_64
glibc-0:2.22-3.fc23.i686
gawk-0:4.1.3-2.fc23.x86_64
libcom_err-0:1.42.13-3.fc23.x86_64
glibc-0:2.22-7.fc23.x86_64
libverto-0:0.2.6-5.fc23.x86_64
grep-0:2.21-7.fc23.x86_64
sed-0:4.2.2-11.fc23.x86_64
keyutils-libs-0:1.5.9-7.fc23.i686
openssl-libs-1:1.0.2f-1.fc23.x86_64

real    0m0.223s
user    0m0.180s
sys     0m0.044s
Comment 16 Sergio Monteiro Basto 2016-02-10 23:58:17 EST
I found another dnf repoquery that is extremely slow: --srpm .


time dnf repoquery --srpm --qf="%{name}\t%{version}\t%{release}" 

real    16m24.975s
user    16m4.735s
sys     0m0.820s


while:

time dnf repoquery --arch=src --disablerepo='*'  --enablerepo=fedora-source --enablerepo=updates-source  --qf="%{name}\t%{version}\t%{release}" 

real    0m2.129s
user    0m1.131s
sys     0m0.216s


But more than extremely slow, consumes 100% of CPU while is running ...

Version-Release number of selected component:
dnf-1.1.6-2.fc23.noarch
dnf-plugins-core-0.1.16-1.fc23.noarch
Comment 17 Jan Pokorný 2016-02-25 12:35:44 EST
Suffer from this when running fedora-review, too.

Sitting there, waiting for it to finish (/etc/mock/fedora-23-x86_64.cfg
is being used) and grep'ing processes, I can see that, for instance, this
is pretty frequented:

    /usr/bin/python /bin/dnf repoquery -q -C --requires --resolve glibc

Per this random sampling of mine, this process takes about 4 minutes of
wall clock time, only to be followed by the very unique instance of the
same command in a very short time.  So far, several times in row and
counting.  Just exceptionally, I can see a different package name
in there.

I have to wonder what is going on here and where any sanity has gone
with this.
Comment 18 Lukas Slebodnik 2016-02-29 02:25:12 EST
(In reply to Jan Pokorný from comment #17)
> Suffer from this when running fedora-review, too.
>
My workaround is to "replace usage of" dnf repoquery with "repoquery" which is provided in the package yum-utils.

@see /usr/share/fedora-review/plugins/generic_build.py generic_build.py
@see /usr/lib/python2.7/site-packages/FedoraReview/deps.py

IMHO, it worth to open bug against the fedora-review package to do such change.
They do not provide python3 version so there's no reason for use very slow "dnf repoquery" instead of very fast "repoquery".
 
> Sitting there, waiting for it to finish (/etc/mock/fedora-23-x86_64.cfg
> is being used) and grep'ing processes, I can see that, for instance, this
> is pretty frequented:
> 
>     /usr/bin/python /bin/dnf repoquery -q -C --requires --resolve glibc
> 
> Per this random sampling of mine, this process takes about 4 minutes of
> wall clock time, only to be followed by the very unique instance of the
> same command in a very short time.  So far, several times in row and
> counting.  Just exceptionally, I can see a different package name
> in there.
> 
> I have to wonder what is going on here and where any sanity has gone
> with this.
Comment 19 Jan Pokorný 2016-03-07 08:23:57 EST
Re [comment 18]:
> IMHO, it worth to open bug against the fedora-review package to do such
> change

My hope is that already referenced [bug 1275275] will eventually lead to
the performance improvement, but my understanding is that unless this very
bug gets resolved, original speed of the overall operation will not be
matched.

BTW. direct repoquery run makes it clear this is now obsolete (F22):

$ repoquery -f '*/repoquery'
> 
> Yum-utils package has been deprecated, use dnf instead.
> See 'man yum2dnf' for more information.
> 
> 
> yum-utils-0:1.1.31-505.fc22.noarch
> yum-utils-0:1.1.31-508.fc22.noarch
Comment 20 Lukas Slebodnik 2016-03-07 08:53:30 EST
(In reply to Jan Pokorný from comment #19)
> Re [comment 18]:
> > IMHO, it worth to open bug against the fedora-review package to do such
> > change
> 
> My hope is that already referenced [bug 1275275] will eventually lead to
> the performance improvement,
very small performance improvement until this bug will be resolved.
@see comment 15

> but my understanding is that unless this very
> bug gets resolved, original speed of the overall operation will not be
> matched.
> 
> BTW. direct repoquery run makes it clear this is now obsolete (F22):
>
I will rather use 500x faster obsolete utility rather then broken/slow
new utility.

I just wanted to help. Feel free to use anything you want.
Comment 21 Sergio Monteiro Basto 2016-04-13 12:59:11 EDT
time dnf repoquery -q -C --requires glibc
(...)
real    0m1.335s
user    0m1.084s
sys     0m0.110s

time dnf repoquery -q -C --requires --resolve glibc
(...)
real    4m24.474s
user    4m22.064s
sys     0m2.130s

with CPU usage in 100% , is not acceptable  !
Comment 22 Michael Mráka 2016-04-26 08:18:32 EDT
Addressed in PR
https://github.com/rpm-software-management/dnf-plugins-core/pull/159
Comment 23 Alec Leamas 2016-04-26 12:42:04 EDT
hm... will this fix the performance to be comparable with yum? I was just about to revert to use yum-utils to be able to make a fedora-review release....
Comment 24 Michael Mráka 2016-04-26 16:11:30 EDT
> hm... will this fix the performance to be comparable with yum?

yum repoquery:
time   repoquery -q -C --requires --resolve glibc
...
real	0m3.763s
user	0m0.707s
sys	0m0.410s

dnf repoquery before
time dnf repoquery -q -C --requires --resolve glibc
...
real	8m38.467s
user	8m27.835s
sys	0m7.743s


dnf repoquery fixed
time dnf repoquery -q -C --requires --resolve glibc
...
real	0m3.179s
user	0m2.634s
sys	0m0.497s
Comment 25 Jan Pokorný 2016-04-29 04:59:52 EDT
Confirming that fedora-review tool became usable again for me
with the unglobbing change in the repoquery plugin.

Thanks for listening to our laments!
Comment 26 Alec Leamas 2016-05-03 08:13:08 EDT
fedora-review 0.6.1 is in updates-testing. Together with the dnf fix this should resolve this bug.
Comment 27 Fedora Update System 2016-05-19 07:07:49 EDT
dnf-plugins-core-0.1.21-1.fc24 dnf-1.1.9-1.fc24 has been submitted as an update to Fedora 24. https://bodhi.fedoraproject.org/updates/FEDORA-2016-1efd7bc386
Comment 28 Fedora Update System 2016-05-19 07:10:14 EDT
dnf-1.1.9-1.fc23 dnf-plugins-core-0.1.21-1.fc23 has been submitted as an update to Fedora 23. https://bodhi.fedoraproject.org/updates/FEDORA-2016-bb69db975e
Comment 29 Fedora Update System 2016-05-20 21:32:53 EDT
dnf-1.1.9-1.fc24, dnf-plugins-core-0.1.21-1.fc24 has been pushed to the Fedora 24 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-1efd7bc386
Comment 30 Fedora Update System 2016-05-20 22:27:11 EDT
dnf-1.1.9-1.fc23, dnf-plugins-core-0.1.21-1.fc23 has been pushed to the Fedora 23 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2016-bb69db975e
Comment 31 Fedora Update System 2016-05-21 22:24:06 EDT
dnf-1.1.9-1.fc23, dnf-plugins-core-0.1.21-1.fc23 has been pushed to the Fedora 23 stable repository. If problems still persist, please make note of it in this bug report.

Note You need to log in before you can comment on or make changes to this bug.