Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

curl 7.87.0 test 0313 [CRL test] failing on EL-9 #10135

Closed
pghmcfc opened this issue Dec 22, 2022 · 7 comments
Closed

curl 7.87.0 test 0313 [CRL test] failing on EL-9 #10135

pghmcfc opened this issue Dec 22, 2022 · 7 comments

Comments

@pghmcfc
Copy link
Contributor

pghmcfc commented Dec 22, 2022

I did this

Updated my curl packaging from 7.86.0 to 7.87.0 and built for current Fedora and RHEL releases (RHEL builds on Rocky Linux, an RHEL clone).

I expected the following

All builds completing successfully. And they did, except for the build on Rocky Linux 9.

curl/libcurl version

7.87.0

[curl -V output]
Don't get as far as a built curl package but here are the system characteristics from the start of the test run:

 ********* System characteristics ******** 
* curl 7.87.0 (x86_64-redhat-linux-gnu)
* libcurl/7.87.0 OpenSSL/3.0.1 zlib/1.2.11 libidn2/2.3.0 nghttp2/1.43.0 
* Features: alt-svc AsynchDNS GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz SPNEGO SSL threadsafe UnixSockets
* Disabled: 
* Host: 329c6f4b6550494fa67371c7360baef3 
* System: Linux 329c6f4b6550494fa67371c7360baef3 6.0.12-300.fc37.x86_64 #1 SMP PREEMPT_DYNAMIC Thu Dec 8 16:58:47 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
* OS: linux
* Servers: SSL HTTP-IPv6 HTTP-unix FTP-IPv6  
* Env: 
* Seed: 264484 
* Unix socket paths:
*   HTTP-Unix:http71383.sock
*   Socks-Unix:/builddir/build/BUILD/curl-7.87.0/build-minimal/tests/socks71383.sock
*****************************************

operating system

I am building on a Fedora 37 (x86_64) host using a chroot-based build system targeting Rocky Linux 9 (x86_64).

Here is the build output from the failing test:

-------e--- OK (312 out of 1544, remaining: 09:00, took 7.351s, duration: 02:16)
RUN: Process with pid 75961 signalled to die
RUN: Process with pid 75977 signalled to die
RUN: Process with pid 75981 signalled to die
RUN: Process with pid 75981 gracefully died
RUN: Process with pid 75961 forced to die with SIGKILL
RUN: Process with pid 75977 forced to die with SIGKILL 
startnew: perl -I../../tests ../../tests/httpserver.pl --pidfile ".http_server.pid" --logfile "log/http_server.log" --portfile .http_server.port --ipv4 --port 0 --srcdir "../../tests/data/.." 
RUN: ../src/curl --max-time 13 --output log/http_verify.out --silent --verbose --globoff "http://127.0.0.1:35713/verifiedserver" 2>log/http_verify.log
CMD (0): ../src/curl --max-time 13 --output log/http_verify.out --silent --verbose --globoff "http://127.0.0.1:35713/verifiedserver" 2>log/http_verify.log
RUN: HTTP server is on PID 76002 port 35713
* pid http => 76002 76002
startnew: perl -I../../tests ../../tests/secureserver.pl --pidfile ".https_server.pid" --logfile "log/https_stunnel.log" --ipv4 --proto https --certfile "Server-localhost-sv.pem" --stunnel "/usr/bin/stunnel" --srcdir "../../tests" --connect 35713 --accept 25073
RUN: HTTPS server is PID 76018 port 25073
* pid https => 76018 76022
prechecked /usr/bin/perl -e "print 'Test requires default test server host' if ( '127.0.0.1' ne '127.0.0.1' );"
test 0313...[CRL test]
../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:25073/313 >log/stdout313 2>log/stderr313
CMD (8960): ../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:25073/313 >log/stdout313 2>log/stderr313
curl returned 35, when expecting 60
 exit FAILED 
== Contents of files in the log/ dir after test 313
=== Start of file commands.log
 ../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:25073/313 >log/stdout313 2>log/stderr313
=== End of file commands.log 
=== Start of file ftpserver.cmd
 Testnum 313
