BIO_read fails when performing DTLS handshake

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

BIO_read fails when performing DTLS handshake

Matthew

Hello everyone!

This is my first "post" to the mailing list.

I have been working on an OSSL wrapper for C# for several months, and am currently implementing the DTLS portion. I've succeeded in establishing a DTLS session with cookie exchange, sending and receiving data, and gracefully closing the connection.

I've appended a snippet of the C# for those who may be curious.

Once I got the ugly bits working, I started chipping away at building a nice API. This is where my problem started.

I've spend hours debugging and I think I've hit the limit of my abilities. I have 2 unit tests in C# (at the end of this mail). The first one (BasicDtlsTest) is a strightforward echo of one client's data. The second (BasicListenerTest) is essentially the same, only wrapped in a friendlier API.

Specifically, my problem is that the second unit test fails to reply to a ClientHello with a cookie (it successfully send the HelloVerifyRequest with the cookie). I have traced the problem to where I think things go wrong. I followed the call stack starting from SSL_do_handshake.

SSL_do_handshake -> ossl_statem_accept -> state_machine -> read_state_machine -> dtls_get_message -> dtls_get_reassembled_message -> dtls1_read_bytes -> dtls1_get_record -> ssl3_read_n.

I stepped through both the working unit test and the non-working one in order to find differences in the result. What I have found is that, in ssl3_read_n, the call to BIO_read (line 300 in rec_layer_s3.c) returns -1.

ret = BIO_read(s->rbio, pkt + len + left, max - left);

At this line, pkt is a char[8], len and left = 0 and max = 16717

I'm curious as to why the "data" argument is not a pointer to a buffer, but rather the result of an addition. Maybe my C isnt strong enough...

Going even further down the stack, I finally end up at the bottom:

static int mem_read(BIO *b, char *out, int outl)

And this is where the -1 that is a thorn in my side originates:

ret = (outl >= 0 && (size_t)outl > bm->length) ? (int)bm->length : outl;

At this line, (size_t)outl is 16717 and bm->length is 0, so ret = (int)bm->length. Then, a little further:

if ((out != NULL) && (ret > 0)) {
    memcpy(out, bm->data, ret);
    bm->length -= ret;
    bm->max -= ret;
    bm->data += ret;
} else if (bm->length == 0) {
    ret = b->num;
    if (ret != 0)
        BIO_set_retry_read(b);
}
return ret;


At this point, ret = -1 and that just gets propagated all the way back up, causing the entire record to be thrown out and ignored. The client keeps sending ClientHellos with the cookie and the server keeps ignoring them.

I really have no idea what is happening.

You can see my entire source code here:https://gitlab.com/matthew.goulart/openssl.net

I realize it's a lot to ask you to read all of my code, so if anyone has suggestions as to what I might try next, I'm open!


Thanks!

