Crystal: TLS bug

[arubinofaux]

Trying to connect to a socket over wss:// will result in a time out.

Running Crystal 0.22.0 (2017-04-20) LLVM 4.0.0

code

payload = {"type" => "subscribe", "product_ids" => ["BTC-USD"]}.to_json

ws = HTTP::WebSocket.new(URI.parse("wss://ws-feed.gdax.com"))

ws.on_message do |msg|
  msg = JSON.parse(msg).as_h
  puts msg
end

ws.send(payload)

ws.on_close do |msg|
  msg = JSON.parse(msg).as_h
  puts msg
end

ws.run

error

Unexpected end of http request (Exception)
0x107ab5fc5: *CallStack::unwind:Array(Pointer(Void)) at ??
0x107ab5f61: *CallStack#initialize:Array(Pointer(Void)) at ??
0x107ab5f38: *CallStack::new:CallStack at ??
0x107a9c251: *raise<Exception>:NoReturn at ??
0x107a9c231: *raise<String>:NoReturn at ??
0x107be72cf: *HTTP::Client::Response::from_io<(OpenSSL::SSL::Socket::Client | TCPSocket), Bool, Bool>:HTTP::Client::Response at ??
0x107be7279: *HTTP::Client::Response::from_io<(OpenSSL::SSL::Socket::Client | TCPSocket)>:HTTP::Client::Response at ??
0x107b900d1: *HTTP::WebSocket::Protocol::new<String, String, (Int32 | Nil), Bool>:HTTP::WebSocket::Protocol at ??
0x107b8fcd0: *HTTP::WebSocket::Protocol::new<URI>:HTTP::WebSocket::Protocol at ??
0x107bd6489: *HTTP::WebSocket::new<URI>:HTTP::WebSocket at ??
0x107a9bb57: __crystal_main at ??
0x107aad198: main at ??
make: *** [run] Error 1

[RX14]

This was broken by 32e4dd51b6699986b8cdeba0cec487171e18846a. I'm debugging this now, just making a note in case I get distracted and forget to report my findings ;)

[RX14]

This is definitely a SSL issue, this code can reproduce the issue without websockets:

require "openssl"

io = TCPSocket.new("google.com", 443)
ssl = OpenSSL::SSL::Socket::Client.new(io)

request = <<-HTTP
  GET / HTTP/1.1
  Content-Length: 0


  HTTP

ssl.puts(request.gsub('\n', "\r\n"))

slice = Bytes.new(1)
size = ssl.read(slice)
pp size, String.new(slice[0, size])

I have no idea what HTTP::Client is doing differently to make it still work but 32e4dd5 definitely broke OpenSSL::SSL::Socket.

[RX14]

Oh, forgot to say that before and after the broken commit, the crystal BIO works just fine and reads TLS data. After the broken commit, ssl_read returns 0, whereas before it returns data. And I have no idea why changing the method name would affect the results, because reading exactly 8192 bytes from a OpenSSL::SSL::Socket::Client works just fine before the change. Weird.

[RX14]

Ended up being an errant flush... I was so busy debugging the receive side I didn't think about the sending! Fix is in #4386.

[arubinofaux]

Thank you so much @RX14 this was driving me crazy

[asterite]

Seems to be fixed by #4386

@RX14 Thank you! And let me know if your fix wasn't for this particular issue.