Bug#1141371: curl: autopkgtests fail on ppc64el: tests/http/test_06_eyeballs.py:136: AssertionError
Colin Watson <[email protected]> Fri, 3 Jul 2026 15:32:02 +0100
| Newsgroups | gmane.linux.debian.ports.powerpc |
|---|---|
| Message-ID | <akfH4nszUlVtRTXJ__44260.7485501625$1783091771$gmane$org@camorr.rosewood.vpn.ucam.org> |
Source: curl Version: 8.21.0-2 Severity: serious X-Debbugs-Cc: [email protected] User: [email protected] Usertags: ppc64el https://ci.debian.net/packages/c/curl/testing/ppc64el/ shows that the=20 latest version of curl consistently fails its autopkgtests on ppc64el,=20 when the version currently in testing passed. The test log seems to=20 pretty consistently look like this: =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D FAILURES =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D ________________________ TestEyeballs.test_06_13_timers ___________________= _____ self =3D <test_06_eyeballs.TestEyeballs object at 0x3fffad08c350> env =3D <testenv.env.Env object at 0x3fffad246d50> @pytest.mark.skipif(condition=3Dnot Env.curl_has_feature('IPv6'), reason=3D'curl lacks ipv6 support') @pytest.mark.skipif(condition=3Dnot Env.curl_has_feature('AsynchDNS'), reason=3D'curl lacks async DNS support') @pytest.mark.skipif(condition=3Dnot Env.curl_is_verbose(), reason=3D"ne= eds curl verbose strings") def test_06_13_timers(self, env: Env): curl =3D CurlClient(env=3Denv) # ipv6 0100::/64 is supposed to go into the void (rfc6666) r =3D curl.http_download(urls=3D['https://xxx.invalid/'], extra_arg= s=3D[ '--resolve', 'xxx.invalid:443:0100::1,0100::2,0100::3', '--connect-timeout', '1', '--happy-eyeballs-timeout-ms', '123', '--trace-config', 'timer,happy-eyeballs,tcp' ]) r.check_response(count=3D1, http_status=3DNone, exitcode=3DFalse) assert r.stats[0]['time_connect'] =3D=3D 0 # no one connected # check that we indeed started attempts on all 3 addresses tcp_attempts =3D [line for line in r.trace_lines if re.match(r'.*Trying \[100::[123]]:443', line)] assert len(tcp_attempts) =3D=3D 3, f'fond: {"".join(tcp_attempts)}\= n{r.dump_logs()}' # if the 0100::/64 really goes into the void, we should see 2 HAPPY= _EYEBALLS # timeouts being set here failed_attempts =3D [line for line in r.trace_lines if re.match(r'.*checked connect attempts: 0 ongo= ing', line)] if len(failed_attempts): # github CI fails right away with "Network is unreachable", sla= ckers... assert len(failed_attempts) =3D=3D 3, f'found: {"".join(failed_= attempts)}\n{r.dump_logs()}' else: # no immediately failed attempts, as should be he_timers_set =3D [line for line in r.trace_lines if re.match(r'.*\[TIMER] \[HAPPY_EYEBALLS] set= for', line)] > assert len(he_timers_set) =3D=3D 2, f'found: {"".join(he_timers= _set)}\n{r.dump_logs()}' E AssertionError: found: 11:35:58.211780 [0-0] * [TIMER] [HAPPY_E= YEBALLS] set for 123000ns E 11:35:58.336539 [0-0] * [TIMER] [HAPPY_EYEBALLS] set for 1229= 99ns E 11:35:58.337195 [0-0] * [TIMER] [HAPPY_EYEBALLS] set for 1230= 00ns E E >>--stdout ---------------------------------------------- E {"certs":"","conn_id":0,"content_type":null,"errormsg":"Conne= ction timed out after 1001 milliseconds","exitcode":28,"filename_effective"= :"download_#1.data","ftp_entry_path":null,"http_code":0,"http_connect":0,"h= ttp_version":"0","local_ip":"","local_port":-1,"method":"GET","num_certs":0= ,"num_connects":0,"num_headers":0,"num_redirects":0,"num_retries":0,"proxy_= ssl_verify_result":0,"proxy_used":0,"redirect_url":null,"referer":null,"rem= ote_ip":"","remote_port":-1,"response_code":0,"scheme":"https","size_delive= red":0,"size_download":0,"size_header":0,"size_request":0,"size_upload":0,"= speed_download":0,"speed_upload":0,"ssl_verify_result":0,"time_appconnect":= 0.000000,"time_connect":0.000000,"time_namelookup":0.000069,"time_posttrans= fer":1.001221,"time_pretransfer":1.001220,"time_queue":0.000042,"time_redir= ect":0.000000,"time_starttransfer":1.001221,"time_total":1.001224,"tls_earl= ydata":0,"url":"https://xxx.invalid/","url.fragment":null,"url.host":"xxx.i= nvalid","url.options":null,"url.password":null,"url.path":"/","url.port":"4= 43","url.query":null,"url.scheme":"https","url.user":null,"url.zoneid":null= ,"url_effective":"https://xxx.invalid/","urle.fragment":null,"urle.host":"x= xx.invalid","urle.options":null,"urle.password":null,"urle.path":"/","urle.= port":"443","urle.query":null,"urle.scheme":"https","urle.user":null,"urle.= zoneid":null,"urlnum":0,"xfer_id":0,"curl_version":"libcurl/8.21.0 GnuTLS/3= =2E8.13 zlib/1.3.2 brotli/1.2.0 zstd/1.5.7 libidn2/2.3.8 libpsl/0.22.0 libs= sh2/1.11.1 nghttp2/1.69.0 ngtcp2/1.22.1 nghttp3/1.15.0 mit-krb5/1.22.1 Open= LDAP/2.6.10"} E >>--stderr ---------------------------------------------- E 11:35:58.211166 [0-x] * Added xxx.invalid:443:0100::1,0100::2= ,0100::3 to DNS cache E 11:35:58.211227 [0-x] * [TIMER] [CONNECTTIMEOUT] set for 1000= 000ns E 11:35:58.211277 [0-0] * Hostname xxx.invalid was found in DNS= cache E 11:35:58.211295 [0-0] * Host xxx.invalid:443 was resolved. E 11:35:58.211317 [0-0] * IPv6: 100::1, 100::2, 100::3 E 11:35:58.211334 [0-0] * IPv4: (none) E 11:35:58.211354 [0-0] * [HAPPY-EYEBALLS] init ip ballers for = transport 3 E 11:35:58.211372 [0-0] * [HAPPY-EYEBALLS] want to do more E 11:35:58.211390 [0-0] * [HAPPY-EYEBALLS] check for next AAAA = address: found E 11:35:58.211409 [0-0] * [HAPPY-EYEBALLS] starting first attem= pt for ipv6 -> 0 E 11:35:58.211433 [0-0] * Trying [100::1]:443... E 11:35:58.211458 [0-0] * [TCP] cf_socket_open() -> 0, fd=3D4 E 11:35:58.211725 [0-0] * [TCP] local address fc42:5009:ba4b:5a= b0:b7b2:9e1a:c428:9a6c port 37694... E 11:35:58.211744 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 1 ongoing, 0 inconclusive E 11:35:58.211762 [0-0] * [HAPPY-EYEBALLS] next HAPPY_EYEBALLS = timeout in 123ms E 11:35:58.211780 [0-0] * [TIMER] [HAPPY_EYEBALLS] set for 1230= 00ns E 11:35:58.211802 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D4 E 11:35:58.211819 [0-0] * [HAPPY-EYEBALLS] adjust_pollset -> 0,= 1 socks E 11:35:58.211837 [0-0] * [TIMER] [HAPPY_EYEBALLS] gives multi = timeout in 124ms E 11:35:58.336065 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.336105 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 1 ongoing, 0 inconclusive E 11:35:58.336125 [0-0] * [HAPPY-EYEBALLS] happy eyeballs timeo= ut expired, start next attempt E 11:35:58.336142 [0-0] * [HAPPY-EYEBALLS] want to do more E 11:35:58.336159 [0-0] * [HAPPY-EYEBALLS] check for next AAAA = address: found E 11:35:58.336183 [0-0] * [HAPPY-EYEBALLS] starting next attemp= t for ipv6 -> 0 E 11:35:58.336201 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.336255 [0-0] * Trying [100::2]:443... E 11:35:58.336282 [0-0] * [TCP] cf_socket_open() -> 0, fd=3D5 E 11:35:58.336483 [0-0] * [TCP] local address fc42:5009:ba4b:5a= b0:b7b2:9e1a:c428:9a6c port 43470... E 11:35:58.336502 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 2 ongoing, 0 inconclusive E 11:35:58.336521 [0-0] * [HAPPY-EYEBALLS] next HAPPY_EYEBALLS = timeout in 123ms E 11:35:58.336539 [0-0] * [TIMER] [HAPPY_EYEBALLS] set for 1229= 99ns E 11:35:58.336564 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D4 E 11:35:58.336582 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D5 E 11:35:58.336599 [0-0] * [HAPPY-EYEBALLS] adjust_pollset -> 0,= 2 socks E 11:35:58.336617 [0-0] * [TIMER] [HAPPY_EYEBALLS] gives multi = timeout in 123ms E 11:35:58.337023 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.337044 [0-0] * [TCP] poll/select error on fd=3D5 E 11:35:58.337124 [0-0] * connect to 100::2 port 443 from fc42:= 5009:ba4b:5ab0:b7b2:9e1a:c428:9a6c port 43470 failed: Network is unreachable E 11:35:58.337142 [0-0] * [TCP] destroy E 11:35:58.337160 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 1 ongoing, 0 inconclusive E 11:35:58.337178 [0-0] * [HAPPY-EYEBALLS] next HAPPY_EYEBALLS = timeout in 123ms E 11:35:58.337195 [0-0] * [TIMER] [HAPPY_EYEBALLS] set for 1230= 00ns E 11:35:58.337214 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D4 E 11:35:58.337232 [0-0] * [HAPPY-EYEBALLS] adjust_pollset -> 0,= 1 socks E 11:35:58.337250 [0-0] * [TIMER] [HAPPY_EYEBALLS] gives multi = timeout in 123ms E 11:35:58.460468 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.460510 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 1 ongoing, 0 inconclusive E 11:35:58.460529 [0-0] * [HAPPY-EYEBALLS] happy eyeballs timeo= ut expired, start next attempt E 11:35:58.460546 [0-0] * [HAPPY-EYEBALLS] want to do more E 11:35:58.460564 [0-0] * [HAPPY-EYEBALLS] check for next AAAA = address: found E 11:35:58.460586 [0-0] * [HAPPY-EYEBALLS] starting next attemp= t for ipv6 -> 0 E 11:35:58.460605 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.460651 [0-0] * Trying [100::3]:443... E 11:35:58.460679 [0-0] * [TCP] cf_socket_open() -> 0, fd=3D5 E 11:35:58.460911 [0-0] * [TCP] local address fc42:5009:ba4b:5a= b0:b7b2:9e1a:c428:9a6c port 48088... E 11:35:58.460930 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 2 ongoing, 0 inconclusive E 11:35:58.460977 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D4 E 11:35:58.460995 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D5 E 11:35:58.461013 [0-0] * [HAPPY-EYEBALLS] adjust_pollset -> 0,= 2 socks E 11:35:58.461033 [0-0] * [TIMER] [CONNECTTIMEOUT] gives multi = timeout in 751ms E 11:35:58.461271 [0-0] * [TCP] not connected yet on fd=3D4 E 11:35:58.461290 [0-0] * [TCP] poll/select error on fd=3D5 E 11:35:58.461343 [0-0] * connect to 100::3 port 443 from fc42:= 5009:ba4b:5ab0:b7b2:9e1a:c428:9a6c port 48088 failed: Network is unreachable E 11:35:58.461361 [0-0] * [TCP] destroy E 11:35:58.461378 [0-0] * [HAPPY-EYEBALLS] checked connect atte= mpts: 1 ongoing, 0 inconclusive E 11:35:58.461398 [0-0] * [TCP] adjust_pollset, !connected, POL= LOUT fd=3D4 E 11:35:58.461416 [0-0] * [HAPPY-EYEBALLS] adjust_pollset -> 0,= 1 socks E 11:35:58.461434 [0-0] * [TIMER] [CONNECTTIMEOUT] gives multi = timeout in 750ms E 11:35:59.212283 [0-0] * Connection timed out after 1001 milli= seconds E 11:35:59.212354 [0-0] * closing connection #0 E <<------------------------------------------------------- E E assert 3 =3D=3D 2 E + where 3 =3D len(['11:35:58.211780 [0-0] * [TIMER] [HAPPY_EY= EBALLS] set for 123000ns\n', '11:35:58.336539 [0-0] * [TIMER] [HAPPY_EYEBAL= LS] set for 122999ns\n', '11:35:58.337195 [0-0] * [TIMER] [HAPPY_EYEBALLS] = set for 123000ns\n']) tests/http/test_06_eyeballs.py:136: AssertionError Thanks, --=20 Colin Watson (he/him) [[email protected]]