Occurrence of " MbedTLS error code -29312: SSL - The connection indicated an EOF" results in termination of the HTTP.listen() loop #318

mkoonen · 2018-09-27T08:26:13Z

Version Information
Julia Version 1.0.0 (2018-08-08), Ubuntu 18.04 x64 and

julia> Pkg.status()
    Status `~/.julia/environments/v1.0/Project.toml`
  [cd3eb016] HTTP v0.7.0
  [739be429] MbedTLS v0.6.3

Given code server.jl:

using HTTP
using MbedTLS

# SSL configuration via files (cert and key)
const CERT_FILE = "server_cert.pem"
const PK_FILE = "server_key.pem"

println("Create the SSLConfig")
tlsconfig = invoke(
  HTTP.Servers.SSLConfig, Tuple{Any,Any}, CERT_FILE, PK_FILE
)

function show_debug(level, filename, number, msg)
  println("[DBG] $filename $number $msg")  
end

MbedTLS.dbg!(tlsconfig,show_debug)
MbedTLS.set_dbg_level(MbedTLS.INFO)

println(tlsconfig)
println(tlsconfig.cert)

HTTP.listen("0.0.0.0", 8000, ssl=true, sslconfig = tlsconfig) do request::HTTP.Request
   @show request
   @show request.method
   @show HTTP.header(request, "Content-Type")
   try
      return HTTP.Response("Hello Julia World!")
   catch e
      return HTTP.Response(404, "Error: $e")
   end
end

with a proven correct tlsconfig.
Creation of error situation
Run server.jl. Execute:

$ nc dev.xxxxxxxx.com 8000
^C

where dev.xxxxxxxx.com resolves correctly to localhost.

Oberved result is termination of HTTP.listen() because of an exception:

[ Info: Listening on: Sockets.InetAddr{Sockets.IPv4}(ip"0.0.0.0", 0x1f40)
[DBG] /workspace/srcdir/mbedtls/library/ssl_srv.c 1228 mbedtls_ssl_fetch_input() returned -29312 (-0x7280)

ERROR: LoadError: MbedTLS error code -29312: SSL - The connection indicated an EOF
Stacktrace:
 [1] mbed_err(::Int32) at /home/mkoonen/.julia/packages/MbedTLS/mkHpa/src/error.jl:17
 [2] handshake(::MbedTLS.SSLContext) at /home/mkoonen/.julia/packages/MbedTLS/mkHpa/src/ssl.jl:180
 [3] handshake! at /home/mkoonen/.julia/packages/MbedTLS/mkHpa/src/MbedTLS.jl:101 [inlined]
 [4] getsslcontext(::Sockets.TCPSocket, ::SSLConfig) at /home/mkoonen/.julia/packages/HTTP/mwR9J/src/Servers.jl:228
 [5] macro expansion at ./logging.jl:309 [inlined]
 [6] #listenloop#48(::Base.Iterators.Pairs{Symbol,Bool,Tuple{Symbol},NamedTuple{(:verbose,),Tuple{Bool}}}, ::Function, ::Function, ::Sockets.TCPServer, ::SSLConfig, ::String, ::String, ::Int64, ::Bool, ::getfield(HTTP.Servers, Symbol("##42#47")), ::Base.RefValue{Int64}) at /home/mkoonen/.julia/packages/HTTP/mwR9J/src/Servers.jl:336
 [7] (::getfield(HTTP.Servers, Symbol("#kw##listenloop")))(::NamedTuple{(:verbose,),Tuple{Bool}}, ::typeof(HTTP.Servers.listenloop), ::Function, ::Sockets.TCPServer, ::SSLConfig, ::String, ::String, ::Int64, ::Bool, ::getfield(HTTP.Servers, Symbol("##42#47")), ::Base.RefValue{Int64}) at ./none:0
 [8] #listen#39(::Bool, ::Bool, ::SSLConfig, ::Int64, ::Function, ::Base.RefValue{Base.IOServer}, ::Bool, ::Base.RefValue{Int64}, ::Base.Iterators.Pairs{Symbol,Bool,Tuple{Symbol},NamedTuple{(:verbose,),Tuple{Bool}}}, ::typeof(HTTP.Servers.listen), ::getfield(Main, Symbol("##3#4")), ::Sockets.InetAddr{Sockets.IPv4}) at /home/mkoonen/.julia/packages/HTTP/mwR9J/src/Servers.jl:303
 [9] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::Sockets.InetAddr{Sockets.IPv4}) at ./none:0
 [10] #listen#36 at /home/mkoonen/.julia/packages/HTTP/mwR9J/src/Servers.jl:280 [inlined]
 [11] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::Sockets.IPv4, ::Int64) at ./none:0
 [12] #listen#37(::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}}, ::Function, ::Function, ::String, ::Int64) at /home/mkoonen/.julia/packages/HTTP/mwR9J/src/Servers.jl:281
 [13] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::String, ::Int64) at ./none:0
 [14] top-level scope at none:0
 [15] include at ./boot.jl:317 [inlined]
 [16] include_relative(::Module, ::String) at ./loading.jl:1038
 [17] include(::Module, ::String) at ./sysimg.jl:29
 [18] include(::String) at ./client.jl:388
 [19] top-level scope at none:0
