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

Change logs to use current_exceptions_to_string() instead of exception= pattern #1092

Merged
merged 7 commits into from
Sep 18, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions src/Connections.jl
Original file line number Diff line number Diff line change
Expand Up @@ -478,9 +478,9 @@ function keepalive!(tcp)
Base.iolock_begin()
try
Base.check_open(tcp)
err = ccall(:uv_tcp_keepalive, Cint, (Ptr{Nothing}, Cint, Cuint),
msg = ccall(:uv_tcp_keepalive, Cint, (Ptr{Nothing}, Cint, Cuint),
tcp.handle, 1, 1)
Base.uv_error("failed to set keepalive on tcp socket", err)
Base.uv_error("failed to set keepalive on tcp socket", msg)
finally
Base.iolock_end()
end
Expand Down
9 changes: 7 additions & 2 deletions src/Exceptions.jl
Original file line number Diff line number Diff line change
Expand Up @@ -100,8 +100,13 @@ function current_exceptions_to_string()
buf = IOBuffer()
println(buf)
println(buf, "\n===========================\nHTTP Error message:\n")
Base.display_error(buf, Base.catch_stack())
exc = @static if VERSION >= v"1.8.0-"
Base.current_exceptions()
else
Base.catch_stack()
end
Base.display_error(buf, exc)
return String(take!(buf))
end

end # module Exceptions
end # module Exceptions
19 changes: 12 additions & 7 deletions src/Servers.jl
Original file line number Diff line number Diff line change
Expand Up @@ -192,8 +192,9 @@ shutdown(::Nothing) = nothing
function shutdown(fn::Function)
try
fn()
catch e
@error "shutdown function $fn failed" exception=(e, catch_backtrace())
catch
msg = current_exceptions_to_string()
@error "shutdown function $fn failed. $msg"
end
end

Expand Down Expand Up @@ -392,7 +393,8 @@ function listenloop(f, listener, conns, tcpisvalid,
if e isa Base.IOError && e.code == Base.UV_ECONNABORTED
verbose >= 0 && @infov 1 "Server on $(listener.hostname):$(listener.hostport) closing"
else
@errorv 2 "Server on $(listener.hostname):$(listener.hostport) errored" exception=(e, catch_backtrace())
msg = current_exceptions_to_string()
@errorv 2 "Server on $(listener.hostname):$(listener.hostport) errored. $msg"
# quick little sleep in case there's a temporary
# local error accepting and this might help avoid quickly re-erroring
sleep(0.05 + rand() * 0.05)
Expand Down Expand Up @@ -431,7 +433,8 @@ function handle_connection(f, c::Connection, listener, readtimeout, access_log)
if e isa ParseError
write(c, Response(e.code == :HEADER_SIZE_EXCEEDS_LIMIT ? 431 : 400, string(e.code)))
end
@debugv 1 "handle_connection startread error" exception=(e, catch_backtrace())
msg = current_exceptions_to_string()
@debugv 1 "handle_connection startread error. $msg"
break
end

Expand All @@ -458,7 +461,8 @@ function handle_connection(f, c::Connection, listener, readtimeout, access_log)
# 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
@logmsgv 1 level "handle_connection handler error" exception=(e, stacktrace(catch_backtrace()))
msg = current_exceptions_to_string()
@logmsgv 1 level "handle_connection handler error. $msg"

if isopen(http) && !iswritable(http)
request.response.status = 500
Expand All @@ -473,9 +477,10 @@ function handle_connection(f, c::Connection, listener, readtimeout, access_log)
end
end
end
catch e
catch
# we should be catching everything inside the while loop, but just in case
@errorv 1 "error while handling connection" exception=(e, catch_backtrace())
msg = current_exceptions_to_string()
@errorv 1 "error while handling connection. $msg"
finally
if readtimeout > 0
wait_for_timeout[] = false
Expand Down
2 changes: 1 addition & 1 deletion src/Streams.jl
Original file line number Diff line number Diff line change
Expand Up @@ -326,7 +326,7 @@ function IOExtras.readuntil(http::Stream, f::Function)::ByteView
bytes = IOExtras.readuntil(http.stream, f)
update_ntoread(http, length(bytes))
return bytes
catch e
catch
# if we error, it means we didn't find what we were looking for
return UInt8[]
end
Expand Down
4 changes: 3 additions & 1 deletion src/WebSockets.jl
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ module WebSockets
using Base64, LoggingExtras, UUIDs, Sockets, Random
using MbedTLS: digest, MD_SHA1, SSLContext
using ..IOExtras, ..Streams, ..Connections, ..Messages, ..Conditions, ..Servers
using ..Exceptions: current_exceptions_to_string
import ..open
import ..HTTP # for doc references

Expand Down Expand Up @@ -439,7 +440,8 @@ function upgrade(f::Function, http::Streams.Stream; suppress_close_error::Bool=f
f(ws)
catch e
if !isok(e)
suppress_close_error || @error "$(ws.id): Unexpected websocket server error" exception=(e, catch_backtrace())
msg = current_exceptions_to_string()
suppress_close_error || @error "$(ws.id): Unexpected websocket server error. $msg"
end
if !isclosed(ws)
if e isa WebSocketError && e.message isa CloseFrameBody
Expand Down
12 changes: 6 additions & 6 deletions src/clientlayers/ConnectionRequest.jl
Original file line number Diff line number Diff line change
Expand Up @@ -80,8 +80,8 @@ function connectionlayer(handler)
io = newconnection(IOType, url.host, url.port; readtimeout=readtimeout, connect_timeout=connect_timeout, kw...)
catch e
if logerrors
err = current_exceptions_to_string()
@error err type=Symbol("HTTP.ConnectError") method=req.method url=req.url context=req.context logtag=logtag
msg = current_exceptions_to_string()
@error msg type=Symbol("HTTP.ConnectError") method=req.method url=req.url context=req.context logtag=logtag
end
req.context[:connect_errors] = get(req.context, :connect_errors, 0) + 1
throw(ConnectError(string(url), e))
Expand Down Expand Up @@ -127,12 +127,12 @@ function connectionlayer(handler)
root_err = ExceptionUnwrapping.unwrap_exception_to_root(e)
# don't log if it's an HTTPError since we should have already logged it
if logerrors && root_err isa StatusError
err = current_exceptions_to_string()
@error err type=Symbol("HTTP.StatusError") method=req.method url=req.url context=req.context logtag=logtag
msg = current_exceptions_to_string()
@error msg type=Symbol("HTTP.StatusError") method=req.method url=req.url context=req.context logtag=logtag
end
if logerrors && !ExceptionUnwrapping.has_wrapped_exception(e, HTTPError)
err = current_exceptions_to_string(e)
@error err type=Symbol("HTTP.ConnectionRequest") method=req.method url=req.url context=req.context logtag=logtag
msg = current_exceptions_to_string()
@error msg type=Symbol("HTTP.ConnectionRequest") method=req.method url=req.url context=req.context logtag=logtag
end
@debugv 1 "❗️ ConnectionLayer $root_err. Closing: $io"
if @isdefined(stream) && stream.nwritten == -1
Expand Down
6 changes: 3 additions & 3 deletions src/clientlayers/StreamRequest.jl
Original file line number Diff line number Diff line change
Expand Up @@ -68,12 +68,12 @@ function streamlayer(stream::Stream; iofunction=nothing, decompress::Union{Nothi
end
end
end
catch e
catch
if timedout === nothing || !timedout[]
req.context[:io_errors] = get(req.context, :io_errors, 0) + 1
if logerrors
err = current_exceptions_to_string()
@error err type=Symbol("HTTP.IOError") method=req.method url=req.url context=req.context logtag=logtag
msg = current_exceptions_to_string()
@error msg type=Symbol("HTTP.IOError") method=req.method url=req.url context=req.context logtag=logtag
end
end
rethrow()
Expand Down
5 changes: 3 additions & 2 deletions src/clientlayers/TimeoutRequest.jl
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@ module TimeoutRequest

using ..Connections, ..Streams, ..Exceptions, ..Messages
using LoggingExtras, ConcurrentUtilities
using ..Exceptions: current_exceptions_to_string

export timeoutlayer

Expand All @@ -25,8 +26,8 @@ function timeoutlayer(handler)
req = stream.message.request
req.context[:timeout_errors] = get(req.context, :timeout_errors, 0) + 1
if logerrors
err = current_exceptions_to_string()
@error err type=Symbol("HTTP.TimeoutError") method=req.method url=req.url context=req.context timeout=readtimeout logtag=logtag
msg = current_exceptions_to_string()
@error msg type=Symbol("HTTP.TimeoutError") method=req.method url=req.url context=req.context timeout=readtimeout logtag=logtag
end
e = Exceptions.TimeoutError(readtimeout)
end
Expand Down
4 changes: 2 additions & 2 deletions test/client.jl
Original file line number Diff line number Diff line change
Expand Up @@ -646,8 +646,8 @@ end
end

@testset "Don't retry on internal exceptions" begin
kws = (retry_delays = [1, 2, 3], retries=3) # ~ 6 secs
max_wait = 3
kws = (retry_delays = [10, 20, 30], retries=3) # ~ 60 secs
max_wait = 30

function test_finish_within(f, secs)
timedout = Ref(false)
Expand Down
10 changes: 5 additions & 5 deletions test/server.jl
Original file line number Diff line number Diff line change
Expand Up @@ -191,17 +191,17 @@ const echostreamhandler = HTTP.streamhandler(echohandler)
HTTP.startwrite(http)
write(http, "response body\n")
end

port = HTTP.port(server)

sock = connect(host, port)
close(sock)

r = HTTP.get("https://$(host):$(port)/"; readtimeout=30, require_ssl_verification = false)
@test r.status == 200

close(server)
end
end
end # @testset

@testset "on_shutdown" begin
Expand All @@ -222,7 +222,7 @@ end # @testset
# First shutdown function errors, second adds 1
shutdown_throw() = throw(ErrorException("Broken"))
server = HTTP.listen!(x -> nothing; listenany=true, on_shutdown=[shutdown_throw, shutdown_add])
@test_logs (:error, r"shutdown function .* failed") close(server)
@test_logs (:error, r"shutdown function .* failed.*ERROR: Broken.*"s) close(server)
@test TEST_COUNT[] == 4
end # @testset

Expand Down