[TestMethod]
public async Task BasicDtlsTest()
{
    var socket = new Socket(AddressFamily.InterNetwork, SocketType.Dgram, ProtocolType.Udp);
        socket.SetSocketOption(SocketOptionLevel.Socket, SocketOptionName.ReuseAddress, true);
        socket.Bind(new IPEndPoint(IPAddress.Loopback, 1114));

        var ctx = new Context(SslMethod.DTLS);
        ctx.UseCertificateFile("certs/cert.crt", CertificateType.PEM);
        ctx.UsePrivateKeyFile("certs/key.key", CertificateType.PEM);
        ctx.SetVerify(SslVerificationKind.SSL_VERIFY_PEER | SslVerificationKind.SSL_VERIFY_CLIENT_ONCE,
            VerifyCert);
        ctx.SetGenerateCookieCallback(GenerateCookie);
        ctx.SetVerifyCookieCallback(VerifyCookie);
        ctx.SetOptions(SslOptions.SSL_OP_COOKIE_EXCHANGE);

        var ssl = new Ssl(ctx, new MemoryBio(), new MemoryBio());

        var remoteEp = new IPEndPoint(IPAddress.Any, 0);

        var owner = MemoryPool<byte>.Shared.Rent(4096);
        var mem = owner.Memory;
        MemoryMarshal.TryGetArray(mem, out ArraySegment<byte> seg);
        var buf = seg.Array;

        SocketReceiveFromResult rcv;
        BioAddress bioAddr = new BioAddress();

        rcv = await socket.ReceiveFromAsync(seg, SocketFlags.None, new IPEndPoint(IPAddress.Any, 0));
        ssl.ReadBio.Write(buf, rcv.ReceivedBytes);

        Ssl.DtlsListen(ssl, bioAddr);

        var bytesRead = ssl.WriteBio.Read(buf, Ssl.TLS_MAX_RECORD_SIZE);
        await socket.SendToAsync(seg.Slice(0, bytesRead), SocketFlags.None, rcv.RemoteEndPoint);

        rcv = await socket.ReceiveFromAsync(seg, SocketFlags.None, new IPEndPoint(IPAddress.Any, 0));
        ssl.ReadBio.Write(buf, rcv.ReceivedBytes);

        Assert.IsTrue(Ssl.DtlsListen(ssl, bioAddr));

        socket.Close();
        
        var clientSock = new Socket(AddressFamily.InterNetwork, SocketType.Dgram, ProtocolType.Udp);
        clientSock.SetSocketOption(SocketOptionLevel.Socket, SocketOptionName.ReuseAddress, true);
        clientSock.Bind(new IPEndPoint(IPAddress.Loopback, 1114));
        clientSock.Connect(rcv.RemoteEndPoint);

        while (!ssl.IsInitFinished)
        {
            Debug.WriteLine($"Current handshake state is {ssl.HandshakeState}");

            int bytesRcvd = await clientSock.ReceiveAsync(mem, SocketFlags.None);
            Debug.WriteLine($"{bytesRcvd} bytes read from socket.");
            int bytesWritten = ssl.ReadBio.Write(buf, bytesRcvd);
            Debug.WriteLine($"{bytesWritten} bytes written to SSL");
            Debug.Assert(bytesRcvd == bytesWritten);

            int acc = ssl.Accept();
            SslError result = ssl.GetError(acc);
            if (result == SslError.SSL_ERROR_SYSCALL) throw new SslException(ErrorHandler.GetError());

            Debug.WriteLine($"Auth result was: {result}");

            if (ssl.WriteBio.BytesPending > 0)
            {
                Debug.WriteLine($"{ssl.WriteBio.BytesPending} bytes pending in write bio");
                bytesRead = ssl.WriteBio.Read(buf, 4096);
                Debug.WriteLine($"{bytesRead} bytes read from write bio");
                int bytesSent = await clientSock.SendAsync(mem.Slice(0, bytesRead), SocketFlags.None);
                Debug.WriteLine($"{bytesSent} bytes sent to client");
            }
        }

        ssl.Shutdown();

        if (ssl.WriteBio.BytesPending > 0)
        {
            Debug.WriteLine($"{ssl.WriteBio.BytesPending} bytes pending in write bio");
            bytesRead = ssl.WriteBio.Read(buf, 4096);
            Debug.WriteLine($"{bytesRead} bytes read from write bio");
            int bytesSent = await clientSock.SendAsync(mem.Slice(0, bytesRead), SocketFlags.None);
            Debug.WriteLine($"{bytesSent} bytes sent to client");
        }
}

[TestMethod]
public async Task BasicListenerTest()
{
    var listener = new DtlsListener(new IPEndPoint(IPAddress.Loopback, 1114), "certs/cert.crt",
        "certs/key.key");
    listener.Start();
        
    Debug.WriteLine("Server => Signalling ready to accept client");

    var client = await listener.AcceptClientAsync();
        
    Debug.WriteLine($"Server => Client session started");

    await client.AuthenticateAsServerAsync();
        
    Debug.WriteLine("Server => Client successfully authenticated");

    var msg = await client.ReceiveAsync();

    Assert.IsTrue(msg.Length >= 4 && msg.Length <= 5);
    Assert.AreEqual("test", Encoding.Default.GetString(msg.Span.Slice(0, 4)));

    await client.SendAsync(MemoryMarshal.AsMemory(msg));

    await listener.Stop();
}
    }
Reply | Threaded
Open this post in threaded view
|

RE: BIO_read fails when performing DTLS handshake

Michael Wojcik
> From: openssl-users [mailto:[hidden email]] On Behalf Of Matthew
> Sent: Friday, August 30, 2019 23:06

Welcome to the list. When posting, please remember to tell us what version of OpenSSL you're using, and what platform you're on.

Since you're talking about C#, I'll assume the platform is Windows. And I'll assume you're working with OpenSSL 1.1.1c, because that would be the sensible thing to do. But it would be better if I didn't have to make either assumption.

> I stepped through both the working unit test and the non-working one in order to find
> differences in the result. What I have found is that, in ssl3_read_n, the call to
> BIO_read (line 300 in rec_layer_s3.c) returns -1.
> ret = BIO_read(s->rbio, pkt + len + left, max - left);

> At this line, pkt is a char[8], len and left = 0 and max = 16717

I don't think pkt is a char[8]. It's defined at the top of ssl3_read_n as unsigne char *pkt.

And it had better not be a char[8], since 1) plain char and unsigned char are not the same type, and 2) if max - left is 16717, then you have potential for a massive buffer overflow.

> I'm curious as to why the "data" argument is not a pointer to a buffer, but rather
> the result of an addition. Maybe my C isnt strong enough...

It's a pointer into a buffer (specifically, in this case, a pointer to the start of a buffer). In C, adding an integer type to a pointer results in a pointer value. That is, in fact, basic C.

(At least you're only reading C, not writing it. I have in recent days seen C code posted by people who really need to put the language down and back away slowly. C should not be used by people who don't know the language very well.)

> Going even further down the stack, I finally end up at the bottom:
> static int mem_read(BIO *b, char *out, int outl)
> ...
> } else if (bm->length == 0) {
>     ret = b->num;
>     if (ret != 0)
>         BIO_set_retry_read(b);
> }
> return ret;

> At this point, ret = -1...

So b->num == -1 when you arrived here with bm->length == 0.

The num field is initialized to -1 when a memory BIO is initialized (mem_init in bss_mem.c). And the length is 0, which means there's no data in the BIO.

I don't know (without reading through your code, which I don't have time to do right now) why you're using a memory BIO, or how you've initialized it. It looks like you've simply never put any data into it.

--
Michael Wojcik
Distinguished Engineer, Micro Focus



Reply | Threaded
Open this post in threaded view
|

Re: BIO_read fails when performing DTLS handshake

Matthew

Hi Michael,


Of course I should have provided a version: 1.1.1c, on linux-x64 (dotnet core 2.2)

Just a quick question while I prepare a clearer, more contextual and concise email about my problem;

Is it normal for an SSL's readBio to be empty right after DTLSv1_listen?

I noticed that after calling DTLSv1_listen, and it returning 1, the SSL's readBio's bytes pending = 0. Would this not force the client to send a second hello with cookie? Or does DTLSv1_listen perform the clientHello processing and then let SSL_accept send the response?

On 2019-08-31 10:51 a.m., Michael Wojcik wrote:
From: openssl-users [[hidden email]] On Behalf Of Matthew
Sent: Friday, August 30, 2019 23:06
Welcome to the list. When posting, please remember to tell us what version of OpenSSL you're using, and what platform you're on.

Since you're talking about C#, I'll assume the platform is Windows. And I'll assume you're working with OpenSSL 1.1.1c, because that would be the sensible thing to do. But it would be better if I didn't have to make either assumption.

I stepped through both the working unit test and the non-working one in order to find
differences in the result. What I have found is that, in ssl3_read_n, the call to
BIO_read (line 300 in rec_layer_s3.c) returns -1.
ret = BIO_read(s->rbio, pkt + len + left, max - left);

      
At this line, pkt is a char[8], len and left = 0 and max = 16717
I don't think pkt is a char[8]. It's defined at the top of ssl3_read_n as unsigne char *pkt.

And it had better not be a char[8], since 1) plain char and unsigned char are not the same type, and 2) if max - left is 16717, then you have potential for a massive buffer overflow.

I'm curious as to why the "data" argument is not a pointer to a buffer, but rather
the result of an addition. Maybe my C isnt strong enough...
It's a pointer into a buffer (specifically, in this case, a pointer to the start of a buffer). In C, adding an integer type to a pointer results in a pointer value. That is, in fact, basic C.

(At least you're only reading C, not writing it. I have in recent days seen C code posted by people who really need to put the language down and back away slowly. C should not be used by people who don't know the language very well.)

Going even further down the stack, I finally end up at the bottom:
static int mem_read(BIO *b, char *out, int outl)
...
} else if (bm->length == 0) {
    ret = b->num;
    if (ret != 0)
        BIO_set_retry_read(b);
}
return ret;

      
At this point, ret = -1...
So b->num == -1 when you arrived here with bm->length == 0.

The num field is initialized to -1 when a memory BIO is initialized (mem_init in bss_mem.c). And the length is 0, which means there's no data in the BIO.

I don't know (without reading through your code, which I don't have time to do right now) why you're using a memory BIO, or how you've initialized it. It looks like you've simply never put any data into it.

--
Michael Wojcik
Distinguished Engineer, Micro Focus



Reply | Threaded
Open this post in threaded view
|

RE: BIO_read fails when performing DTLS handshake

Michael Wojcik
> From: openssl-users [mailto:[hidden email]] On Behalf Of Matthew
> Sent: Saturday, August 31, 2019 14:40

> Is it normal for an SSL's readBio to be empty right after DTLSv1_listen?

Offhand I don't know. I've never used DTLS. Perhaps someone who knows more about it will join in.

--
Michael Wojcik
Distinguished Engineer, Micro Focus



Reply | Threaded
Open this post in threaded view
|

Re: BIO_read fails when performing DTLS handshake

Matt Caswell-2
In reply to this post by Matthew


On 31/08/2019 19:40, Matthew wrote:

> Hi Michael,
>
>
> Of course I should have provided a version: 1.1.1c, on linux-x64 (dotnet core 2.2)
>
> Just a quick question while I prepare a clearer, more contextual and concise
> email about my problem;
>
> Is it normal for an SSL's readBio to be empty /right/ after DTLSv1_listen?
>
> I noticed that after calling DTLSv1_listen, and it returning 1, the SSL's
> readBio's bytes pending = 0. Would this not force the client to send a second
> hello with cookie? Or does DTLSv1_listen perform the clientHello processing and
> then let SSL_accept send the response?

DTLSv1_listen() (in 1.1.1c) does the following (simplified):

- Listens for incoming ClientHellos
- Reads the ClientHello from the underlying BIO
- Checks to see if the ClientHello contains a cookie or not
- If the cookie is NOT present then it sends a HelloVerifyRequest back and goes
back to the first step above
- Otherwise it verifies the coolie. If verification fails then it sends a
HelloVerifyRequest and goes back to the first step above.
- Otherwise if verification succeeds then it buffers the received ClientHello
record internally in the SSL object and returns 1

So it is normal after DTLSv1_listen() for the BIO to be empty because it has
already read the ClientHello and has buffered it internally.

Note that running DTLS over a mem bio may not always work as expected. Mem bio's
are implemented conceptually as a stream. Therefore they do not respect packet
boundaries and so you may get unusual behaviour. Additionally it doesn't support
any of the datagram related ctrls that a dgram BIO supports. Therefore it can't
do things like identify the address of the peer and query the MTU of the link.

In other words I would recommend using dgram bio rather than a mem bio.

Matt

>
> On 2019-08-31 10:51 a.m., Michael Wojcik wrote:
>>> From: openssl-users [mailto:[hidden email]] On Behalf Of Matthew
>>> Sent: Friday, August 30, 2019 23:06
>> Welcome to the list. When posting, please remember to tell us what version of OpenSSL you're using, and what platform you're on.
>>
>> Since you're talking about C#, I'll assume the platform is Windows. And I'll assume you're working with OpenSSL 1.1.1c, because that would be the sensible thing to do. But it would be better if I didn't have to make either assumption.
>>
>>> I stepped through both the working unit test and the non-working one in order to find
>>> differences in the result. What I have found is that, in ssl3_read_n, the call to
>>> BIO_read (line 300 in rec_layer_s3.c) returns -1.
>>> ret = BIO_read(s->rbio, pkt + len + left, max - left);
>>> At this line, pkt is a char[8], len and left = 0 and max = 16717
>> I don't think pkt is a char[8]. It's defined at the top of ssl3_read_n as unsigne char *pkt.
>>
>> And it had better not be a char[8], since 1) plain char and unsigned char are not the same type, and 2) if max - left is 16717, then you have potential for a massive buffer overflow.
>>
>>> I'm curious as to why the "data" argument is not a pointer to a buffer, but rather
>>> the result of an addition. Maybe my C isnt strong enough...
>> It's a pointer into a buffer (specifically, in this case, a pointer to the start of a buffer). In C, adding an integer type to a pointer results in a pointer value. That is, in fact, basic C.
>>
>> (At least you're only reading C, not writing it. I have in recent days seen C code posted by people who really need to put the language down and back away slowly. C should not be used by people who don't know the language very well.)
>>
>>> Going even further down the stack, I finally end up at the bottom:
>>> static int mem_read(BIO *b, char *out, int outl)
>>> ...
>>> } else if (bm->length == 0) {
>>>     ret = b->num;
>>>     if (ret != 0)
>>>         BIO_set_retry_read(b);
>>> }
>>> return ret;
>>> At this point, ret = -1...
>> So b->num == -1 when you arrived here with bm->length == 0.
>>
>> The num field is initialized to -1 when a memory BIO is initialized (mem_init in bss_mem.c). And the length is 0, which means there's no data in the BIO.
>>
>> I don't know (without reading through your code, which I don't have time to do right now) why you're using a memory BIO, or how you've initialized it. It looks like you've simply never put any data into it.
>>
>> --
>> Michael Wojcik
>> Distinguished Engineer, Micro Focus
>>
>>
>>