Skip to content

Commit 95c0c44

Browse files
committed
Add binary body formatting to the logging feature
Binary request bodies (IO/Enumerable sources and binary-encoded strings) and binary-encoded response bodies are now formatted instead of dumped raw, preventing unreadable log output when transferring files. Add `Request::Body#loggable?` and `Response::Body#loggable?` predicates to detect inspectable body content, and a `binary_formatter` option on the Logging feature with three modes: * `:stats` (default) — logs "BINARY DATA (N bytes)" * `:base64` — logs base64-encoded content with byte count * `Proc` — custom formatting via a callable Closes #784.
1 parent 43798f0 commit 95c0c44

8 files changed

Lines changed: 420 additions & 9 deletions

File tree

CHANGELOG.md

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,14 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
2727
per RFC 3986. Supports chaining (`HTTP.base_uri("https://api.example.com/v1")
2828
.get("users")`), and integrates with `persistent` connections by deriving the
2929
host when omitted (#519, #512, #493)
30+
- `Request::Body#loggable?` and `Response::Body#loggable?` predicates, and a
31+
`binary_formatter` option for the logging feature. Binary bodies
32+
(IO/Enumerable request sources, binary-encoded request strings, and
33+
binary-encoded responses) are now formatted instead of dumped raw,
34+
preventing unreadable log output when transferring files like images or
35+
audio. Available formatters: `:stats` (default, logs byte count),
36+
`:base64` (logs base64-encoded content), or a custom `Proc`. Invalid
37+
formatter values raise `ArgumentError` (#784)
3038
- `Feature#on_request` and `Feature#around_request` lifecycle hooks, called
3139
before/around each request attempt (including retries), for per-attempt side
3240
effects like instrumentation spans and circuit breakers (#826)

lib/http/features/logging.rb

Lines changed: 71 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,17 @@ module Features
99
#
1010
# HTTP.use(logging: {logger: Logger.new(STDOUT)}).get("https://example.com/")
1111
#
12+
# Binary bodies (IO/Enumerable request sources and binary-encoded
13+
# responses) are formatted using the +binary_formatter+ option instead
14+
# of being dumped raw. Available formatters:
15+
#
16+
# - +:stats+ (default) — logs <tt>BINARY DATA (N bytes)</tt>
17+
# - +:base64+ — logs <tt>BINARY DATA (N bytes)\n<base64></tt>
18+
# - +Proc+ — calls the proc with the raw binary string
19+
#
20+
# @example Custom binary formatter
21+
# HTTP.use(logging: {logger: Logger.new(STDOUT), binary_formatter: :base64})
22+
#
1223
class Logging < Feature
1324
HTTP::Options.register_feature(:logging, self)
1425

@@ -39,12 +50,17 @@ class NullLogger
3950
# @example
4051
# Logging.new(logger: Logger.new(STDOUT))
4152
#
53+
# @example With binary formatter
54+
# Logging.new(logger: Logger.new(STDOUT), binary_formatter: :base64)
55+
#
4256
# @param logger [#info, #debug] logger instance
57+
# @param binary_formatter [:stats, :base64, #call] how to log binary bodies
4358
# @return [Logging]
4459
# @api public
45-
def initialize(logger: NullLogger.new)
60+
def initialize(logger: NullLogger.new, binary_formatter: :stats)
4661
super()
4762
@logger = logger
63+
@binary_formatter = validate_binary_formatter!(binary_formatter)
4864
end
4965

5066
# Logs and returns the request
@@ -57,7 +73,7 @@ def initialize(logger: NullLogger.new)
5773
# @api public
5874
def wrap_request(request)
5975
logger.info { "> #{request.verb.to_s.upcase} #{request.uri}" }
60-
logger.debug { "#{stringify_headers(request.headers)}\n\n#{request.body.source}" }
76+
log_request_details(request)
6177

6278
request
6379
end
@@ -83,11 +99,43 @@ def wrap_response(response)
8399

84100
private
85101

102+
# Validate and return the binary_formatter option
103+
# @return [:stats, :base64, #call]
104+
# @raise [ArgumentError] if the formatter is not a valid option
105+
# @api private
106+
def validate_binary_formatter!(formatter)
107+
return formatter if formatter == :stats || formatter == :base64 || formatter.respond_to?(:call)
108+
109+
raise ArgumentError,
110+
"binary_formatter must be :stats, :base64, or a callable " \
111+
"(got #{formatter.inspect})"
112+
end
113+
114+
# Log request headers and body (when loggable)
115+
# @return [void]
116+
# @api private
117+
def log_request_details(request)
118+
headers = stringify_headers(request.headers)
119+
if request.body.loggable?
120+
source = request.body.source
121+
body = source.encoding == Encoding::BINARY ? format_binary(source) : source # steep:ignore
122+
logger.debug { "#{headers}\n\n#{body}" }
123+
else
124+
logger.debug { headers }
125+
end
126+
end
127+
86128
# Log response with body inline (for non-streaming string bodies)
87129
# @return [HTTP::Response]
88130
# @api private
89131
def log_response_body_inline(response)
90-
logger.debug { "#{stringify_headers(response.headers)}\n\n#{response.body}" }
132+
body = response.body
133+
headers = stringify_headers(response.headers)
134+
if body.respond_to?(:encoding) && body.encoding == Encoding::BINARY # steep:ignore
135+
logger.debug { "#{headers}\n\n#{format_binary(body)}" } # steep:ignore
136+
else
137+
logger.debug { "#{headers}\n\n#{body}" }
138+
end
91139
response
92140
end
93141

@@ -110,10 +158,25 @@ def logged_response_options(response)
110158
# @return [HTTP::Response::Body]
111159
# @api private
112160
def logged_body(body)
113-
stream = BodyLogger.new(body.instance_variable_get(:@stream), logger)
161+
formatter = body.loggable? ? nil : method(:format_binary) # steep:ignore
162+
stream = BodyLogger.new(body.instance_variable_get(:@stream), logger, formatter: formatter) # steep:ignore
114163
Response::Body.new(stream, encoding: body.encoding)
115164
end
116165

166+
# Format binary data according to the configured binary_formatter
167+
# @return [String]
168+
# @api private
169+
def format_binary(data)
170+
case @binary_formatter
171+
when :stats
172+
format("BINARY DATA (%d bytes)", data.bytesize)
173+
when :base64
174+
format("BINARY DATA (%d bytes)\n%s", data.bytesize, [data].pack("m0"))
175+
else
176+
@binary_formatter.call(data) # steep:ignore
177+
end
178+
end
179+
117180
# Convert headers to a string representation
118181
# @return [String]
119182
# @api private
@@ -139,12 +202,14 @@ class BodyLogger
139202
#
140203
# @param stream [#readpartial] the stream to wrap
141204
# @param logger [#debug] the logger instance
205+
# @param formatter [#call, nil] optional formatter for each chunk
142206
# @return [BodyLogger]
143207
# @api public
144-
def initialize(stream, logger)
208+
def initialize(stream, logger, formatter: nil)
145209
@stream = stream
146210
@connection = stream.respond_to?(:connection) ? stream.connection : stream
147211
@logger = logger
212+
@formatter = formatter
148213
end
149214

150215
# Read a chunk from the underlying stream and log it
@@ -157,7 +222,7 @@ def initialize(stream, logger)
157222
# @api public
158223
def readpartial(*)
159224
chunk = @stream.readpartial(*)
160-
@logger.debug { chunk }
225+
@logger.debug { @formatter ? @formatter.call(chunk) : chunk } # steep:ignore
161226
chunk
162227
end
163228
end

lib/http/request/body.rb

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,24 @@ def empty?
3737
@source.nil?
3838
end
3939

40+
# Whether the body content can be accessed for logging
41+
#
42+
# Returns true for String sources (the content can be inspected).
43+
# Returns false for IO streams and Enumerables (which cannot be
44+
# read without consuming them), and for nil bodies.
45+
#
46+
# The logging feature checks the string encoding separately to
47+
# decide whether to log the content as text or format it as binary.
48+
#
49+
# @example
50+
# body.loggable? # => true
51+
#
52+
# @return [Boolean]
53+
# @api public
54+
def loggable?
55+
@source.is_a?(String)
56+
end
57+
4058
# Returns size for the "Content-Length" header
4159
#
4260
# @example

lib/http/response/body.rb

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -115,6 +115,20 @@ def stream!
115115
@streaming = true
116116
end
117117

118+
# Whether the body content is suitable for logging
119+
#
120+
# Returns true when the body encoding is not binary. Binary responses
121+
# (images, audio, compressed data) produce unreadable log output.
122+
#
123+
# @example
124+
# body.loggable? # => true
125+
#
126+
# @return [Boolean]
127+
# @api public
128+
def loggable?
129+
@encoding != Encoding::BINARY
130+
end
131+
118132
# Easier to interpret string inspect
119133
#
120134
# @example

sig/http.rbs

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -395,21 +395,28 @@ module HTTP
395395

396396
attr_reader logger: untyped
397397

398-
def initialize: (?logger: untyped) -> void
398+
@binary_formatter: :stats | :base64 | ^(String) -> String
399+
400+
def initialize: (?logger: untyped, ?binary_formatter: :stats | :base64 | ^(String) -> String) -> void
399401
def wrap_request: (Request request) -> Request
400402
def wrap_response: (Response response) -> Response
401403

402404
private
403405

406+
def validate_binary_formatter!: (:stats | :base64 | ^(String) -> String formatter) -> (:stats | :base64 | ^(String) -> String)
407+
def log_request_details: (Request request) -> void
404408
def log_response_body_inline: (Response response) -> Response
405409
def logged_response_options: (Response response) -> Hash[Symbol, untyped]
406410
def logged_body: (Response::Body body) -> Response::Body
411+
def format_binary: (String data) -> String
407412
def stringify_headers: (Headers headers) -> String
408413

409414
class BodyLogger
410415
attr_reader connection: untyped
411416

412-
def initialize: (untyped stream, untyped logger) -> void
417+
@formatter: (^(String) -> String)?
418+
419+
def initialize: (untyped stream, untyped logger, ?formatter: (^(String) -> String)?) -> void
413420
def readpartial: (?Integer size, ?String? outbuf) -> String
414421
end
415422
end
@@ -741,6 +748,7 @@ module HTTP
741748

742749
def initialize: (untyped source) -> void
743750
def empty?: () -> bool
751+
def loggable?: () -> bool
744752
def size: () -> Integer
745753
def each: () { (String) -> void } -> self
746754
| () -> Enumerator[String, self]
@@ -881,6 +889,7 @@ module HTTP
881889
def to_s: () -> untyped
882890
alias to_str to_s
883891
def stream!: () -> untyped
892+
def loggable?: () -> bool
884893
def inspect: () -> String
885894

886895
private

0 commit comments

Comments
 (0)