Bug 1414116

Summary:	librepo sometimes times out when it should not
Product:	[Fedora] Fedora	Reporter:	Kevin Fenzi <kevin>
Component:	librepo	Assignee:	Tomas Mlcoch <tmlcoch>
Status:	CLOSED EOL	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	unspecified	Docs Contact:
Priority:	unspecified
Version:	25	CC:	kparal, tmlcoch
Target Milestone:	---	Keywords:	Triaged
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2017-12-12 10:53:17 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Kevin Fenzi 2017-01-17 19:25:01 UTC

We are seeing sporadic failures in the Fedora build system where dnf says it cannot download a package for the mock chroot, but really it did download it fine. 

This issue is very sporadic, most of the time things are fine. 
It seems to affect every arch. 
It seems to happen on both Fedora 24 and Fedora 25 builders. 

An example task: 

https://koji.fedoraproject.org/koji/taskinfo?taskID=17312953

in https://kojipkgs.fedoraproject.org//work/tasks/3016/17313016/root.log

DEBUG util.py:421:  Downloading Packages:
DEBUG util.py:421:  Error: Error downloading packages:
DEBUG util.py:421:    Cannot download toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm: All mirrors were tried
DEBUG util.py:557:  Child return code was: 1

On the builder, in the chroot, /var/log/dnf.librepo.log has for gcc: 

15:16:58 lr_download: Target: toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm (-)
15:16:58 select_next_target: Selecting mirror for: toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm
15:16:58 prepare_next_transfer: URL: https://kojipkgs.fedoraproject.org//repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm
15:19:06 check_transfer_statuses: Transfer finished: toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm (Effective url: https://kojipkgs.fedoraproject.org//repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm)
15:19:06 check_finished_transfer_status: Serious error - Curl code (28): Timeout was reached for https://kojipkgs.fedoraproject.org//repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 120 seconds]
15:19:06 check_transfer_statuses: Error during transfer: Curl error (28): Timeout was reached for https://kojipkgs.fedoraproject.org//repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 120 seconds]
15:19:06 select_next_target: Selecting mirror for: toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm
15:19:06 lr_download: Error while downloading: Cannot download toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm: All mirrors were tried

kojipkgs.fedoraproject.org goes to a proxy that sends to a squid proxy. 

That squid proxy has: 

1484666759.892 001079 10.5.129.159 TCP_MEM_HIT/200 16798917 GET http://kojipkgs.fedoraproject.org/repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm - HIER_NONE/- application/x-rpm
1484667218.844 1000010 10.5.129.159 TCP_MISS_ABORTED/200 11223180 GET http://kojipkgs.fedoraproject.org/repos/f26-build/686094/aarch64/toplink/packages/gcc/6.3.1/1.fc26/aarch64/gcc-6.3.1-1.fc26.aarch64.rpm - HIER_NONE/- application/x-rpm

in its logs for this access. 

Happy to try and gather more info or debugging.

Comment 1 Kevin Fenzi 2017-01-20 05:19:36 UTC

So, it turns out the root of our problem here was squid operating in smp mode. Sometimes it would cause connections to hang. 

That said, it might be nice if librepo could retry 'retries' amount. We have it set to 20, but it gave up after the one connection timeout.

Comment 2 Fedora End Of Life 2017-11-16 19:39:02 UTC

This message is a reminder that Fedora 25 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 25. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '25'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version'
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not
able to fix it before Fedora 25 is end of life. If you would still like
to see this bug fixed and are able to reproduce it against a later version
of Fedora, you are encouraged  change the 'version' to a later Fedora
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's
lifetime, sometimes those efforts are overtaken by events. Often a
more recent Fedora release includes newer upstream software that fixes
bugs or makes them obsolete.

Comment 3 Fedora End Of Life 2017-12-12 10:53:17 UTC

Fedora 25 changed to end-of-life (EOL) status on 2017-12-12. Fedora 25 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.