Bug 1192524 - DNF cannot download metadata
Summary: DNF cannot download metadata
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: dnf
Version: 23
Hardware: x86_64
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: rpm-software-management
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On: 1196629
Blocks:
TreeView+ depends on / blocked
 
Reported: 2015-02-13 15:49 UTC by Andrea
Modified: 2016-11-24 13:04 UTC (History)
14 users (show)

Fixed In Version:
Clone Of:
Environment:
Last Closed: 2016-11-24 12:55:28 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
dnf.log for skip_if_unavailable=True (2.41 KB, application/x-gzip)
2015-03-10 09:21 UTC, Andrea
no flags Details

Description Andrea 2015-02-13 15:49:07 UTC
Description of problem:

"sudo dnf update" gets stuck while updating metadata and never finishes.
"sudo yum update" manages to complete

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

dnf 0.6.3

How reproducible:

always

It gets stuck downloading files, getting to 99%, then going back to 0% and never finishes it.
yum does a few retries, partial downloads and finally succeeds.

after "yum clean all", yum needs a couple of minutes to download the metadata, trying various mirrors and doing partial downloads. The log is at the bottom of this comment.

did the same with dnf and it tries forever to download a file.

I did comment on an other similar bug, but being closed, probability gets ignored.

https://bugzilla.redhat.com/show_bug.cgi?id=1130685

output of dnf

Fedora 21 - x86_64    37% [=======-            ]  26 kB/s |  15 MB     16:08 ETA

it goes almost at 100%, then starts again, then stops halfway, starts again.... After more that 1 hour nothing else happened.
Other times, the target size is 39 MB, it varies.

The proxy I need to use does some file inspection and sometimes blocks the download almost at the end while it checks the file and then continues. If it matters this runs inside VirtualBox.

yum never had an issue with this, and after a few try / partial downloads, in 5 minutes finishes the job.

here is the output of yum. I was not able to find a similar verbose output for dnf.


$ sudo yum update   
Loaded plugins: langpacks
fedora/21/x86_64/metalink                                                                   |  22 kB  00:00:00     
fedora                                                                                      | 3.8 kB  00:00:00     
updates/21/x86_64/metalink                                                                  |  25 kB  00:00:00     
updates                                                                                     | 4.9 kB  00:00:00     
(1/4): fedora/21/x86_64/group_gz                                                            | 232 kB  00:00:00     
updates/21/x86_64/primary_db   FAILED                                          
http://mirror.netcologne.de/fedora/linux/updates/21/x86_64/repodata/d07ceea118929066df06bfaa36d42bae37e0ccb26905a8e06470a1c0c9d69c1d-primary.sqlite.bz2: [Errno 14] HTTP Error 404 - Not Found
Trying other mirror.
(2/4): updates/21/x86_64/group_gz                                                           | 406 kB  00:00:00     
(3/4): updates/21/x86_64/primary_db                                                         | 4.2 MB  00:00:00     
fedora/21/x86_64/primary_db    FAILED                                          - ] 2.5 MB/s |  21 MB  00:00:00 ETA 
http://mirror.netcologne.de/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 14] curl#18 - "transfer closed with 16119 bytes remaining to read"
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                          ==] 1.3 kB/s |  39 MB  --:--:-- ETA 
ftp://ftp.mirrorservice.org/sites/dl.fedoraproject.org/pub/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 12] Timeout on ftp://ftp.mirrorservice.org/sites/dl.fedoraproject.org/pub/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: (28, 'Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds')
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                          
http://mirror.karneval.cz/pub/linux/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 14] HTTP Error 416 - Requested Range Not Satisfiable
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                          
http://ftp.upjs.sk/pub/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 14] HTTP Error 416 - Requested Range Not Satisfiable
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                          
http://mirror.proserve.nl/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 14] HTTP Error 416 - Requested Range Not Satisfiable
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                          
http://mirror.slu.cz/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 14] HTTP Error 416 - Requested Range Not Satisfiable
Trying other mirror.
fedora/21/x86_64/primary_db    FAILED                                            ]   68 B/s | 5.7 MB  69:57:39 ETA 
http://vesta.informatik.rwth-aachen.de/ftp/pub/Linux/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: [Errno 12] Timeout on http://vesta.informatik.rwth-aachen.de/ftp/pub/Linux/fedora/linux/development/21/x86_64/os/repodata/4c0ea0d0ca8fd81fd3a96cacabfbcf9e02c33125670505fcf20aacefab48df02-primary.sqlite.xz: (28, 'Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds')
Trying other mirror.
(4/4): fedora/21/x86_64/primary_db                                                          |  17 MB  00:00:15     
(1/2): updates/21/x86_64/updateinfo                                                         | 486 kB  00:00:00     
updates/21/x86_64/pkgtags      FAILED                                          
http://mirror.netcologne.de/fedora/linux/updates/21/x86_64/repodata/c0c7a3f6711eaca1a55b75fe7cc31aef35363d87e0b6a57f6fb4cc5b33345493-pkgtags.sqlite.gz: [Errno 14] HTTP Error 404 - Not Found
Trying other mirror.
(2/2): updates/21/x86_64/pkgtags                                                            | 1.3 MB  00:00:00     
No packages marked for update