=== End of file ftpserver.cmd
=== Start of file http_server.log
 22:21:17.184802 exit_signal_handler: 15
 22:21:17.185144 signalled to die
 22:21:17.185232 ========> IPv4 sws (port 37921 pid: 75961) exits with signal (15)
 22:21:22.245861 Running HTTP IPv4 version on port 35713
 22:21:22.245946 Wrote pid 76002 to .http_server.pid
 22:21:22.245973 Wrote port 35713 to .http_server.port
 22:21:23.244589 ====> Client connect
 22:21:23.244675 accept_connection 3 returned 4
 22:21:23.244725 accept_connection 3 returned 0
 22:21:23.244766 Read 93 bytes
 22:21:23.244797 Process 93 bytes request
 22:21:23.244845 Got request: GET /verifiedserver HTTP/1.1
 22:21:23.244872 Are-we-friendly question received
 22:21:23.244922 Wrote request (93 bytes) input to log/server.input
 22:21:23.244981 Identifying ourselves as friends
 22:21:23.245205 Response sent (56 bytes) and written to log/server.response
 22:21:23.245244 special request received, no persistency
 22:21:23.245266 ====> Client disconnect 0
=== End of file http_server.log
=== Start of file http_verify.log
 *   Trying 127.0.0.1:35713...
 * Connected to 127.0.0.1 (127.0.0.1) port 35713 (#0)
 > GET /verifiedserver HTTP/1.1
 > Host: 127.0.0.1:35713
 > User-Agent: curl/7.87.0
 > Accept: */*
 >
 * Mark bundle as not supporting multiuse
 < HTTP/1.1 200 OK
 < Content-Length: 17
 <
 { [1 bytes data]
 * Connection #0 to host 127.0.0.1 left intact
=== End of file http_verify.log
=== Start of file http_verify.out
 WE ROOLZ: 76002
=== End of file http_verify.out
=== Start of file https_stunnel.log
 2022.12.21 22:21:23 LOG5[ui]: stunnel 5.62 on x86_64-redhat-linux-gnu platform
 2022.12.21 22:21:23 LOG5[ui]: Compiled/running with OpenSSL 3.0.1 14 Dec 2021
 2022.12.21 22:21:23 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
 2022.12.21 22:21:23 LOG5[ui]: Reading configuration from file /builddir/build/BUILD/curl-7.87.0/build-minimal/tests/https_stunnel.conf
 2022.12.21 22:21:23 LOG5[ui]: UTF-8 byte order mark not detected
 2022.12.21 22:21:23 LOG5[ui]: FIPS mode disabled
 2022.12.21 22:21:23 LOG5[ui]: Configuration successful
 2022.12.21 22:21:23 LOG5[ui]: Binding service [curltest] to :::25073: Address already in use (98)
 2022.12.21 22:21:23 LOG5[cron]: Updating DH parameters
 2022.12.21 22:21:24 LOG5[0]: Service [curltest] accepted connection from 127.0.0.1:47430
 2022.12.21 22:21:24 LOG3[0]: SSL_accept: ssl/record/rec_layer_s3.c:1584: error:0A00041B:SSL routines::tlsv1 alert decrypt error
 2022.12.21 22:21:24 LOG5[0]: Connection reset: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
=== End of file https_stunnel.log
=== Start of file server.response
 HTTP/1.1 200 OK
 Content-Length: 17
 WE ROOLZ: 76002
=== End of file server.response
=== Start of file stderr313
   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                  Dload  Upload   Total   Spent    Left  Speed
 
   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
 curl: (35) OpenSSL/3.0.1: error:03000098:digital envelope routines::invalid digest
=== End of file stderr313
=== Start of file trace313
 22:21:24.309341 == Info:   Trying 127.0.0.1:25073...
 22:21:24.508941 == Info: Connected to localhost (127.0.0.1) port 25073 (#0)
 22:21:24.514959 == Info: ALPN: offers h2
 22:21:24.514984 == Info: ALPN: offers http/1.1
 22:21:24.517003 == Info:  CAfile: ../../tests/certs/EdelCurlRoot-ca.crt
 22:21:24.517026 == Info:  CApath: none
 22:21:24.517228 == Info: successfully loaded CRL file:
 22:21:24.517245 == Info:   CRLfile: ../../tests/certs/Server-localhost-sv.crl
 22:21:24.517786 == Info: [CONN-0-0][CF-SSL] TLSv1.0 (OUT), TLS header, Certificate Status (22):
 22:21:24.517804 => Send SSL data, 5 bytes (0x5)
 0000: .....
 22:21:24.517847 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS handshake, Client hello (1):
 22:21:24.517858 => Send SSL data, 512 bytes (0x200)
 0000: ............F.......J..y............[9 .H=s.#.1p.U.;.c..p..-..5.
 0040: ..OR....>.......,.0.........+./...$.(.k.#.'.g.....9.....3.....=.
 0080: <.5./.....u.........localhost...................................
 00c0: ......h2.http/1.1.........1.....*.(.............................
 0100: ............+............-.....3.&.$... X.3...#..2A.....7.,0....
 0140: :H..d.\q........................................................
 0180: ................................................................
 01c0: ................................................................
 22:21:24.524820 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Certificate Status (22):
22:21:24.524852 <= Recv SSL data, 5 bytes (0x5)
 0000: ....z
 22:21:24.524893 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Server hello (2):
 22:21:24.524905 <= Recv SSL data, 122 bytes (0x7a)
 0000: ...v..sVH..C...is.m30..i"......!....6= .H=s.#.1p.U.;.c..p..-..5.
 0040: ..OR.........+.....3.$... W~..c.kzw70..........Uz..@v.X`SH
 22:21:24.525642 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Finished (20):
 22:21:24.525661 <= Recv SSL data, 5 bytes (0x5)
 0000: .....
 22:21:24.525688 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
 22:21:24.525699 <= Recv SSL data, 5 bytes (0x5)
 0000: .....
 22:21:24.525724 <= Recv SSL data, 1 bytes (0x1)
 0000: .
 22:21:24.525766 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
 22:21:24.525777 <= Recv SSL data, 10 bytes (0xa)
 0000: ..........
 22:21:24.525804 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
 22:21:24.525814 <= Recv SSL data, 5 bytes (0x5)
 0000: ....f
 22:21:24.525845 <= Recv SSL data, 1 bytes (0x1)
 0000: .
 22:21:24.525872 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Certificate (11):
 22:21:24.525881 <= Recv SSL data, 1109 bytes (0x455)
 0000: ...Q...M..H0..D0..,............f0...*.H........0h1.0...U....NN11
 0040: 0/..U...(Edel Curl Arctic Illudium Research Cloud1&0$..U....Nort
 0080: hern Nowhere Trust Anchor0...221125123246Z..310211123246Z0T1.0..
 00c0: .U....NN110/..U...(Edel Curl Arctic Illudium Research Cloud1.0..
 0100: .U....localhost0.."0...*.H.............0.........h2O..O}2.......
 0140: d|-...+.T..r]..9..u.......G.......(&& ,|*...)x-.>o.........v..Xj
 0180: 9.....=.GYQ_....B..B..O[V../.c{......>..N...D..N...bj6cP....".#.
 01c0: ...\...c.....F...R..{.[......9..P.....`..&Y."..W.1....jZ......q.
 0200: ..*..z.....s..r.....7s..^.....fK..\....k.................0...0..
 0240: .U....0...localhost0...U........0...U.%..0...+.......0...U......
 0280: dg......A.b.v...).2A0...U.#..0...R@..O.X)..g.........0...U....0.
 02c0: 0C..+........70503..+.....0..'http://test.curl.se/ca/EdelCurlRoo
 0300: t.cer08..U...10/0-.+.).'http://test.curl.se/ca/EdelCurlRoot.crl0
 0340: ...*.H.............1.c.../.Z.....I...........3v.....T..M.S....Q.
 0380: l82..V..."E......,6A..X..~TA..`..T.g..+......(..=...O3....4...3X
 03c0: .#..9."..1.GqM.&kP.M._.m<..-..=...>.[...1.......g.4.z..W...>....
 0400: 0VM1.e}j:o&...;...Z...j.,....l.._v......7.....t.ST..B.@..H.../|.
 0440: .......q....Ps*"..V..
 22:21:24.527991 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Unknown (21):
 22:21:24.528013 => Send SSL data, 5 bytes (0x5)
 0000: .....
 22:21:24.528106 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS alert, decrypt error (563):
 22:21:24.528120 => Send SSL data, 2 bytes (0x2)
 0000: .3
 22:21:24.528164 == Info: OpenSSL/3.0.1: error:03000098:digital envelope routines::invalid digest
 22:21:24.528309 == Info: Closing connection 0
=== End of file trace313

The equivalent test in 7.86.0 still passes in the same build environment. At first I suspected that this would be related to the more strict crypto policies in RHEL9 that disallow SHA1 signatures etc., but the certificates in this test look to be using SHA256, which should be fine. Then, whilst pasting in the build log above I noticed this inhttps_stunnel.log:

 2022.12.21 22:21:23 LOG5[ui]: Binding service [curltest] to :::25073: Address already in use (98)

This is a type of error I've seen many times before, usually when running a second iteration of the test suite for a differently-configured curl build in the same environment, where a test server from the original test run was still running. That's not the case here though, because this is the first test run. Also, I don't see any mention of the use of port 25073 earlier in the build log. That would usually lead me to suspect a service running on that port on the build host but I can't see anything there either.

I suspect that if I could persuade the test to run stunnel on a different port that it might work, but since the port numbers seem to be selected at random and based on the build environment somehow, I don't know how to do that. Any suggestions?

Ideally, the test suite could be made a bit more robust about this sort of thing if it could check that the ports needed for a test were not already in use, and pick different ports if necessary. Clearly that would be racy but better than nothing.

@bagder bagder added the TLS label Dec 22, 2022
@bagder
Copy link
Member

bagder commented Dec 22, 2022

OpenSSL/3.0.1 really?

Ideally, the test suite could be made a bit more robust about this sort of thing if it could check that the ports needed for a test were not already in use, and pick different ports if necessary.

It already does.

@pghmcfc
Copy link
Contributor Author

pghmcfc commented Dec 22, 2022

OpenSSL/3.0.1 really?

Yes, but heavily patched. See the SOURCES directory here:
https://git.rockylinux.org/staging/rpms/openssl/-/tree/r9

Ideally, the test suite could be made a bit more robust about this sort of thing if it could check that the ports needed for a test were not already in use, and pick different ports if necessary.

It already does.

Thanks for the hint. I took a look at runtests.pl and found the --seed option. Trying again with --seed=1 gave similar results but with a different port:

startnew: perl -I../../tests ../../tests/httpserver.pl --pidfile ".http_server.pid" --logfile "log/http_server.log" --portfile .http_server.port --ipv4 --port 0 --srcdir "../../tests/data/.."
RUN: ../src/curl --max-time 13 --output log/http_verify.out --silent --verbose --globoff "http://127.0.0.1:39779/verifiedserver" 2>log/http_verify.log
CMD (0): ../src/curl --max-time 13 --output log/http_verify.out --silent --verbose --globoff "http://127.0.0.1:39779/verifiedserver" 2>log/http_verify.log
RUN: HTTP server is on PID 75987 port 39779
* pid http => 75987 75987
startnew: perl -I../../tests ../../tests/secureserver.pl --pidfile ".https_server.pid" --logfile "log/https_stunnel.log" --ipv4 --proto https --certfile "Server-localhost-sv.pem" --stunnel "/usr/bin/stunnel" --srcdir "../../tests" --connect 39779 --accept 24851
RUN: HTTPS server is PID 76003 port 24851
* pid https => 76003 76007
prechecked /usr/bin/perl -e "print 'Test requires default test server host' if ( '127.0.0.1' ne '127.0.0.1' );"
test 0313...[CRL test]
../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:24851/313 >log/stdout313 2>log/stderr313
CMD (8960): ../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:24851/313 >log/stdout313 2>log/stderr313

curl returned 35, when expecting 60
 exit FAILED
== Contents of files in the log/ dir after test 313
=== Start of file commands.log
 ../src/curl --output log/curl313.out  --include --trace-ascii log/trace313 --trace-time --cacert ../../tests/certs/EdelCurlRoot-ca.crt --crlfile ../../tests/certs/Server-localhost-sv.crl https://localhost:24851/313 >log/stdout313 2>log/stderr313
=== End of file commands.log
=== Start of file ftpserver.cmd
 Testnum 313
=== End of file ftpserver.cmd
=== Start of file http_server.log
 14:26:34.461099 exit_signal_handler: 15
 14:26:34.461277 signalled to die
 14:26:34.461366 ========> IPv4 sws (port 39419 pid: 75946) exits with signal (15)
 14:26:39.521894 Running HTTP IPv4 version on port 39779
 14:26:39.521983 Wrote pid 75987 to .http_server.pid
 14:26:39.522012 Wrote port 39779 to .http_server.port
 14:26:40.521418 ====> Client connect
 14:26:40.521479 accept_connection 3 returned 4
 14:26:40.521526 accept_connection 3 returned 0
 14:26:40.521569 Read 93 bytes
 14:26:40.521596 Process 93 bytes request
 14:26:40.521682 Got request: GET /verifiedserver HTTP/1.1
 14:26:40.521718 Are-we-friendly question received
 14:26:40.521771 Wrote request (93 bytes) input to log/server.input
 14:26:40.521830 Identifying ourselves as friends
 14:26:40.522083 Response sent (56 bytes) and written to log/server.response
 14:26:40.522123 special request received, no persistency
 14:26:40.522168 ====> Client disconnect 0
=== End of file http_server.log
=== Start of file http_verify.log
 *   Trying 127.0.0.1:39779...
 * Connected to 127.0.0.1 (127.0.0.1) port 39779 (#0)
 > GET /verifiedserver HTTP/1.1
 > Host: 127.0.0.1:39779
 > User-Agent: curl/7.87.0
 > Accept: */*
 > 
 * Mark bundle as not supporting multiuse
 < HTTP/1.1 200 OK
 < Content-Length: 17
 < 
 { [1 bytes data]
 * Connection #0 to host 127.0.0.1 left intact
=== End of file http_verify.log
=== Start of file http_verify.out
 WE ROOLZ: 75987
=== End of file http_verify.out
=== Start of file https_stunnel.log
 2022.12.22 14:26:40 LOG5[ui]: stunnel 5.62 on x86_64-redhat-linux-gnu platform
 2022.12.22 14:26:40 LOG5[ui]: Compiled/running with OpenSSL 3.0.1 14 Dec 2021
 2022.12.22 14:26:40 LOG5[ui]: Threading:PTHREAD Sockets:POLL,IPv6 TLS:ENGINE,FIPS,OCSP,PSK,SNI
 2022.12.22 14:26:40 LOG5[ui]: Reading configuration from file /builddir/build/BUILD/curl-7.87.0/build-minimal/tests/https_stunnel.conf
 2022.12.22 14:26:40 LOG5[ui]: UTF-8 byte order mark not detected
 2022.12.22 14:26:40 LOG5[ui]: FIPS mode disabled
 2022.12.22 14:26:40 LOG5[ui]: Configuration successful
 2022.12.22 14:26:40 LOG5[ui]: Binding service [curltest] to :::24851: Address already in use (98)
 2022.12.22 14:26:40 LOG5[cron]: Updating DH parameters
 2022.12.22 14:26:41 LOG5[0]: Service [curltest] accepted connection from 127.0.0.1:38218
 2022.12.22 14:26:41 LOG3[0]: SSL_accept: ssl/record/rec_layer_s3.c:1584: error:0A00041B:SSL routines::tlsv1 alert decrypt error
 2022.12.22 14:26:41 LOG5[0]: Connection reset: 0 byte(s) sent to TLS, 0 byte(s) sent to socket
=== End of file https_stunnel.log
=== Start of file server.response
 HTTP/1.1 200 OK
 Content-Length: 17
 WE ROOLZ: 75987
=== End of file server.response
=== Start of file stderr313
   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                  Dload  Upload   Total   Spent    Left  Speed
 
   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
   0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
 curl: (35) OpenSSL/3.0.1: error:03000098:digital envelope routines::invalid digest
=== End of file stderr313
=== Start of file trace313
 14:26:41.586244 == Info:   Trying 127.0.0.1:24851...
 14:26:41.785777 == Info: Connected to localhost (127.0.0.1) port 24851 (#0)
 14:26:41.791828 == Info: ALPN: offers h2
 14:26:41.791851 == Info: ALPN: offers http/1.1
 14:26:41.793892 == Info:  CAfile: ../../tests/certs/EdelCurlRoot-ca.crt
 14:26:41.793915 == Info:  CApath: none
 14:26:41.794124 == Info: successfully loaded CRL file:
 14:26:41.794141 == Info:   CRLfile: ../../tests/certs/Server-localhost-sv.crl
 14:26:41.794669 == Info: [CONN-0-0][CF-SSL] TLSv1.0 (OUT), TLS header, Certificate Status (22):
 14:26:41.794687 => Send SSL data, 5 bytes (0x5)
 0000: .....
 14:26:41.794728 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS handshake, Client hello (1):
 14:26:41.794738 => Send SSL data, 512 bytes (0x200)
 0000: ......-.+=.s...G....F.HF..z.X`.6...&UK ....o...u.=...f.{.F.3.S2.
 0040: ........>.......,.0.........+./...$.(.k.#.'.g.....9.....3.....=.
 0080: <.5./.....u.........localhost...................................
 00c0: ......h2.http/1.1.........1.....*.(.............................
 0100: ............+............-.....3.&.$... .<.Z....d...HNI.....m...
 0140: ]b.....L........................................................
 0180: ................................................................
 01c0: ................................................................
 14:26:41.801864 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Certificate Status (22):
 14:26:41.801894 <= Recv SSL data, 5 bytes (0x5)
 0000: ....z
 14:26:41.801934 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Server hello (2):
 14:26:41.801945 <= Recv SSL data, 122 bytes (0x7a)
 0000: ...v..=l.B.G:....-............L.cx..*. ....o...u.=...f.{.F.3.S2.
 0040: .............+.....3.$... 1....\V......C...RIWr......NI!.g
 14:26:41.802666 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Finished (20):
 14:26:41.802685 <= Recv SSL data, 5 bytes (0x5)
 0000: .....
 14:26:41.802710 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
 14:26:41.802720 <= Recv SSL data, 5 bytes (0x5)
 0000: .....
 14:26:41.802745 <= Recv SSL data, 1 bytes (0x1)
 0000: .
 14:26:41.802786 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
 14:26:41.802797 <= Recv SSL data, 10 bytes (0xa)
 0000: ..........
 14:26:41.802823 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
 14:26:41.802832 <= Recv SSL data, 5 bytes (0x5)
 0000: ....f
 14:26:41.802861 <= Recv SSL data, 1 bytes (0x1)
 0000: .
 14:26:41.802887 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Certificate (11):
 14:26:41.802896 <= Recv SSL data, 1109 bytes (0x455)
 0000: ...Q...M..H0..D0..,............f0...*.H........0h1.0...U....NN11
 0040: 0/..U...(Edel Curl Arctic Illudium Research Cloud1&0$..U....Nort
 0080: hern Nowhere Trust Anchor0...221125123246Z..310211123246Z0T1.0..
 00c0: .U....NN110/..U...(Edel Curl Arctic Illudium Research Cloud1.0..
 0100: .U....localhost0.."0...*.H.............0.........h2O..O}2.......
 0140: d|-...+.T..r]..9..u.......G.......(&& ,|*...)x-.>o.........v..Xj
 0180: 9.....=.GYQ_....B..B..O[V../.c{......>..N...D..N...bj6cP....".#.
 01c0: ...\...c.....F...R..{.[......9..P.....`..&Y."..W.1....jZ......q.
 0200: ..*..z.....s..r.....7s..^.....fK..\....k.................0...0..
 0240: .U....0...localhost0...U........0...U.%..0...+.......0...U......
 0280: dg......A.b.v...).2A0...U.#..0...R@..O.X)..g.........0...U....0.
 02c0: 0C..+........70503..+.....0..'http://test.curl.se/ca/EdelCurlRoo
 0300: t.cer08..U...10/0-.+.).'http://test.curl.se/ca/EdelCurlRoot.crl0
 0340: ...*.H.............1.c.../.Z.....I...........3v.....T..M.S....Q.
 0380: l82..V..."E......,6A..X..~TA..`..T.g..+......(..=...O3....4...3X
 03c0: .#..9."..1.GqM.&kP.M._.m<..-..=...>.[...1.......g.4.z..W...>....
 0400: 0VM1.e}j:o&...;...Z...j.,....l.._v......7.....t.ST..B.@..H.../|.
 0440: .......q....Ps*"..V..
 14:26:41.805005 == Info: [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Unknown (21):
 14:26:41.805027 => Send SSL data, 5 bytes (0x5)
 0000: .....
 14:26:41.805118 == Info: [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS alert, decrypt error (563):
 14:26:41.805132 => Send SSL data, 2 bytes (0x2)
 0000: .3
 14:26:41.805173 == Info: OpenSSL/3.0.1: error:03000098:digital envelope routines::invalid digest
 14:26:41.805316 == Info: Closing connection 0
=== End of file trace313

So, still getting "Address already in use", this time on port 24851. This is weird, the other stunnel-based tests are working OK.

@bagder
Copy link
Member

bagder commented Dec 22, 2022

Since curl logs a lot of TLS traffic, I think "Address already in use" is a ghost chase. Part of finding an unused port can involve trying a port that is in use, but then it should continue and try another port. (Unfortunately stunnel does not allow us to make it pick a random unused one by itself.)

The problem is rather this:

curl returned 35, when expecting 60

35 being CURLE_SSL_CONNECT_ERROR and 60 CURLE_PEER_FAILED_VERIFICATION

The error message from OpenSSL in there is also weird: curl: (35) OpenSSL/3.0.1: error:03000098:digital envelope routines::invalid digest. That's not expected.

@bagder bagder added the tests label Dec 22, 2022
@pghmcfc
Copy link
Contributor Author

pghmcfc commented Dec 22, 2022

Looks like a certificate issue. I copied the files EdelCurlRoot-ca.crt, Server-localhost-sv.crl and Server-localhost-sv.pem from the tests/certs directory of the curl 7.86.0 release and that made test 0313 pass, at the expense of tests 2034, 2037, 2041, 3000 and 3001 failing for various certificate non-matching issues.

@bagder
Copy link
Member

bagder commented Dec 22, 2022

... which then suggests this is an OpenSSL issue (your version of it), since these certs work fine with lots of TLS libraries otherwise and with OpenSSL 3.0.7 etc.

The curl tests certs were updated in #9980

@icing
Copy link
Contributor

icing commented Dec 22, 2022

I think we would take in any improvements to tests/certs/Makefile.am and related scripts. These are the ones used to generate the current batch.

pghmcfc added a commit to pghmcfc/curl that referenced this issue Dec 23, 2022
The SHA-1 algorithm is deprecated (particularly for security-sensitive
applications) in a variety of OS environments. This already affects
RHEL-9 and derivatives, which are not willing to use certificates using
that algorithm. The fix is to use sha256 instead, which is already
used for most of the other certificates in the test suite.

Fixes curl#10135
@bagder bagder closed this as completed in ef07452 Dec 26, 2022
@sevenrats
Copy link

this thread is one of the only search hits for "0A00041B."
in my case it had been working before, but I had accidentally reconfigured tpm2tss-engine without --disable-digestsign which causes signatures to fail. curl gave this error "0A00041B" but nginx showed signature failures on the client side which eventually led me to the solution: reconfigure tpm-tss-engine with --disable-digestsign

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Development

Successfully merging a pull request may close this issue.

4 participants