in expression starting at /home/mkoonen/issues/julia/mbedtls/rca/server.jl:25

julia>

I would expect only the execution flow w.r.t. the specific failing HTTPS-connection would be terminated and not the entire HTTP.listen() because there might be, e.g. in Azure, health probes that use HTTP to try to make a connection.
Direction of a solution
If I change these lines in Servers.jl from HTTP.jl

if e isa Base.IOError
  @warn "$e"
  break
else
  rethrow(e)
end

into

if e isa Base.IOError
  @warn "$e"
  break
else
  if e isa MbedException
    @warn "$e"
  else
    rethrow(e)
  end
end

it works like expected for the test case I described in this issue. Next question for me would be if

if e isa MbedException
# ...
else
# ...
end

is the exact/correct way to solve this?

The text was updated successfully, but these errors were encountered:

quinnj · 2018-10-19T13:50:13Z

@mkoonen , sorry for the delay here; there's been a decent amount of refactoring done in MbedTLS.jl recently by @samoconnor (ref: JuliaLang/MbedTLS.jl#174). The updates are now in the latest MbedTLS.jl release; could you check w/ the latest release and see if your issue here has been fixed?

mkoonen · 2018-10-19T14:26:20Z

@quinnj , thank you for your response. I executed the scenario as described before with the following configuration:

Ubuntu Linux 18.04 x64
Julia version 1.0.1
julia> Pkg.status()
    Status `~/.julia/environments/v1.0/Project.toml`
  [cd3eb016] HTTP v0.7.1
  [739be429] MbedTLS v0.6.4

After I have started server.jl and execute

nc dev.xxxxxxxx.com 8000
^C

I get the following error message:

ERROR: LoadError: EOFError: read end of file
Stacktrace:
 [1] handshake(::MbedTLS.SSLContext) at /home/mkoonen/.julia/packages/MbedTLS/CwGUN/src/ssl.jl:69
 [2] handshake! at /home/mkoonen/.julia/packages/MbedTLS/CwGUN/src/MbedTLS.jl:101 [inlined]
 [3] getsslcontext(::Sockets.TCPSocket, ::SSLConfig) at /home/mkoonen/.julia/packages/HTTP/YjRCz/src/Servers.jl:228
 [4] macro expansion at ./logging.jl:309 [inlined]
 [5] #listenloop#48(::Base.Iterators.Pairs{Symbol,Bool,Tuple{Symbol},NamedTuple{(:verbose,),Tuple{Bool}}}, ::Function, ::Function, ::Sockets.TCPServer, ::SSLConfig, ::String, ::String, ::Int64, ::Bool, ::getfield(HTTP.Servers, Symbol("##42#47")), ::Base.RefValue{Int64}) at /home/mkoonen/.julia/packages/HTTP/YjRCz/src/Servers.jl:336
 [6] (::getfield(HTTP.Servers, Symbol("#kw##listenloop")))(::NamedTuple{(:verbose,),Tuple{Bool}}, ::typeof(HTTP.Servers.listenloop), ::Function, ::Sockets.TCPServer, ::SSLConfig, ::String, ::String, ::Int64, ::Bool, ::getfield(HTTP.Servers, Symbol("##42#47")), ::Base.RefValue{Int64}) at ./none:0
 [7] #listen#39(::Bool, ::Bool, ::SSLConfig, ::Int64, ::Function, ::Base.RefValue{Base.IOServer}, ::Bool, ::Base.RefValue{Int64}, ::Base.Iterators.Pairs{Symbol,Bool,Tuple{Symbol},NamedTuple{(:verbose,),Tuple{Bool}}}, ::typeof(HTTP.Servers.listen), ::getfield(Main, Symbol("##3#4")), ::Sockets.InetAddr{Sockets.IPv4}) at /home/mkoonen/.julia/packages/HTTP/YjRCz/src/Servers.jl:303
 [8] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::Sockets.InetAddr{Sockets.IPv4}) at ./none:0
 [9] #listen#36 at /home/mkoonen/.julia/packages/HTTP/YjRCz/src/Servers.jl:280 [inlined]
 [10] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::Sockets.IPv4, ::Int64) at ./none:0
 [11] #listen#37(::Base.Iterators.Pairs{Symbol,Any,Tuple{Symbol,Symbol,Symbol},NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}}, ::Function, ::Function, ::String, ::Int64) at /home/mkoonen/.julia/packages/HTTP/YjRCz/src/Servers.jl:281
 [12] (::getfield(HTTP.Servers, Symbol("#kw##listen")))(::NamedTuple{(:ssl, :sslconfig, :verbose),Tuple{Bool,SSLConfig,Bool}}, ::typeof(HTTP.Servers.listen), ::Function, ::String, ::Int64) at ./none:0
 [13] top-level scope at none:0
 [14] include at ./boot.jl:317 [inlined]
 [15] include_relative(::Module, ::String) at ./loading.jl:1041
 [16] include(::Module, ::String) at ./sysimg.jl:29
 [17] include(::String) at ./client.jl:388
 [18] top-level scope at none:0
