Client: Last SSL payload from server not being waited for breaks stuff

[HoneyryderChuck]

As said in the other issue, I've managed to get my tests running with ruby-tls. However, from time to time (and quite often if I'm running them all at once) I'm getting errors, which seems to be due to the way the handshake is processed.

I've also implemented my client with ruby-tls, and I'm sure that the error is there (server with ruby-tls seems to work fine when ussing openssl as client). So, my client is only able to send requests after having an enabled ssl connection, which in my case means "handshake has been complete":

def initialize(...)
 ...
  @handshake_completed = false
  io_read_write until @handshake_completed
end
...
def handshake_cb(protocol)
  @handshake_completed = true
  puts "handshake completed: #{protocol.inspect}"
end

I get then two different logs, for when it succeeds and when it fails (gonna copy the relevant part only):

# it succeeds
client: handshake completed: :h2
client: encrypted: "\x16\x03\x03\x01\x06\x10...."
client: written 318 bytes
server: encrypted: "\x16\x03\x03\x00\xAA...."
client: frame was sent!
client: {:type=>:settings, :stream=>0, :payload=>[[:settings_max_concurrent_streams, 100]]}
client: frame was sent!
client: {:type=>:headers, :flags=>[:end_headers, :end_stream], :payload=>[["accept", "*/*"], [":scheme", "https"], [":method", "GET"], [":path", "/"]], :stream=>1}
client response (HTTP/2) (stream {1): is half closed
client: read 226 bytes
client: encrypted: "\x17\x03\x03\x00P\x00..."
....


# it fails
client: handshake completed: :h2
client: encrypted: "\x16\x03\x03\x01\x06..."
client: written 318 bytes
client: frame was sent!
client: {:type=>:settings, :stream=>0, :payload=>[[:settings_max_concurrent_streams, 100]]}
client: frame was sent!
client: {:type=>:headers, :flags=>[:end_headers, :end_stream], :payload=>[["accept", "*/*"], ["accept-encoding", "deflate"], [":scheme", "https"], [":method", "GET"], [":path", "/"]], :stream=>1}
client response (HTTP/2) (stream {1): is half closed
server: encrypted: "\x16\x03\x03\x00\xAA...."
client: read 226 bytes
client: shutdown

so, in both cases, what happens is: after the handshake has been completed, it sends some payload to the server (I assume this is the change cipher message from the spec?). But after, I proceed to start building buffering tls packets without processing the last ssl handshake message coming from the server, which is (probably) invalidating my already build TLS packets, and then boom, shutdown.

I think that the handshake should only be considered complete after those last tls messages, and then my assertion io_read_write until @handshake_completed could be considered valid. Either that or I need a different method/variable/callback to tell me if handshake is really over.

I've looked at the source code and I didn't find it. Is there a way to signal to usercode when the change-cipher dance is over?

[HoneyryderChuck]

I've implemented a workaround, which does the trick for now:

def initialize(...)
 ...
  io_rw until @handshake_completed
  io_rw(timeout: 0.2) rescue nil
...

meaning: read and write to server til handshake complete, and then try to read some more just in case server has sent some, and continue otherwise. For testing purposes, it's an ok workaround, but I'd need something more robust for a client implementation.

[stakach]

Weird, the callbacks all come out of openssl so the negotiation should definitely have completed.
You can see my implementation here: https://github.com/cotag/libuv/blob/master/lib/libuv/tcp.rb#L53

Tested against a wide range of servers and devices however I haven't done much with http2
The Libuv library for the lower level IO stuff is pretty awesome too, makes life super easy

[HoneyryderChuck]

I think that the fact that we are using different I/O stacks might influence the outcome.

The problem is what happens "after handshake". I think (if I read about TLS correctly) that there are two additional messages exchanged between client/server, for "cipher change", and this is what's causing the weird behaviour. If I start building TLS packets on the client before the cipher coming from the server changes, I'm sending it invalid packets. It's a question of timing, but also of signalizing to the client/server when is the TLS initialization process really over. Now, if only there was a callback for that... haven't found one yet, living with the workaround for now.

[HoneyryderChuck]

Maybe my problem here is the meaning of "handshake", and looking at my logs, I think that the handshake is considered "complete":

• client: after the server certificate has been verified
• server: after the DH channel is established (before server sends the certificate)

which seems not to be enough to start building TLS packets (for that, the last packets need to be exchanged).