Comment 1 Andrea 2015-02-17 09:06:09 UTC
I've found some logs of dnf, here is the relevant part

Feb 17 06:37:47 DDEBUG repo: downloading from remote: fedora, _Handle: metalnk: https://mirrors.fedoraproject.org/metalink?repo=fedora-21&arch=x86_64, mlist: None, urls [].
Feb 17 06:37:56 DDEBUG Cleaning up.
Feb 17 06:37:56 SUBDEBUG 
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/dnf/cli/main.py", line 84, in main
    return _main(base, args)
  File "/usr/lib/python2.7/site-packages/dnf/cli/main.py", line 134, in _main
    cli.run()
  File "/usr/lib/python2.7/site-packages/dnf/cli/cli.py", line 1059, in run
    return self.command.run(self.base.extcmds)
  File "/usr/lib/python2.7/site-packages/dnf/cli/commands/makecache.py", line 87, in run
    self.base.fill_sack() # performs the md sync
  File "/usr/lib/python2.7/site-packages/dnf/base.py", line 222, in fill_sack
    self._add_repo_to_sack(r.id)
  File "/usr/lib/python2.7/site-packages/dnf/base.py", line 98, in _add_repo_to_sack
    repo.load()
  File "/usr/lib/python2.7/site-packages/dnf/repo.py", line 781, in load
    raise dnf.exceptions.RepoError(msg)
RepoError: Failed to synchronize cache for repo 'fedora' from 'https://mirrors.fedoraproject.org/metalink?repo=fedora-21&arch=x86_64': Yum repo downloading error: Downloading error(s): repodata/abb4ea5ccb9ad46253984126c6bdc86868442a4662dbcfa0e0f51b1bb209331e-filelists.xml.gz - Download failed: Curl error (18): Transferred a partial file for ftp://ftp.mirrorservice.org/sites/dl.fedoraproject.org/pub/fedora/linux/releases/21/Everything/x86_64/os/repodata/abb4ea5ccb9ad46253984126c6bdc86868442a4662dbcfa0e0f51b1bb209331e-filelists.xml.gz [transfer closed with 10133739 bytes remaining to read]
Feb 17 06:37:56 CRITICAL Error: Failed to synchronize cache for repo 'fedora' from 'https://mirrors.fedoraproject.org/metalink?repo=fedora-21&arch=x86_64': Yum repo downloading error: Downloading error(s): repodata/abb4ea5ccb9ad46253984126c6bdc86868442a4662dbcfa0e0f51b1bb209331e-filelists.xml.gz - Download failed: Curl error (18): Transferred a partial file for ftp://ftp.mirrorservice.org/sites/dl.fedoraproject.org/pub/fedora/linux/releases/21/Everything/x86_64/os/repodata/abb4ea5ccb9ad46253984126c6bdc86868442a4662dbcfa0e0f51b1bb209331e-filelists.xml.gz [transfer closed with 10133739 bytes remaining to read]