in expression starting at /home/mkoonen/issues/julia/mbedtls/rca/server.jl:24

and HTTP.list() is terminated.

samoconnor · 2018-10-19T23:10:38Z

@quinnj,

It looks to me like if e isa Base.IOError @warn... should probably be if isioerror(e) @warn... ?

HTTP.jl/src/IOExtras.jl

Lines 33 to 42 in a81ff0a

    
           """ 
        
               isioerror(exception) 
        
           Is `exception` caused by a possibly recoverable IO error. 
        
           """ 
        
           isioerror(e) = false 
        
           isioerror(::Base.EOFError) = true 
        
           isioerror(::Base.IOError) = true 
        
           isioerror(e::ArgumentError) = e.msg == "stream is closed or unusable" 
        
           isioerror(::MbedException) = true

Really, Base should have an abstract IOError type and make EOFError <: IOError.

stefan911 · 2018-11-19T20:41:27Z

@samoconnor
I think a warning without a break is correct.
HTTP.jl/src/Servers.jl listenloop()

variable id and i=id are unused, in listen loop so exiting the catch and continue are equivalent.

line 355:
catch e
if isioerror(e)
@warn "$e"
else
rethrow(e)
end
end

Tested with a ratelimit::5//1 and fast connections causing throttling and EOFError

citkane · 2020-09-29T13:12:50Z

I am just confirming that this issue is still present in Julia 1.5 with latest HTTP and MbedTLS

Given a server:

using HTTP, MbedTLS, Pkg
Pkg.status()

# HTTP.Servers.SSLConfig("snakeoil.crt", "snakeoil.key") #Same behaviour on HTTP MbedTLS version
tlsconfig = SSLConfig("snakeoil.crt", "snakeoil.key")

@async try
    HTTP.listen("127.0.0.1", 8085; sslconfig = tlsconfig) do http::HTTP.Stream
        while !eof(http)
            println("body data: ", String(readavailable(http)))
        end
        HTTP.setstatus(http, 101)
        HTTP.startwrite(http)
        write(http, "response body\n")
        write(http, "more response body")
    end
catch err
    @error err exception = (err, catch_backtrace())
end

wait()

And a client:

using HTTP

clientoptions = (;
    require_ssl_verification = false,
)
@info "First request to https is successful"
r = HTTP.request("GET", "https://127.0.0.1:8085"; clientoptions...)
println(r.status)
println(String(r.body))

try
    @info "Second request to http request causes server listen() loop to error and exit"
    HTTP.request("GET", "http://127.0.0.1:8085"; clientoptions...)
catch
    @info "Subsequent requests to the server fail"
    HTTP.request("GET", "https://127.0.0.1:8085"; clientoptions...)
end

The client ouput is:

[ Info: First request to https is successful
101
response body
more response body
[ Info: Second request to http request causes server listenloop to error and exit
[ Info: Subsequent requests to the server fail
ERROR: LoadError: IOError(Base.IOError("connect: connection refused (ECONNREFUSED)", -111) during request(https://127.0.0.1:8085))

Stacktrace: ...
IOError(Base.IOError("connect: connection refused (ECONNREFUSED)", -111) during request(http://127.0.0.1:8085))

Stacktrace: ...

and the server output is:

Status `/var/opt/testssl/Project.toml`
  [cd3eb016] HTTP v0.8.19
  [739be429] MbedTLS v1.0.2
┌ Error: MbedTLS error code -30976: SSL - Processing of the ClientHello handshake message failed
│   exception =
│    MbedTLS error code -30976: SSL - Processing of the ClientHello handshake message failed
│    Stacktrace:
│     [1] handshake(::MbedTLS.SSLContext) at /home/michaeladmin/.julia/packages/MbedTLS/VbsaQ/src/ssl.jl:83
│     [2] handshake! at /home/michaeladmin/.julia/packages/MbedTLS/VbsaQ/src/MbedTLS.jl:134 [inlined]
│     [3] getsslcontext(::Sockets.TCPSocket, ::SSLConfig) at /home/michaeladmin/.julia/packages/HTTP/IAI92/src/Servers.jl:89
│     [4] accept at /home/michaeladmin/.julia/packages/HTTP/IAI92/src/Servers.jl:83 [inlined]
│     [5] listenloop(::Function, ::HTTP.Servers.Server{SSLConfig,Sockets.TCPServer}, ::HTTP.Servers.var"#2#5"{Nothing,HTTP.Servers.var"#4#7"}, ::Base.RefValue{Int64}, ::Int64, ::Int64, ::Bool) at /home/michaeladmin/.julia/packages/HTTP/IAI92/src/Servers.jl:247
│     [6] listen(::var"#2#4", ::String, ::Int64; sslconfig::SSLConfig, tcpisvalid::Function, server::Nothing, reuseaddr::Bool, connection_count::Base.RefValue{Int64}, rate_limit::Nothing, reuse_limit::Int64, readtimeout::Int64, verbose::Bool) at /home/michaeladmin/.julia/packages/HTTP/IAI92/src/Servers.jl:234
│     [7] macro expansion at /var/opt/testssl/testserver.jl:12 [inlined]
│     [8] (::var"#1#3")() at ./task.jl:356
└ @ Main /var/opt/testssl/testserver.jl:22

Fixes #318. This is a bad bug. Basically, if you're running an ssl server, any client who sends a non-perfect https request (like simply a plain *http* request) would result in the server task throwing an error and closing. This is partly because the thrown error isn't super obvious, nested down a few calls in our overloaded `Sockets.accept(::Server{SSLConfig})` method. The fix proposed here is that we'll put a try-catch in the ssl handshaking code and if an error is thrown, we return `nothing`; in the server `listenloop`, if the accepted `io` is `nothing`, then we'll skip and try to accept the next connection.

quinnj · 2020-10-09T04:32:06Z

Sorry for the delay in fixing here and thanks for the reminder @citkane. A proposed fix is up: #602

mkoonen · 2020-11-12T09:43:23Z

I checked with release v0.9.0 and I can confirm the issue as I described does not occur anymore.

@quinnj : thanks for fixing this!

mkoonen mentioned this issue Sep 27, 2018

Stuck in infinite handshake loop when performing a non https connection with correct SSLConfig provided. JuliaLang/MbedTLS.jl#164

Closed

quinnj mentioned this issue Oct 9, 2020

Broken pipe when trying to create a simple server with SSL #491

Closed

quinnj mentioned this issue Oct 9, 2020

Catch getsslcontext errors in server listenloop #602

Merged

quinnj mentioned this issue Oct 9, 2020

mwe.jl Unit Test Failure #467

Closed

quinnj closed this as completed in #602 Oct 9, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Occurrence of " MbedTLS error code -29312: SSL - The connection indicated an EOF" results in termination of the HTTP.listen() loop #318

Occurrence of " MbedTLS error code -29312: SSL - The connection indicated an EOF" results in termination of the HTTP.listen() loop #318

mkoonen commented Sep 27, 2018 •

edited

Loading

quinnj commented Oct 19, 2018

mkoonen commented Oct 19, 2018

samoconnor commented Oct 19, 2018

stefan911 commented Nov 19, 2018

citkane commented Sep 29, 2020

quinnj commented Oct 9, 2020

mkoonen commented Nov 12, 2020

Occurrence of " MbedTLS error code -29312: SSL - The connection indicated an EOF" results in termination of the HTTP.listen() loop #318

Occurrence of " MbedTLS error code -29312: SSL - The connection indicated an EOF" results in termination of the HTTP.listen() loop #318

Comments

mkoonen commented Sep 27, 2018 • edited Loading

quinnj commented Oct 19, 2018

mkoonen commented Oct 19, 2018

samoconnor commented Oct 19, 2018

stefan911 commented Nov 19, 2018

citkane commented Sep 29, 2020

quinnj commented Oct 9, 2020

mkoonen commented Nov 12, 2020

mkoonen commented Sep 27, 2018 •

edited

Loading