Search code examples
ruby-on-railsherokupuma

Heroku H18 error in a Rails app on an unhandled route

I'm getting mysterious H18 errors on Heroku. Theses requests seems to be made by bots or crawlers sending POST requests on the root URL of my application. What concerns me is that these requests all take more than 30 seconds to process before they get terminated, most likely by a timeout. Here is a sample of my log file and Metric graph:

Dec 14 03:52:26 poll-en heroku/router sock=backend at=error code=H18 desc="Server Request Interrupted" method=POST path="/" host=app.do request_id=72252a6a-d4b5-4ecc-ae3c-bc69c273eb16 fwd="138.201.76.138" dyno=web.1 connect=1ms service=30034ms status=503 bytes=71 protocol=http
Dec 14 04:05:11 poll-en heroku/router sock=backend at=error code=H18 desc="Server Request Interrupted" method=POST path="/" host=app.do request_id=78ea5ae4-9e8a-4c90-b26e-c2eae40116b4 fwd="148.251.231.105" dyno=web.1 connect=0ms service=31392ms status=503 bytes=71 protocol=http
Dec 14 04:19:07 poll-en heroku/router sock=backend at=error code=H18 desc="Server Request Interrupted" method=POST path="/" host=app.do request_id=bcc76545-24e0-4fc7-8e63-a08bb463bb31 fwd="148.251.231.105" dyno=web.1 connect=0ms service=30195ms status=503 bytes=71 protocol=http
Dec 14 04:45:35 poll-en heroku/router sock=backend at=error code=H18 desc="Server Request Interrupted" method=POST path="/" host=app.do request_id=87efe086-9879-4506-a7ac-52504219126d fwd="144.76.141.230" dyno=web.1 connect=0ms service=31733ms status=503 bytes=71 protocol=http

enter image description here

My application doesn't handle POST requests on the root URL and I can't replicate the error using cURL. Just to be sure, I also added a Rack Middleware that runs first and terminates all POST requests on the root URL. So the request shouldn't even reach the Rails router but I still get these H18 errors in my log file.

How can this happen? What kind of request could hang for 30 seconds when it is not even reaching my app?

Solution

  • What version of Puma are you using and what does your Puma config look like?

    Heroku documents that the request do reach your app when H18 happens:

    An H18 signifies that the socket connected, some data was sent as part of a response by the app, but then the socket was destroyed without completing the response.

    Perhaps you are experiencing this bug in Puma, where is sounds like the request can be stuck in Puma (never reaching your app): https://github.com/puma/puma/issues/2282 (solved in Puma 5.0.3 and above)

    You could try setting first_data_timeout in your Puma config to something that's lower than 30 seconds. Then Puma should respond with 408 Request Timeout before Heroku gives you the H18 error.