Skip to content

Commit

Permalink
Change log_protocol_errors config option to accept short and verbose …
Browse files Browse the repository at this point in the history
…options
  • Loading branch information
mtrudel committed Jun 7, 2024
1 parent 2d5a78c commit a2cbe62
Show file tree
Hide file tree
Showing 4 changed files with 86 additions and 5 deletions.
7 changes: 4 additions & 3 deletions lib/bandit.ex
Original file line number Diff line number Diff line change
Expand Up @@ -106,14 +106,15 @@ defmodule Bandit do
* `log_exceptions_with_status_codes`: Which exceptions to log. Bandit will log only those
exceptions whose status codes (as determined by `Plug.Exception.status/1`) match the specified
list or range. Defaults to `500..599`
* `log_protocol_errors`: Whether or not to log protocol errors such as malformed requests.
Defaults to `true`
* `log_protocol_errors`: How to log protocol errors such as malformed requests. `:short` will
log a single-line summary, while `:verbose` will log full stack traces. The value of `false`
will disable protocol error logging entirely. Defaults to `:short`
"""
@type http_options :: [
{:compress, boolean()}
| {:deflate_opions, deflate_options()}
| {:log_exceptions_with_status_codes, list() | Range.t()}
| {:log_protocol_errors, boolean()}
| {:log_protocol_errors, :short | :verbose | false}
]

@typedoc """
Expand Down
7 changes: 5 additions & 2 deletions lib/bandit/pipeline.ex
Original file line number Diff line number Diff line change
Expand Up @@ -208,8 +208,11 @@ defmodule Bandit.Pipeline do
] do
Bandit.Telemetry.stop_span(span, %{}, %{error: error.message})

if Keyword.get(opts.http, :log_protocol_errors, true),
do: Logger.error(Exception.format(:error, error, stacktrace))
case Keyword.get(opts.http, :log_protocol_errors, :short) do
:short -> Logger.error(Exception.format_banner(:error, error, stacktrace))
:verbose -> Logger.error(Exception.format(:error, error, stacktrace))
false -> :ok
end

# We want to do this at the end of the function, since the HTTP2 stack may kill this process
# in the course of handling a ConnectionError
Expand Down
32 changes: 32 additions & 0 deletions test/bandit/http1/request_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -36,6 +36,38 @@ defmodule HTTP1RequestTest do
end

describe "suppressing protocol error logging" do
test "errors are short logged by default", context do
output =
capture_log(fn ->
client = SimpleHTTP1Client.tcp_client(context)
Transport.send(client, "GET / HTTP/1.1\r\nGARBAGE\r\n\r\n")
assert {:ok, "400 Bad Request", _headers, <<>>} = SimpleHTTP1Client.recv_reply(client)
Process.sleep(100)
end)

assert output =~ "[error] ** (Bandit.HTTPError) Header read HTTP error"

# Make sure we don't log a stacktrace
refute output =~ "lib/bandit/pipeline.ex:"
end

test "errors are verbosely logged if so configured", context do
context = http_server(context, http_options: [log_protocol_errors: :verbose])

output =
capture_log(fn ->
client = SimpleHTTP1Client.tcp_client(context)
Transport.send(client, "GET / HTTP/1.1\r\nGARBAGE\r\n\r\n")
assert {:ok, "400 Bad Request", _headers, <<>>} = SimpleHTTP1Client.recv_reply(client)
Process.sleep(100)
end)

assert output =~ "[error] ** (Bandit.HTTPError) Header read HTTP error"

# Make sure we log a stacktrace
assert output =~ "lib/bandit/pipeline.ex:"
end

test "errors are not logged if so configured", context do
context = http_server(context, http_options: [log_protocol_errors: false])

Expand Down
45 changes: 45 additions & 0 deletions test/bandit/http2/protocol_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,51 @@ defmodule HTTP2ProtocolTest do
"(Bandit.HTTP2.Errors.StreamError) Received trailers with pseudo headers"
end

test "stream errors are short logged by default", context do
socket = SimpleH2Client.tls_client(context)
SimpleH2Client.exchange_prefaces(socket)

output =
capture_log(fn ->
# Send trailers with pseudo headers
{:ok, ctx} = SimpleH2Client.send_simple_headers(socket, 1, :post, "/echo", context.port)
SimpleH2Client.send_headers(socket, 1, true, [{":path", "/foo"}], ctx)
assert SimpleH2Client.recv_rst_stream(socket) == {:ok, 1, 1}
Process.sleep(100)
end)

assert output =~
"[error] ** (Bandit.HTTP2.Errors.StreamError) Received trailers with pseudo headers"

# Make sure we don't log a stacktrace
refute output =~ "lib/bandit/pipeline.ex:"
end

test "stream errors are verbosely logged if so configured", context do
context =
context
|> https_server(http_options: [log_protocol_errors: :verbose])
|> Enum.into(context)

socket = SimpleH2Client.tls_client(context)
SimpleH2Client.exchange_prefaces(socket)

output =
capture_log(fn ->
# Send trailers with pseudo headers
{:ok, ctx} = SimpleH2Client.send_simple_headers(socket, 1, :post, "/echo", context.port)
SimpleH2Client.send_headers(socket, 1, true, [{":path", "/foo"}], ctx)
assert SimpleH2Client.recv_rst_stream(socket) == {:ok, 1, 1}
Process.sleep(100)
end)

assert output =~
"[error] ** (Bandit.HTTP2.Errors.StreamError) Received trailers with pseudo headers"

# Make sure we log a stacktrace
assert output =~ "lib/bandit/pipeline.ex:"
end

test "stream errors are not logged if so configured", context do
context =
context
Expand Down

0 comments on commit a2cbe62

Please sign in to comment.