Bug 14467

Summary: curl timeout while dnf is downloading package
Product: [QA/Testing] Runtime Testing Reporter: Alexandre Belloni <alexandre.belloni>
Component: oeqa/runtimeAssignee: Sakib Sajal <sakib.sajal>
Status: RESOLVED WORKSFORME QA Contact:
Severity: normal    
Priority: Medium+ CC: alexandre.belloni, chee.yang.lee, oobitots, randy.macleod, tvgamblin
Version: unspecified   
Target Milestone: 4.2 M2   
Hardware: x86   
OS: Multiple   
Whiteboard: AB-INT AB-INT-NET
OS type for building Yocto: --- Type of Regression: ---
Verified: Documentation change: No (bug/feature does not impact docs)

Description Alexandre Belloni 2021-07-03 09:04:38 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/61/builds/3489/steps/12/logs/stdio


INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.5:40585/core2_32/libc6-dbg-2.33-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.5:40585/core2_32/libc6-dbg-2.33-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]

pkgman-rpm-non-rpm ubuntu1804-ty-2


https://autobuilder.yoctoproject.org/typhoon/#/builders/53/builds/3631/steps/13/logs/stdio

NFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:36663/armv7vet2hf_neon/curl-dbg-7.77.0-r0.armv7vet2hf_neon.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:36663/armv7vet2hf_neon/curl-dbg-7.77.0-r0.armv7vet2hf_neon.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:36663/armv7vet2hf_neon/curl-dev-7.77.0-r0.armv7vet2hf_neon.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:36663/armv7vet2hf_neon/curl-dev-7.77.0-r0.armv7vet2hf_neon.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]


qemuarm ubuntu1804-ty-2
Comment 2 Alexandre Belloni 2021-08-11 20:22:56 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/61/builds/3767/steps/12/logs/stdio

pkgman-rpm-non-rpm ubuntu1804-ty-3

2021-08-04T18:48:50+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:46327/core2_32/curl-dbg-7.78.0-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-08-04T18:48:50+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:46327/core2_32/curl-dbg-7.78.0-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-08-04T18:48:50+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:46327/core2_32/curl-src-7.78.0-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-08-04T18:48:50+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:46327/core2_32/curl-src-7.78.0-r0.core2_32.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
Comment 3 Alexandre Belloni 2021-09-10 19:30:07 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/109/builds/2888

2021-09-10T07:56:34+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:42027/core2_64/busybox-1.34.0-r0.core2_64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-09-10T07:56:34+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:42027/core2_64/busybox-1.34.0-r0.core2_64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-09-10T07:56:34+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:42027/core2_64/libc6-2.34-r0.core2_64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-09-10T07:56:34+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:42027/core2_64/libc6-2.34-r0.core2_64.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-09-10T07:56:34+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:42027/noarch/run-postinsts-1.0-r10.noarch.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-09-10T07:56:34+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:42027/noarch/run-postinsts-1.0-r10.noarch.rpm [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]

qemux86-64-alt ubuntu1804-ty-1
Comment 4 Alexandre Belloni 2021-09-16 10:07:19 UTC 
2021-08-20T01:40:37+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.3:36759/qemumips64/repodata/repomd.xml [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2021-08-20T01:40:37+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.3:36759/qemumips64/repodata/repomd.xml [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]


https://autobuilder.yoctoproject.org/typhoon/#/builders/74/builds/3834/steps/13/logs/stdio
qemumips64 centos8-ty-1
Comment 6 Randy MacLeod 2021-12-21 00:40:18 UTC 
Hasn't been seen in a while so bumping to M3.
Comment 7 Oleksiy Obitotskyy 2022-02-20 17:12:50 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/72/builds/4779/steps/15/logs/stdio

qa-extras2 debian11-ty-3 

Traceback (most recent call last):
  File "/home/pokybuild/yocto-worker/qa-extras2/build/meta/lib/oeqa/core/decorator/__init__.py", line 36, in wrapped_f
    return func(*args, **kwargs)
  File "/home/pokybuild/yocto-worker/qa-extras2/build/meta/lib/oeqa/runtime/cases/parselogs.py", line 387, in test_parselogs
    self.assertEqual(errcount, 0, msg=self.msg)
AssertionError: 3 != 0 : Log: /home/pokybuild/yocto-worker/qa-extras2/build/build/tmp/work/qemux86_64-poky-linux/core-image-sato/1.0-r0/target_logs/dnf.librepo.log
-----------------------
Central error: 2022-02-20T01:12:26+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
***********************
2022-02-20T01:11:54+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:54+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:55+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:55+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:56+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:56+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:11:56+0000 INFO Downloading: http://192.168.7.1:37321/noarch/repodata/repomd.xml
2022-02-20T01:11:56+0000 INFO Downloading: http://192.168.7.1:37321/noarch/repodata/657663bf3dfcd7af9397bdf0ee6929e6a3f6d1e7e36775581706ef525a8ce8dd-primary.xml.gz
2022-02-20T01:11:56+0000 INFO Downloading: http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz
2022-02-20T01:12:26+0000 INFO Serious error - Curl code (28): Timeout was reached for http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2022-02-20T01:12:26+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/core2_64/repodata/repomd.xml
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/core2_64/repodata/f5cf312130f82f5facf351771301476a2a75203ea8f321d79e583c1c4a38338f-primary.xml.gz
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/core2_64/repodata/f8e9b103898c2be4147b1e7384fe5ea49231329bedcecd534ced27e722b8de8b-filelists.xml.gz
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/qemux86_64/repodata/repomd.xml
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/qemux86_64/repodata/1cb61ea996355add02b1426ed4c1780ea75ce0c04c5d1107c025c3fbd7d8bcae-primary.xml.gz
2022-02-20T01:12:26+0000 INFO Downloading: http://192.168.7.1:37321/qemux86_64/repodata/95a4415d859d7120efb6b3cf964c07bebbff9a5275ca673e6e74a97bcbfb2a5f-filelists.xml.gz
2022-02-20T01:12:26+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)
2022-02-20T01:12:26+0000 INFO Librepo version: 1.14.2 with CURL_GLOBAL_ACK_EINTR support (libcurl/7.81.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.2)

