Downloading packages makes DNF consume 100% of one CPU core, even for a modest download speed of 1.7MBytes/s: (2/2): kernel-debug-debuginfo-5.0.3 1% [ ] 1.7 MB/s | 15 MB 11:24 ETA Top reports: PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 5559 root 20 0 501004 226224 31184 R 100,0 1,9 0:20.93 dnf 944 root -51 0 0 0 0 S 2,0 0,0 0:24.03 irq/127-iwlwifi Download should not be CPU bound, unless having a speedy network connection. I've noticed the issue because the laptop's fan doesn't stop during the whole downloads, which seems to be a new thing, not happening before ... When using perf: Samples: 123K of event 'cycles:ppp', Event count (approx.): 79317414716 Overhead Command Shared Object Symbol 2,83% dnf [kernel.kallsyms] [k] syscall_return_via_sysret 2,79% dnf [kernel.kallsyms] [k] entry_SYSCALL_64 2,39% dnf libpython3.7m.so.1.0 [.] lookdict_unicode_nodummy 1,61% dnf libc-2.29.so [.] __strlen_avx2 1,48% dnf libpython3.7m.so.1.0 [.] lookdict_split 1,45% dnf libpython3.7m.so.1.0 [.] call_function 1,44% dnf libc-2.29.so [.] __vfprintf_internal 1,06% dnf libsolv.so.1 [.] dirpool_add_dir ...
strace output is probably more useful: poll([{fd=35, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=37, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=35, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=37, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=35, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=37, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 poll([{fd=35, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout) rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, 8) = 0 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[], sa_flags=SA_RESTORER, sa_restorer=0x7f221fca3180}, NULL, 8) = 0 It seems dnf is busylooping on the sockets (fd 35 and and fd 37) connected to the HTTP servers where the files are downloaded. There's a bug somewhere.
gdb: Breakpoint 1, __GI___poll (fds=fds@entry=0x7ffcfc020190, nfds=nfds@entry=1, timeout=timeout@entry=0) at ../sysdeps/unix/sysv/linux/poll.c:27 27 { (gdb) bt #0 0x00007f46a4a0f7f0 in __GI___poll (fds=fds@entry=0x7ffcfc020190, nfds=nfds@entry=1, timeout=timeout@entry=0) at ../sysdeps/unix/sysv/linux/poll.c:27 #1 0x00007f46a4a2b0e2 in __poll_chk (fds=fds@entry=0x7ffcfc020190, nfds=nfds@entry=1, timeout=timeout@entry=0, fdslen=fdslen@entry=24) at poll_chk.c:27 #2 0x00007f469c260d96 in poll (__timeout=0, __nfds=<optimized out>, __fds=0x7ffcfc020190) at /usr/include/bits/poll2.h:41 #3 0x00007f469c260d96 in Curl_socket_check (readfd0=37, readfd1=readfd1@entry=-1, writefd=-1, timeout_ms=timeout_ms@entry=0) at ../../lib/select.c:217 #4 0x00007f469c2522c4 in Curl_readwrite (conn=0x5575f846c4b0, data=data@entry=0x5575f6aabc30, done=done@entry=0x7ffcfc0202aa, comeback=comeback@entry=0x7ffcfc0202ab) at ../../lib/transfer.c:1281 #5 0x00007f469c25bf8c in multi_runsingle (multi=0x5575f6154c70, now=..., data=0x5575f6aabc30) at ../../lib/multi.c:1932 #6 0x00007f469c25d4d1 in curl_multi_perform (multi=0x5575f6154c70, running_handles=running_handles@entry=0x7ffcfc020428) at ../../lib/multi.c:2217 #7 0x00007f469cb2cede in lr_perform (err=0x7ffcfc020430, dd=0x7ffcfc020450) at /usr/src/debug/librepo-1.9.5-1.fc30.x86_64/librepo/downloader.c:2505 #8 0x00007f469cb2cede in lr_download (targets=targets@entry=0x5575f34e9260 = {...}, failfast=failfast@entry=1, err=err@entry=0x7ffcfc020828) at /usr/src/debug/librepo-1.9.5-1.fc30.x86_64/librepo/downloader.c:2620 #9 0x00007f469cb35eae in lr_download_packages (targets=targets@entry=0x5575f33c3a30 = {...}, flags=flags@entry=LR_PACKAGEDOWNLOAD_FAILFAST, err=err@entry=0x7ffcfc020828) at /usr/src/debug/librepo-1.9.5-1.fc30.x86_64/librepo/package_downloader.c:416 #10 0x00007f469cc82eaa in libdnf::PackageTarget::downloadPackages(std::vector<libdnf::PackageTarget*, std::allocator<libdnf::PackageTarget*> >&, bool) (targets=std::vector of length 2, capacity 2 = {...}, failFast=<optimized out>) at /usr/src/debug/libdnf-0.28.0-1.fc30.x86_64/libdnf/repo/Repo.cpp:1668 ... (gdb) frame 3 #3 Curl_socket_check (readfd0=37, readfd1=readfd1@entry=-1, writefd=-1, timeout_ms=timeout_ms@entry=0) at ../../lib/select.c:217 217 r = poll(pfd, num, pending_ms); (gdb) frame 4 #4 0x00007f469c2522c4 in Curl_readwrite (conn=0x5575f846c4b0, data=data@entry=0x5575f6aabc30, done=done@entry=0x7ffcfc0202aa, comeback=comeback@entry=0x7ffcfc0202ab) at ../../lib/transfer.c:1281 1281 select_res = Curl_socket_check(fd_read, CURL_SOCKET_BAD, fd_write, 0);
It's likely an issue with librepo: # rpm -q --changelog librepo * lun. mars 11 2019 Pavla Kratochvilova <pkratoch> - 1.9.5-1 - Update to 1.9.5 - Reduce download delays
(In reply to Yann Droneaud from comment #3) > It's likely an issue with librepo: > > # rpm -q --changelog librepo > * lun. mars 11 2019 Pavla Kratochvilova <pkratoch> - 1.9.5-1 > - Update to 1.9.5 > - Reduce download delays It's there, and I've proposed a fix as https://github.com/rpm-software-management/librepo/pull/144 Once rebuilt with this patch, the CPU consumption is down to less than 20%, which is more acceptable.
Affecting F29 too https://bodhi.fedoraproject.org/updates/FEDORA-2019-a03be2cebe https://bodhi.fedoraproject.org/updates/FEDORA-2019-bc9607a8dc
The PR https://github.com/rpm-software-management/librepo/pull/144 from Yann Droneaud fixes it.
dnf-4.2.2-1.fc30 librepo-1.9.6-1.fc30 libdnf-0.28.1-1.fc30 has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-b504d6ad8f
dnf-4.2.2-1.fc29 librepo-1.9.6-1.fc29 libdnf-0.28.1-1.fc29 has been submitted as an update to Fedora 29. https://bodhi.fedoraproject.org/updates/FEDORA-2019-7fbfa37585
dnf-4.2.2-1.fc30, libdnf-0.28.1-1.fc30, librepo-1.9.6-1.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-b504d6ad8f
dnf-4.2.2-1.fc29, libdnf-0.28.1-1.fc29, librepo-1.9.6-1.fc29 has been pushed to the Fedora 29 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-7fbfa37585
*** Bug 1692423 has been marked as a duplicate of this bug. ***
dnf-4.2.2-1.fc30, libdnf-0.28.1-1.fc30, librepo-1.9.6-1.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.
dnf-4.2.2-1.fc29, libdnf-0.28.1-1.fc29, librepo-1.9.6-1.fc29 has been pushed to the Fedora 29 stable repository. If problems still persist, please make note of it in this bug report.