Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.
Bug 1279538 - [perf] dnf repoquery --resolve is extremely slow
Summary: [perf] dnf repoquery --resolve is extremely slow
Keywords:
Status: CLOSED UPSTREAM
Alias: None
Product: Fedora
Classification: Fedora
Component: dnf-plugins-core
Version: 23
Hardware: Unspecified
OS: Unspecified
urgent
urgent
Target Milestone: ---
Assignee: Jaroslav Mracek
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
: 1285360 1296657 (view as bug list)
Depends On:
Blocks: 1275275
TreeView+ depends on / blocked
 
Reported: 2015-11-09 16:52 UTC by Christian Dersch
Modified: 2018-09-24 15:21 UTC (History)
26 users (show)

Fixed In Version: dnf-plugins-core-0.1.21-1.fc23
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-05-15 07:22:13 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
strace of dnf --requires --resolve gnome-terminal (deleted)
2015-12-22 17:16 UTC, Dominique Brazziel
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1275275 0 unspecified CLOSED fedora-review queries too many times for same thing 2021-02-22 00:41:40 UTC

Internal Links: 1275275

Description Christian Dersch 2015-11-09 16:52:54 UTC
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 13:27:59 UTC
Thanks for the report.

Comment 2 Christian Dersch 2015-11-26 09:06:27 UTC
*** Bug 1285360 has been marked as a duplicate of this bug. ***

Comment 3 Alec Leamas 2015-11-26 09:25:22 UTC
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 13:32:49 UTC
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 13:41:03 UTC
I agree with Alec on prio. For me waiting > 1 hour on f-r makes reviewing new packages unworkable.

Comment 6 Antonio T. (sagitter) 2015-11-27 13:45:32 UTC
(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 17:16:23 UTC
Created attachment 1108674 [details]
strace of dnf --requires --resolve gnome-terminal

Comment 8 Dominique Brazziel 2015-12-22 17:18:08 UTC
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 09:12:13 UTC
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 10:48:37 UTC
@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 11:04:22 UTC
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 12:44:53 UTC
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 13:11:46 UTC
*** Bug 1296657 has been marked as a duplicate of this bug. ***

Comment 15 Lukas Slebodnik 2016-02-01 13:54:44 UTC
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 Basto 2016-02-11 04:58:17 UTC
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ý [poki] 2016-02-25 17:35:44 UTC
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 07:25:12 UTC
(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ý [poki] 2016-03-07 13:23:57 UTC
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 13:53:30 UTC
(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 Basto 2016-04-13 16:59:11 UTC
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 12:18:32 UTC
Addressed in PR
https://github.com/rpm-software-management/dnf-plugins-core/pull/159

Comment 23 Alec Leamas 2016-04-26 16:42:04 UTC
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 20:11:30 UTC
> 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ý [poki] 2016-04-29 08:59:52 UTC
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 12:13:08 UTC
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 11:07:49 UTC
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 11:10:14 UTC
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-21 01:32:53 UTC
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-21 02:27:11 UTC
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-22 02:24:06 UTC
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.

Comment 32 XU Guang-zhao 2018-04-05 08:40:31 UTC
Unfortunately, this issue still exists in Fedora 27

$ time dnf repoquery -Cq --requires wine-core-0:3.4-1.fc27.x86_64 > /dev/null

real	0m0.661s
user	0m0.563s
sys	0m0.090s
$ time dnf repoquery -Cq --requires --resolve wine-core-0:3.4-1.fc27.x86_64 > /dev/null

real	3m10.014s
user	3m4.963s
sys	0m3.093s
$ rpm -qa dnf*
dnf-plugins-core-2.1.5-4.fc27.noarch
dnf-2.7.5-2.fc27.noarch
dnf-conf-2.7.5-2.fc27.noarch
dnf-yum-2.7.5-2.fc27.noarch
$

Comment 33 Zbigniew Jędrzejewski-Szmek 2018-04-05 10:19:22 UTC
Interesting:
Comment #c24 says that --resolve --requires glibc is 3 s (F26).

On F28:
dnf repoquery -q -C --requires --resolve glibc >/dev/null
8.81s user 0.22s system 99% cpu 9.105 total

And wine-core:
dnf repoquery -q -C --requires --resolve wine-core >/dev/null
333.01s user 3.02s system 99% cpu 5:38.79 total

It seems to scale badly with the number of packages involved.

Comment 34 Jaroslav Mracek 2018-05-15 07:22:13 UTC
I guess that the problem is already solved in upstream. The fix will be available in dnf-3.x. We provide also our testing repository where upstream version is available ( # dnf copr enable rpmsoftwaremanagement/dnf-nightly).

Comment 35 Jan Pokorný [poki] 2018-07-11 14:34:44 UTC
Any ETA for dnf 3 in Rawhide, at least?

I believe I am still heavily impacted with fedora-review use case
(see [bug 1275275]).

$ rpm -q dnf fedora-review
> dnf-2.7.5-12.fc29.noarch
> fedora-review-0.6.1-9.fc29.noarch

Comment 36 Tom Hughes 2018-07-11 14:38:47 UTC
I's already in rawhide (currently 3.0.2).

Comment 37 Jason Tibbitts 2018-07-11 14:45:30 UTC
For the record, dnf 3 was first built for rawhide on June 26 and should have been available in the next compose.  My test VMs received it early on June 28.

Comment 38 Jan Pokorný [poki] 2018-07-16 14:32:15 UTC
Indeed, sorry for noise, dnf update was silently blocked in plain
update command for me because of some other Python 3 related issues
(IIRC, libreoffice + one other package that is currently FTBFS).
Will report when I rerun fedora-review using the updated dnf whether
the total time is noticeably quicker = bearably fast.


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