***********************
Central error: 2022-02-20T01:12:26+0000 INFO Error during transfer: Curl error (28): Timeout was reached for http://192.168.7.1:37321/noarch/repodata/1c496a9431d8faf9a4f2e388d2b8736b9ebd157cddf26ec3125233c2768d5c86-filelists.xml.gz [Operation too slow. Less than 1000 bytes/sec transferred the last 30 seconds]
Comment 8 Randy MacLeod 2022-07-14 14:46:11 UTC 
Lots has changed since this was filed (network, ssd) and it hasn't happened recently.
Comment 11 Randy MacLeod 2022-08-18 15:04:12 UTC 
Could the http server be assigned to the wrong network interface?
Comment 12 Alexandre Belloni 2022-08-18 19:23:32 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/131/builds/1031/steps/13/logs/stdio

That one could not even connect:
2022-08-07T01:46:16+0000 INFO Added oe-testimage-repo-qemuarm64 repo from http://192.168.7.1:46293/qemuarm64
2022-08-07T01:46:16+0000 DEBUG User-Agent: falling back to 'libdnf': could not detect OS or basearch
2022-08-07T01:46:16+0000 DEBUG repo: downloading from remote: oe-testimage-repo-noarch
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 11 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:17+0000 WARNING Errors during downloading metadata for repository 'oe-testimage-repo-noarch':
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 11 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host]
2022-08-07T01:46:17+0000 WARNING Error: Failed to download metadata for repo 'oe-testimage-repo-noarch': Cannot download repomd.xml: Cannot download repodata/repomd.xml: All mirrors were tried
2022-08-07T01:46:17+0000 DEBUG repo: downloading from remote: oe-testimage-repo-cortexa57
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:17+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:18+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1204 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:19+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1205 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:19+0000 WARNING Errors during downloading metadata for repository 'oe-testimage-repo-cortexa57':
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1205 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1204 ms: No route to host]
--
2022-08-07T01:46:29+0000 INFO Added oe-testimage-repo-qemuarm64 repo from http://192.168.7.1:46293/qemuarm64
2022-08-07T01:46:29+0000 DEBUG User-Agent: falling back to 'libdnf': could not detect OS or basearch
2022-08-07T01:46:31+0000 DEBUG repo: downloading from remote: oe-testimage-repo-noarch
2022-08-07T01:46:31+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 9 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:31+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:31+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:31+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host] (http://192.168.7.1:46293/noarch/repodata/repomd.xml).
2022-08-07T01:46:31+0000 WARNING Errors during downloading metadata for repository 'oe-testimage-repo-noarch':
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 9 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/noarch/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host]
2022-08-07T01:46:31+0000 WARNING Error: Failed to download metadata for repo 'oe-testimage-repo-noarch': Cannot download repomd.xml: Cannot download repodata/repomd.xml: All mirrors were tried
2022-08-07T01:46:31+0000 DEBUG repo: downloading from remote: oe-testimage-repo-cortexa57
2022-08-07T01:46:32+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1203 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:32+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:33+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1203 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:34+0000 DEBUG error: Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1205 ms: No route to host] (http://192.168.7.1:46293/cortexa57/repodata/repomd.xml).
2022-08-07T01:46:34+0000 WARNING Errors during downloading metadata for repository 'oe-testimage-repo-cortexa57':
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1205 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 1203 ms: No route to host]
  - Curl error (7): Couldn't connect to server for http://192.168.7.1:46293/cortexa57/repodata/repomd.xml [Failed to connect to 192.168.7.1 port 46293 after 2 ms: No route to host]
Comment 13 Alexandre Belloni 2022-10-27 14:50:51 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/59/builds/5999/steps/13/logs/stdio

qemux86 opensuse154-ty-1
Comment 14 Alexandre Belloni 2022-12-07 16:32:42 UTC 
https://autobuilder.yoctoproject.org/typhoon/#/builders/57/builds/6162/steps/15/logs/stdio

qemux86-64-x32 opensuse154-ty-1
Comment 15 Randy MacLeod 2023-02-09 15:54:29 UTC 
A rare problem. We've added more logging around the http server so if it happens again, we may be able to learn more.