OpenSSL Read/Write into a BIO_s_mem works only on first call per connection #24266

g2px1 · 2024-04-25T18:09:42Z

g2px1
Apr 25, 2024

SSL *ssl = static_cast<SSL *>(clientData.ssl);
    std::vector<uint8_t> decrypted_data;
    size_t total_read = 0;
    size_t just_read = 0;
    BIO *rbio = SSL_get_rbio(ssl);
    BIO_reset(rbio);
    if (!rbio) {
        std::cerr << "Read BIO not set." << std::endl;
        return -1;
    }

    decrypted_data.resize(clientData.inData.size());

    // Write the encrypted data to the existing rbio
    if (BIO_write(rbio, clientData.inData.data(), clientData.inData.size()) <= 0) {
        std::cerr << "Failed to load encrypted data into BIO." << std::endl;
        return -1;
    }

    while (SSL_read_ex(ssl, decrypted_data.data() + total_read, decrypted_data.size() - total_read, &just_read)) {
        total_read += just_read;
        if (total_read > decrypted_data.size()) {
            decrypted_data.resize(total_read + 512);
        }
    }

    std::cout << "Encrypted data: ";
    for (auto byte: clientData.inData) std::cout << std::hex << static_cast<int>(byte) << " ";
    std::cout << std::endl;

    std::cout << "Decrypted data: ";
    for (auto byte: decrypted_data) std::cout << std::hex << static_cast<int>(byte) << " ";
    std::cout << std::endl;

this gives me output like this:

Encrypted data: 17 3 3 0 29 15 a6 f9 84 b1 fa fe af 70 88 e6 1b 90 d4 cc 54 ab c5 8e bc ba 52 6f 55 ed e0 fe c8 cb 62 d9 3c 35 94 6b 9a 6a 0 7d 48 a4 0 
Decrypted data: 50 52 49 20 2a 20 48 54 54 50 2f 32 2e 30 d a d a 53 4d d a d a 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

which is right connection headers for http2 PRI *HTTP2...
but when its run on second and all later "frames"

Encrypted data: 17 3 3 0 2c 3 28 60 2 7a ba 61 a8 9f ba e3 80 43 c4 f3 ec 1e 25 b2 c9 a2 4d 22 de 33 b3 a7 8c fe 81 56 e3 23 19 bb 41 1f e0 a6 d4 d6 7f d3 92 17 3 3 0 1e 8 62 51 4c 75 95 e8 8e 2c 55 3a 3e 18 78 49 52 26 6e 20 7e 8b 34 7e 9d c6 1c 5f b6 31 5a 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
Decrypted data: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

The decrypted data is empty, BIO_cntl tells that there is still data in rbio, but less then when writing to that rbio, calling BIO_reset didn't change anything and BIO_should_read is also false.

I am at a loss, all frames starts with 17 3 3 0 so this should be one message at a time.

Edit: The bio is BIO_s_mem as already mentioned, and I've read almost everything that's connected to BIO and SSL_read, but I'm not very good in english so, if its possible, I ask you for explanation of this

Edit 2:

Update: after logging the issue on second call i get 007E53F7FF7F0000:error:0A00010B:SSL routines:ssl3_get_record:wrong version number:../ssl/record/ssl3_record.c:358: Despite it having the same header bytes, 17 is application data, 3 3 is ssl3 and tlsv3.

g2px1 · 2024-04-29T17:55:05Z

g2px1
Apr 29, 2024
Author

Discussed in #24266

Originally posted by g2px1 April 25, 2024
SSL *ssl = static_cast<SSL *>(clientData.ssl);
    std::vector<uint8_t> decrypted_data;
    size_t total_read = 0;
    size_t just_read = 0;
    BIO *rbio = SSL_get_rbio(ssl);
    BIO_reset(rbio);
    if (!rbio) {
        std::cerr << "Read BIO not set." << std::endl;
        return -1;
    }

    decrypted_data.resize(clientData.inData.size());

    // Write the encrypted data to the existing rbio
    if (BIO_write(rbio, clientData.inData.data(), clientData.inData.size()) <= 0) {
        std::cerr << "Failed to load encrypted data into BIO." << std::endl;
        return -1;
    }

    while (SSL_read_ex(ssl, decrypted_data.data() + total_read, decrypted_data.size() - total_read, &just_read)) {
        total_read += just_read;
        if (total_read > decrypted_data.size()) {
            decrypted_data.resize(total_read + 512);
        }
    }

    std::cout << "Encrypted data: ";
    for (auto byte: clientData.inData) std::cout << std::hex << static_cast<int>(byte) << " ";
    std::cout << std::endl;

    std::cout << "Decrypted data: ";
    for (auto byte: decrypted_data) std::cout << std::hex << static_cast<int>(byte) << " ";
    std::cout << std::endl;
this gives me output like this:
Encrypted data: 17 3 3 0 29 15 a6 f9 84 b1 fa fe af 70 88 e6 1b 90 d4 cc 54 ab c5 8e bc ba 52 6f 55 ed e0 fe c8 cb 62 d9 3c 35 94 6b 9a 6a 0 7d 48 a4 0 
Decrypted data: 50 52 49 20 2a 20 48 54 54 50 2f 32 2e 30 d a d a 53 4d d a d a 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
which is right connection headers for http2 PRI *HTTP2... but when its run on second and all later "frames"
Encrypted data: 17 3 3 0 2c 3 28 60 2 7a ba 61 a8 9f ba e3 80 43 c4 f3 ec 1e 25 b2 c9 a2 4d 22 de 33 b3 a7 8c fe 81 56 e3 23 19 bb 41 1f e0 a6 d4 d6 7f d3 92 17 3 3 0 1e 8 62 51 4c 75 95 e8 8e 2c 55 3a 3e 18 78 49 52 26 6e 20 7e 8b 34 7e 9d c6 1c 5f b6 31 5a 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
Decrypted data: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
The decrypted data is empty, BIO_cntl tells that there is still data in rbio, but less then when writing to that rbio, calling BIO_reset didn't change anything and BIO_should_read is also false.

I am at a loss, all frames starts with 17 3 3 0 so this should be one message at a time.

Edit: The bio is BIO_s_mem as already mentioned, and I've read almost everything that's connected to BIO and SSL_read, but I'm not very good in english so, if its possible, I ask you for explanation of this

Edit 2:
Update: after logging the issue on second call i get 007E53F7FF7F0000:error:0A00010B:SSL routines:ssl3_get_record:wrong version number:../ssl/record/ssl3_record.c:358: Despite it having the same header bytes, 17 is application data, 3 3 is ssl3 and tlsv3.
On further testing with my good friend, it seems to be some kind of, bug.

Configuration:

First, a bit about configuration, I'm using -- Found OpenSSL: /usr/lib/x86_64-linux-gnu/libcrypto.so (found version "3.0.2") the command that i used for testing is either curl https://localhost:8080 -k -v --http1.1, curl https://localhost:8080 -k -v --http2, echo -e "GET / HTTP/1.1\r\nHost: 127.0.0.1\r\nConnection: close\r\n\r\n" | openssl s_client -connect 127.0.0.1:8080 -msg -debug -state.

The handshake is already finished by the time this function is called. This was checked by repeated calling to SSL_is_init_finished() on literally every step of the way. The agreed communication method is New, TLSv1.3, Cipher is TLS_AES_256_GCM_SHA384 Both rbio, wbio were set to BIO_s_mem after handshake finishes.
SSL *ssl = static_cast<SSL *>(clientData.ssl);
    BIO *rbio = BIO_new(BIO_s_mem());
    BIO *wbio = BIO_new(BIO_s_mem());

    if (!rbio || !wbio) {
        // Clean up in case of failure
        if (rbio) BIO_free(rbio);
        if (wbio) BIO_free(wbio);
        return -1;
    }

    SSL_set_bio(ssl, rbio, wbio);
    return 0;
the ssl_ctx is set up with SSL_CTX_set_options(ssl_ctx, SSL_OP_ALL | SSL_OP_NO_SSLv2 | SSL_OP_NO_SSLv3 | SSL_OP_NO_COMPRESSION | SSL_OP_NO_SESSION_RESUMPTION_ON_RENEGOTIATION);

If more data is needed, please ask.

Function update:

The function was simplified and modified quite a bit, so right now it's more like this example. Note that modifying the example code it results in the same error where no data is decoded.

