JuliaLang / MbedTLS.jl

Wrapper around mbedtls
Other
41 stars 50 forks source link

MbedTLS > 0.6.3 problem with WebSockets #186

Open christopher-dG opened 6 years ago

christopher-dG commented 6 years ago

There seems to be a sort of lag/offset of one message when reading from a WebSocket on new versions of MbedTLS.jl.

using Dates, WebSockets
function mwe()
    WebSockets.open("wss://echo.websocket.org") do io
        @async while isopen(io)
            x = String(read(io))
            println(now(), " READ: ", x)
        end
        for i in 1:5
            write(io, string(i))
            println(now(), " WROTE: ", i)
            sleep(rand(1:5))
        end
        println("done")
    end
end

Expected behaviour, WebSockets v1.0.3, MbedTLS 0.6.3:

2018-11-02T16:41:19.119 WROTE: 1
2018-11-02T16:41:19.382 READ: 1
2018-11-02T16:41:21.122 WROTE: 2
2018-11-02T16:41:21.318 READ: 2
2018-11-02T16:41:24.126 WROTE: 3
2018-11-02T16:41:24.401 READ: 3
2018-11-02T16:41:25.127 WROTE: 4
2018-11-02T16:41:25.322 READ: 4
2018-11-02T16:41:28.13 WROTE: 5
2018-11-02T16:41:28.327 READ: 5
done

WebSockets v1.0.3, MbedTLS master:

2018-11-02T16:42:49.548 WROTE: 1
2018-11-02T16:42:51.664 WROTE: 2
2018-11-02T16:42:51.953 READ: 1
2018-11-02T16:42:55.667 WROTE: 3
2018-11-02T16:42:55.943 READ: 2
2018-11-02T16:42:59.672 WROTE: 4
2018-11-02T16:42:59.87 READ: 3
2018-11-02T16:43:04.676 WROTE: 5
2018-11-02T16:43:04.954 READ: 4
done
2018-11-02T16:43:08.134 READ: 5

Interestingly (to me at least), the fifth read does return after the non-async loop exits. I wish I could offer some suggestions as to what could be the problem but I'm completely in the dark.

samoconnor commented 6 years ago

The first thing I notice is x = String(read(io)). The semantics of Base.read are not well defined. I suspect there is an issue with blocking vs non-blocking behaviour of a read call somewhere.

I think it would make more sense to say x = String(readavailable(io)) to make it clear that you intend to do a non-blocking read (but I that WebSockets.jl defines it's own semantics for Base.read(::WebSocket), so that is probably not the source of the issue in this case).

I note that inside Base.read(::WebSocket) there are calls to Base.read(io, nb) with commentary that suggests that the author expects non-blocking behaviour.

read(::SSLContext, nb) resolves to read(s::IO, nb):

julia> @which read(MbedTLS.SSLContext(), 7)
read(s::IO, nb::Integer) in Base at io.jl:827

This in turn calls readbytes!(s, b, nb) which ends up here: https://github.com/JuliaWeb/MbedTLS.jl/blob/master/src/ssl.jl#L423-L444

This function follows the spec for Base.read(::IOStream, b, nb) and is blocking by default.

 read(s::IOStream, nb::Integer; all=true)

  Read at most nb bytes from s, returning a Vector{UInt8} of the bytes read.

  If all is true (the default), this function will block repeatedly trying to read all requested bytes
samoconnor commented 6 years ago

Have you tried the WebSockets module that is built into HTTP.jl?

Your example seems to run ok using HTTP.Websockets: (I've changed the read call to readavailable and added @sync to wait for the @async before printing "done".

julia> function mwe()
           HTTP.WebSockets.open("wss://echo.websocket.org") do io
              @sync begin
                   @async while isopen(io)
                       x = String(readavailable(io))
                       println(now(), " READ: ", x)
                   end
                   for i in 1:5
                       write(io, string(i))
                       println(now(), " WROTE: ", i)
                       sleep(rand(1:5))
                   end
                   close(io)
               end
               println("done")
           end
           nothing
       end
mwe (generic function with 1 method)

julia> mwe()
2018-11-03T10:19:09.533 WROTE: 1
2018-11-03T10:19:10.049 READ: 1
2018-11-03T10:19:14.534 WROTE: 2
2018-11-03T10:19:15.062 READ: 2
2018-11-03T10:19:19.541 WROTE: 3
2018-11-03T10:19:20.063 READ: 3
2018-11-03T10:19:23.543 WROTE: 4
2018-11-03T10:19:24.069 READ: 4
2018-11-03T10:19:24.547 WROTE: 5
2018-11-03T10:19:25.066 READ: 5
2018-11-03T10:19:27.792 READ:
done
christopher-dG commented 6 years ago

Wow, thank you for this great response! HTTP.WebSockets does solve the issues here (I didn't really know it existed, since it isn't documented on the gh pages site).

One only slightly related question before I go open a new issue: Can I close the websocket with a status code? You can do so with WebSockets.jl here. Having that would make HTTP's WebSockets a perfect replacement.

samoconnor commented 6 years ago

The relevant method in HTTP.WebSockets is closeread: https://github.com/JuliaWeb/HTTP.jl/blob/master/src/WebSockets.jl#L167-L173

It currently just sends a zero-length close packet:

opcode = WS_FINAL | WS_CLOSE
write(ws.io, [opcode, 0x00])

You could modify this method to add a statuscode= option.

Note that the closeread method currently writes a raw packet directly to ws.io, so to send a payload you might need to call wswrite instead. Something like:

opcode = WS_FINAL | WS_CLOSE
if statuscode == nothing
    write(ws.io, [opcode, 0x00])
else
    wswrite(ws, opcode, reinterpret(UInt8, [hton(UInt16(statuscode)])
end

PR welcome :)

christopher-dG commented 6 years ago

Thanks! I'll open an issue for that and give it a try when I have a chance.