JuliaWeb / WebSockets.jl

A WebSockets library for Julia
MIT License
157 stars 58 forks source link

Problem with SSL I/O: "MbedTLS.SSLContext does not support byte I/O" #169

Closed albestro closed 3 years ago

albestro commented 3 years ago

I wrote some code a month ago or so, and it was working, not it does not work anymore.

I investigated a bit, and with a simple connect/write/read session similar to this snippet

using WebSockets, Logging
using JSON

global_logger(WebSocketLogger(stderr, Logging.Debug))

WebSockets.open("...") do ws
  # msg = ...
  success = writeguarded(ws, msg)
  !success && error("writing error")

  data, success = readguarded(ws)
  !success && error("reading error")
end

I get

┌ Debug: ErrorException("MbedTLS.SSLContext does not support byte I/O")
└ 23:26:07.164 @ WebSockets ~/.julia/packages/WebSockets/vfjsy/src/WebSockets.jl:718

ERROR: LoadError: reading error
Stacktrace:
 [1] error(::String) at ./error.jl:33
 ...
 [3] _openstream(::var"#1#2", ::HTTP.Streams.Stream{HTTP.Messages.Response,HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}}, ::String) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:124
 [4] openstream at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:91 [inlined]
 [5] macro expansion at /Users/username/.julia/packages/HTTP/IAI92/src/StreamRequest.jl:70 [inlined]
 [6] macro expansion at ./task.jl:332 [inlined]
 [7] request(::Type{HTTP.StreamRequest.StreamLayer{Union{}}}, ::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, ::HTTP.Messages.Request, ::Nothing; reached_redirect_limit::Bool, response_stream::Nothing, iofunction::WebSockets.var"#openstream#4"{var"#1#2",String}, verbose::Int64, kw::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/StreamRequest.jl:57
 [8] request(::Type{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}, ::HTTP.URIs.URI, ::HTTP.Messages.Request, ::Nothing; proxy::Nothing, socket_type::Type{T} where T, reuse_limit::Int64, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/ConnectionRequest.jl:96
 [9] request(::Type{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}, ::HTTP.URIs.URI, ::Vararg{Any,N} where N; kw::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/ExceptionRequest.jl:19
 [10] (::Base.var"#56#58"{Base.var"#56#57#59"{ExponentialBackOff,HTTP.RetryRequest.var"#2#3"{Bool,HTTP.Messages.Request},typeof(HTTP.request)}})(::Type{T} where T, ::Vararg{Any,N} where N; kwargs::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64,Int64}}}) at ./error.jl:288
 [11] #request#1 at /Users/username/.julia/packages/HTTP/IAI92/src/RetryRequest.jl:44 [inlined]
 [12] request(::Type{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; http_version::VersionNumber, target::String, parent::Nothing, iofunction::Function, kw::Base.Iterators.Pairs{Symbol,Integer,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:reached_redirect_limit, :reuse_limit, :verbose),Tuple{Bool,Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/MessageRequest.jl:51
 [13] request(::Type{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; kw::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:reached_redirect_limit, :iofunction, :reuse_limit, :verbose),Tuple{Bool,WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/BasicAuthRequest.jl:28
 [14] request(::Type{HTTP.RedirectRequest.RedirectLayer{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; redirect_limit::Int64, forwardheaders::Bool, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/RedirectRequest.jl:24
 [15] request(::String, ::HTTP.URIs.URI, ::Array{Pair{String,String},1}, ::Nothing; headers::Array{Pair{String,String},1}, body::Nothing, query::Nothing, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/HTTP.jl:314
 [16] open(::Function, ::String, ::HTTP.URIs.URI, ::Array{Pair{String,String},1}; kw::Base.Iterators.Pairs{Symbol,Int64,Tuple{Symbol,Symbol},NamedTuple{(:reuse_limit, :verbose),Tuple{Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/HTTP.jl:348
 [17] open(::Function, ::String; verbose::Bool, subprotocol::String, kw::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:93
 [18] open(::Function, ::String) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:73
 ...

For double checking, I migrated the code to HTTP.WebSockets and it works.

Unfortunately, I still don't have enough experience with Julia, so I can't be of much help in fixing this. I don't know if it can help, but I found this https://github.com/JuliaLang/MbedTLS.jl/issues/197

hustf commented 3 years ago

Thanks, I believe this is because of an intricate detail in @Simon recent cleanup. We used to always read two no matter, and this was the reason we did not remember. And also perhaps some expensive browser tests have been dropped. On mobile now, unsure of whether or not to revert or fix more cleanly.

tir. 5. jan. 2021, 11:37 p.m. skrev albestro notifications@github.com:

I wrote some code a month ago or so, and it was working, not it does not work anymore.

I investigated a bit, and with a simple connect/write/read session similar to this snippet

using WebSockets, Logging using JSON

global_logger(WebSocketLogger(stderr, Logging.Debug))

WebSockets.open("...") do ws

msg = ...

success = writeguarded(ws, msg)

!success && error("writing error")

data, success = readguarded(ws)

!success && error("reading error") end

I get

┌ Debug: ErrorException("MbedTLS.SSLContext does not support byte I/O")

└ 23:26:07.164 @ WebSockets ~/.julia/packages/WebSockets/vfjsy/src/WebSockets.jl:718

ERROR: LoadError: reading error

Stacktrace:

[1] error(::String) at ./error.jl:33

...

[3] _openstream(::var"#1#2", ::HTTP.Streams.Stream{HTTP.Messages.Response,HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}}, ::String) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:124

[4] openstream at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:91 [inlined]

[5] macro expansion at /Users/username/.julia/packages/HTTP/IAI92/src/StreamRequest.jl:70 [inlined]

[6] macro expansion at ./task.jl:332 [inlined]

[7] request(::Type{HTTP.StreamRequest.StreamLayer{Union{}}}, ::HTTP.ConnectionPool.Transaction{MbedTLS.SSLContext}, ::HTTP.Messages.Request, ::Nothing; reached_redirect_limit::Bool, response_stream::Nothing, iofunction::WebSockets.var"#openstream#4"{var"#1#2",String}, verbose::Int64, kw::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/StreamRequest.jl:57

[8] request(::Type{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}, ::HTTP.URIs.URI, ::HTTP.Messages.Request, ::Nothing; proxy::Nothing, socket_type::Type{T} where T, reuse_limit::Int64, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/ConnectionRequest.jl:96

[9] request(::Type{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}, ::HTTP.URIs.URI, ::Vararg{Any,N} where N; kw::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/ExceptionRequest.jl:19

[10] (::Base.var"#56#58"{Base.var"#56#57#59"{ExponentialBackOff,HTTP.RetryRequest.var"#2#3"{Bool,HTTP.Messages.Request},typeof(HTTP.request)}})(::Type{T} where T, ::Vararg{Any,N} where N; kwargs::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:iofunction, :reached_redirect_limit, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Bool,Int64,Int64}}}) at ./error.jl:288

[11] #request#1 at /Users/username/.julia/packages/HTTP/IAI92/src/RetryRequest.jl:44 [inlined]

[12] request(::Type{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; http_version::VersionNumber, target::String, parent::Nothing, iofunction::Function, kw::Base.Iterators.Pairs{Symbol,Integer,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:reached_redirect_limit, :reuse_limit, :verbose),Tuple{Bool,Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/MessageRequest.jl:51

[13] request(::Type{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; kw::Base.Iterators.Pairs{Symbol,Any,NTuple{4,Symbol},NamedTuple{(:reached_redirect_limit, :iofunction, :reuse_limit, :verbose),Tuple{Bool,WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/BasicAuthRequest.jl:28

[14] request(::Type{HTTP.RedirectRequest.RedirectLayer{HTTP.BasicAuthRequest.BasicAuthLayer{HTTP.MessageRequest.MessageLayer{HTTP.RetryRequest.RetryLayer{HTTP.ExceptionRequest.ExceptionLayer{HTTP.ConnectionRequest.ConnectionPoolLayer{HTTP.StreamRequest.StreamLayer{Union{}}}}}}}}}, ::String, ::HTTP.URIs.URI, ::Array{Pair{SubString{String},SubString{String}},1}, ::Nothing; redirect_limit::Int64, forwardheaders::Bool, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/RedirectRequest.jl:24

[15] request(::String, ::HTTP.URIs.URI, ::Array{Pair{String,String},1}, ::Nothing; headers::Array{Pair{String,String},1}, body::Nothing, query::Nothing, kw::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:iofunction, :reuse_limit, :verbose),Tuple{WebSockets.var"#openstream#4"{var"#1#2",String},Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/HTTP.jl:314

[16] open(::Function, ::String, ::HTTP.URIs.URI, ::Array{Pair{String,String},1}; kw::Base.Iterators.Pairs{Symbol,Int64,Tuple{Symbol,Symbol},NamedTuple{(:reuse_limit, :verbose),Tuple{Int64,Int64}}}) at /Users/username/.julia/packages/HTTP/IAI92/src/HTTP.jl:348

[17] open(::Function, ::String; verbose::Bool, subprotocol::String, kw::Base.Iterators.Pairs{Union{},Union{},Tuple{},NamedTuple{(),Tuple{}}}) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:93

[18] open(::Function, ::String) at /Users/username/.julia/packages/WebSockets/vfjsy/src/HTTP.jl:73

...

For double checking, I migrated the code to HTTP.WebSockets and it works.

Unfortunately, I still don't have enough experience with Julia, so I can't be of much help in fixing this. I don't know if it can help, but I found this JuliaLang/MbedTLS.jl#197 https://github.com/JuliaLang/MbedTLS.jl/issues/197

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/JuliaWeb/WebSockets.jl/issues/169, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADKNVNBAI7CLUX4YE73KHE3SYOICJANCNFSM4VWQVEQA .

hustf commented 3 years ago

I take it this is related. No mention of WebSockets there, so the safest way out may be to revert to the old WebSockets code, where we read two bytes no matter?

albestro commented 3 years ago

Do you already have a branch with the fix or can you give me some hint to spot the commit to revert?

I can absolutely give it a try in case 😉

hustf commented 3 years ago

Version 1.5.6, I believe, should be fine. Haven't checked that so just try an older version than that if no success!

albestro commented 3 years ago

I tested my simple example with WebSocket 1.5.6 a2bb02f0b2630e6c8ba746d57025ad0ba5406825 and it works.

Just for double checking, I did a git bisect and everything points to what you were suggesting few days ago

8c31b66075794d19e8912a66b6d9330659f027dd is the first bad commit
commit 8c31b66075794d19e8912a66b6d9330659f027dd
Author: SimonDanisch <sdanisch@gmail.com>
Date:   Sun Aug 18 20:57:14 2019 +0200

    improve error on client abrupt close

:040000 040000 426eb170ec74030e1e0f875705062351759d0864 c963e4d667779c3844ac4cd64bd4095e0b0e881e M  src

Then, for triple checking, I tested its parent commit 207c4424b9e5ebbcc3b69de33ff66c3f43fb9c16 and it works.

Then, I partially reverted the "bad" commit 8c31b66075794d19e8912a66b6d9330659f027dd and the problematic patch is this https://github.com/JuliaWeb/WebSockets.jl/commit/8c31b66075794d19e8912a66b6d9330659f027dd#diff-e4b79c2b159b94f67f6688228850f646a9f8e766459222d7148783ea2d9fbd5eL390-R401

Your suspect were correct.

EDIT: From the commit author, I think you may have tagged the wrong one. @SimonDanisch should be the right one 😉

hustf commented 3 years ago

Oh, sorry to the cameo Simon. We'll give herr Danisch a brief chance to comment then.

The previous tests which would have saved us the trouble were dropped because launching browsers during tests is quite high maintenance. We should figure out a simpler test which covers this. I see you have plenty of experience with git and other languages - a PR is the most traceable and neat fix here. So - as always - PRs are welcome!

hustf commented 3 years ago

For reference: https://github.com/JuliaWeb/WebSockets.jl/pull/153#discussion_r546075120

albestro commented 3 years ago

Unfortunately yesterday night my time was over, but I will surely as soon as I have time in the next days (or in the weekend at last). I will move this discussion in the PR (that I will mention).

Thanks for the hints!

hustf commented 3 years ago

That's very nice of you, albestro. You may have found already that Julia code is not always easily readable, but it's old code, reasonably low level and normally not user-facing. So errors here can be a real time thief for users like I was. More hints:

Instead of

whatyouwanttodo

Try

logger= WebSocketLogger(stderr, WebSockets.Logging.Debug))
with_logger(logger) do
    whatyouwanttodo
end
hustf commented 3 years ago

A little experiment: @JuliaRegistrator register

JuliaRegistrator commented 3 years ago

Error while trying to register: "Tag with name v1.5.7 already exists and points to a different commit"

hustf commented 3 years ago

Ok... will make a new tag and add the triggering comment there...

hustf commented 3 years ago

Made the new tag, but tagbot wasn't triggered. Please, kind @JuliaRegistrator register

JuliaRegistrator commented 3 years ago

Error while trying to register: "Tag with name v1.5.7 already exists and points to a different commit"