It is also good to note that no data is being written in the socket by our code or SSL_write, at any point, after the handshake is finished.
template<class EndpointHandlerType>
void Http1Context<EndpointHandlerType>::readCallbackHTTPS(
        usub::core::ClientData &clientData) {
    SSL *ssl = static_cast<SSL *>(clientData.ssl);
    std::vector<uint8_t> decrypted_data;
    size_t total_read = 0;
    size_t just_read = 0;
    int ret;
    BIO *rbio = SSL_get_rbio(ssl);

    if (!rbio) {
        std::cerr << "Read BIO not set." << std::endl;
        return;
    }

    decrypted_data.resize(clientData.inData.size());

    if (BIO_write(rbio, clientData.inData.data(), clientData.inData.size()) <= 0) {
        std::cerr << "Failed to load encrypted data into BIO." << std::endl;
        return;
    }

    do {
        ret = SSL_read(ssl, decrypted_data.data(), decrypted_data.size());
    } while (ret > 0);

    int ssl_err = SSL_get_error(ssl, ret);
    if (ssl_err == SSL_ERROR_WANT_READ || ssl_err == SSL_ERROR_WANT_WRITE) {
        do {
            ret = BIO_read(SSL_get_wbio(ssl), decrypted_data.data(), decrypted_data.size());
        } while (ret > 0);
    } else {
        ERR_print_errors_fp(stderr);
    }
    // ... logging decrypted and encrypted data.
 }
The difference is when we encounter other error but WANT_READ or WANT_WRITE, we just return in his example.

First call to readCallbackHTTPS:

Now returning to the problem, the error is first call to readCallbackHTTPS successfully decrypts any message, be it provided using openssl command
Encrypted data: 17 3 3 0 48 64 8c b7 b3 36 dc 91 d2 fb 86 2d 84 6d ed cc d4 da f1 60 b3 b5 78 2e a2 5f ed a8 61 29 58 b1 b8 79 47 c2 5 c6 7f b eb 78 bd 20 38 59 c4 60 e5 6c 22 40 89 7e 9d 63 d0 a0 f3 90 7a f0 fc 31 4d d8 f3 7f 66 ce 72 7b 77 0 
Decrypted data 1: GET / HTTP/1.1
Host: 127.0.0.1
Connection: close
Same with CURL commands, first run is always decrypted

Second call:
009EC418EE7F0000:error:0A00010B:SSL routines:ssl3_get_record:wrong version number:../ssl/record/ssl3_record.c:358:
Encrypted data: 17 3 3 0 13 83 ee 7 b8 ad a2 d9 1f d2 cb c5 5 77 72 7c b5 90 1d 96 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
Decrypted data 1:                                                          // Literally nothing the hex output is all 0s
openssl command log can be read here, it's a local server with a self-signed certificate, so no harm done in posting it

This part near the end receives a session ticket from somewhere. Then sends some Application data (code 17) that can't be decrypted
SSL_connect:SSLv3/TLS read server session ticket
read R BLOCK
DONE
>>> TLS 1.2, RecordHeader [length 0005]
    17 03 03 00 13
>>> TLS 1.2, InnerContent [length 0001]
    15
write to 0x557dfd5ed720 [0x557dfd6ce483] (24 bytes => 24 (0x18))
0000 - 17 03 03 00 13 83 ee 07-b8 ad a2 d9 1f d2 cb c5   ................
0010 - 05 77 72 7c b5 90 1d 96-                          .wr|....

0 replies

t8m · 2024-04-30T06:41:02Z

t8m
Apr 30, 2024
Maintainer

@mattcaswell Any idea here what could be happening?

0 replies

nhorman · 2024-04-30T07:47:05Z

nhorman
Apr 30, 2024
Maintainer

FWIW, I've tried the example attached and on the latest openssl, the issue doesn't reproduce for me

1 reply

StormLord07 Apr 30, 2024

Hm, did your version decode 2 messages or only one? Because example also recieves two but outputs only first one.

This was checked through gdb and/or modifying on_read_cb

StormLord07 · 2024-05-01T18:23:50Z

StormLord07
May 1, 2024

We,ve moved onto the openssl-3.2.1 that i build from releases and the error message updated to

40471431D07F0000:error:0A0001BB:SSL routines:tls13_validate_record_header:bad record type:ssl/record/methods/tls13_me      th.c:185:
   22 40471431D07F0000:error:0A000139:SSL routines::record layer failure:ssl/record/rec_layer_s3.c:645:

Edit:
I deleted all http protocol handling to simplify stuff.
And I'm now using this command to test things, where I can just test plaintext stuff without session just closing.

openssl s_client -connect localhost:8080 -tls1_3 -msg -debug -state
openssl s_client -connect localhost:8080 -tls1_2 -msg -debug -state

The error still stands. however now I know that it cant decode even plaintext stuff after first call.

right here i Used -tls1_2 command

Openssl command output:

1  // <- Plaintext
>>> TLS 1.2, RecordHeader [length 0005]
    17 03 03 00 13
>>> TLS 1.2, InnerContent [length 0001]
    17
