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

OpenSSL 3.0.8 "SSL routines internal error (s3_enc.c:354)" #21422

Closed
mgdaniel opened this issue Jul 11, 2023 · 15 comments
Closed

OpenSSL 3.0.8 "SSL routines internal error (s3_enc.c:354)" #21422

mgdaniel opened this issue Jul 11, 2023 · 15 comments
Labels
triaged: bug The issue/pr is/fixes a bug

Comments

@mgdaniel
Copy link

SSL3 for OpenVMS V3.0(8) Apr 10 2023 (Library: SSL3 for OpenVMS V3.0(8) Apr 10 2023)
(problem exhibited also when build against OpenSSL 1.1.1t)

The server, for TLSv1.2, uses renegotiation for requesting a client certificate be provided (for authentication/authorisation).

I have been chasing the the reason for the above error and it appears to be related to the server certificate in use! A current Let's Encrypt issued server cert results in the above error very early in the renegotiation. A self-signed server cert does not. I have no third alternative to try.

Using the s_client to make the request:

$ openssl s_client -cert clientl.pem -tls1_2 -state -nbio -connect host-name:443

8< snip 8<
New, TLSv1.2, Cipher is ECDHE-RSA-AES128-SHA256
Server public key is 4096 bit
Secure Renegotiation IS supported
8< snip 8<
SSL_connect:SSL negotiation finished successfully
SSL_connect:SSL negotiation finished successfully
SSL_connect:SSLv3/TLS read hello request
SSL_connect:SSLv3/TLS write client hello
SSL_connect:error in SSLv3/TLS write client hello
read R BLOCK
SSL_connect:SSLv3/TLS write client hello
SSL3 alert write:fatal:decode error
SSL_connect:error in error
80CEBC7B00000000:error:0A000126:SSL routines:(unknown function):unexpected eof while reading:rec_layer_s3.c;1:321:

and the server reports:

8< snip 8<
|09:11:39.11 SESOLANE 0249 000002 SSL        BEGIN TLSv1.2|
|09:11:39.11 SESOLA   3570 000002 SSL        START handshake|
8< snip 8<
|09:11:40.14 SESOLA   3717 000002 SSL        SESSION hit:no protocol:TLSv1.2 cipher:ECDHE-RSA-AES128-SHA256 keysize:128/128 X509:no|
8< snip 8<
|09:11:51.23 SESOLACL 1229 000002 SSL        X509 client certificate VERIFY:REQUIRED|
|09:11:51.23 SESOLA   3570 000002 SSL        START handshake|
8< snip 8<
|09:11:51.24 SESOLACL 1281 000002 SSL        STATE 1 "SSLOK" SSL negotiation finished successfully cert:FALSE|
|09:11:51.24 SESOLA   3652 000002 SSL        READ 528/528 (complete)|
|09:11:51.24 SESOLA   3570 000002 SSL        START handshake|
|09:11:51.24 SESOLA   3666 000002 SSL        CTRL 6 0|
|09:11:51.24 SESOLA   3512 000002 SSL        LOOP SSL negotiation finished successfully|
|09:11:51.24 SESOLA   3512 000002 SSL        LOOP SSL negotiation finished successfully|
|09:11:51.24 SESOLA   3512 000002 SSL        LOOP SSLv3/TLS read client hello|
|09:11:51.24 SESOLA   3512 000002 SSL        LOOP SSLv3/TLS write server hello|
|09:11:51.24 SESOLA   3657 000002 SSL        WRITE 4096/0 (outstanding)|
|09:11:51.24 SESOLA   3657 000002 SSL        WRITE 4096/0 (outstanding)|
|09:11:51.24 SESOLA   3522 000002 SSL        EXIT error/blocking in error|
|09:11:51.24 SESOLACL 1270 000002 SSL        SSL_do_handshake() -1 1|
|09:11:51.24 SESOLA   3768 000002 SSL        SSL routines  internal error (s3_enc.c:354)|
|09:11:51.24 SESOLACL 1281 000002 SSL        STATE 23 "SSLERR" error cert:FALSE|

I have sought a way to reproduce this using s_server (to make the investigation platform-neutral) but cannot seem to trigger the renegotiation to include the client cert.

