Created attachment 1564080 [details] Squid access log Description of problem: When running dnf behind a proxy, downloading the "updates" metadata works initially but fails on subsequent updates. Version-Release number of selected component (if applicable): dnf-4.2.2-2.fc30.noarch How reproducible: Always Steps to Reproduce: 1. dnf -vvv --disableplugin=* --disablerepo=* --enablerepo=updates --refresh upgrade Actual results: DNF version: 4.2.2 cachedir: /var/cache/dnf Fedora 30 - x86_64 - Updates 68 kB/s | 7.6 kB 00:00 reviving: failed for 'updates', mismatched repomd. repo: downloading from remote: updates Fedora 30 - x86_64 - Updates 72 kB/s | 395 kB 00:05 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/b7914b050694990fa934e8ec80f02e875b289e51be3d72a6699b041b1ff7f884-prestodelta.xml.zck - Not finished; repodata/54b146a9401e01f73c03b2605ac264f7f87cf9d132652c9411c00521eb733d30-updateinfo.xml.xz - Not finished. Failed to synchronize cache for repo 'updates' Error: Failed to synchronize cache for repo 'updates' Expected results: Repo should be updated successfully. Additional info: Further data points: /etc/dnf/dnf.conf: [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=http://XXXX/ proxy_username=XXX proxy_password=XXXX deltarpm=0 max_parallel_downloads=1 excludepkgs=kernel-debug-devel I've attached the squid access log generated on the proxy during the above exchange. You'll notice that all the requests are successful AND are revalidated against the server every time. You an discount the DENIED lines, this is just proxy authentication doing its job. Downloading the metadata files manually with wget yields the same results with and without the proxy. The exact same setup works perfectly fine in Fedora 28 and Fedora 29.
I forgot to add that if I run: dnf clean all dnf upgrade Then everything works fine.
Seeing similar indications on Fedora 30 XFCE spin Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync DNF version: 4.2.5 cachedir: /var/cache/dnf Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id “failovermethod” does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id “failovermethod” does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id “failovermethod” does not exist repo: using cache for: fedora-modular fedora-modular: using metadata from Thu 25 Apr 2019 07:47:30 PM EDT. repo: using cache for: updates-modular updates-modular: using metadata from Thu 09 May 2019 10:52:19 PM EDT. Fedora 30 - x86_64 - Updates 26 kB/s | 16 kB 00:00 reviving: failed for ‘updates’, mismatched sha256 sum. repo: downloading from remote: updates Fedora 30 - x86_64 - Updates 187 kB/s | 341 kB 00:01 Cannot download ‘https://mirrors.fedoraproject.org/metalink?repo=updates-released-f30&arch=x86_64’: Yum repo downloading error: Downloading error(s): repodata/0978310fe47b07fc7fd0df959389a82d27887bb7e2c82fea0875883463483711-prestodelta.xml.zck - Not finished; repodata/491ab687aee1392591b20a065824656f1f690bbde3bbfcab8f7e6ebf9ae78705-updateinfo.xml.xz - Not finished. Failed to synchronize cache for repo ‘updates’ Error: Failed to synchronize cache for repo ‘updates’ Link to the last few entries in dnf.librepo.log https://paste.fedoraproject.org/paste/5gzFZUXaEfMcJGs4WODxrQ Doing dnf clean metadata allows things to work normally.
(In reply to joe.c.walker0 from comment #2) > Seeing similar indications on Fedora 30 XFCE spin > > Loaded plugins: builddep, changelog, config-manager, copr, debug, > debuginfo-install, download, generate_completion_cache, needs-restarting, > playground, repoclosure, repodiff, repograph, repomanage, reposync > DNF version: 4.2.5 > cachedir: /var/cache/dnf > Unknown configuration value: failovermethod=priority in > /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding > with id “failovermethod” does not exist > Unknown configuration value: failovermethod=priority in > /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding > with id “failovermethod” does not exist > Unknown configuration value: failovermethod=priority in > /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding > with id “failovermethod” does not exist > repo: using cache for: fedora-modular > fedora-modular: using metadata from Thu 25 Apr 2019 07:47:30 PM EDT. > repo: using cache for: updates-modular > updates-modular: using metadata from Thu 09 May 2019 10:52:19 PM EDT. > Fedora 30 - x86_64 - Updates 26 kB/s | 16 kB 00:00 > reviving: failed for ‘updates’, mismatched sha256 sum. > repo: downloading from remote: updates > Fedora 30 - x86_64 - Updates 187 kB/s | 341 kB 00:01 > Cannot download > ‘https://mirrors.fedoraproject.org/metalink?repo=updates-released- > f30&arch=x86_64’: Yum repo downloading error: Downloading error(s): > repodata/0978310fe47b07fc7fd0df959389a82d27887bb7e2c82fea0875883463483711- > prestodelta.xml.zck - Not finished; > repodata/491ab687aee1392591b20a065824656f1f690bbde3bbfcab8f7e6ebf9ae78705- > updateinfo.xml.xz - Not finished. > Failed to synchronize cache for repo ‘updates’ > Error: Failed to synchronize cache for repo ‘updates’ > > Link to the last few entries in dnf.librepo.log > https://paste.fedoraproject.org/paste/5gzFZUXaEfMcJGs4WODxrQ > > Doing dnf clean metadata allows things to work normally. /etc/dnf.conf [main] gpgcheck=1 installonly_limit=2 clean_requirements_on_remove=True max_parallel_downloads=1
might be duplicate of: https://bugzilla.redhat.com/show_bug.cgi?id=1706321
(In reply to grumpey0 from comment #4) > might be duplicate of: https://bugzilla.redhat.com/show_bug.cgi?id=1706321 Could you please update to the version of librepo in https://bugzilla.redhat.com/show_bug.cgi?id=1706321#c27? If it doesn't work, can you please attach the full dnf.librepo.log?
Sorry, just to clarify, if, after updating to that version of librepo, metadata downloads still don't work, then please attach the full dnf.librepo.log.
Created attachment 1568090 [details] last 100 lines of dnf.librepo.log Full log was too large to upload so I dumped the last 100 lines.
(In reply to grumpey0 from comment #7) > Created attachment 1568090 [details] > last 100 lines of dnf.librepo.log > > Full log was too large to upload so I dumped the last 100 lines. So, did it work this time?
Scratch that, I see that it didn't. Unfortunately, there's not enough of the log to see the errors. Can you compress the log using gzip or xz and attach it?
Created attachment 1568123 [details] dnf lib repo log Re-Ran with a fresh log file.
Ok, thats... odd. No errors are listed until the very last line. Are you behind a proxy? And could you please tar up /var/cache/dnf/updates-d6521d96a82a4d6a/repodata/ and post it somewhere where I can access it? I'm hoping that using whatever you've currently got in your cache will help me figure this out.
Created attachment 1568149 [details] compressed updates directory from /var/cache Zipped and attached. I have to use Verizon wireless as my ISP, I don't think I'm behind a proxy.
I can't update aymore even if I execute sudo dnf clean all dnf clean all sync error in -> 'updates-modular' is there a wokaround??? regards.,
Please try this workaround (/etc/dnf/dnf.conf): fastestmirror=True fastestmirror=False If your repo fails to sync and you've got fastest mirrors set to true, then disable them by writing false; or do just the oposite. Then dnf update once again.
I've added:
Sorry about the unfinished comment 15. Adding: zchunk = False to /etc/dnf/dnf.conf is the best work-around to date. But that won't help with fixing the issue :-/
(In reply to Héctor Louzao from comment #13) > I can't update aymore even if I execute > > sudo dnf clean all > dnf clean all > > sync error in -> 'updates-modular' > > is there a wokaround??? > > regards., This is most likely https://bugzilla.redhat.com/show_bug.cgi?id=1706321. If setting zchunk=False fixes it, try to update to librepo-1.9.6-3 listed in that bug report. If that fixes your problem, it's not this bug (I think).
(In reply to grumpey0 from comment #12) > Created attachment 1568149 [details] > compressed updates directory from /var/cache > > Zipped and attached. > > I have to use Verizon wireless as my ISP, I don't think I'm behind a proxy. Ok, I'm officially baffled. I've tried to reproduce the bug on my local machine and I can't make it happen. I've tried using the compressed updates directory you sent me and tried using a proxy, and everything works perfectly for me for every combination of the two. The logs also don't really make sense. primary.xml.zck and filelists.xml.zck all download perfectly (which indicates that it's not a range problem). There are no indications of download failures until the last couple of lines of the log where it just says that prestodelta.xml.zck and updateinfo.xml.xz are "Not finished". Unfortunately, if I can't reproduce it and the logs don't show where the error is happening, I can't really debug this. If any of those running into this particular problem (indicated by prestodelta.xml.zck and updateinfo.xml.xz showing as "Not finished") have any ideas on how I can reproduce this bug, I'd appreciate any inspiration.
FWIW, if those running into this particular problem (indicated by prestodelta.xml.zck and updateinfo.xml.xz showing as "Not finished") could try setting zchunk=False and seeing if it fixes the problem, it would at least indicate that this is a zchunk problem. I've been making that assumption, but the fact that updateinfo.xml.xz, a non-zchunk file, is "Not finished", makes me wonder if something else is going on.
(In reply to Jonathan Dieter from comment #19) > FWIW, if those running into this particular problem (indicated by > prestodelta.xml.zck and updateinfo.xml.xz showing as "Not finished") could > try setting zchunk=False and seeing if it fixes the problem, it would at > least indicate that this is a zchunk problem. I've been making that > assumption, but the fact that updateinfo.xml.xz, a non-zchunk file, is "Not > finished", makes me wonder if something else is going on. I've tried librepo-1.9.6-3, it didn't help: I didn't have zchunk=0/False in my dnf.conf for these tests. Note that I *also* have pinned a particular mirror in my /etc/yum.repos.d/fedora*.repo to avoid other potential issues with mirror lack of synchronization. All my testing is done while dealing with a single mirror (dl.fedoraproject.org). 1. dnf update was showing the error after new packages showed up on the mirror. 2. dnf -C update --best --allowerasing https://kojipkgs.fedoraproject.org//work/tasks/9926/34789926/librepo-1.9.6-3.fc30.x86_64.rpm https://kojipkgs.fedoraproject.org//work/tasks/9926/34789926/python3-librepo-1.9.6-3.fc30.x86_64.rpm https://kojipkgs.fedoraproject.org//work/tasks/9926/34789926/librepo-devel-1.9.6-3.fc30.x86_64.rpm (Installation was successful) 3. dnf update gave the same error as at step 1.
I set zchunk=False this morning and was able to check for updates this morning and this evening after I got home. I've cleared that setting from my dnf.conf and have changed the max_parallel_downloads=2. I was able to run a full update after that but I think that was because the metadata had just been updated. Is there a faster way to make this expire or just wait it out? Thanks
(In reply to grumpey0 from comment #21) > Is there a faster way to make this expire or just wait it out? Either: dnf --refresh upgrade dnf clean all; dnf upgrade (In reply to Jonathan Dieter from comment #18) > Unfortunately, if I can't reproduce it and the logs don't show where the > error is happening, I can't really debug this. If any of those running into > this particular problem (indicated by prestodelta.xml.zck and > updateinfo.xml.xz showing as "Not finished") have any ideas on how I can > reproduce this bug, I'd appreciate any inspiration. I can reproduce easily by using F30's squid as a proxy and pointing dnf at it. I can give you all the conf files needed (squid.conf, dnf.conf, yum.repos.d/*.repo). All you need to do is run 'dnf makecache' and wait for the repo to change. Actually, I can reproduce as well *without waiting for the repo to update* with: # dnf clean all 9 files removed # dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo', 'updates-testing', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Excludes in dnf.conf: kernel-debug-devel Making cache files for all metadata files. updates-testing: has expired and will be refreshed. updates: has expired and will be refreshed. repo: downloading from remote: updates-testing Fedora 30 - x86_64 - Test Updates 12 MB/s | 16 MB 00:01 updates-testing: using metadata from Mon May 13 18:32:36 2019. repo: downloading from remote: updates Fedora 30 - x86_64 - Updates 12 MB/s | 8.5 MB 00:00 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/9c1db8f60d6ad0620841fc083b208a08c07fc62efaecf84062c0692169d011c5-prestodelta.xml.zck - Not finished; repodata/7f5be4ef41b3c9fad4b45c7bb5d916ca6a6edd566af93412ad8a4cb40ffeb368-updateinfo.xml.xz - Not finished. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates'
(In reply to Philippe Troin from comment #22) So this morning I was able to successfully check for updates, the only difference from previous attempts was the max_parallel_downloads being set to 2 vice 1. (Does that make any sense at all??) I'm going to revert that back to 1 and see what happens.
(In reply to grumpey0 from comment #23) > (In reply to Philippe Troin from comment #22) > So this morning I was able to successfully check for updates, the only > difference from previous attempts was the max_parallel_downloads being set > to 2 vice 1. (Does that make any sense at all??) I've tried resetting max_parallel_downloads=2 and the commands listed in comment 22 still fail. However, this morning, there are new error messages. This is with zchunk=1, and proxy* set. # dnf clean all 9 files removed # dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo', 'updates-testing', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Excludes in dnf.conf: kernel-debug-devel Making cache files for all metadata files. updates-testing: has expired and will be refreshed. updates: has expired and will be refreshed. repo: downloading from remote: updates-testing Fedora 30 - x86_64 - Test Updates 19 MB/s | 16 MB 00:00 updates-testing: using metadata from Wed May 15 06:35:54 2019. repo: downloading from remote: updates error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f-primary.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f-primary.xml.zck). error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f-filelists.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f-filelists.xml.zck). Fedora 30 - x86_64 - Updates 372 kB/s | 553 kB 00:01 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f-primary.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f-primary.xml.zck [Failed writing body (0 != 16384)]; repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f-filelists.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f-filelists.xml.zck [Failed writing body (0 != 16384)]. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' The "error: Curl error (23)" messages are new.
(In reply to Philippe Troin from comment #24) > Fedora 30 - x86_64 - Updates > 372 kB/s | 553 kB 00:01 > Cannot download > 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': > Yum repo downloading error: Downloading error(s): > repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f- > primary.xml.zck - Download failed: Curl error (23): Failed writing received > data to disk/application for > http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/ > repodata/bde1a09b7768323d5e1fc5f5ba02dc932207754d7efe20454becfff90d03139f- > primary.xml.zck [Failed writing body (0 != 16384)]; > repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f- > filelists.xml.zck - Download failed: Curl error (23): Failed writing > received data to disk/application for > http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/ > repodata/f990fd4380cdb4a5f5b4694251bcd2209060ddb02b9a8b00bec999a495fdc69f- > filelists.xml.zck [Failed writing body (0 != 16384)]. > Failed to synchronize cache for repo 'updates' > Cleaning up. > Error: Failed to synchronize cache for repo 'updates' I don't suppose you could remove /var/log/dnf.librepo.log, rerun the command that gave you the output above, and then attach the newly generated dnf.librepo.log? Also, this may be a dumb question, but what does 'df -h' show?
Ok, I finally reproduced. I hadn't noticed that both of you are using max_parallel_downloads=1. When I set that, I hit the same error. I would suggest removing that option completely and seeing if you hit any problems. In the meantime, I'll see if I can figure out why this is causing problems.
(In reply to Jonathan Dieter from comment #26) I was ok using one this afternoon when I checked and just switched it back to two.
(In reply to Jonathan Dieter from comment #25) > I don't suppose you could remove /var/log/dnf.librepo.log, rerun the command > that gave you the output above, and then attach the newly generated > dnf.librepo.log? I sure can. I've attached /var/log/dnf.librepo.log as requested. This run was captured with: # : > /var/log/dnf.librepo.log # dnf clean all 10 files removed # rpm -q dnf librepo dnf-4.2.5-1.fc30.noarch librepo-1.9.6-2.fc30.x86_64 # egrep -v '#' /etc/dnf/dnf.conf [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=http://someproxy proxy_username=proxyuser proxy_password=proxypass # dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo', 'updates-testing', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Making cache files for all metadata files. updates-testing: has expired and will be refreshed. updates: has expired and will be refreshed. repo: downloading from remote: updates-testing Fedora 30 - x86_64 - Test Updates 23 MB/s | 16 MB 00:00 updates-testing: using metadata from Wed May 15 06:35:54 2019. repo: downloading from remote: updates error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck). error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck). Fedora 30 - x86_64 - Updates 1.1 MB/s | 592 kB 00:00 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck [Failed writing body (0 != 16384)]; repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck [Failed writing body (0 != 16384)]. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' > Also, this may be a dumb question, but what does 'df -h' show? Plenty of space: Filesystem Size Used Avail Use% Mounted on devtmpfs 16G 0 16G 0% /dev tmpfs 16G 0 16G 0% /dev/shm tmpfs 16G 2.5M 16G 1% /run tmpfs 16G 0 16G 0% /sys/fs/cgroup /dev/mapper/vg_ceramic-root 80G 67G 14G 84% / tmpfs 16G 592K 16G 1% /tmp /dev/md1 992M 287M 638M 32% /boot /dev/mapper/vg_ceramic-var 16G 2.6G 14G 17% /var /dev/mapper/vg_ceramic-mysql 8.0G 1.6G 6.5G 20% /export/mysql /dev/mapper/vg_ceramic-home 1.8T 1.2T 636G 65% /export/home tmpfs 3.1G 36K 3.1G 1% /run/user/42 tmpfs 3.1G 104K 3.1G 1% /run/user/1000 /dev/dm-5 3.6T 3.5T 113G 97% /run/media/root/FifTM-Manual-1 tantale:/export/srv 1.5T 631G 906G 42% /vol/srv
Created attachment 1569262 [details] dnf.librepo.log This run was captured with: # : > /var/log/dnf.librepo.log # dnf clean all 10 files removed # rpm -q dnf librepo dnf-4.2.5-1.fc30.noarch librepo-1.9.6-2.fc30.x86_64 # egrep -v '#' /etc/dnf/dnf.conf [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=http://someproxy proxy_username=proxyuser proxy_password=proxypass # dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo updates-testing --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo', 'updates-testing', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Making cache files for all metadata files. updates-testing: has expired and will be refreshed. updates: has expired and will be refreshed. repo: downloading from remote: updates-testing Fedora 30 - x86_64 - Test Updates 23 MB/s | 16 MB 00:00 updates-testing: using metadata from Wed May 15 06:35:54 2019. repo: downloading from remote: updates error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck). error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck [Failed writing body (0 != 16384)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck). Fedora 30 - x86_64 - Updates 1.1 MB/s | 592 kB 00:00 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/7679c2bd49254c04f120290d2c0e98fc0b4381c91057b8d0e7b25b5f33c74164-primary.xml.zck [Failed writing body (0 != 16384)]; repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/9a2270fbc282a699cfa797191532aafd174767cbc173aefec4da46f8e6c64f34-filelists.xml.zck [Failed writing body (0 != 16384)]. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates'
Ok, I've found and fixed the bug: https://github.com/rpm-software-management/librepo/pull/153 It was a single line of code (of course). I've created a scratch build of the fix that should be available for a while: https://koji.fedoraproject.org/koji/taskinfo?taskID=34886005 If you want to test right now, go ahead and run: sudo dnf update https://kojipkgs.fedoraproject.org//work/tasks/6006/34886006/librepo-1.9.6-4.fc30.x86_64.rpm https://kojipkgs.fedoraproject.org//work/tasks/6006/34886006/python3-librepo-1.9.6-4.fc30.x86_64.rpm
Created attachment 1570015 [details] dnf lib repo log - Installed last night and set max_parallel_downloads back to one. Ran update this morning with no issues, attached dnf lib repo log file just in case. Thanks!
After updating to 1.9.6-4.fc30, the issue I reported at comment 28 and comment 29. I'll have to wait until the repo updates to confirm that the initially reported issue is fixed. Thank you.
And nope, after tonight's repo update, the original bug (fails behind a proxy) is still there: # : > /var/log/dnf.librepo.log # dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Excludes in dnf.conf: kernel-debug-devel Making cache files for all metadata files. updates: has expired and will be refreshed. Fedora 30 - x86_64 - Updates 62 kB/s | 7.6 kB 00:00 reviving: failed for 'updates', mismatched repomd. repo: downloading from remote: updates error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck [Failed writing body (0 != 10716)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck). error: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck [Failed writing body (0 != 9888)] (http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck). Fedora 30 - x86_64 - Updates 701 kB/s | 706 kB 00:01 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck [Failed writing body (0 != 10716)]; repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck [Failed writing body (0 != 9888)]. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' # rpm -q dnf libdnf librepo python3-librepo dnf-4.2.5-1.fc30.noarch libdnf-0.31.0-3.fc30.x86_64 librepo-1.9.6-4.fc30.x86_64 python3-librepo-1.9.6-4.fc30.x86_64
Created attachment 1570434 [details] dnf.librepo.log
Created attachment 1570435 [details] cd /var/cache/dnf && tar cJf var-cache-dnf-updates.tar.xz updates*
(In reply to Philippe Troin from comment #33) > Cannot download > 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': > Yum repo downloading error: Downloading error(s): > repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751- > primary.xml.zck - Download failed: Curl error (23): Failed writing received > data to disk/application for > http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/ > repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751- > primary.xml.zck [Failed writing body (0 != 10716)]; This isn't the original error message you got; this is what you were seeing in comments #28 and #29, where it's running into problems writing the file to the local filesystem. I've tried to mimic your setup as best I can (using your /var/cache/dnf/updates*, dl.fedoraproject.org as the only mirror and going through squid), and updates are working fine for me. Some suggestions: - This may be a permissions/selinux problem. Try clearing /var/cache/dnf/updates* and make sure you re-run as root. - Make sure max_parallel_downloads is set to 1, not 2 (just so we're testing the same thing you started with) Beyond that, if you could attach your squid.conf (removing any sensitive information in it), I could see if there's something there. Jonathan
Created attachment 1570661 [details] squid.conf (In reply to Jonathan Dieter from comment #36) > This isn't the original error message you got; this is what you were seeing > in comments #28 and #29, where it's running into problems writing the file > to the local filesystem. Indeed. > I've tried to mimic your setup as best I can > (using your /var/cache/dnf/updates*, dl.fedoraproject.org as the only mirror > and going through squid), and updates are working fine for me. > Some suggestions: > - This may be a permissions/selinux problem. Try clearing > /var/cache/dnf/updates* and make sure you re-run as root. I have SELinux turned off, and /var/cache/dnf was cleared 12 hours before. > - Make sure max_parallel_downloads is set to 1, not 2 (just so we're testing > the same thing you started with) It was set to 1 when the test was ran. > Beyond that, if you could attach your squid.conf (removing any sensitive > information in it), I could see if there's something there. I've attached an anonymized version of squid.conf for the proxy. It is running squid-4.4-2.fc30.x86_64.
Created attachment 1570673 [details] output of strace dnf I'm attaching a strace output, generated by: # rm -fr /var/cache/dnf/* # cd /var/cache/dnf/ # tar xJf ~/var-cache-dnf-updates.tar.xz # sed -re 's!^(proxy[^=]*=).*!\1XXXXX!' -e 's!#.*!!' -e '/^[[:space:]]*$/d' /etc/dnf/dnf.conf [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=XXXXX proxy_username=XXXXX proxy_password=XXXXX deltarpm=0 max_parallel_downloads=1 excludepkgs=kernel-debug-devel # strace -ff -o LOG dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache # tar cJf strace.out.tar.xz LOG.*
Forgot to add: # rpm -q dnf libdnf librepo python3-librepo curl dnf-4.2.5-1.fc30.noarch libdnf-0.31.0-3.fc30.x86_64 librepo-1.9.6-4.fc30.x86_64 python3-librepo-1.9.6-4.fc30.x86_64 curl-7.64.0-6.fc30.x86_64
(In reply to Philippe Troin from comment #39) > Forgot to add: > > # rpm -q dnf libdnf librepo python3-librepo curl > dnf-4.2.5-1.fc30.noarch > libdnf-0.31.0-3.fc30.x86_64 > librepo-1.9.6-4.fc30.x86_64 > python3-librepo-1.9.6-4.fc30.x86_64 > curl-7.64.0-6.fc30.x86_64 Not that it probably matters, but what version of zchunk-libs?
Ok, I've setup a local squid proxy using your config and the same version of squid, setup my own user and password in it, and retested. Everything worked as expected. I'm baffled. Can you try using the regular metalink instead of limiting it to dl.fedoraproject.org?
(In reply to Jonathan Dieter from comment #40) > Not that it probably matters, but what version of zchunk-libs? zchunk-1.1.1-3.fc30.x86_64 (In reply to Jonathan Dieter from comment #41) > Ok, I've setup a local squid proxy using your config and the same version of > squid, setup my own user and password in it, and retested. Everything > worked as expected. I'm baffled. Can you try using the regular metalink > instead of limiting it to dl.fedoraproject.org? Okay, this is a run with a stock /etc/yum.repos.d/fedora-updates.repo: # rm -fr /var/cache/dnf/* # cd /var/cache/dnf # tar xJf ~/var-cache-dnf-updates.tar.xz # dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache timer: config: 1 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Excludes in dnf.conf: kernel-debug-devel Making cache files for all metadata files. updates: has expired and will be refreshed. repo: downloading from remote: updates error: Curl error (23): Failed writing received data to disk/application for http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck [Failed writing body (0 != 8509)] (http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck). error: Curl error (23): Failed writing received data to disk/application for http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck [Failed writing body (0 != 749)] (http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck). Fedora 30 - x86_64 - Updates 164 kB/s | 691 kB 00:04 Cannot download 'https://mirrors.fedoraproject.org/metalink?repo=updates-released-f30&arch=x86_64': Yum repo downloading error: Downloading error(s): repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck [Failed writing body (0 != 8509)]; repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck - Download failed: Curl error (23): Failed writing received data to disk/application for http://mirror.umd.edu/fedora/linux/updates/30/Everything/x86_64/repodata/fedfbb113e1b500acade85ef10d0b795507410138416f9f5d10779a5d5ed5f8f-filelists.xml.zck [Failed writing body (0 != 749)]. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' # rpm -q dnf libdnf librepo python3-librepo curl zchunk dnf-4.2.5-1.fc30.noarch libdnf-0.31.0-3.fc30.x86_64 librepo-1.9.6-4.fc30.x86_64 python3-librepo-1.9.6-4.fc30.x86_64 curl-7.64.0-6.fc30.x86_64 zchunk-1.1.1-3.fc30.x86_64 # sed -re 's!^(proxy[^=]*=).*!\1XXXXX!' -e 's!#.*!!' -e '/^[[:space:]]*$/d' /etc/dnf/dnf.conf [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=XXXXX proxy_username=XXXXX proxy_password=XXXXX deltarpm=0 max_parallel_downloads=1 excludepkgs=kernel-debug-devel Other mirrors are hit, the problem remains. Also, I can reproduce this on any machine on my network, including 32-bit i686 boxes.
One more data point: I may have found an issue with librepo. I've set up debuginfo and ran dnf with gdb. I've put a breakpoint where the error message is emitted: Thread 1 "python3" hit Breakpoint 1, curl_easy_strerror (error=<optimized out>) at ../../lib/strerror.c:132 132 return "Failed writing received data to disk/application"; (gdb) bt #0 0x00007fffe90edf70 in curl_easy_strerror (error=<optimized out>) at ../../lib/strerror.c:132 #1 0x00007fffe99a872e in check_finished_transfer_status (err=0x7fffffffb458, transfer_err=0x7fffffffb468, fatal_error=<synthetic pointer>, serious_error=<synthetic pointer>, target=0x555555a92370, msg=0x555555ac72a0) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:1772 #2 0x00007fffe99a872e in check_transfer_statuses (err=0x7fffffffb458, dd=0x7fffffffb490) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:2149 #3 0x00007fffe99a872e in lr_perform (err=0x7fffffffb458, dd=0x7fffffffb490) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:2453 #4 0x00007fffe99a872e in lr_download (targets=<optimized out>, failfast=<optimized out>, err=0x7fffffffb5a0) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:2583 #5 0x00007fffe99a9610 in lr_download_single_cb (targets=0x555555745db0 = {...}, failfast=failfast@entry=0, cb=<optimized out>, mfcb=<optimized out>, err=err@entry=0x7fffffffb5a0) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:2787 #6 0x00007fffe99ba593 in lr_yum_download_repo (handle=handle@entry=0x555555a83c30, repo=repo@entry=0x555555a7c750, repomd=repomd@entry=0x555555a884a0, err=err@entry=0x7fffffffb618) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/yum.c:952 #7 0x00007fffe99badf5 in lr_yum_download_remote --Type <RET> for more, q to quit, c to continue without paging--c (err=0x7fffffffb688, result=0x555555a83c30, handle=0x555555a83c30) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/yum.c:1344 #8 0x00007fffe99badf5 in lr_yum_perform (handle=handle@entry=0x555555a83c30, result=result@entry=0x555555a83f40, err=err@entry=0x7fffffffb688) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/yum.c:1420 #9 0x00007fffe99ae74d in lr_handle_perform (handle=handle@entry=0x555555a83c30, result=0x555555a83f40, err=err@entry=0x7fffffffb848) at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/handle.c:1220 #10 0x00007fffe9b0c4e9 in libdnf::Repo::Impl::lrHandlePerform(_LrHandle*, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, bool) (this=0x5555559e3f00, handle=0x555555a83c30, destDirectory="/var/cache/dnf/updates-17305a87bca1d4ed/tmpdir.NhJgLy", setGPGHomeEnv=<optimized out>) at /usr/src/debug/libdnf-0.31.0-3.fc30.x86_64/libdnf/repo/Repo.cpp:916 #11 0x00007fffe9b0e7c3 in libdnf::Repo::Impl::fetch(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&, std::unique_ptr<_LrHandle, std::default_delete<_LrHandle> >&&) (this=0x5555559e3f00, destdir="/var/cache/dnf/updates-17305a87bca1d4ed", h=...) at /usr/include/c++/9/bits/unique_ptr.h:357 #12 0x00007fffe9b0f39a in libdnf::Repo::Impl::load() (this=0x5555559e3f00) at /usr/src/debug/libdnf-0.31.0-3.fc30.x86_64/libdnf/repo/Repo.cpp:1199 #13 0x00007fffe9b9a7eb in () at /usr/lib64/python3.7/site-packages/libdnf/_repo.so #14 0x00007ffff7b1f931 in _PyMethodDef_RawFastCallKeywords () at /lib64/libpython3.7m.so.1.0 #15 0x00007ffff7b1fa63 in _PyCFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #16 0x00007ffff7b58063 in () at /lib64/libpython3.7m.so.1.0 #17 0x00007ffff7b9a8b2 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #18 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #19 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #20 0x00007ffff7b9a8b2 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #21 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #22 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #23 0x00007ffff7b9a8b2 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #24 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #25 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #26 0x00007ffff7b95ae5 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #27 0x00007ffff7b44000 in _PyEval_EvalCodeWithName () at /lib64/libpython3.7m.so.1.0 #28 0x00007ffff7b45022 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #29 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #30 0x00007ffff7b968e9 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #31 0x00007ffff7b44000 in _PyEval_EvalCodeWithName () at /lib64/libpython3.7m.so.1.0 #32 0x00007ffff7b45022 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #33 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #34 0x00007ffff7b95ae5 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #35 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #36 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #37 0x00007ffff7b95ae5 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #38 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #39 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #40 0x00007ffff7b95ae5 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #41 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #42 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #43 0x00007ffff7b95a40 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #44 0x00007ffff7b44e82 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #45 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #46 0x00007ffff7b95a40 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #47 0x00007ffff7b44000 in _PyEval_EvalCodeWithName () at /lib64/libpython3.7m.so.1.0 #48 0x00007ffff7b45022 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #49 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #50 0x00007ffff7b95a40 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #51 0x00007ffff7b44000 in _PyEval_EvalCodeWithName () at /lib64/libpython3.7m.so.1.0 #52 0x00007ffff7b45022 in _PyFunction_FastCallKeywords () at /lib64/libpython3.7m.so.1.0 #53 0x00007ffff7b57f4f in () at /lib64/libpython3.7m.so.1.0 #54 0x00007ffff7b968e9 in _PyEval_EvalFrameDefault () at /lib64/libpython3.7m.so.1.0 #55 0x00007ffff7b44000 in _PyEval_EvalCodeWithName () at /lib64/libpython3.7m.so.1.0 #56 0x00007ffff7b44d59 in PyEval_EvalCodeEx () at /lib64/libpython3.7m.so.1.0 #57 0x00007ffff7b44d7b in PyEval_EvalCode () at /lib64/libpython3.7m.so.1.0 #58 0x00007ffff7c11093 in () at /lib64/libpython3.7m.so.1.0 #59 0x00007ffff7c113f7 in PyRun_FileExFlags () at /lib64/libpython3.7m.so.1.0 #60 0x00007ffff7c170aa in PyRun_SimpleFileExFlags () at /lib64/libpython3.7m.so.1.0 #61 0x00007ffff7c18d9c in () at /lib64/libpython3.7m.so.1.0 #62 0x00007ffff7c18f4c in _Py_UnixMain () at /lib64/libpython3.7m.so.1.0 #63 0x00007ffff7d80f33 in __libc_start_main () at /lib64/libc.so.6 #64 0x000055555555508e in _start () If you look at stack frame #1: /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:1733-1738: 1733 curl_easy_getinfo(msg->easy_handle, 1734 CURLINFO_EFFECTIVE_URL, 1735 &effective_url); 1736 1737 if (msg->data.result != CURLE_OK) { 1738 // There was an error that is reported by CURLcode man curl_easy_getinfo() says that the error code is returned, not stashed in msg->data.result. When running with # gdb python3 (gdb) run /usr/bin/dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache Then putting a break point at: 3 breakpoint keep y 0x00007fffe99a7eaa in check_finished_transfer_status at /usr/src/debug/librepo-1.9.6-4.fc30.x86_64/librepo/downloader.c:1733 The error is hit 3 times after this break point is hit. curl_easy_getinfo() returns CURLE_OK, but msg->data.result is set to CURLE_WRITE_ERROR, causing the error. If I force with the debugger: (gdb) set msg->data.result = CURLE_OK (gdb) c Continuing. Fedora 30 - x86_64 - Updates 38 B/s | 8.5 kB 03:50 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error: Unable to initialize zchunk file repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck: Unable to set zchunk file descriptor for repodata/416702351a05210396f8c7fca61a6eaa2c35df69d062e2811f6b0ae6193ed751-primary.xml.zck: Unable to find multipart download range . Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' [Inferior 1 (process 156726) exited with code 01] So it could be that the real error is the one above, and not CURLE_WRITE_ERROR.
Please disregard comment 43, I found the root cause after peeling all the layers off. The problem is in zchunk. I'll update this bug with a zchunk PR.
The problem is caused by by zchunk parsing incorrectly multipart content-type boundary field: zchunk wasn't stripping the optional double quotes around the boundary field in Content-Type, causing it it barf on chunked-encoding transfers when Squid was serving a chunked request from cache. Squid does use quoted boundaries. This is such a header: Content-Type: multipart/byteranges; boundary="squid/4.4:F82935BEEAFF2D18713D8DE52D79E38A"
(In reply to Philippe Troin from comment #45) > The problem is caused by by zchunk parsing incorrectly multipart > content-type boundary field: zchunk wasn't stripping the optional double > quotes around the boundary field in Content-Type, causing it it barf on > chunked-encoding transfers when Squid was serving a chunked request from > cache. Squid does use quoted boundaries. This is such a header: > > Content-Type: multipart/byteranges; > boundary="squid/4.4:F82935BEEAFF2D18713D8DE52D79E38A" Thanks so much for tracking this down! I've merged the PR (as well as your second one), and am pushing out zchunk updates as we speak.
zchunk-1.1.2-2.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-2a885ceb39
zchunk-1.1.2-2.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-2a885ceb39
zchunk-1.1.2-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.
I have some information about not having zchunk installed namely that it also failed with the error message in the original bug report (about not being able to synchronise): # rpm -q zchunk package zchunk is not installed After adding zchunk = False to dnf.conf it seems to works fine (I found after doing a clean all some time later it would fail to synchronise again. Every time - so I don't want to say it's 'worked around'[which is what it would be] permanently). So.. it seems that zchunk option has an effect even when it's not installed which to me as a programmer reminds me of accessing invalid memory (but I am by no means likening the two) or trying to load a .so object that's missing but not reporting that and just 'failing' with a general message (but again I am not likening the two). I haven't tested installing zchunk nor do I have any reason to (I have too much going on to care as long as this works but I still think it worth reporting here).
Reopening this issue as I've seen it happen again this morning on multiple machines. # dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache timer: config: 2 ms DNF version: 4.2.5 Command: dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache Installroot: / Releasever: 30 cachedir: /var/cache/dnf Base command: makecache Extra commands: ['-d10', '--noplugins', '--disablerepo=*', '--enablerepo=updates', 'makecache'] Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Unknown configuration value: failovermethod=priority in /etc/yum.repos.d/fedora-updates-modular.repo; Configuration: OptionBinding with id "failovermethod" does not exist Excludes in dnf.conf: kernel-debug-devel Making cache files for all metadata files. updates: has expired and will be refreshed. Fedora 30 - x86_64 - Updates 68 kB/s | 7.6 kB 00:00 reviving: failed for 'updates', mismatched repomd. repo: downloading from remote: updates Fedora 30 - x86_64 - Updates 798 kB/s | 569 kB 00:00 Cannot download 'http://dl.fedoraproject.org/pub/fedora/linux/updates/30/Everything/x86_64/': Yum repo downloading error: Downloading error(s): repodata/6b3c8e65b37887f0a1da433a246896aee069670dbeab3d713d5961a0a788a0df-prestodelta.xml.zck - Not finished; repodata/4bb872046641b34f99b90fe335f8c8c824f6472bb2544fbf807ccbf35bb23f2d-updateinfo.xml.xz - Not finished. Failed to synchronize cache for repo 'updates' Cleaning up. Error: Failed to synchronize cache for repo 'updates' [1] 911068 exit 1 noglob dnf -d10 --noplugins --disablerepo=* --enablerepo=updates makecache # rpm -q dnf libdnf librepo zchunk-libs dnf-4.2.5-1.fc30.noarch libdnf-0.31.0-3.fc30.x86_64 librepo-1.10.2-1.fc30.x86_64 zchunk-libs-1.1.2-2.fc30.x86_64 # sed -re 's!^(proxy[^=]*=).*!\1XXXXX!' -e 's!#.*!!' -e '/^[[:space:]]*$/d' /etc/dnf/dnf.conf [main] gpgcheck=1 installonly_limit=3 clean_requirements_on_remove=True proxy=XXXXX proxy_username=XXXXX proxy_password=XXXXX deltarpm=0 max_parallel_downloads=1 excludepkgs=kernel-debug-devel # tail /var/log/dnf.librepo.log 05-23 10:51 2019-05-23T17:45:51Z DEBUG find_local_zck_header: Cache directory: /var/cache/dnf 2019-05-23T17:45:51Z DEBUG find_local_zck_header: Found file with same header at /var/cache/dnf/fedora-2339a4ec9d07b27f/repodata/62bac009b415e09f578d9427a630d0b0f4f3ad4d28dc60bf4eb581c72240640e-comps-Everything.x86_64.xml.zck 2019-05-23T17:45:51Z DEBUG Checking checksum: 4: 62d42a3c754a25e2c5ad0456bcb7907c6823c4e684ac184819b0d20472706f7d 2019-05-23T17:45:51Z DEBUG lr_zck_init_read: Found matching header in /var/cache/dnf/fedora-2339a4ec9d07b27f/repodata/62bac009b415e09f578d9427a630d0b0f4f3ad4d28dc60bf4eb581c72240640e-comps-Everything.x86_64.xml.zck 2019-05-23T17:45:51Z DEBUG check_zck: Checking zchunk data checksum: repodata/62bac009b415e09f578d9427a630d0b0f4f3ad4d28dc60bf4eb581c72240640e-comps-Everything.x86_64.xml.zck 2019-05-23T17:45:51Z DEBUG check_zck: File is complete 2019-05-23T17:45:51Z DEBUG prepare_next_transfer: Target already fully downloaded: repodata/62bac009b415e09f578d9427a630d0b0f4f3ad4d28dc60bf4eb581c72240640e-comps-Everything.x86_64.xml.zck 2019-05-23T17:45:51Z DEBUG lr_yum_download_remote: Repository download error: Downloading error(s): repodata/6b3c8e65b37887f0a1da433a246896aee069670dbeab3d713d5961a0a788a0df-prestodelta.xml.zck - Not finished; repodata/4bb872046641b34f99b90fe335f8c8c824f6472bb2544fbf807ccbf35bb23f2d-updateinfo.xml.xz - Not finished 2019-05-23T17:45:51Z DEBUG lr_handle_perform: Restoring an old SIGINT handler This looks like I have all the fixes discussed earlier on: updated librepo and zchunk-libs. Should I dig back into gdb, or am I missing a piece of the puzzle?
Unfortunately, librepo-1.10.2 doesn't have the fix for this. We have to wait until the next librepo comes out, so yes, let's leave this open.
(In reply to Cody from comment #50) > I have some information about not having zchunk installed namely that it > also failed with the error message in the original bug report (about not > being able to synchronise): > > # rpm -q zchunk > package zchunk is not installed > > After adding zchunk = False to dnf.conf it seems to works fine (I found > after doing a clean all some time later it would fail to synchronise again. > Every time - so I don't want to say it's 'worked around'[which is what it > would be] permanently). So.. it seems that zchunk option has an effect even > when it's not installed which to me as a programmer reminds me of accessing > invalid memory (but I am by no means likening the two) or trying to load a > .so object that's missing but not reporting that and just 'failing' with a > general message (but again I am not likening the two). I haven't tested > installing zchunk nor do I have any reason to (I have too much going on to > care as long as this works but I still think it worth reporting here). I'm pretty sure you do have zchunk-libs installed. If you didn't, dnf wouldn't even start. This is a separate problem (see my previous comment).
librepo-1.10.2-2.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-b74be9c74d
librepo-1.10.2-2.fc30 has been pushed to the Fedora 30 testing repository. If problems still persist, please make note of it in this bug report. See https://fedoraproject.org/wiki/QA:Updates_Testing for instructions on how to install test updates. You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2019-b74be9c74d
librepo-1.10.2-2.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.
I'm seeing this in Fedora 33. I have "proxy=localhost:8118" in my dnf.conf and I'm using Privoxy 3.0.29 [avatar@localhost ~]$ sudo dnf update [sudo] password for avatar: Fedora Modular 33 - x86_64 - Updates 1.0 kB/s | 7.0 kB 00:06 Fedora 33 - x86_64 - Updates 6.9 kB/s | 4.9 kB 00:00 Fedora 33 - x86_64 - Updates 156 kB/s | 602 kB 00:03 Errors during downloading metadata for repository 'updates': - Zchunk error: Unable to find multipart download range Error: Failed to download metadata for repo 'updates': Yum repo downloading error: Downloading error: Unable to initialize zchunk file repodata/c135b25f5228fcc5f8a0bfd23584d376a1162ff7ded02a0e6307471407d776e1-primary.xml.zck: Unable to set zchunk file descriptor for repodata/c135b25f5228fcc5f8a0bfd23584d376a1162ff7ded02a0e6307471407d776e1-primary.xml.zck: Unable to find multipart download range [avatar@localhost ~]$ while [ $? -ne 0 ]; do sudo dnf update -y; done Fedora 33 - x86_64 - Updates 2.0 kB/s | 4.9 kB 00:02 Fedora 33 - x86_64 - Updates 192 kB/s | 602 kB 00:03 Errors during downloading metadata for repository 'updates': - Zchunk error: Unable to find multipart download range Error: Failed to download metadata for repo 'updates': Yum repo downloading error: Downloading error: Unable to initialize zchunk file repodata/fae0afacf4f7073a109db13d8eec0748fe81de6b956141e52699bd4ba87a08eb-filelists.xml.zck: Unable to set zchunk file descriptor for repodata/fae0afacf4f7073a109db13d8eec0748fe81de6b956141e52699bd4ba87a08eb-filelists.xml.zck: Unable to find multipart download range Fedora 33 - x86_64 - Updates 1.0 kB/s | 4.9 kB 00:04 Fedora 33 - x86_64 - Updates 127 kB/s | 2.2 MB 00:18 insync repo 465 B/s | 2.9 kB 00:06 Dependencies resolved. ============================================================================================================================================================================================== Package Architecture Version Repository Size ============================================================================================================================================================================================== Upgrading: kexec-tools x86_64 2.0.21-4.fc33 updates 472 k net-snmp-libs x86_64 1:5.9-4.fc33 updates 752 k pipewire i686 0.3.20-1.fc33 updates 121 k pipewire x86_64 0.3.20-1.fc33 updates 121 k pipewire-alsa i686 0.3.20-1.fc33 updates 52 k pipewire-alsa x86_64 0.3.20-1.fc33 updates 52 k pipewire-gstreamer x86_64 0.3.20-1.fc33 updates 52 k pipewire-libs i686 0.3.20-1.fc33 updates 962 k pipewire-libs x86_64 0.3.20-1.fc33 updates 965 k python3-pyOpenSSL noarch 20.0.1-1.fc33 updates 89 k wget x86_64 1.21.1-1.fc33 updates 819 k Installing dependencies: bluez-libs i686 5.55-1.fc33 fedora 91 k Transaction Summary ============================================================================================================================================================================================== Install 1 Package Upgrade 11 Packages Total download size: 4.4 M Downloading Packages: 172% [=============================================================================================================(1/12): pipewire-alsa-0.3.19-3.fc33_0.3.20-1.fc33.i686.drpm 92 kB/s | 29 kB 00:00 (2/12): pipewire-alsa-0.3.19-3.fc33_0.3.20-1.fc33.x86_64.drpm 87 kB/s | 28 kB
I am experiencing the same problem on a Fedora 33 system behind a network proxy. zchunk must be disabled in dnf.conf for me to be able to retrieve repository metadata, running `dnf clean all` has no effect.
For those still seeing problems with specific proxies, please open a new bug report and include the name and configuration files for the proxy server so I can debug the issue.