Skip to content

Commit

Permalink
Backport #1092: Change logs to use current_exceptions_to_string() ins…
Browse files Browse the repository at this point in the history
…tead of `exception=` pattern (#1115)

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

* Change logs to use `current_exceptions_to_string()` instead of `exception=`

* cleanup unused variable `catch e`

* Update Exceptions.jl for older julia

* Rename err => msg; fix missing import

* Make "Don't retry on internal exceptions" less flakey

---------

Co-authored-by: Nick Robinson <[email protected]>
Co-authored-by: Tomáš Drvoštěp <[email protected]>

* Bump release to v1.9.16 for #1092

---------

Co-authored-by: Nick Robinson <[email protected]>
Co-authored-by: Tomáš Drvoštěp <[email protected]>
  • Loading branch information
3 people authored Oct 2, 2023
1 parent cefae7b commit e04a6ba
Show file tree
Hide file tree
Showing 10 changed files with 43 additions and 30 deletions.
2 changes: 1 addition & 1 deletion Project.toml
Original file line number Diff line number Diff line change
@@ -1,7 +1,7 @@
name = "HTTP"
uuid = "cd3eb016-35fb-5094-929b-558a96fad6f3"
authors = ["Jacob Quinn", "contributors: https://github.com/JuliaWeb/HTTP.jl/graphs/contributors"]
version = "1.9.15"
version = "1.9.16"

[deps]
Base64 = "2a0f44e3-6c83-55bd-87e4-b1978d98bd5f"
Expand Down
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
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

2 comments on commit e04a6ba

@NHDaly
Copy link
Collaborator Author

@NHDaly NHDaly commented on e04a6ba Oct 2, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@JuliaRegistrator register()

@JuliaRegistrator
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Registration pull request created: JuliaRegistries/General/92635

After the above pull request is merged, it is recommended that a tag is created on this repository for the registered package version.

This will be done automatically if the Julia TagBot GitHub Action is installed, or can be done manually through the github interface, or via:

git tag -a v1.9.16 -m "<description of version>" e04a6bac1797ed638f6e398b1cdc3af423c29df5
git push origin v1.9.16

Please sign in to comment.