Just to repeat, this works with no other change than the server cert from LE to self-signed.

TLSv1.3 also works without issue with both server certs but of course that is via the entirely separate PHA mechanism.

@mgdaniel mgdaniel added the issue: bug report The issue was opened to report a bug label Jul 11, 2023
@mattcaswell
Copy link
Member

|09:11:51.24 SESOLA 3768 000002 SSL SSL routines internal error (s3_enc.c:354)|

That error is a fundamental very low-level "should not happen" failure:

openssl/ssl/s3_enc.c

Lines 352 to 356 in 31157bc

ret = BIO_write(s->s3.handshake_buffer, (void *)buf, (int)len);
if (ret <= 0 || ret != (int)len) {
SSLfatal(s, SSL_AD_INTERNAL_ERROR, ERR_R_INTERNAL_ERROR);
return 0;
}

s->s3.handshake_buffer here is just a mem BIO which should just automatically expand if it runs out of space. Opportunities for this BIO_write to fail are somewhat limited. Possibilities that spring to mind could be:

  • handshake_buffer is unexpectedly NULL
  • Memory allocation failure expanding the size of handshake_buffer
  • len is unexpectedly very large (which would ultimately cause memory allocation failure above)
  • Some casting issue such that len != (int)len, i.e. if len is so large that (int)len is negative (this shouldn't ever happen in practice)

I don't know if you are able to do some debugging to figure out what is causing it to fail?

@mattcaswell mattcaswell added triaged: bug The issue/pr is/fixes a bug and removed issue: bug report The issue was opened to report a bug labels Jul 11, 2023
@mgdaniel
Copy link
Author

I don't know if you are able to do some debugging to figure out what is causing it to fail?

Sure. Server is mine. Just provide some direction. Thanks.

@mattcaswell
Copy link
Member

Let's start with some simple checks. If you can set a breakpoint on the SSLfatal line above and discover the value of ret and len at that point, also confirming that handshake_buffer and buf are non-NULL (or just use some "printf's" at that point if its easier than using the debugger).

@mgdaniel
Copy link
Author

mgdaniel commented Jul 11, 2023

Matt, this is pre- built and packaged OpenVMS release of OpenSSL. Such requests are difficult (but not entirely impossible) for me. This one needs to be considered accessible from the outside if at all possible. I could at a pinch obtain the appropriate OpenSSL tarball and build from scratch but it will be a long and drawn-out process on a 20 year old architecture.

The code reporting

|09:11:51.24 SESOLA 3768 000002 SSL SSL routines internal error (s3_enc.c:354)|

is from a callback that is expressed

/*
Provide some OpenSSL-internal error information.
(Based on code from [.CRYPTO.ERR]ERR_PRN.C)
*/
8< snip 8<
   while (cnt = ERR_get_error_line_data (&FileNamePtr, &LineNumber,
                                         &DataPtr, &flags))
   {
      ERR_error_string_n (cnt, ErrorString, sizeof(ErrorString));
      for (cptr1 = ErrorString; *cptr1 && *cptr1 != ':'; cptr1++);
      if (*cptr1) cptr1++;
      while (*cptr1 && *cptr1 != ':') cptr1++;
      if (*cptr1) cptr1++;
      for (cptr2 = cptr1; *cptr2 && *cptr2 != ':'; cptr2++);
      if (*cptr2) *cptr2++ = '\0';
      for (cptr3 = cptr2; *cptr3 && *cptr3 != ':'; cptr3++);
      if (*cptr3) *cptr3++ = '\0';
      for (cptr = FileNamePtr; *cptr; cptr++);
      while (cptr > FileNamePtr && *cptr != ']') cptr--;
      if (*cptr == ']') cptr++;
      sptr = ModuleName;
      while (*cptr && *cptr != ';') *sptr++ = *cptr++;
      *sptr = '\0';
      WatchThis (WATCHITM(rqptr), WATCH_SESOLA,
                 "!AZ !AZ !AZ !AZ!&? \r\r(!AZ:!UL)",
                 cptr1, cptr2, cptr3,
                 flags & ERR_TXT_STRING ? DataPtr : "",
                 flags & ERR_TXT_STRING, ModuleName, LineNumber);
   }

If the error could be detected in there and the relevant measurement initiated from there, that would be eminently doable. Note: that underlying bio is essentially used an a (convoluted) asynch mode.

The above report example is itself called from

      value = SSL_do_handshake (sesolaptr->SslPtr);  <<<---(1)

      if (WATCHING (rqptr, WATCH_SESOLA))
      {
         WatchThis (WATCHITM(rqptr), WATCH_SESOLA,
                    "SSL_do_handshake() !SL !SL",
                    value, SSL_get_error(sesolaptr->SslPtr,value));  <<<-----(2)
         SesolaWatchErrors (rqptr);
      }

so the underlying pointer to SSL struct is available for access (1) and use (2).

@mgdaniel
Copy link
Author

OK, I have obtained the 3.0.8 tarball (equivalent to original reported issue release) and built local libraries, adding the debug statement:

int ssl3_finish_mac(SSL *s, const unsigned char *buf, size_t len)
{
8< snip 8<
        ret = BIO_write(s->s3.handshake_buffer, (void *)buf, (int)len);
printf("++++++++++1 %u %u %d %d\n", s->s3.handshake_buffer, buf, len, ret);
        if (ret <= 0 || ret != (int)len) {
            SSLfatal(s, SSL_AD_INTERNAL_ERROR, ERR_R_INTERNAL_ERROR);
            return 0;
        }
8< snip 8<
}

and issued the previously documented s_client request

KLAATU$ openssl s_client -cert client.pem -tls1_2 -state -nbio -connect host.name:443
Enter pass phrase for client.pem:
CONNECTED(00000003)
Turned on non blocking io

SSL_connect:before SSL initialization
SSL_connect:SSLv3/TLS write client hello
SSL_connect:error in SSLv3/TLS write client hello
write R BLOCK
SSL_connect:SSLv3/TLS write client hello
8< snip 8<
SSL_connect:SSLv3/TLS read server hello
depth=2 C = US, O = Internet Security Research Group, CN = ISRG Root X1
verify error:num=20:unable to get local issuer certificate
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = R3
verify return:1
8< snip 8<
No client certificate CA names sent
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: X25519, 253 bits
---
SSL handshake has read 5270 bytes and written 348 bytes
Verification error: unable to get local issuer certificate
---
New, TLSv1.2, Cipher is ECDHE-RSA-AES128-SHA256
Server public key is 4096 bit
Secure Renegotiation IS supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
SSL-Session:
    Protocol  : TLSv1.2
    Cipher    : ECDHE-RSA-AES128-SHA256
8< snip 8<
GET /x509/cgi-bin/cgi_symbols HTTP/1.0

SSL_connect:SSL negotiation finished successfully
SSL_connect:SSL negotiation finished successfully
SSL_connect:SSLv3/TLS read hello request
SSL_connect:SSLv3/TLS write client hello
SSL_connect:error in SSLv3/TLS write client hello
read R BLOCK
SSL_connect:SSLv3/TLS write client hello
SSL3 alert write:fatal:decode error
SSL_connect:error in error
80CEBC7B00000000:error:0A000126:SSL routines:(unknown function):unexpected eof while reading:rec_layer_s3.c;1:321:

with the corresponding output in the server log

++++++++++1 19350576 23773192 210 210
++++++++++1 19350576 23773192 4 4
++++++++++1 19432744 23773192 465 465
++++++++++1 19432744 23773192 93 93
++++++++++1 19432744 23773192 0 0
++++++++++1 23870096 23773192 512 512
++++++++++1 19312080 23773192 512 512

I am now in a position to add debug statements as requested.

@mattcaswell
Copy link
Member

Hmmm....and you still see the SSL routines internal error (s3_enc.c:354) error in the server log? Because, if so, that's quite perplexing. The condition for the if on that line is ret <= 0 || ret != (int)len - but as you can see all lines of output show a positive ret value that is equal to the len value!

@mgdaniel
Copy link
Author

mgdaniel commented Jul 12, 2023

Here's a fresh one, just generated Matt.

|17:17:15.78 AUTH     1389 000002 AUTHORIZE  ["X509 Client Certs"=X509;-;-] - R+W ; - - PROFILE|
[ig:20][ig:21][vf:required]
|17:17:15.78 SESOLACL 1229 000002 SSL        X509 client certificate VERIFY:REQUIRED|
|17:17:15.78 SESOLA   3570 000002 SSL        START handshake|
|17:17:15.78 SESOLA   3666 000002 SSL        CTRL 6 0|
|17:17:15.78 SESOLA   3512 000002 SSL        LOOP SSL negotiation finished successfully|
|17:17:15.78 SESOLA   3657 000002 SSL        WRITE 69/0 (outstanding)|
|17:17:15.78 SESOLA   3522 000002 SSL        EXIT error/blocking in SSLv3/TLS write hello request|
|17:17:15.78 SESOLACL 1270 000002 SSL        SSL_do_handshake() -1 3|
|17:17:15.78 SESOLACL 1281 000002 SSL        STATE 19 "TWHR" SSLv3/TLS write hello request cert:FALSE|
|17:17:15.78 SESOLA   3657 000002 SSL        WRITE 69/0 (outstanding)|
|17:17:15.78 SESOLA   3522 000002 SSL        EXIT error/blocking in SSLv3/TLS write hello request|
|17:17:15.78 SESOLA   3657 000002 SSL        WRITE 69/69 (complete)|
|17:17:15.78 SESOLA   3666 000002 SSL        CTRL 11 1|
|17:17:15.78 SESOLA   3512 000002 SSL        LOOP SSLv3/TLS write hello request|
|17:17:15.78 SESOLA   3666 000002 SSL        CTRL 7 0|
|17:17:15.78 SESOLA   3573 000002 SSL        DONE handshake|
|17:17:15.78 SESOLACL 1270 000002 SSL        SSL_do_handshake() 1 0|
|17:17:15.78 SESOLACL 1281 000002 SSL        STATE 1 "SSLOK" SSL negotiation finished successfully cert:FALSE|
|17:17:15.78 SESOLA   3652 000002 SSL        READ 5/-1 (outstanding)|
|17:17:15.79 SESOLACL 1270 000002 SSL        SSL_do_handshake() 1 0|
|17:17:15.79 SESOLACL 1281 000002 SSL        STATE 1 "SSLOK" SSL negotiation finished successfully cert:FALSE|
|17:17:15.79 SESOLA   3652 000002 SSL        READ 5/5 (complete)|
|17:17:15.79 SESOLA   3652 000002 SSL        READ 528/-1 (outstanding)|
|17:17:15.79 SESOLACL 1270 000002 SSL        SSL_do_handshake() 1 0|
|17:17:15.79 SESOLACL 1281 000002 SSL        STATE 1 "SSLOK" SSL negotiation finished successfully cert:FALSE|
|17:17:15.79 SESOLA   3652 000002 SSL        READ 528/528 (complete)|
|17:17:15.79 SESOLA   3570 000002 SSL        START handshake|
|17:17:15.79 SESOLA   3666 000002 SSL        CTRL 6 0|
|17:17:15.79 SESOLA   3512 000002 SSL        LOOP SSL negotiation finished successfully|
|17:17:15.79 SESOLA   3512 000002 SSL        LOOP SSL negotiation finished successfully|
|17:17:15.79 SESOLA   3512 000002 SSL        LOOP SSLv3/TLS read client hello|
|17:17:15.79 SESOLA   3512 000002 SSL        LOOP SSLv3/TLS write server hello|
|17:17:15.79 SESOLA   3657 000002 SSL        WRITE 4096/0 (outstanding)|
|17:17:15.79 SESOLA   3657 000002 SSL        WRITE 4096/0 (outstanding)|
|17:17:15.79 SESOLA   3522 000002 SSL        EXIT error/blocking in error|
|17:17:15.79 SESOLACL 1270 000002 SSL        SSL_do_handshake() -1 1|
|17:17:15.79 SESOLA   3768 000002 SSL        SSL routines  internal error (s3_enc.c:355)|
|17:17:15.79 SESOLACL 1281 000002 SSL        STATE 23 "SSLERR" error cert:FALSE|
|17:17:15.79 SESOLA   3717 000002 SSL        SESSION hit:no protocol:TLSv1.2 cipher:(none) keysize:0/0 X509:no|
|17:17:15.79 ERROR    1161 000002 RESPONSE   AUTH:3292 (detailed) 403(403) "Authentication failed."|
|17:17:15.80 GZIP     1022 000002 RESPONSE   DEFLATE no, client does not accept|
|17:17:15.80 REQUEST  1435 000002 REQUEST    STATUS 403 (Forbidden) rx:518 tx:9435 bytes 16.10s 618 B/s|
|--------------------------------------------
|17:17:15.80 SESOLANE 0508 000002 SSL        SHUTDOWN|
|17:17:15.80 SESOLANE 0554 000002 SSL        END|

with associated log entries

++++++++++1 23870680 24633168 512 512
++++++++++1 19427568 24633168 512 512
++++++++++1 19312080 24633168 210 210
++++++++++1 19312080 24633168 4 4
++++++++++1 19427568 24633168 465 465
++++++++++1 19427568 24633168 93 93
++++++++++1 19427568 24633168 0 0   <<<---(1)
++++++++++1 24626664 24633168 512 512
++++++++++1 19350576 24633168 512 512

What does this one represent then?

@mattcaswell
Copy link
Member

Ah...sorry. Somehow I missed that important line. The 0 len/ret value does look suspicious

Does the debugging log output correspond to exactly one handshake?

@mattcaswell
Copy link
Member

Please also add this additional logging:

diff --git a/ssl/statem/statem_lib.c b/ssl/statem/statem_lib.c
index bcce73bcdc..0268ffa144 100644
--- a/ssl/statem/statem_lib.c
+++ b/ssl/statem/statem_lib.c
@@ -57,11 +57,13 @@ int ssl3_do_write(SSL *s, int type)
          */
         if (!SSL_IS_TLS13(s) || (s->statem.hand_state != TLS_ST_SW_SESSION_TICKET
                                  && s->statem.hand_state != TLS_ST_CW_KEY_UPDATE
-                                 && s->statem.hand_state != TLS_ST_SW_KEY_UPDATE))
+                                 && s->statem.hand_state != TLS_ST_SW_KEY_UPDATE)) {
+            printf("++++++ In ssl3_do_write. written is %u, init_num is %u\n", (unsigned int)written, (unsigned int)s->init_num);
             if (!ssl3_finish_mac(s,
                                  (unsigned char *)&s->init_buf->data[s->init_off],
                                  written))
                 return -1;
+        }
     if (written == s->init_num) {
         if (s->msg_callback)
             s->msg_callback(1, s->version, type, s->init_buf->data,
@@ -1305,6 +1307,7 @@ int tls_get_message_body(SSL *s, size_t *len)
 
     /* Feed this message into MAC computation. */
     if (RECORD_LAYER_is_sslv2_record(&s->rlayer)) {
+        printf("++++++ In tls_get_message_body (SSLv2 record). init_num is %u\n", (unsigned int)s->init_num);
         if (!ssl3_finish_mac(s, (unsigned char *)s->init_buf->data,
                              s->init_num)) {
             /* SSLfatal() already called */

@mgdaniel
Copy link
Author

++++++++++1 19312080 23773192 210 210
++++++ In ssl3_do_write. written is 73, init_num is 73
++++++ In ssl3_do_write. written is 0, init_num is 4303
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 218, init_num is 218
++++++ In ssl3_do_write. written is 16, init_num is 16
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++++++1 19312080 23773192 4 4
++++++++++1 19432744 23773192 465 465
++++++ In ssl3_do_write. written is 93, init_num is 93
++++++++++1 19432744 23773192 93 93
++++++ In ssl3_do_write. written is 0, init_num is 4303
++++++++++1 19432744 23773192 0 0
++++++++++1 23869424 23773192 512 512
++++++ In ssl3_do_write. written is 80, init_num is 80
++++++ In ssl3_do_write. written is 0, init_num is 4303
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 16, init_num is 16
++++++++++1 19350576 23773192 512 512
++++++ In ssl3_do_write. written is 80, init_num is 80
++++++ In ssl3_do_write. written is 0, init_num is 4303
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 16, init_num is 16

@mattcaswell
Copy link
Member

Please could you try applying the patch below?

diff --git a/ssl/statem/statem_lib.c b/ssl/statem/statem_lib.c
index 0268ffa144..0fd71f3d4b 100644
--- a/ssl/statem/statem_lib.c
+++ b/ssl/statem/statem_lib.c
@@ -49,7 +49,7 @@ int ssl3_do_write(SSL *s, int type)
                            s->init_num, &written);
     if (ret < 0)
         return -1;
-    if (type == SSL3_RT_HANDSHAKE)
+    if (type == SSL3_RT_HANDSHAKE && written > 0)
         /*
          * should not be done for 'Hello Request's, but in that case we'll
          * ignore the result anyway

@mgdaniel
Copy link
Author

mgdaniel commented Jul 12, 2023

BINGO!!

++++++++++1 19312080 23773192 210 210
++++++ In ssl3_do_write. written is 73, init_num is 73
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 218, init_num is 218
++++++ In ssl3_do_write. written is 16, init_num is 16
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++++++1 19312080 23773192 4 4
++++++++++1 19432744 23773192 465 465
++++++ In ssl3_do_write. written is 93, init_num is 93
++++++++++1 19432744 23773192 93 93
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++++++1 19432744 23773192 4303 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++++++1 19432744 23773192 556 556
++++++ In ssl3_do_write. written is 52, init_num is 52
++++++++++1 19432744 23773192 52 52
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++++++1 19432744 23773192 4 4
++++++++++1 19432744 23773192 1469 1469
++++++++++1 19432744 23773192 37 37
++++++ In ssl3_do_write. written is 16, init_num is 16
++++++++++1 23870008 23773192 512 512
++++++ In ssl3_do_write. written is 80, init_num is 80
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 16, init_num is 16
++++++++++1 19389072 23773192 512 512
++++++ In ssl3_do_write. written is 80, init_num is 80
++++++ In ssl3_do_write. written is 4303, init_num is 4303
++++++ In ssl3_do_write. written is 556, init_num is 556
++++++ In ssl3_do_write. written is 4, init_num is 4
++++++ In ssl3_do_write. written is 16, init_num is 16
GET /x509/cgi-bin/cgi_symbols HTTP/1.0

SSL_connect:SSL negotiation finished successfully
SSL_connect:SSL negotiation finished successfully
SSL_connect:SSLv3/TLS read hello request
SSL_connect:SSLv3/TLS write client hello
SSL_connect:error in SSLv3/TLS write client hello
read R BLOCK
SSL_connect:SSLv3/TLS write client hello
SSL_connect:error in SSLv3/TLS read server hello
8< snip 8<
read R BLOCK
SSL_connect:SSLv3/TLS read server hello
depth=2 C = US, O = Internet Security Research Group, CN = ISRG Root X1
verify error:num=20:unable to get local issuer certificate
verify return:1
depth=1 C = US, O = Let's Encrypt, CN = R3
verify return:1
depth=0 CN = the.host.name
verify return:1
SSL_connect:SSLv3/TLS read server certificate
SSL_connect:SSLv3/TLS read server key exchange
SSL_connect:SSLv3/TLS read server certificate request
SSL_connect:SSLv3/TLS read server done
SSL_connect:SSLv3/TLS write client certificate
SSL_connect:SSLv3/TLS write client key exchange
SSL_connect:SSLv3/TLS write certificate verify
SSL_connect:SSLv3/TLS write change cipher spec
SSL_connect:SSLv3/TLS write finished
SSL_connect:error in SSLv3/TLS write finished
read R BLOCK
SSL_connect:SSLv3/TLS write finished
SSL_connect:SSLv3/TLS read change cipher spec
SSL_connect:SSLv3/TLS read finished
read R BLOCK
HTTP/1.1 200 OK
Server: HTTPd-WASD/12.1.2 OpenVMS/AXP SSL
Date: Wed, 12 Jul 2023 11:29:01 GMT
Accept-Ranges: bytes
Accept-Encoding: gzip, deflate
Content-Type: text/plain; charset=ISO-8859-1
Content-Security-Policy: frame-ancestors 'self'; form-action 'self';

8< snip 8<
-----------
CGI symbols
-----------

  WWW_AUTH_ACCESS == "READ+WRITE"
  WWW_AUTH_REALM == "X509"
  WWW_AUTH_REALM_DESCRIPTION == "X509 Client Certs"
  WWW_AUTH_REMOTE_USER == "237B0FE81A14217A8BDD4378FC66BD3E"
  WWW_AUTH_TYPE == "X509"
  WWW_AUTH_USER == "MGD"
  WWW_AUTH_X509_CIPHER == "ECDHE-RSA-AES128-SHA256"
  WWW_AUTH_X509_FINGERPRINT == "23:7B:0F:E8:1A:14:21:7A:8B:DD:43:78:FC:66:BD:3E"
  WWW_AUTH_X509_ISSUER == "/C=AU/ST=SA/L=Adelaide/O=WASD CA Cert/OU=OpenSSL 1.0.2o Testing Only/CN=WASD VMS Web Services/emailAddress=Mark.Daniel@wasd.vsm.com.au"
  WWW_AUTH_X509_KEYSIZE == "128"
  WWW_AUTH_X509_SUBJECT == "/C=AU/ST=SA/L=Adelaide/O=WASD/OU=OpenSSL 1.0.2o Testing Only/CN=mark.daniel@wasd.vsm.com.au/emailAddress=Mark.Daniel@wasd.vsm.com.au"
  WWW_CONTENT_LENGTH == "0"
8< snip 8<

mattcaswell added a commit to mattcaswell/openssl that referenced this issue Jul 12, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422
mattcaswell added a commit to mattcaswell/openssl that referenced this issue Jul 12, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422
mattcaswell added a commit to mattcaswell/openssl that referenced this issue Jul 12, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422
@mattcaswell
Copy link
Member

PR to fix this in #21434 (master) and #21435 (3.1/3.0).

I was able to reproduce this problem locally after a bit of experimentation. It turns out to be quite tricky to hit. The scenario where I could get this to happen was:

  • 3.1/3.0 only (master is not affected)
  • TLSv1.2 or lower
  • The write BIO returns a "retry" response early in the handshake
  • A large certificate message is sent (larger than the 4k handshake buffer that is being used in the libssl)
  • SSL_VERIFY_PEER is set (non default for servers)
  • The BIO returns 0 on retry not -1. BIO_write() is documented to return -1 on retry - but there are definitely custom BIOs that don't do this (maybe some OpenSSL ones?)

There might be other scenarios where this occurs but this was the only one I found.

In the end I went with a slightly different fix to the one I originally proposed above.

@mgdaniel
Copy link
Author

It was noted in opening the issue, "(problem exhibited also when build against OpenSSL 1.1.1t)", but I see mention of "3.1/3.0 only (master is not affected)", nothing of the 1.1.1 branch. I know it's reaching EOL but with LTS. Just a thought.

@mattcaswell
Copy link
Member

In the last year of LTS support we only typically accept security fixes. Since this isn't a security fix it isn't eligible for backport to 1.1.1.

openssl-machine pushed a commit that referenced this issue Jul 16, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes #21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from #21435)

(cherry picked from commit 034ea1d)
openssl-machine pushed a commit that referenced this issue Jul 16, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes #21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from #21435)
bernd-edlinger pushed a commit to bernd-edlinger/openssl that referenced this issue Jul 19, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from openssl#21435)

(cherry picked from commit 034ea1d)
bernd-edlinger pushed a commit to bernd-edlinger/openssl that referenced this issue Jul 19, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from openssl#21435)

(cherry picked from commit 034ea1d)
bernd-edlinger pushed a commit to bernd-edlinger/openssl that referenced this issue Aug 1, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from openssl#21435)

(cherry picked from commit 034ea1d)
bernd-edlinger pushed a commit to bernd-edlinger/openssl that referenced this issue Aug 19, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from openssl#21435)

(cherry picked from commit 034ea1d)
bernd-edlinger pushed a commit to bernd-edlinger/openssl that referenced this issue Sep 12, 2023
A BIO is documented to return -1 on write retry - but sometimes they return
0. ssl3_do_write() was incorrectly handling a 0 response.

Fixes openssl#21422

Reviewed-by: Dmitry Belyavskiy <beldmit@gmail.com>
Reviewed-by: Paul Dale <pauli@openssl.org>
(Merged from openssl#21435)

(cherry picked from commit 034ea1d)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
triaged: bug The issue/pr is/fixes a bug
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants