How to debug a TLSv1.3 protocol problem?

[Matt Caswell]

On 20/05/2020 17:52, Claus Assmann wrote:
> On Wed, May 20, 2020, Matt Caswell wrote:
> 
> [Thanks for still helping me with this!]
> 
>> Can you test the underlying socket to see if it has been closed down in
>> an orderly way (i.e. recv() should return 0 on the socket if so)? That
> 
> Yes, that what happens.
> 
> So I added some debugging to the client and it shows:
> 
> SSL info:
> read server hello
> write change cipher spec
> write client hello

So the client has written the first clientHello, read the serverhello,
and then written the CCS and 2nd clientHello. The next thing it will
expect to do is read the serverhello again.

> 
> and I/O layer (only last/relevant part):
> want_write=523, want_read=5
> ... write ... and then
> want_read=5 -< read=OK, num_read=5
> want_write=0, want_read=1
> want_read=1 -> read=OK, num_read=1
> want_write=0, want_read=5
> want_read=5 -> read=TIMEOUT, num_read=0

So presumably this is an attempt to read the header data of the next
message (a TLS record header is 5 bytes in length), i.e. the next
ServerHello. But we already know from your earlier analysis that this is
never going to come because the server has already given up before it
gets that far.


> 
> Explanation:
> want_write = BIO_ctrl_pending(network_bio)
> want_read = BIO_ctrl_get_read_request(network_bio)
> 
> I didn't instrument the write part, only the read part.
> want_read>0 -> invoke read, check result:  read=STATUS, num_read=N
> So the last read does not get the data the library wants,
> and hence the client fails and closes the connection.

This sounds odd. Why does the client fail because it hasn't read the
expected data yet? Normally (with non-blocking sockets), a failure to
read the expected data will result in SSL_get_error() returning
SSL_ERROR_WANT_READ - indicating that the data is not currently
available and we should retry again later. That isn't a fatal error, so
the connection should not be closed.

So - when you say the client fails - what exactly happens? What does
SSL_get_error() return at that point?

Matt