mtrudel/bandit

Lots of `(Bandit.HTTPError) closed` errors

Billzabob opened this issue · 7 comments

Billzabob commented

We've recently been seeing a lot of closed errors in production that look like this:

** (Bandit.HTTPError) closed
    (bandit 1.5.2) lib/bandit/http1/socket.ex:398: Bandit.HTTPTransport.Bandit.HTTP1.Socket.request_error!/2
    (bandit 1.5.2) lib/bandit/http1/socket.ex:231: Bandit.HTTPTransport.Bandit.HTTP1.Socket.do_read_content_length_data!/4
    (bandit 1.5.2) lib/bandit/http1/socket.ex:181: Bandit.HTTPTransport.Bandit.HTTP1.Socket.read_data/2
    (bandit 1.5.2) lib/bandit/adapter.ex:60: Bandit.Adapter.read_req_body/2
    (plug 1.16.0) lib/plug/conn.ex:1151: Plug.Conn.read_body/2
    (willow 0.5.0) lib/api/plugs/cache_body_reader.ex:12: Api.Plugs.CacheBodyReader.read_body/2
    (plug 1.16.0) lib/plug/parsers/json.ex:75: Plug.Parsers.JSON.parse/5
    (plug 1.16.0) lib/plug/parsers.ex:340: Plug.Parsers.reduce/8
    (willow 0.5.0) lib/api/endpoint.ex:1: Api.Endpoint.plug_builder_call/2
    (willow 0.5.0) lib/api/endpoint.ex:1: Api.Endpoint.call/2
    (bandit 1.5.2) lib/bandit/pipeline.ex:124: Bandit.Pipeline.call_plug!/2
    (bandit 1.5.2) lib/bandit/pipeline.ex:36: Bandit.Pipeline.run/4
    (bandit 1.5.2) lib/bandit/http1/handler.ex:12: Bandit.HTTP1.Handler.handle_data/3
    (bandit 1.5.2) lib/bandit/delegating_handler.ex:18: Bandit.DelegatingHandler.handle_data/3
    (bandit 1.5.2) /app/deps/thousand_island/lib/thousand_island/handler.ex:379: Bandit.DelegatingHandler.handle_info/2
    (stdlib 5.2) gen_server.erl:1095: :gen_server.try_handle_info/3
    (stdlib 5.2) gen_server.erl:1183: :gen_server.handle_msg/6
    (stdlib 5.2) proc_lib.erl:241: :proc_lib.init_p_do_apply/3

I'm trying to determine the proper course of action.

I'm not sure if this is a Bandit bug or not.

I've tried reproducing it locally by creating and abruptly closing a connection while the backend is still processing it and it seems to work fine. I haven't been able to reproduce this error.

Any chance you could give us some guidance on this one? Thanks.

Billzabob commented

Our current Bandit version is 1.5.2 by the way. It's hard to say exactly but it seems like these have started popping up more frequently since we upgraded to 1.5

mtrudel commented

Sorry for the late reply!

Logging changed pretty extensively in 1.5.0, and now provides a mechanism to be more selective about logging errors that come from within your plug itself vs. errors that come from the client doing unexpected things. You can configure this via the http_options.log_protocol_errors configuration option. This option currently defaults to true, but I'll be adding in a change to 1.5.3 (likely out this weekend) to have it default to (the currently unimplemented) :short option, which will log a single line on protocol errors instead of a whole stack trace.

tl;dr: if you want to wait for 1.5.3 you'll get an improved behaviour on this for free. If you're desperate in the meantime, you can set http_options.log_protocol_errors to false

Billzabob commented

Thanks for the response @mtrudel!

So just to make sure, does that mean that there isn't really anything actionable to do for these errors though? Are they something we should be worried about or should we just set that config to false and forget about them?

mtrudel commented

Unless you control the client, you can safely ignore these. They correspond to client errors, disconnections, and the like.

mtrudel commented

Fix for this is in 1.5.3, just released.

Billzabob commented

@mtrudel did I do something wrong? I set that config but we're still seeing the same errors occasionally:

config :willow, Api.Endpoint,
  adapter: Bandit.PhoenixAdapter,
  http_options: [
    log_protocol_errors: false
  ]
mtrudel commented

The http_options config belongs in the http/https stanza inside the endpoint config. See the docs for an example.

Don't feel bad; phoenix is a tricky one to config sometimes.

  • ❤️1