write to 0x563637339720 [0x56363741bd53] (24 bytes => 24 (0x18))
0000 - 17 03 03 00 13 33 b0 fc-5c f5 6b 20 7c 7b be 2e   .....3..\.k |{..
0010 - 0d 91 7e 22 c1 db 0f 43-                          ..~"...C
2  // <- Plaintext
>>> TLS 1.2, RecordHeader [length 0005]
    17 03 03 00 13
>>> TLS 1.2, InnerContent [length 0001]
    17
write to 0x563637339720 [0x56363741bd53] (24 bytes => 24 (0x18))
0000 - 17 03 03 00 13 eb 4b a9-66 d0 0f dd 11 63 56 ef   ......K.f....cV.
0010 - dc 0f 1b 7b 14 f6 18 5a-                          ...{...Z

my server output:

05/01/24 18:41:49 [info]: ret is -1, error is WANT_READ
Encrypted data: 17 3 3 0 13 33 b0 fc 5c f5 6b 20 7c 7b be 2e d 91 7e 22 c1 db f 43 0 
Decrypted data 1: 1  // First message was decoded

40A78441A77F0000:error:0A0001BB:SSL routines:tls13_validate_record_header:bad record type:ssl/record/methods/tls13_meth.c:185:
40A78441A77F0000:error:0A000139:SSL routines::record layer failure:ssl/record/rec_layer_s3.c:645:
Encrypted data: 17 3 3 0 13 eb 4b a9 66 d0 f dd 11 63 56 ef dc f 1b 7b 14 f6 18 5a 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 
Decrypted data 1:    // Message is not decoded (in vim it shows as a lot of ^@...)

No data manipulation is done on data, it was recieved using recv. Nothing is written to a socket, full message received. Still decoding is not done.

The lowest point where I get error seems to be at ssl/record/methods/tls_common.c:982


983
984         if (rec->rec_version != rl->version) {
985             RLAYERfatal(rl, SSL_AD_PROTOCOL_VERSION, SSL_R_WRONG_VERSION_NUMBER);
986             return 0;
987         }

(gdb) print rec->rec_version
$7 = 5891
(gdb) print rl->version
$8 = 771

There is a version mismatch. Unfortunately, that's all I can provide.

I beg for your help. I'm losing it...

0 replies

StormLord07 · 2024-05-01T20:09:55Z

StormLord07
May 1, 2024

Ok @t8m, sorry for pinging, I seem to have found the issue, and need a bit of clarification. The problem seemed to be that for safety’s sake, the library I used added, zeroes at the end of the data read from the socket. And passing it into BIO, then SSL_read. Seems to fail if there is a lot of them (zeroes).

When I stripped zeroes, it was able to decode all messages. no matter how much.

Is this desired behaviour? Because it doesn't seem so, why on earth then i need the data length then?

Also now there is no error and if there is some data it is decoded but still last part before (01 00 alert)
Encrypted data: 17 3 3 0 13 bf 8 aa a 91 e1 32 34 c3 97 57 ec bb 1a ce 11 71 a4 ee Decrypted data 1: 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0

is not decrypted in any way

>>> TLS 1.2, RecordHeader [length 0005] 17 03 03 00 13 >>> TLS 1.2, InnerContent [length 0001] 15 write to 0x559226dba720 [0x559226e9b483] (24 bytes => 24 (0x18)) 0000 - 17 03 03 00 13 ec 1a bf-14 41 30 77 e6 81 fe 19 .........A0w.... 0010 - 32 ae 6e 57 59 02 0f e5- 2.nWY... >>> TLS 1.3, Alert [length 0002], warning close_notify 01 00
EDIT: It correctly sets ssl error to ERROR_ZERO_RETURN

On every read I still get ERROR_WANT_READ though.

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

OpenSSL Read/Write into a BIO_s_mem works only on first call per connection #24266

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 5 comments 1 reply

{{title}}

Discussed in #24266

Configuration:

Function update:

First call to readCallbackHTTPS:

Second call:

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Select a reply

OpenSSL Read/Write into a BIO_s_mem works only on first call per connection #24266

g2px1 Apr 25, 2024

Replies: 5 comments · 1 reply

g2px1 Apr 29, 2024 Author

Discussed in #24266

Configuration:

Function update:

First call to readCallbackHTTPS:

Second call:

t8m Apr 30, 2024 Maintainer

nhorman Apr 30, 2024 Maintainer

StormLord07 Apr 30, 2024

StormLord07 May 1, 2024

StormLord07 May 1, 2024

g2px1
Apr 25, 2024

Replies: 5 comments 1 reply

g2px1
Apr 29, 2024
Author

t8m
Apr 30, 2024
Maintainer

nhorman
Apr 30, 2024
Maintainer

StormLord07
May 1, 2024

StormLord07
May 1, 2024