It cannot download this file.
What is odd is that yum can finish the download with a partial download.

Has the logic to download a file changed between yum and dnf?

Comment 2 Honza Silhan 2015-03-05 15:00:06 UTC
Thanks for the report. Can you set in /etc/dnf/dnf.conf `skip_if_unavailable=True` install dnf-0.64 and librepo-1.7.14, test it again and share the result, please?

Comment 3 Andrea 2015-03-10 09:19:01 UTC
Nope

dnf-0.64 was already there, installed 

librepo-1.7.14-1.fc23.x86_64.rpm
python-librepo-1.7.14-1.fc23.x86_64.rpm

done a dnf clean up and then

xxxxxx@localhost:~$ sudo time dnf update
Fedora 21 - x86_64                                                                                                                                          44 kB/s |  39 MB     15:14    
Error: Failed to synchronize cache for repo 'updates' from 'https://mirrors.fedoraproject.org/metalink?repo=updates-released-f21&arch=x86_64': Yum repo downloading error: Downloading error(s): repodata/3efed204dbb15a6c7fe0137c5f66446d86749f32c2b0f645accbcaac638cebbe-filelists.xml.gz - Cannot download, all mirrors were already tried without success
32.75user 14.57system 56:50.40elapsed 1%CPU (0avgtext+0avgdata 246848maxresident)k
16inputs+176096outputs (0major+111244minor)pagefaults 0swaps

content of /etc/dnf/dnf.conf

xxxxxx@localhost:/tmp$ cat /etc/dnf/dnf.conf 
[main]
gpgcheck=1
installonly_limit=3
clean_requirements_on_remove=true

proxy=http://localhost:3128

skip_if_unavailable=True

attached is the relevant part of dnf.log

as a comparison, yum was successful and took 55 seconds.

Comment 4 Andrea 2015-03-10 09:21:22 UTC
Created attachment 999784 [details]
dnf.log for skip_if_unavailable=True

/var/log/dnf.log with librepo-1.7.14 and dnf 0.6.4

with

skip_if_unavailable=True

Comment 5 Honza Silhan 2015-03-24 11:06:13 UTC
It seems like the connection of mirrors is closed because of timeout. Can you try to set `timeout=100` (or more) [1] into dnf.conf, please?

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

Comment 6 Andrea 2015-03-30 14:51:19 UTC
it worked!!!!!

I set 300 and finally I got a little update with dnf.

I will try to find out what is (roughly) the minimum acceptable.

My fear is the following: when install F22, will I be able to change this *during* the install?

