Skip to content

handle_connection handler error is noisy and logs at Logging.Error level #1121

Description

@krynju

This is the common case where a connection is established but then client drops
Very noisy in logs and there's no way to filter this reasonably without using LogginExtras.withlevel (which isn't documented I think)

We may want to change it to Debug

below is the simplest example where i start a server, curl and ctrl c and get the error after the ~10s sleep

julia> # HTTP.listen! and HTTP.serve! are the non-blocking versions of HTTP.listen/HTTP.serve
       server = HTTP.serve!() do request::HTTP.Request
          @show request
          @show request.method
          @show HTTP.header(request, "Content-Type")
          @show request.body
          sleep(10)
          try
              return HTTP.Response("Hello")
          catch e
              return HTTP.Response(400, "Error: $e")
          end
       end
[ Info: Listening on: 127.0.0.1:8081, thread id: 1
HTTP.Servers.Server{HTTP.Servers.Listener{Nothing, Sockets.TCPServer}}(HTTP.Servers.Listener{Nothing, Sockets.TCPServer}(Sockets.InetAddr{Sockets.IPv4}(ip"127.0.0.1", 8081), "127.0.0.1", "8081", nothing, Sockets.TCPServer(RawFD(21) active)), nothing, Set{HTTP.Connections.Connection}(), Task (runnable) @0x00007f7b9c528010)

julia> # now I curl localhost:8081 and ctrl+c 

julia> request = HTTP.Messages.Request:
"""
GET / HTTP/1.1
Host: localhost:8081
User-Agent: curl/8.4.0
Accept: */*

"""
request.method = "GET"
HTTP.header(request, "Content-Type") = ""
request.body = UInt8[]
┌ Error: handle_connection handler error. 
│ 
│ ===========================
│ HTTP Error message:
│ 
│ ERROR: IOError: write: broken pipe (EPIPE)
│ Stacktrace:
│   [1] uv_write(s::Sockets.TCPSocket, p::Ptr{UInt8}, n::UInt64)
│     @ Base ./stream.jl:1066
│   [2] unsafe_write(s::Sockets.TCPSocket, p::Ptr{UInt8}, n::UInt64)
│     @ Base ./stream.jl:1120
│   [3] unsafe_write
│     @ ~/.julia/packages/HTTP/SN7VW/src/Connections.jl:129 [inlined]
│   [4] write
│     @ ./strings/io.jl:244 [inlined]
│   [5] write
│     @ ./io.jl:676 [inlined]
│   [6] unsafe_write(http::HTTP.Streams.Stream{HTTP.Messages.Request, HTTP.Connections.Connection{Sockets.TCPSocket}}, p::Ptr{UInt8}, n::UInt64)
│     @ HTTP.Streams ~/.julia/packages/HTTP/SN7VW/src/Streams.jl:95
│   [7] write
│     @ ./strings/io.jl:244 [inlined]
│   [8] write(io::HTTP.Streams.Stream{HTTP.Messages.Request, HTTP.Connections.Connection{Sockets.TCPSocket}}, s::Base.CodeUnits{UInt8, String})
│     @ Base ./strings/basic.jl:761
│   [9] (::HTTP.Handlers.var"#1#2"{var"#9#10"})(stream::HTTP.Streams.Stream{HTTP.Messages.Request, HTTP.Connections.Connection{Sockets.TCPSocket}})
│     @ HTTP.Handlers ~/.julia/packages/HTTP/SN7VW/src/Handlers.jl:61
│  [10] #invokelatest#2
│     @ ./essentials.jl:819 [inlined]
│  [11] invokelatest
│     @ ./essentials.jl:816 [inlined]
│  [12] handle_connection(f::Function, c::HTTP.Connections.Connection{Sockets.TCPSocket}, listener::HTTP.Servers.Listener{Nothing, Sockets.TCPServer}, readtimeout::Int64, access_log::Nothing)
│     @ HTTP.Servers ~/.julia/packages/HTTP/SN7VW/src/Servers.jl:450
│  [13] macro expansion
│     @ ~/.julia/packages/HTTP/SN7VW/src/Servers.jl:386 [inlined]
│  [14] (::HTTP.Servers.var"#16#17"{HTTP.Handlers.var"#1#2"{var"#9#10"}, HTTP.Servers.Listener{Nothing, Sockets.TCPServer}, Set{HTTP.Connections.Connection}, Int64, Nothing, Base.Semaphore, HTTP.Connections.Connection{Sockets.TCPSocket}})()
│     @ HTTP.Servers ./task.jl:514
└ @ HTTP.Servers ~/.julia/packages/HTTP/SN7VW/src/Servers.jl:465

code ref

HTTP.jl/src/Servers.jl

Lines 461 to 465 in 5cd586d

# The remote can close the stream whenever it wants to, but there's nothing
# anyone can do about it on this side. No reason to log an error in that case.
level = e isa Base.IOError && !isopen(c) ? Logging.Debug : Logging.Error
msg = current_exceptions_to_string()
@logmsgv 1 level "handle_connection handler error. $msg"

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions