Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Open
krynju opened this issue Oct 26, 2023 · 0 comments · May be fixed by #1122
Open

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

krynju opened this issue Oct 26, 2023 · 0 comments · May be fixed by #1122

Comments

@krynju
Copy link

krynju commented Oct 26, 2023

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"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant