Bug 1196164 - downloading packages from mirrors sometimes fails with HTTP 500 or 404 although mirror seems OK
Summary: downloading packages from mirrors sometimes fails with HTTP 500 or 404 althou...
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: dnf
Version: 22
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Packaging Maintenance Team
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-02-25 12:16 UTC by Jan Sedlák
Modified: 2015-03-17 10:33 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2015-03-17 10:33:10 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
anaconda log (21.46 KB, text/plain)
2015-02-25 12:16 UTC, Jan Sedlák
no flags Details
dnf log (128.96 KB, text/plain)
2015-02-25 12:16 UTC, Jan Sedlák
no flags Details
hawkey log (2.78 KB, application/octet-stream)
2015-02-25 12:17 UTC, Jan Sedlák
no flags Details
ifcfg (2.27 KB, text/plain)
2015-02-25 12:17 UTC, Jan Sedlák
no flags Details
packaging log (3.61 KB, text/plain)
2015-02-25 12:18 UTC, Jan Sedlák
no flags Details
program log (75.87 KB, text/plain)
2015-02-25 12:18 UTC, Jan Sedlák
no flags Details
sensitive-info log (106 bytes, text/plain)
2015-02-25 12:18 UTC, Jan Sedlák
no flags Details
storage log (246.69 KB, text/plain)
2015-02-25 12:19 UTC, Jan Sedlák
no flags Details
syslog (198.50 KB, text/plain)
2015-02-25 12:20 UTC, Jan Sedlák
no flags Details
packaging log from different machine (in Boston) (2.10 KB, text/plain)
2015-02-25 12:22 UTC, Jan Sedlák
no flags Details
another packaging log (4.77 KB, text/plain)
2015-02-25 12:23 UTC, Jan Sedlák
no flags Details

Description Jan Sedlák 2015-02-25 12:16:09 UTC
Created attachment 995110 [details]
anaconda log

Description of problem:
We are trying to automate anaconda testing and from time to time (approx. one in ten runs) installation from netinst fails during downloading packages with 500 or 404 HTTP code. Interesting is that it happens on different mirrors and when I check it by hand, given mirror actually contains request package. I was able to reproduce it on both, virtual machine and bare metal.

It happens on mirrors here in Brno (vutbr.cz and fi.muni.cz) and in Boston.

I am attaching logs from one failed installation, but I can provide other logs from other runs (it happens fairly often).

Version-Release number of selected component (if applicable):
22.20.1-1

Comment 1 Jan Sedlák 2015-02-25 12:16:31 UTC
Created attachment 995111 [details]
dnf log

Comment 2 Jan Sedlák 2015-02-25 12:17:17 UTC
Created attachment 995112 [details]
hawkey log

Comment 3 Jan Sedlák 2015-02-25 12:17:37 UTC
Created attachment 995113 [details]
ifcfg

Comment 4 Jan Sedlák 2015-02-25 12:18:10 UTC
Created attachment 995114 [details]
packaging log

Comment 5 Jan Sedlák 2015-02-25 12:18:28 UTC
Created attachment 995115 [details]
program log

Comment 6 Jan Sedlák 2015-02-25 12:18:54 UTC
Created attachment 995116 [details]
sensitive-info log

Comment 7 Jan Sedlák 2015-02-25 12:19:14 UTC
Created attachment 995117 [details]
storage log

Comment 8 Jan Sedlák 2015-02-25 12:20:04 UTC
Created attachment 995118 [details]
syslog

Comment 9 Jan Sedlák 2015-02-25 12:22:13 UTC
Created attachment 995119 [details]
packaging log from different machine (in Boston)

Comment 10 Jan Sedlák 2015-02-25 12:23:05 UTC
Created attachment 995125 [details]
another packaging log

Comment 11 Jan Sedlák 2015-02-25 12:40:36 UTC
Although it might seem like it's problem with mirrors, it happens so often and on wide range of mirrors so it seems it could be problem with software used for downloading. It didn't happened with F21, maybe yum retried failed downloads and dnf does not?

Comment 12 Brian Lane 2015-02-26 01:12:15 UTC
dnf handles package downloads, it looks like it is moving to the next mirror, but for whatever reason the mirror and metadata are out of sync. Maybe dnf has some thoughts on it.

Comment 13 Jan Sedlák 2015-02-26 12:32:33 UTC
It is weird that anaconda says that it got 404 when requesting package, but when you try it by hand, that mirror contains that package. I have tried it and immediately after anaconda failed with 404 during downloading package, I ran curl on that link and it worked without problem.

Another weird thing is, when you look on this log: https://bugzilla.redhat.com/attachment.cgi?id=995125 anaconda gets FTP 550 when requesting package (I have tried it back then and I was able to download that package) and then immediately it tries the same mirror, only via HTTP and it gets HTTP 404 (although again, I was able to download that package via curl).

Comment 14 Honza Silhan 2015-03-03 09:55:47 UTC
Thanks for the report. Can you try that again with dnf-0.6.4 and librepo-1.7.13 setting `timeout` config option [1] to higher number (optionally setting metadata_expire to low value) and share the result, please?

[1] http://dnf.readthedocs.org/en/latest/conf_ref.html?highlight=timeout#options-for-both-main-and-repo

Comment 15 Kamil Páral 2015-03-03 10:11:51 UTC
Thanks for info, Jan Silhan.

Brian, can we manually play with these options inside the anaconda environment, and how? We can create an updates.img if needed, just tell us what to edit (config files in /etc or anaconda source files). Thanks.

Btw, another option that caught my attention is "minrate", and I'm not sure why it is '0' by default and whether it has some special meaning. But it could help us also with an issue related to bug 1196629, when downloading metadata in the main hub takes 5-10 minutes (which makes our automated tests fail, and is quite user unfriendly), and trying a different mirror automatically could solve it all.

Comment 16 Brian Lane 2015-03-03 21:35:36 UTC
You can adjust those in the _configure method, here:

https://github.com/rhinstaller/anaconda/blob/f22-branch/pyanaconda/packaging/dnfpayload.py#L348

Comment 17 Honza Silhan 2015-03-04 12:34:53 UTC
You can play around with `minrate` but by default the remaining seconds to timeout is count when 0 bytes are transferred - IMO good enough.

Comment 18 Jan Sedlák 2015-03-04 14:01:37 UTC
Unfortunately, I am now unable to reproduce this, so I am unable to play with `timeout` and `minrate` options. Even machines that are running our tests hadn't encountered this bug since 24. 2., but they have encountered it several times before that.

Comment 19 Honza Silhan 2015-03-17 10:33:10 UTC
Closing this. The new version of librepo improves the mirror selection mechanism so that could be the reason why you can't reproduce it. Either way I am closing this, feel free to reopen once you find the reproducer.


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