"handler error": show request in log

[fonsp]

This will show the request that caused a handler error in the log.

For example, if I add error("Test") in my handler, I get this log:

┌ Error: handle_connection handler error. 
│ 
│ ===========================
│ HTTP Error message:
│ 
│ ERROR: Test
│ Stacktrace:
│  [1] error(s::String)
│    @ Base ./error.jl:35
│  [2] is_authenticated(session::Pluto.ServerSession, request::HTTP.Messages.Request)
│    @ Pluto ~/Documents/Pluto.jl/src/webserver/Authentication.jl:8
│  [3] (::Pluto.var"#385#395"{Pluto.ServerSession, Pluto.var"#280#282"{Pluto.var"#283#285"{HTTP.Handlers.Router{typeof(Pluto.default_404), typeof(HTTP.Handlers.default405), Nothing}}, Pluto.ServerSession}})(http::HTTP.Streams.Stream{HTTP.Messages.Request, HTTP.Connections.Connection{Sockets.TCPSocket}})
│    @ Pluto ~/Documents/Pluto.jl/src/webserver/WebServer.jl:193
│  [4] #invokelatest#2
│    @ ./essentials.jl:887 [inlined]
│  [5] invokelatest
│    @ ./essentials.jl:884 [inlined]
│  [6] 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/P8MWj/src/Servers.jl:469
│  [7] (::HTTP.Servers.var"#16#17"{Pluto.var"#385#395"{Pluto.ServerSession, Pluto.var"#280#282"{Pluto.var"#283#285"{HTTP.Handlers.Router{typeof(Pluto.default_404), typeof(HTTP.Handlers.default405), Nothing}}, Pluto.ServerSession}}, HTTP.Servers.Listener{Nothing, Sockets.TCPServer}, Set{HTTP.Connections.Connection}, Int64, Nothing, ReentrantLock, Base.Semaphore, HTTP.Connections.Connection{Sockets.TCPSocket}})()
│    @ HTTP.Servers ~/.julia/packages/HTTP/P8MWj/src/Servers.jl:401
│   request =
│    HTTP.Messages.Request:
│    """
│    GET / HTTP/1.1
│    Host: localhost:1234
│    Pragma: no-cache
│    Accept: */*
│    Sec-WebSocket-Key: S12qX44J2ZL/2yAUCTzNgA==
│    Sec-Fetch-Site: same-origin
│    Sec-WebSocket-Version: 13
│    Sec-WebSocket-Extensions: permessage-deflate
│    Cache-Control: no-cache
│    Sec-Fetch-Mode: websocket
│    Accept-Language: nl-NL,nl;q=0.9
│    Origin: http://localhost:1234
│    User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.3.1 Safari/605.1.15
│    Connection: Upgrade
│    Accept-Encoding: gzip, deflate
│    Upgrade: websocket
│    Sec-Fetch-Dest: websocket
│    Cookie: ******
│    
│    """
└ @ HTTP.Servers ~/.julia/packages/HTTP/P8MWj/src/Servers.jl:483

Instead of this:

┌ Error: handle_connection handler error. 
│ 
│ ===========================
│ HTTP Error message:
│ 
│ ERROR: Test
│ Stacktrace:
│  [1] error(s::String)
│    @ Base ./error.jl:35
│  [2] is_authenticated(session::Pluto.ServerSession, request::HTTP.Messages.Request)
│    @ Pluto ~/Documents/Pluto.jl/src/webserver/Authentication.jl:8
│  [3] (::Pluto.var"#385#395"{Pluto.ServerSession, Pluto.var"#280#282"{Pluto.var"#283#285"{HTTP.Handlers.Router{typeof(Pluto.default_404), typeof(HTTP.Handlers.default405), Nothing}}, Pluto.ServerSession}})(http::HTTP.Streams.Stream{HTTP.Messages.Request, HTTP.Connections.Connection{Sockets.TCPSocket}})
│    @ Pluto ~/Documents/Pluto.jl/src/webserver/WebServer.jl:193
│  [4] #invokelatest#2
│    @ ./essentials.jl:887 [inlined]
│  [5] invokelatest
│    @ ./essentials.jl:884 [inlined]
│  [6] 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/P8MWj/src/Servers.jl:469
│  [7] (::HTTP.Servers.var"#16#17"{Pluto.var"#385#395"{Pluto.ServerSession, Pluto.var"#280#282"{Pluto.var"#283#285"{HTTP.Handlers.Router{typeof(Pluto.default_404), typeof(HTTP.Handlers.default405), Nothing}}, Pluto.ServerSession}}, HTTP.Servers.Listener{Nothing, Sockets.TCPServer}, Set{HTTP.Connections.Connection}, Int64, Nothing, ReentrantLock, Base.Semaphore, HTTP.Connections.Connection{Sockets.TCPSocket}})()
│    @ HTTP.Servers ~/.julia/packages/HTTP/P8MWj/src/Servers.jl:401
└ @ HTTP.Servers ~/.julia/packages/HTTP/P8MWj/src/Servers.jl:483

I think this is useful debugging information! For example, I am currently trying to chase down the origin of a "Server never wrote a response" (like #1023 and #1156). Since my app is quite complex, it's really useful to know the path and method of the request that was handled wrong.

[fonsp]

My goal is to be able to trace the "Server never wrote a response" error to its request. If you prefer, I can also add this information to

HTTP.jl/src/Servers.jl

Line 472 in eb1d2a9

error("Server never wrote a response")

and leave the logging for other handler errors as-is.

[codecov-commenter]

Codecov Report

Attention: Patch coverage is 0% with 1 lines in your changes are missing coverage. Please review.

Project coverage is 83.19%. Comparing base (eb1d2a9) to head (28ed65b).

Files	Patch %	Lines
src/Servers.jl	0.00%	1 Missing ⚠️

Additional details and impacted files

@@           Coverage Diff           @@
##           master    #1163   +/-   ##
=======================================
  Coverage   83.19%   83.19%           
=======================================
  Files          32       32           
  Lines        3058     3058           
=======================================
  Hits         2544     2544           
  Misses        514      514           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[quinnj]

sgtm; thanks @fonsp