mtrudel/bandit

Dealing with "request line read error"

Stroemgren opened this issue · 11 comments

I recently switched to Bandit for my Phoenix app, which has been great for performance 🥇

However, I get errors in Sentry that I'm not sure how to deal with:
(Sentry.CrashError ** (exit) "request line read error: \"GET /?name=Paul Leger HTTP/1.1\\r\\n\"")

These are coming from the HTTP1 adapter and as I understand they're from reading and parsing the incoming request which is somehow malformed?

In case I'm right, is there any way to suppress or catch these? The API is serving millions of daily requests and some are bound to be malformed.

Bandit: 1.2.3
Phoenix: 1.7.11
Elixir: 1.15.7

That request is malformed (there's a space in the request target, see RFC9112§3).

As a general policy, Bandit is intentionally noisy about errors, including client ones (I can't begin the tell you how many issues have been raised from people switching to Bandit, only to discover that the errors they were now seeing were errors on their code that had always been there but silently swallowed by Cowboy's policy of silence).

If you wish to disable Bandit's noisiness, you can do so as described here. Note that this will swallow all exceptional exits, which is more or less what Cowboy does.

Hopefully this solves your problem. If I've missed something, feel free to reopen this issue or file another one. Thanks!

Thanks for the quick response @mtrudel.

I do get the point about being intentionally noisy - and following the development of Bandit I've actually come across some of these stories of people realizing bugs that have been there for a long time 😺

I'm having a harder time understanding the philosophy in this case, where it's an obvious client error. In these cases, I'd like to just return a 400 (possibly a custom one matching the content-type) and I don't see much value in seeing it in an error log. This is a public API with high volume, so I expect that there will be malformed requests all the time.

On a more practical level - it's literally exhausting my Sentry quota in no time and I don't feel like disabling all logging.

Am I missing something? Could I maybe ask how you'd go about this situation yourself?

A very fair question! The short answer is: mostly because I haven't had the time to rework this properly. I've had this on the back burner for a while, but you're correct that it IS a pain.

I think I see a way to solve this pretty quickly. Let me reopen this issue and try and put something together this evening; are you able to deploy branches of Bandit to verify it does what you want it to?

@Stroemgren check out the branch put forward in #321 and test it if you're able:

{:bandit, github: "mtrudel/bandit", branch: "no_error_on_4xx"}

I'd love to hear if this works for you. If so I'll get it in the next release!

Thanks for the quick attempt @mtrudel

Unfortunately, the errors still appear.

I don't really get any stack trace in Sentry. This is all that's printed:

Sentry.CrashError
** (exit) "request line read error: \"GET /genderize?name=MARK JAY&country_id=PH HTTP/1.1\\r\\n\""

I do get another error as well. This is from LiveDashboard, but definitely triggered by the switch to Bandit.

Plug.Conn.InvalidQueryError
invalid UTF-8 on urlencoded params, got byte 252

lib/plug/conn/utils.ex in Plug.Conn.Utils.do_validate_utf8!/3 at line 295
lib/plug/conn/query.ex in Plug.Conn.Query.decode_www_form/3 at line 155
lib/plug/conn/query.ex in Plug.Conn.Query.decode_www_pair/4 at line 136
lib/enum.ex in Enum."-reduce/3-lists^foldl/2-0-"/3 at line 2510
lib/plug/conn/query.ex in Plug.Conn.Query.decode/4 at line 123
lib/plug/conn.ex in Plug.Conn.fetch_query_params/2 at line 1086
lib/phoenix/live_dashboard/request_logger.ex in Phoenix.LiveDashboard.RequestLogger.verify_from_param_key/2 at line 35
lib/phoenix/live_dashboard/request_logger.ex in Phoenix.LiveDashboard.RequestLogger.call/2 at line 27

Thinking out loud - and I know you were just trying to come up with something that would make it work here, but would it not be possible to turn these errors into exceptions for example, so they could be catched further up. That would allow you to handle the client errors the same way as you would handle other client errors, like validation and return error messages in the same format.

Anyways, I'm happy to help you test things out if you decide to pursue this further. I'm eager to make the final switch to Bandit. The Sentry quota is the only real blocker right now as I would quickly have to pay a lot of bucks. Alternatively I could maybe set up a RegEx filter on the Sentry client.

Wait, I misunderstood. I thought the branch configured the errors to be suppressed, not just providing the option. I'll be back soon :)

This did it @mtrudel :)

Thinking out loud - and I know you were just trying to come up with something that would make it work here, but would it not be possible to turn these errors into exceptions for example, so they could be catched further up. That would allow you to handle the client errors the same way as you would handle other client errors, like validation and return error messages in the same format.

Not to pass the buck, but that's an error raised by the Plug library's validation routines, not anything that Bandit has direct control over.

Generally speaking, Bandit's error handling is concerned with errors that Bandit encounters building the initial request separately from error raised within the plug call. That is, the actual code looks theoretically like this (liberties taken for clarity):

with {:ok, conn} <- build_conn(socket) do
  try do
    plug.call(conn)
    {:stop, :normal, state}
  rescue
    error -> 
      return_5xx(error)
      {:stop, error, state}
  end
else
  {:error, error} -> 
    return_4xx(error)
    {:stop, error, state}
end  

the change in this PR was essentially to add an option to the return_4xx logic above to change whether or not the process then terminates cleanly or with an error, by optionally changing the final {:stop, error, state} to a {:stop, :normal, state}. But fundamentally, the overall structure is unchanged; Bandit's error handling is pretty strictly segmented between the errors that WE identify vs the errors that are identified within the plug call. As you can see from the stack trace you list above, the UTF-8 validation error is in the latter category.

Merging #321 and will release in a few minutes

Awesome @mtrudel. I'll get back on the main track then :)

'A few minutes' may be 'a few hours'; I'm trying to get one more test iteration on #322 done before merging that as part of this same release.