diff --git a/src/Connections.jl b/src/Connections.jl index 332ac04e..ef586b66 100644 --- a/src/Connections.jl +++ b/src/Connections.jl @@ -21,7 +21,7 @@ module Connections export Connection, newconnection, releaseconnection, getrawstream, inactiveseconds, shouldtimeout, default_connection_limit, set_default_connection_limit!, Pool -using Sockets, LoggingExtras, NetworkOptions +using Sockets, NetworkOptions using MbedTLS: SSLConfig, SSLContext, setup!, associate!, hostname!, handshake! using MbedTLS, OpenSSL, ConcurrentUtilities using ..IOExtras, ..Conditions, ..Exceptions @@ -254,7 +254,7 @@ end function IOExtras.startwrite(c::Connection) @require !iswritable(c) c.writable = true - @debugv 3 "👁 Start write:$c" + @debug "👁 Start write:$c" return end @@ -266,7 +266,7 @@ Signal that an entire Request Message has been written to the `Connection`. function IOExtras.closewrite(c::Connection) @require iswritable(c) c.writable = false - @debugv 3 "🗣 Write done: $c" + @debug "🗣 Write done: $c" flush(c) return end @@ -278,7 +278,7 @@ function IOExtras.startread(c::Connection) @require !isreadable(c) c.timestamp = time() c.readable = true - @debugv 3 "👁 Start read: $c" + @debug "👁 Start read: $c" return end @@ -289,7 +289,7 @@ TODO: or if response data arrives when no request was sent (isreadable == false) """ function monitor_idle_connection(c::Connection) try - if eof(c.io) ;@debugv 3 "💀 Closed: $c" + if eof(c.io) ;@debug "💀 Closed: $c" close(c.io) end catch ex @@ -307,7 +307,7 @@ Signal that an entire Response Message has been read from the `Connection`. function IOExtras.closeread(c::Connection) @require isreadable(c) c.readable = false - @debugv 3 "✉️ Read done: $c" + @debug "✉️ Read done: $c" if c.clientconnection t = Threads.@spawn monitor_idle_connection(c) @isdefined(errormonitor) && errormonitor(t) @@ -516,7 +516,7 @@ function getconnection(::Type{TCPSocket}, kw...)::TCPSocket p::UInt = isempty(port) ? UInt(80) : parse(UInt, port) - @debugv 2 "TCP connect: $host:$p..." + @debug "TCP connect: $host:$p..." addrs = Sockets.getalladdrinfo(host) err = ErrorException("failed to connect") for addr in addrs @@ -570,7 +570,7 @@ function getconnection(::Type{SSLContext}, kw...)::SSLContext port = isempty(port) ? "443" : port - @debugv 2 "SSL connect: $host:$port..." + @debug "SSL connect: $host:$port..." tcp = getconnection(TCPSocket, host, port; kw...) return sslconnection(SSLContext, tcp, host; kw...) end @@ -581,7 +581,7 @@ function getconnection(::Type{SSLStream}, kw...)::SSLStream port = isempty(port) ? "443" : port - @debugv 2 "SSL connect: $host:$port..." + @debug "SSL connect: $host:$port..." tcp = getconnection(TCPSocket, host, port; kw...) return sslconnection(SSLStream, tcp, host; kw...) end diff --git a/src/Exceptions.jl b/src/Exceptions.jl index ba7a30df..579a1ae9 100644 --- a/src/Exceptions.jl +++ b/src/Exceptions.jl @@ -1,7 +1,7 @@ module Exceptions export @try, HTTPError, ConnectError, TimeoutError, StatusError, RequestError, current_exceptions_to_string -using LoggingExtras, ExceptionUnwrapping +using ExceptionUnwrapping import ..HTTP # for doc references @eval begin diff --git a/src/HTTP.jl b/src/HTTP.jl index cf6824d2..8dc68871 100644 --- a/src/HTTP.jl +++ b/src/HTTP.jl @@ -7,7 +7,7 @@ const DEBUG_LEVEL = Ref(0) Base.@deprecate escape escapeuri -using Base64, Sockets, Dates, URIs, LoggingExtras, MbedTLS, OpenSSL +using Base64, Sockets, Dates, URIs, MbedTLS, OpenSSL function access_threaded(f, v::Vector) tid = Threads.threadid() diff --git a/src/Servers.jl b/src/Servers.jl index f4c4b798..0190dfe0 100644 --- a/src/Servers.jl +++ b/src/Servers.jl @@ -443,14 +443,14 @@ function handle_connection(f, c::Connection, listener, readtimeout, access_log) # attempt to read request line and headers try startread(http) - @debugv 1 "startread called" + @debug "startread called" c.state = ACTIVE # once we've started reading, set ACTIVE state catch e # for ParserErrors, try to inform client of the problem if e isa ParseError write(c, Response(e.code == :HEADER_SIZE_EXCEEDS_LIMIT ? 431 : 400, string(e.code))) end - @debugv 1 begin + @debug begin msg = current_exceptions_to_string() "handle_connection startread error. $msg" end @@ -465,15 +465,15 @@ function handle_connection(f, c::Connection, listener, readtimeout, access_log) try # invokelatest becuase the perf is negligible, but this makes live-editing handlers more Revise friendly - @debugv 1 "invoking handler" + @debug "invoking handler" Base.invokelatest(f, http) # If `startwrite()` was never called, throw an error so we send a 500 and log this if isopen(http) && !iswritable(http) error("Server never wrote a response.\n\n$request") end - @debugv 1 "closeread" + @debug "closeread" closeread(http) - @debugv 1 "closewrite" + @debug "closewrite" closewrite(http) c.state = IDLE catch e diff --git a/src/Streams.jl b/src/Streams.jl index 2fb488be..26ce305b 100644 --- a/src/Streams.jl +++ b/src/Streams.jl @@ -2,7 +2,7 @@ module Streams export Stream, closebody, isaborted, setstatus, readall! -using Sockets, LoggingExtras +using Sockets using ..IOExtras, ..Messages, ..Connections, ..Conditions, ..Exceptions import ..HTTP # for doc references @@ -132,7 +132,7 @@ function IOExtras.closewrite(http::Stream{<:Request}) http.message.version < v"1.1" && !hasheader(http.message, "Connection", "keep-alive") - @debugv 1 "✋ \"Connection: close\": $(http.stream)" + @debug "✋ \"Connection: close\": $(http.stream)" close(http.stream) end end @@ -166,7 +166,7 @@ https://tools.ietf.org/html/rfc7231#section-6.2.1 """ function handle_continue(http::Stream{<:Response}) if http.message.status == 100 - @debugv 1 "✅ Continue: $(http.stream)" + @debug "✅ Continue: $(http.stream)" readheaders(http.stream, http.message) end end @@ -176,7 +176,7 @@ function handle_continue(http::Stream{<:Request}) if !iswritable(http.stream) startwrite(http.stream) end - @debugv 1 "✅ Continue: $(http.stream)" + @debug "✅ Continue: $(http.stream)" writeheaders(http.stream, Response(100)) end end @@ -361,9 +361,9 @@ function isaborted(http::Stream{<:Response}) if iswritable(http.stream) && iserror(http.message) && hasheader(http.message, "Connection", "close") - @debugv 1 "✋ Abort on $(sprint(writestartline, http.message)): " * + @debug "✋ Abort on $(sprint(writestartline, http.message)): " * "$(http.stream)" - @debugv 2 "✋ $(http.message)" + @debug "✋ $(http.message)" return true end return false @@ -379,7 +379,7 @@ function IOExtras.closeread(http::Stream{<:Response}) if hasheader(http.message, "Connection", "close") # Close conncetion if server sent "Connection: close"... - @debugv 1 "✋ \"Connection: close\": $(http.stream)" + @debug "✋ \"Connection: close\": $(http.stream)" close(http.stream) # Error if Message is not complete... incomplete(http) && throw(EOFError()) diff --git a/src/WebSockets.jl b/src/WebSockets.jl index fd39bd72..0e2ed56e 100644 --- a/src/WebSockets.jl +++ b/src/WebSockets.jl @@ -1,6 +1,6 @@ module WebSockets -using Base64, LoggingExtras, UUIDs, Sockets, Random +using Base64, UUIDs, Sockets, Random using MbedTLS: digest, MD_SHA1, SSLContext using ..IOExtras, ..Streams, ..Connections, ..Messages, ..Conditions, ..Servers using ..Exceptions: current_exceptions_to_string @@ -373,7 +373,7 @@ function open(f::Function, url; suppress_close_error::Bool=false, verbose=false, http.ntoread = 0 io = http.stream ws = WebSocket(io, http.message.request, http.message; maxframesize, maxfragmentation) - @debugv 2 "$(ws.id): WebSocket opened" + @debug "$(ws.id): WebSocket opened" try f(ws) catch e @@ -423,7 +423,7 @@ listen(f, args...; kw...) = Servers.listen(http -> upgrade(f, http; kw...), args listen!(f, args...; kw...) = Servers.listen!(http -> upgrade(f, http; kw...), args...; kw...) function upgrade(f::Function, http::Streams.Stream; suppress_close_error::Bool=false, maxframesize::Integer=typemax(Int), maxfragmentation::Integer=DEFAULT_MAX_FRAG, nagle=false, quickack=true, kw...) - @debugv 2 "Server websocket upgrade requested" + @debug "Server websocket upgrade requested" isupgrade(http.message) || handshakeerror() if !hasheader(http, "Sec-WebSocket-Version", "13") throw(WebSocketError("Expected \"Sec-WebSocket-Version: 13\"!\n" * "$(http.message)")) @@ -451,7 +451,7 @@ function upgrade(f::Function, http::Streams.Stream; suppress_close_error::Bool=f end ws = WebSocket(io, req, req.response; client=false, maxframesize, maxfragmentation) - @debugv 2 "$(ws.id): WebSocket upgraded; connection established" + @debug "$(ws.id): WebSocket upgraded; connection established" try f(ws) catch e @@ -511,7 +511,7 @@ or `close(ws[, body::WebSockets.CloseFrameBody])`. Calling `close` will initiate the close sequence and close the underlying connection. """ function Sockets.send(ws::WebSocket, x) - @debugv 2 "$(ws.id): Writing non-control message" + @debug "$(ws.id): Writing non-control message" @require !ws.writeclosed if !isbinary(x) && !istext(x) # if x is not single binary or text, then assume it's an iterable of binary or text @@ -524,7 +524,7 @@ function Sockets.send(ws::WebSocket, x) x = "" @goto write_single_frame end - @debugv 2 "$(ws.id): Writing fragmented message" + @debug "$(ws.id): Writing fragmented message" item, st = state # we prefetch next state so we know if we're on the last item or not # so we can appropriately set the FIN bit for the last fragmented frame @@ -553,7 +553,7 @@ to when a PING message is received by a websocket connection. """ function ping(ws::WebSocket, data=UInt8[]) @require !ws.writeclosed - @debugv 2 "$(ws.id): sending ping" + @debug "$(ws.id): sending ping" return writeframe(ws.io, Frame(true, PING, ws.client, payload(ws, data))) end @@ -568,7 +568,7 @@ used as a one-way heartbeat. """ function pong(ws::WebSocket, data=UInt8[]) @require !ws.writeclosed - @debugv 2 "$(ws.id): sending pong" + @debug "$(ws.id): sending pong" return writeframe(ws.io, Frame(true, PONG, ws.client, payload(ws, data))) end @@ -584,7 +584,7 @@ frame. """ function Base.close(ws::WebSocket, body::CloseFrameBody=CloseFrameBody(1000, "")) isclosed(ws) && return - @debugv 2 "$(ws.id): Closing websocket" + @debug "$(ws.id): Closing websocket" ws.writeclosed = true data = Vector{UInt8}(body.message) prepend!(data, reinterpret(UInt8, [hton(UInt16(body.status))])) @@ -676,10 +676,10 @@ returned by `receive`. Note that `WebSocket` objects can be iterated, where each iteration yields a message until the connection is closed. """ function receive(ws::WebSocket) - @debugv 2 "$(ws.id): Reading message" + @debug "$(ws.id): Reading message" @require !ws.readclosed frame = readframe(ws.io, Frame, ws.readbuffer) - @debugv 2 "$(ws.id): Received frame: $frame" + @debug "$(ws.id): Received frame: $frame" done = checkreadframe!(ws, frame) # common case of reading single non-control frame done && return frame.payload @@ -689,16 +689,16 @@ function receive(ws::WebSocket) payload = frame.payload while true frame = readframe(ws.io, Frame, ws.readbuffer, opcode) - @debugv 2 "$(ws.id): Received frame: $frame" + @debug "$(ws.id): Received frame: $frame" done = checkreadframe!(ws, frame) if !iscontrol(frame.flags.opcode) payload = _append(payload, frame.payload) - @debugv 2 "$(ws.id): payload len = $(length(payload))" + @debug "$(ws.id): payload len = $(length(payload))" end done && break end payload isa String && utf8check(payload) - @debugv 2 "Read message: $(payload[1:min(1024, sizeof(payload))])" + @debug "Read message: $(payload[1:min(1024, sizeof(payload))])" return payload end diff --git a/src/clientlayers/ConnectionRequest.jl b/src/clientlayers/ConnectionRequest.jl index e63c1134..62dcd553 100644 --- a/src/clientlayers/ConnectionRequest.jl +++ b/src/clientlayers/ConnectionRequest.jl @@ -1,6 +1,6 @@ module ConnectionRequest -using URIs, Sockets, Base64, LoggingExtras, ConcurrentUtilities, ExceptionUnwrapping +using URIs, Sockets, Base64, ConcurrentUtilities, ExceptionUnwrapping import MbedTLS import OpenSSL using ..Messages, ..IOExtras, ..Connections, ..Streams, ..Exceptions @@ -68,7 +68,7 @@ function connectionlayer(handler) userinfo = unescapeuri(url.userinfo) if !isempty(userinfo) && !hasheader(req.headers, "Proxy-Authorization") - @debugv 1 "Adding Proxy-Authorization: Basic header." + @debug "Adding Proxy-Authorization: Basic header." setheader(req.headers, "Proxy-Authorization" => "Basic $(base64encode(userinfo))") end else @@ -134,7 +134,7 @@ function connectionlayer(handler) if logerrors && !ExceptionUnwrapping.has_wrapped_exception(e, HTTPError) @error current_exceptions_to_string() type=Symbol("HTTP.ConnectionRequest") method=req.method url=req.url context=req.context logtag=logtag end - @debugv 1 "❗️ ConnectionLayer $root_err. Closing: $io" + @debug "❗️ ConnectionLayer $root_err. Closing: $io" if @isdefined(stream) && stream.nwritten == -1 # we didn't write anything, so don't need to worry about # idempotency of the request @@ -210,17 +210,17 @@ end function connect_tunnel(io, target_url, req) target = "$(URIs.hoststring(target_url.host)):$(target_url.port)" - @debugv 1 "📡 CONNECT HTTPS tunnel to $target" + @debug "📡 CONNECT HTTPS tunnel to $target" headers = Dict("Host" => target) if (auth = header(req, "Proxy-Authorization"); !isempty(auth)) headers["Proxy-Authorization"] = auth end request = Request("CONNECT", target, headers) - # @debugv 2 "connect_tunnel: writing headers" + # @debug "connect_tunnel: writing headers" writeheaders(io, request) - # @debugv 2 "connect_tunnel: reading headers" + # @debug "connect_tunnel: reading headers" readheaders(io, request.response) - # @debugv 2 "connect_tunnel: done reading headers" + # @debug "connect_tunnel: done reading headers" return request.response end diff --git a/src/clientlayers/CookieRequest.jl b/src/clientlayers/CookieRequest.jl index a740db5b..cb581f48 100644 --- a/src/clientlayers/CookieRequest.jl +++ b/src/clientlayers/CookieRequest.jl @@ -1,6 +1,6 @@ module CookieRequest -using Dates, LoggingExtras, URIs +using Dates, URIs using ..Cookies, ..Messages, ..Strings # default global cookie jar diff --git a/src/clientlayers/HeadersRequest.jl b/src/clientlayers/HeadersRequest.jl index 6c6f7e32..eda77ca7 100644 --- a/src/clientlayers/HeadersRequest.jl +++ b/src/clientlayers/HeadersRequest.jl @@ -2,7 +2,7 @@ module HeadersRequest export headerslayer, setuseragent! -using Base64, URIs, LoggingExtras +using Base64, URIs using ..Messages, ..Forms, ..IOExtras, ..Sniff, ..Forms, ..Strings """ @@ -18,7 +18,7 @@ function headerslayer(handler) if basicauth userinfo = unescapeuri(req.url.userinfo) if !isempty(userinfo) && !hasheader(headers, "Authorization") - @debugv 1 "Adding Authorization: Basic header." + @debug "Adding Authorization: Basic header." setheader(headers, "Authorization" => "Basic $(base64encode(userinfo))") end end @@ -29,7 +29,7 @@ function headerslayer(handler) sn = sniff(bytes(req.body)) setheader(headers, "Content-Type" => sn) - @debugv 1 "setting Content-Type header to: $sn" + @debug "setting Content-Type header to: $sn" end ## default headers if isempty(req.url.port) || diff --git a/src/clientlayers/RedirectRequest.jl b/src/clientlayers/RedirectRequest.jl index 53a9f0ae..5f4a62a4 100644 --- a/src/clientlayers/RedirectRequest.jl +++ b/src/clientlayers/RedirectRequest.jl @@ -1,6 +1,6 @@ module RedirectRequest -using URIs, LoggingExtras +using URIs using ..Messages, ..Pairs export redirectlayer, nredirects @@ -52,7 +52,7 @@ function redirectlayer(handler) else req.headers = Header[] end - @debugv 1 "➡️ Redirect: $url" + @debug "➡️ Redirect: $url" count += 1 if count == redirect_limit req.context[:redirectlimitreached] = true diff --git a/src/clientlayers/RetryRequest.jl b/src/clientlayers/RetryRequest.jl index 001c2212..ab62b527 100644 --- a/src/clientlayers/RetryRequest.jl +++ b/src/clientlayers/RetryRequest.jl @@ -1,6 +1,6 @@ module RetryRequest -using Sockets, LoggingExtras, MbedTLS, OpenSSL, ExceptionUnwrapping +using Sockets, MbedTLS, OpenSSL, ExceptionUnwrapping using ..IOExtras, ..Messages, ..Strings, ..ExceptionRequest, ..Exceptions export retrylayer @@ -41,7 +41,7 @@ function retrylayer(handler) end req_body_is_marked = false if req.body isa IO && Messages.supportsmark(req.body) - @debugv 2 "Marking request body stream" + @debug "Marking request body stream" req_body_is_marked = true mark(req.body) end @@ -59,15 +59,15 @@ function retrylayer(handler) req.context[:retrylimitreached] = true end if retry - @debugv 1 "🔄 Retry $ex: $(sprintcompact(req))" + @debug "🔄 Retry $ex: $(sprintcompact(req))" reset!(req.response) if req_body_is_marked - @debugv 2 "Resetting request body stream" + @debug "Resetting request body stream" reset(req.body) mark(req.body) end else - @debugv 1 "🚷 No Retry: $(no_retry_reason(ex, req))" + @debug "🚷 No Retry: $(no_retry_reason(ex, req))" end return s, retry end diff --git a/src/clientlayers/StreamRequest.jl b/src/clientlayers/StreamRequest.jl index 4f6e8a9c..9d8c48a4 100644 --- a/src/clientlayers/StreamRequest.jl +++ b/src/clientlayers/StreamRequest.jl @@ -1,7 +1,7 @@ module StreamRequest using ..IOExtras, ..Messages, ..Streams, ..Connections, ..Strings, ..RedirectRequest, ..Exceptions -using LoggingExtras, CodecZlib, URIs +using CodecZlib, URIs using SimpleBufferStream: BufferStream using ConcurrentUtilities: @samethreadpool_spawn @@ -21,14 +21,14 @@ indicates that the server does not wish to receive the message body. function streamlayer(stream::Stream; iofunction=nothing, decompress::Union{Nothing, Bool}=nothing, logerrors::Bool=false, logtag=nothing, timedout=nothing, kw...)::Response response = stream.message req = response.request - @debugv 1 sprintcompact(req) - @debugv 2 "client startwrite" + @debug sprintcompact(req) + @debug "client startwrite" write_start = time() startwrite(stream) - @debugv 2 sprint(show, req) + @debug sprint(show, req) if iofunction === nothing && !isbytes(req.body) - @debugv 2 "$(typeof(req)).body: $(sprintcompact(req.body))" + @debug "$(typeof(req)).body: $(sprintcompact(req.body))" end try @@ -43,12 +43,12 @@ function streamlayer(stream::Stream; iofunction=nothing, decompress::Union{Nothi Base.@lock lock begin req.context[:write_duration_ms] = get(req.context, :write_duration_ms, 0.0) + ((time() - write_start) * 1000) end - @debugv 2 "client closewrite" + @debug "client closewrite" closewrite(stream) end read_start = time() @samethreadpool_spawn try - @debugv 2 "client startread" + @debug "client startread" startread(stream) if !isaborted(stream) readbody(stream, response, decompress, lock) @@ -57,7 +57,7 @@ function streamlayer(stream::Stream; iofunction=nothing, decompress::Union{Nothi Base.@lock lock begin req.context[:read_duration_ms] = get(req.context, :read_duration_ms, 0.0) + ((time() - read_start) * 1000) end - @debugv 2 "client closeread" + @debug "client closeread" closeread(stream) end else @@ -79,8 +79,8 @@ function streamlayer(stream::Stream; iofunction=nothing, decompress::Union{Nothi rethrow() end - @debugv 1 sprintcompact(response) - @debugv 2 sprint(show, response) + @debug sprintcompact(response) + @debug sprint(show, response) return response end diff --git a/src/clientlayers/TimeoutRequest.jl b/src/clientlayers/TimeoutRequest.jl index 5bac3249..5ca728d3 100644 --- a/src/clientlayers/TimeoutRequest.jl +++ b/src/clientlayers/TimeoutRequest.jl @@ -1,7 +1,7 @@ module TimeoutRequest using ..Connections, ..Streams, ..Exceptions, ..Messages -using LoggingExtras, ConcurrentUtilities +using ConcurrentUtilities using ..Exceptions: current_exceptions_to_string export timeoutlayer diff --git a/src/cookiejar.jl b/src/cookiejar.jl index fe742f44..0a358dbf 100644 --- a/src/cookiejar.jl +++ b/src/cookiejar.jl @@ -78,7 +78,7 @@ function getcookies!(jar::CookieJar, url::URI, now::DateTime=Dates.now(Dates.UTC expired = Cookie[] for (id, e) in entries if e.persistent && e.expires != DateTime(1) && e.expires < now - @debugv 1 "Deleting expired cookie: $(e.name)" + @debug "Deleting expired cookie: $(e.name)" push!(expired, e) continue end @@ -86,7 +86,7 @@ function getcookies!(jar::CookieJar, url::URI, now::DateTime=Dates.now(Dates.UTC continue end e.lastaccess = now - @debugv 1 "Including cookie in request: $(e.name) to $(url.host)" + @debug "Including cookie in request: $(e.name) to $(url.host)" push!(cookies, e) end for c in expired @@ -141,7 +141,7 @@ function setcookies!(jar::CookieJar, url::URI, headers::Headers) c.persistent = false else if c.expires < now - @debugv 1 "Cookie expired: $(c.name)" + @debug "Cookie expired: $(c.name)" @goto remove end c.persistent = true diff --git a/src/cookies.jl b/src/cookies.jl index 50a95e8d..a38852ec 100644 --- a/src/cookies.jl +++ b/src/cookies.jl @@ -33,7 +33,7 @@ module Cookies export Cookie, CookieJar, cookies, stringify, getcookies!, setcookies!, addcookie! import Base: == -using Dates, URIs, LoggingExtras, Sockets +using Dates, URIs, Sockets using ..IOExtras, ..Parsers, ..Messages @enum SameSite SameSiteDefaultMode=1 SameSiteLaxMode SameSiteStrictMode SameSiteNoneMode diff --git a/src/download.jl b/src/download.jl index 43cffd5d..a92b88fd 100644 --- a/src/download.jl +++ b/src/download.jl @@ -100,7 +100,7 @@ function download(url::AbstractString, local_path=nothing, headers=Header[]; upd format_bytes_per_second(x) = format_bytes(x) * "/s" - @debugv 1 "downloading $url" + @debug "downloading $url" local file hdrs = String[] HTTP.open("GET", url, headers; kw...) do stream