Bug 963627 - dnf shows way over 100% in its progress bar
Summary: dnf shows way over 100% in its progress bar
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: librepo (Show other bugs)
(Show other bugs)
Version: rawhide
Hardware: Unspecified Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Tomas Mlcoch
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Keywords:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-05-16 09:41 UTC by Jan Synacek
Modified: 2013-06-07 04:38 UTC (History)
3 users (show)

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 04:38:06 UTC
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)

Description Jan Synacek 2013-05-16 09:41:29 UTC
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 10:27:57 UTC
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 10:32:45 UTC
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 10:40:27 UTC
> --:--:-- 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 13:05:19 UTC
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 13:21:34 UTC
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 17:03:37 UTC
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 17:48:49 UTC
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 04:38:06 UTC
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.