Bug 963627 - dnf shows way over 100% in its progress bar
dnf shows way over 100% in its progress bar
Status: CLOSED ERRATA
Product: Fedora
Classification: Fedora
Component: librepo (Show other bugs)
rawhide
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: Tomas Mlcoch
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2013-05-16 05:41 EDT by Jan Synacek
Modified: 2013-06-07 00:38 EDT (History)
3 users (show)

See Also:
Fixed In Version: hawkey-0.3.13-2.git15db39f.fc19
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2013-06-07 00:38:06 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)

  None (edit)
Description Jan Synacek 2013-05-16 05:41:29 EDT
Description of problem:
I spotted this when updating my rawhide machine.

(16/18): python-devel-.7.4-4.fc20.x86_64.rpm                                                        (84%) 64490% [==========================================================================================]  82 kB/s | 184 kB  --:--:-- ETA

Note the "64490%" at the end of the line. However, I don't how to reproduce it, so I'm filing this just for the record.


Version-Release number of selected component (if applicable):
dnf-0.3.3-3.git91ba5e0.fc20.noarch


Steps to Reproduce:
1. dnf update
2.
3.
  
Actual results:
Over 100% in the progress bar.

Expected results:
Progress bar percentage stays in 0-100% range.
Comment 1 Jan Synacek 2013-05-16 06:27:57 EDT
It happened again. I didn't do anything special, just ran dnf update.

dnf seems to be calculating the current progress wrongly as the percentage gets increased by very large numbers.

(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 1484705% [==========================================================================================] 153 kB/s | 4.1 MB  --:--:-- ETA 
(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 1625990% [==========================================================================================] 148 kB/s | 4.5 MB  --:--:-- ETA 
(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 1876134% [==========================================================================================] 129 kB/s | 5.2 MB  --:--:-- ETA 
(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 1936817% [==========================================================================================] 128 kB/s | 5.4 MB  --:--:-- ETA 
(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 2032706% [==========================================================================================] 133 kB/s | 5.6 MB  --:--:-- ETA 
(33/515): glibc-common-2.17-8.fc20.x86_64.rpm             (7%) 2359370% [==========================================================================================] 200 kB/s | 6.5 MB  --:--:-- ETA
Comment 2 Ales Kozumplik 2013-05-16 06:32:45 EDT
Thanks, apparently there is something odd going on in the librepo vs. progress bar callback interaction in DNF.
Comment 3 Zdeněk Pavlas 2013-05-16 06:40:27 EDT
> --:--:-- ETA 

This means that progress.start() was called without "size" arg set.

> 1484705%

This should contain the per-file progress percentage.  Likely a bug in urlgrabber.progress module (the percentage filed should be empty in this case).  I'll take a look at this.
Comment 4 Zdeněk Pavlas 2013-05-16 09:05:19 EDT
This is a librepo bug.  It's feeding invalid initial "total_to_download" value (about 290, in this case) value to the progress callback.  The "downloaded" value seems to be okay.

>>> import urlgrabber.progress as p
>>> p.text_meter_total_size(100<<30, 7<<30)
>>> m=p.TextMeter()
>>> m.start(text='glibc-common-2.17-8.fc20.x86_64.rpm', size=290)
>>> m.update(4305645)
glibc-common-2.17-8. (7%) 1484705% [==========]  0.0 B/s | 4.1 MB     --:-- ETA 
>>> m.update(4715371)
glibc-common-2.17-8. (7%) 1625990% [==========] 6.7 kB/s | 4.5 MB     --:-- ETA 
...

This reproduces the reported output very closely.  Since downloaded > total_to_download, ETA is negative and not shown.
Comment 5 Fedora Update System 2013-05-27 09:21:34 EDT
hawkey-0.3.13-2.git15db39f.fc19, dnf-0.3.6-1.git24ce938.fc19 has been submitted as an update for Fedora 19.
https://admin.fedoraproject.org/updates/dnf-0.3.6-1.git24ce938.fc19,hawkey-0.3.13-2.git15db39f.fc19
Comment 6 Fedora Update System 2013-05-27 13:03:37 EDT
Package hawkey-0.3.13-2.git15db39f.fc19, dnf-0.3.6-1.git24ce938.fc19:
* should fix your issue,
* was pushed to the Fedora 19 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing hawkey-0.3.13-2.git15db39f.fc19 dnf-0.3.6-1.git24ce938.fc19'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-9385/dnf-0.3.6-1.git24ce938.fc19,hawkey-0.3.13-2.git15db39f.fc19
then log in and leave karma (feedback).
Comment 7 Fedora Update System 2013-05-29 13:48:49 EDT
Package hawkey-0.3.13-2.git15db39f.fc19, dnf-0.3.7-1.gitf8bdc98.fc19:
* should fix your issue,
* was pushed to the Fedora 19 testing repository,
* should be available at your local mirror within two days.
Update it with:
# su -c 'yum update --enablerepo=updates-testing hawkey-0.3.13-2.git15db39f.fc19 dnf-0.3.7-1.gitf8bdc98.fc19'
as soon as you are able to.
Please go to the following url:
https://admin.fedoraproject.org/updates/FEDORA-2013-9385/hawkey-0.3.13-2.git15db39f.fc19,dnf-0.3.7-1.gitf8bdc98.fc19
then log in and leave karma (feedback).
Comment 8 Fedora Update System 2013-06-07 00:38:06 EDT
hawkey-0.3.13-2.git15db39f.fc19, dnf-0.3.7-1.gitf8bdc98.fc19 has been pushed to the Fedora 19 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.