Comment 7 Honza Silhan 2015-04-02 13:45:57 UTC
(In reply to Andrea from comment #6)
> it worked!!!!!
> 
> I set 300 and finally I got a little update with dnf.
> 
> I will try to find out what is (roughly) the minimum acceptable.
> 
> My fear is the following: when install F22, will I be able to change this
> *during* the install?

Do you mean clean install from Anaconda or FedUp / Fedora upgrade / distro-sync to newer Fedora release?

Either way the conf should be set beforehand.

Comment 8 Andrea 2015-04-03 12:16:46 UTC
I mean brand new install of F22 on a new PC / VM, where yum has been removed.

In any case, dnf is much much slower than yum, even now that it succeeds.

Comment 9 EMR_Fedora 2015-06-19 18:14:14 UTC
Yeah, DNF is very slow... it hangs on almost every repository. It attempts to connect on ports that are either blocked, or unavailable on the remote server. (i.e.: SYN_SENT for servers that aren't responding) Attempted the above timeout=5 and still nothing.

Comment 10 EMR_Fedora 2015-09-11 16:58:12 UTC
Yeah, this is definitely a bug... curl vs wget:

2 minutes with curl, 0.1seconds with wget:

$ curl -o foobar ftp://mirror.symnds.com/distributions/fedora/releases/22/Everything/i386/os/Packages/m/maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1409k  100 1409k    0     0  11313      0  0:02:07  0:02:07 --:--:--  348k


$ wget ftp://mirror.symnds.com/distributions/fedora/releases/22/Everything/i386/os/Packages/m/maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm
--2015-09-11 12:56:58--  ftp://mirror.symnds.com/distributions/fedora/releases/22/Everything/i386/os/Packages/m/maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm
           => 'maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm.1'
Resolving mirror.symnds.com (mirror.symnds.com)... 63.245.196.124
Connecting to mirror.symnds.com (mirror.symnds.com)|63.245.196.124|:21... connected.
Logging in as anonymous ... Logged in!
==> SYST ... done.    ==> PWD ... done.
==> TYPE I ... done.  ==> CWD (1) /distributions/fedora/releases/22/Everything/i386/os/Packages/m ... done.
==> SIZE maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm ... 1442888
==> PASV ... done.    ==> RETR maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm ... done.
Length: 1442888 (1.4M) (unauthoritative)

maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm.1          100%[=======================================================================================================================>]   1.38M  --.-KB/s   in 0.1s

2015-09-11 12:56:59 (10.6 MB/s) - 'maven-scm-javadoc-1.9.2-2.fc22.noarch.rpm.1' saved [1442888]

Comment 11 Miroslav Suchý 2016-02-16 23:11:43 UTC
I am hitting the same problems on Copr builders.

Copr builders have:
  dnf-1.1.3-1.fc23.noarch

Yum is able to download packages and repositories, but DNF fails with approximately 30% probability with:

/usr/bin/dnf -d 2 -y --enablerepo=updates-testing check-update\'.\nSee \'man dnf\' and \'man yum2dnf\' for more information.\nTo transfer transaction metadata from yum to DNF, run:\n\'dnf install python-dnf-plugins-extras-migrate && dnf-2 migrate\'\n\nError: Failed to synchronize cache for repo \'updates-testing\' from \'https://mirrors.fedoraproject.org/metalink?repo=updates-testing-f22&arch=ppc64le\': Cannot download repomd.xml: Cannot download repodata/repomd.xml: All mirrors were tried

Those builders are in PHX datacenter so connectivity should not be such issue. Yet DNF very often die with this error.

I put as workaround 
  timeout=1000
in dnf.conf. But this is not sustainable as I will need to modify all mock configs too. Right now we have just 6 of them which use dnf, but it will grow soon.

Comment 12 Michal Luscon 2016-02-19 15:43:17 UTC
Could you please take a look Tomas whether we are able to influence this on the librepo level?

Comment 13 Tomas Mlcoch 2016-03-04 13:10:10 UTC
Hi Miroslav, could you please try this scratch build of librepo?
http://koji.fedoraproject.org/koji/taskinfo?taskID=13226518

This version has two main features:
1) It uses HTTP headers that tell to proxy server to always serve fresh metalink.xml, mirrorlist and repomd.xml files - no proxy cache should be causing issues anymore.

2) Has a new option LRO_FTPUSEEPSV [1] by witch an extended passive mode for FTP could be disabled (the extended passive mode was probably the problem which was described by "EMR_Fedora").

[1] http://rpm-software-management.github.io/librepo/lib.html#librepo.LRO_FTPUSEEPSV

Comment 14 Fedora Admin XMLRPC Client 2016-07-08 09:37:33 UTC
This package has changed ownership in the Fedora Package Database.  Reassigning to the new owner of this component.

Comment 15 Fedora End Of Life 2016-11-24 11:26:53 UTC
This message is a reminder that Fedora 23 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 23. 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 '23'.

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 23 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 16 Michael Mráka 2016-11-24 12:55:28 UTC
Missing needinfo  for half a year, closing.

If you still hit this issue, feel free to reopen.

Comment 17 Michael Mráka 2016-11-24 13:04:21 UTC
Clearing needinfo.


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