added :debug_redact option

when true, text passed to log messages considered sensitive (wrapped in a +#log_redact+ call) will be logged as "[REDACTED}"
This commit is contained in:
HoneyryderChuck 2025-04-27 16:37:51 +01:00
parent 35c18a1b9b
commit 3a417a4623
7 changed files with 69 additions and 21 deletions

View File

@ -119,7 +119,7 @@ module HTTPX
@parser.http_version.join("."),
headers)
log(color: :yellow) { "-> HEADLINE: #{response.status} HTTP/#{@parser.http_version.join(".")}" }
log(color: :yellow) { response.headers.each.map { |f, v| "-> HEADER: #{f}: #{v}" }.join("\n") }
log(color: :yellow) { response.headers.each.map { |f, v| "-> HEADER: #{f}: #{log_redact(v)}" }.join("\n") }
@request.response = response
on_complete if response.finished?
@ -131,7 +131,7 @@ module HTTPX
response = @request.response
log(level: 2) { "trailer headers received" }
log(color: :yellow) { h.each.map { |f, v| "-> HEADER: #{f}: #{v.join(", ")}" }.join("\n") }
log(color: :yellow) { h.each.map { |f, v| "-> HEADER: #{f}: #{log_redact(v.join(", "))}" }.join("\n") }
response.merge_headers(h)
end
@ -141,7 +141,7 @@ module HTTPX
return unless request
log(color: :green) { "-> DATA: #{chunk.bytesize} bytes..." }
log(level: 2, color: :green) { "-> #{chunk.inspect}" }
log(level: 2, color: :green) { "-> #{log_redact(chunk.inspect)}" }
response = request.response
response << chunk
@ -361,7 +361,7 @@ module HTTPX
while (chunk = request.drain_body)
log(color: :green) { "<- DATA: #{chunk.bytesize} bytes..." }
log(level: 2, color: :green) { "<- #{chunk.inspect}" }
log(level: 2, color: :green) { "<- #{log_redact(chunk.inspect)}" }
@buffer << chunk
throw(:buffer_full, request) if @buffer.full?
end
@ -381,9 +381,9 @@ module HTTPX
def join_headers2(headers)
headers.each do |field, value|
buffer = "#{capitalized(field)}: #{value}#{CRLF}"
log(color: :yellow) { "<- HEADER: #{buffer.chomp}" }
@buffer << buffer
field = capitalized(field)
log(color: :yellow) { "<- HEADER: #{[field, log_redact(value)].join(": ")}" }
@buffer << "#{field}: #{value}#{CRLF}"
end
end

View File

@ -224,12 +224,12 @@ module HTTPX
extra_headers = set_protocol_headers(request)
if request.headers.key?("host")
log { "forbidden \"host\" header found (#{request.headers["host"]}), will use it as authority..." }
log { "forbidden \"host\" header found (#{log_redact(request.headers["host"])}), will use it as authority..." }
extra_headers[":authority"] = request.headers["host"]
end
log(level: 1, color: :yellow) do
request.headers.merge(extra_headers).each.map { |k, v| "#{stream.id}: -> HEADER: #{k}: #{v}" }.join("\n")
request.headers.merge(extra_headers).each.map { |k, v| "#{stream.id}: -> HEADER: #{k}: #{log_redact(v)}" }.join("\n")
end
stream.headers(request.headers.each(extra_headers), end_stream: request.body.empty?)
end
@ -241,7 +241,7 @@ module HTTPX
end
log(level: 1, color: :yellow) do
request.trailers.each.map { |k, v| "#{stream.id}: -> HEADER: #{k}: #{v}" }.join("\n")
request.trailers.each.map { |k, v| "#{stream.id}: -> HEADER: #{k}: #{log_redact(v)}" }.join("\n")
end
stream.headers(request.trailers.each, end_stream: true)
end
@ -269,7 +269,7 @@ module HTTPX
def send_chunk(request, stream, chunk, next_chunk)
log(level: 1, color: :green) { "#{stream.id}: -> DATA: #{chunk.bytesize} bytes..." }
log(level: 2, color: :green) { "#{stream.id}: -> #{chunk.inspect}" }
log(level: 2, color: :green) { "#{stream.id}: -> #{log_redact(chunk.inspect)}" }
stream.data(chunk, end_stream: end_stream?(request, next_chunk))
end
@ -290,7 +290,7 @@ module HTTPX
end
log(color: :yellow) do
h.map { |k, v| "#{stream.id}: <- HEADER: #{k}: #{v}" }.join("\n")
h.map { |k, v| "#{stream.id}: <- HEADER: #{k}: #{log_redact(v)}" }.join("\n")
end
_, status = h.shift
headers = request.options.headers_class.new(h)
@ -303,14 +303,14 @@ module HTTPX
def on_stream_trailers(stream, response, h)
log(color: :yellow) do
h.map { |k, v| "#{stream.id}: <- HEADER: #{k}: #{v}" }.join("\n")
h.map { |k, v| "#{stream.id}: <- HEADER: #{k}: #{log_redact(v)}" }.join("\n")
end
response.merge_headers(h)
end
def on_stream_data(stream, request, data)
log(level: 1, color: :green) { "#{stream.id}: <- DATA: #{data.bytesize} bytes..." }
log(level: 2, color: :green) { "#{stream.id}: <- #{data.inspect}" }
log(level: 2, color: :green) { "#{stream.id}: <- #{log_redact(data.inspect)}" }
request.response << data
end
@ -398,8 +398,15 @@ module HTTPX
def on_frame_sent(frame)
log(level: 2) { "#{frame[:stream]}: frame was sent!" }
log(level: 2, color: :blue) do
payload = frame
payload = payload.merge(payload: frame[:payload].bytesize) if frame[:type] == :data
payload =
case frame[:type]
when :data
frame.merge(payload: frame[:payload].bytesize)
when :headers
frame.merge(payload: log_redact(frame[:payload]))
else
frame
end
"#{frame[:stream]}: #{payload}"
end
end
@ -407,15 +414,22 @@ module HTTPX
def on_frame_received(frame)
log(level: 2) { "#{frame[:stream]}: frame was received!" }
log(level: 2, color: :magenta) do
payload = frame
payload = payload.merge(payload: frame[:payload].bytesize) if frame[:type] == :data
payload =
case frame[:type]
when :data
frame.merge(payload: frame[:payload].bytesize)
when :headers
frame.merge(payload: log_redact(frame[:payload]))
else
frame
end
"#{frame[:stream]}: #{payload}"
end
end
def on_altsvc(origin, frame)
log(level: 2) { "#{frame[:stream]}: altsvc frame was received" }
log(level: 2) { "#{frame[:stream]}: #{frame.inspect}" }
log(level: 2) { "#{frame[:stream]}: #{log_redact(frame.inspect)}" }
alt_origin = URI.parse("#{frame[:proto]}://#{frame[:host]}:#{frame[:port]}")
params = { "ma" => frame[:max_age] }
emit(:altsvc, origin, alt_origin, origin, params)

View File

@ -15,7 +15,13 @@ module HTTPX
USE_DEBUG_LOG = ENV.key?("HTTPX_DEBUG")
def log(level: @options.debug_level, color: nil, debug_level: @options.debug_level, debug: @options.debug, &msg)
def log(
level: @options.debug_level,
color: nil,
debug_level: @options.debug_level,
debug: @options.debug,
&msg
)
return unless debug_level >= level
debug_stream = debug || ($stderr if USE_DEBUG_LOG)
@ -37,5 +43,11 @@ module HTTPX
def log_exception(ex, level: @options.debug_level, color: nil, debug_level: @options.debug_level, debug: @options.debug)
log(level: level, color: color, debug_level: debug_level, debug: debug) { ex.full_message }
end
def log_redact(text, should_redact = @options.debug_redact)
return text.to_s unless should_redact
"[REDACTED]"
end
end
end

View File

@ -39,6 +39,7 @@ module HTTPX
:max_requests => Float::INFINITY,
:debug => nil,
:debug_level => (ENV["HTTPX_DEBUG"] || 1).to_i,
:debug_redact => ENV.key?("HTTPX_DEBUG_REDACT"),
:ssl => EMPTY_HASH,
:http2_settings => { settings_enable_push: 0 }.freeze,
:fallback_protocol => "http/1.1",
@ -101,6 +102,7 @@ module HTTPX
#
# :debug :: an object which log messages are written to (must respond to <tt><<</tt>)
# :debug_level :: the log level of messages (can be 1, 2, or 3).
# :debug_redact :: whether header/body payload should be redacted (defaults to <tt>false</tt>).
# :ssl :: a hash of options which can be set as params of OpenSSL::SSL::SSLContext (see HTTPX::IO::SSL)
# :http2_settings :: a hash of options to be passed to a HTTP2::Connection (ex: <tt>{ max_concurrent_streams: 2 }</tt>)
# :fallback_protocol :: version of HTTP protocol to use by default in the absence of protocol negotiation
@ -226,7 +228,7 @@ module HTTPX
request_class response_class headers_class request_body_class
response_body_class connection_class options_class
pool_class pool_options
io fallback_protocol debug resolver_class
io fallback_protocol debug debug_redact resolver_class
compress_request_body decompress_response_body
persistent close_on_fork
].each do |method_name|

View File

@ -11,5 +11,7 @@ module HTTPX
def log: (?level: Integer?, ?color: Symbol?, ?debug_level: Integer, ?debug: _IOLogger?) { () -> String } -> void
def log_exception: (Exception error, ?level: Integer, ?color: Symbol, ?debug_level: Integer, ?debug: _IOLogger?) -> void
def log_redact: (_ToS text, ?bool should_redact) -> String
end
end

View File

@ -58,6 +58,23 @@ class HTTPTest < Minitest::Test
assert log_output.include?("HEADER: content-length: ")
end
def test_verbose_log_redact
log = StringIO.new
uri = URI(build_uri("/get"))
response = HTTPX.plugin(SessionWithPool).get(uri, debug: log, debug_level: 3, debug_redact: true)
verify_status(response, 200)
log_output = log.string
# assert request headers
assert log_output.include?("HEADLINE: \"GET #{uri.path} HTTP/1.1\"")
assert log_output.include?("HEADER: Accept: [REDACTED]")
assert log_output.include?("HEADER: Host: [REDACTED]")
assert log_output.include?("HEADER: Connection: [REDACTED]")
# assert response headers
assert log_output.include?("HEADLINE: 200 HTTP/1.1")
assert log_output.include?("HEADER: content-type: [REDACTED]")
assert log_output.include?("HEADER: content-length: [REDACTED]")
end
def test_debug_with_and_without_color_codes
log = StringIO.new
def log.isatty

View File

@ -98,6 +98,7 @@ class OptionsTest < Minitest::Test
:max_requests => Float::INFINITY,
:debug => nil,
:debug_level => 1,
:debug_redact => false,
:buffer_size => 16_384,
:window_size => 16_384,
:body_threshold_size => 114_688,