The error looks like:
Copr repository 47 kB/s | 3.5 kB 00:00 fedora 0.0 B/s | 0 B 00:30 Failed to synchronize cache for repo 'fedora' Error: Failed to synchronize cache for repo 'fedora'
I briefly checked the librepo implementation, and for downloading metalink - the code seems to use lr_yum_download_url(), which means one attempt to download and "no retry" ever.
lr_yum_download_url()
After discussion in #7301, I have a feeling that downloading from https://dl.fedoraproject.org/ is not load-balanced -> and that only requests against that url end up on one of the dl0.fedoraproject.org servers (multiple A records in dns.git for dl.fedoraproject.org).
https://dl.fedoraproject.org/
A
dl.fedoraproject.org
So I'm curious - how likely is that some of the dl* servers is overloaded, so the client attempt to download metalink timeouts - are there some outage windows (e.g. synchronizing stuff?), and how long they are? - or are problems with download servers so unlikely, so the copr failures are likely client (or client networking) problems?
dl*
I've seen this hack dbb822036b9e4da778972b4a40fec2df0b8ca829 from #7301 in infra repo, which unconditionally flipped dl.fedoraproject.org A record to dl05 on all copr builders (which is not available to normal users). The hack was there for several months, so is it likely that the issues were caused by overloaded dl05.fedoraproject.org? I interpret it like: - the metalink was downloaded from dl05 and - then mirror list returned dl.fedoraproject.org as the closest mirror - so the following package installation ended up in downloading from dl05 anyways. I removed that hack now, to see whether it changes something ... but what do you think about this?
dl05
dl05.fedoraproject.org
Should I report issue/pull-request against librepo, so dnf tries to download the metalink several times (WRT to expected outage windows on dl* servers)?
So I'm curious - how likely is that some of the dl* servers is overloaded, so the client attempt to download metalink timeouts
It is highly likely that the dl servers are overloaded. You are hitting the prime servers and usually hitting them with a much larger load than these boxes were spec'd for in 2009. The times which get the 503's are still when tons of other clients are trying to use them also for downloads versus going to a mirror.
- are there some outage windows (e.g. synchronizing stuff?), and how long they are?
There are no outage windows. What you are running into is that every EPEL/Fedora enabled system in the world is doing a yum update from XX:00 -> XX:15 and some percentage of them are hitting the top level mirrors.
The fix for this would require multiple resource planning and purchases: 1. Faster local storage that you run your own mirror. 2. Upgrading Fedora infrastructure from using 1G NFS network to 10G. 3. Upgrading the backstore NFS server to not be shared with other Red Hat resources. Also have it have fast disks and slow disks and other layout needs.
- or are problems with download servers so unlikely, so the copr failures are likely client (or client networking) problems?
I can't rule that out either. The cloud version that copr is running on is completely dead upstream. All attempts to try and put in a replacement cloud have failed due to multiple reasons no one in Fedora can control. The cloud networking puts all kinds of oddities which could make a transaction to the dl servers hard.
Additionally, I would like to clarify: metalinks are not downloaded from dl servers. metalinks are downloaded from mirrors.fedoraproject.org which is all our proxies. Requests are answered there by apache thats talking to a set of mirrorlist containers running on those machines.
If the problem is the metalink downloading, the problem is with the mirrors / proxies, nothing at all to do with dl.fedoraproject.org.
Ok, you are right @kevin, I got tired while reading all the logs so I missed that:
2019-07-09T08:39:28Z DEBUG prepare_next_transfer: URL: https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64 2019-07-09T08:39:28Z DEBUG lr_download: Downloading started 2019-07-09T08:39:58Z DEBUG check_transfer_statuses: Transfer finished: https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64 (Effective url: https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64) 2019-07-09T08:39:58Z DEBUG check_finished_transfer_status: Serious error - Curl code (28): Timeout was reached for https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64 [Connection timed out after 30000 milliseconds] 2019-07-09T08:39:58Z DEBUG check_transfer_statuses: Error during transfer: Curl error (28): Timeout was reached for https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64 [Connection timed out after 30000 milliseconds] 2019-07-09T08:39:58Z DEBUG check_transfer_statuses: No more retries (tried: 1) 2019-07-09T08:39:58Z DEBUG lr_download: Error while downloading: Curl error (28): Timeout was reached for https://mirrors.fedoraproject.org/metalink?repo=fedora-30&arch=x86_64 [Connection timed out after 30000 milliseconds]
Makes me pretty confident that (a) waiting 30s for metalink download from mirrors is wasting of time, and (b) librepo should at least retry downloading (subsequent try would likely pick different DNS). I'll try to look at this ..
The other thing is that copr is maybe a bit unnecessarily overloading the primary mirrors. How big is this problem @smooge? Is that minimal load for the servers (compared to the rest of traffic), or should we somehow change the content of metalink urls so other download servers are preferred in fedorainfracloud.org (first is dl picking random dl0X now)? Note that for several months all the copr builders were downloading from dl05, was that even "visible" so you noticed?
dl
dl0X
The reason the dl servers were being used was that the latency to get data from outside of PHX2 to other mirrors can be large at times. Forcing it to use dlXX.fedoraproject.org was seen as a fix for other timeout issues. The problem is that there are 15 minutes of every hour where all the mirrors get hit by N million servers looking for updates. During that time copr may get lucky or it may end up finding that the NFS servers are just too damn tired.
librepo attempt: https://github.com/rpm-software-management/librepo/pull/159
So how often are you seeing this on builds? Any pattern? In the cases where it fails can you see a dnf.librepo.log that tells what exact host it hit (ie, what ip/server was answering mirrors.fedoraproject.org).
Or should we just wait for the PR you proposed and see if that solves the issue (or papers it over at least)?
So how often are you seeing this on builds? Any pattern?
From my tries, when I start some build in XX:00 XX:03, I'm very likely to hit about 50% bulid chroots failed because of this.
In the cases where it fails can you see a dnf.librepo.log that tells what exact host it hit (ie, what ip/server was answering mirrors.fedoraproject.org).
Unfortunately not. We could change librepo to provide us this info, or make libcurl more verbose (or maybe look into different log file, dunno). If you wanted us to do this observation, let me know (or fill ticket against copr). Seems like @smooge gave us clear answer what causes the 503 errors.
Probably yes. Closing.
Metadata Update from @praiskup: - Issue close_status updated to: Upstream - Issue status updated to: Closed (was: Open)