Thanks for the report.

*** Bug 1285360 has been marked as a duplicate of this bug. ***

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

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.

I agree with Alec on prio. For me waiting > 1 hour on f-r makes reviewing new packages unworkable.

(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

Created attachment 1108674 [details]
strace of dnf --requires --resolve gnome-terminal

As soon as I remove '--resolve' from 'dnf repoquery --requires --resolve <pkgname>' the command returns results almost instantaneously.

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))

https://github.com/rpm-software-management/dnf-plugins-core/blob/master/plugins/repoquery.py#L390

@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?

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.

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 (?)

*** Bug 1296657 has been marked as a duplicate of this bug. ***

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

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

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.

(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.

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

(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.

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  !

Addressed in PR
https://github.com/rpm-software-management/dnf-plugins-core/pull/159

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....

> 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

Confirming that fedora-review tool became usable again for me
with the unglobbing change in the repoquery plugin.

Thanks for listening to our laments!

fedora-review 0.6.1 is in updates-testing. Together with the dnf fix this should resolve this bug.

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

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

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

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

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.

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
$

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.

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).

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

I's already in rawhide (currently 3.0.2).

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.

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.