Strange request timeout on Heroku
First of all I'm quite familiar with the H12 timeouts on Heroku. I use Delayed Job for long running tasks, etc.
The issue I'm seeing is that a rails 3 request that takes 2 seconds locally, is timing out on Heroku. I've added logging for the entirety of the controller action, and both locally and on heroku the code execution takes about 2 seconds.
Example from Heroku:
2011-09-28T20:06:43+00:00 app[web.2]: Started POST "/xyz" for 69.181.51.78 at Wed Sep 28 13:06:43 -0700 2011
2011-09-28T20:07:12+00:00 app[web.2]: ***saved in 0.027939 s开发者_运维问答econds
2011-09-28T20:07:12+00:00 app[web.2]: ***split in 0.006164 seconds
2011-09-28T20:07:12+00:00 app[web.2]: ***reject in 0.017268 seconds
2011-09-28T20:07:12+00:00 app[web.2]: ***validate in 0.029043 seconds
2011-09-28T20:07:13+00:00 heroku[router]: Error H12 (Request timeout) -> POST xyz.com/xyz dyno=web.2 queue= wait= service=30000ms status=503 bytes=0
2011-09-28T20:07:13+00:00 app[web.2]: ***duped in 0.561905 seconds
2011-09-28T20:07:13+00:00 app[web.2]: ***dropped cats in 0.005318 seconds
2011-09-28T20:07:14+00:00 app[web.2]: ***added in 0.148055 seconds
2011-09-28T20:07:14+00:00 app[web.2]: ***saved in 0.245283 seconds
2011-09-28T20:07:14+00:00 app[web.2]: ***handled in 1.721555 seconds
As you can see from the last line, according to the logging the whole process takes 1.7 seconds, but none of these log lines are showing up for 29 seconds (we're using Rack.Timeout and set it to 29 seconds)
The request is a fairly large POST about 72K, and that ***dup log line I'm duping a hash that is about the same size. Is it possible I'm hitting the Heroku memory limit and that would manifest as an H12 timeout?
It turns out this was a temporary issue on Heroku that lasted for a couple days. It resolved itself.
I would try installing the New Relic add-on (docs here) - it has support for monitoring memory usage on dynos running Rails (ref). See if that gives you any data on how much memory you're using.
The Heroku docs say that dynos get 512MB of memory and begin throwing R14 and R15 errors as they run out. Do you see any R14 or R15s in your logs?
精彩评论