Are you spending too much time in Rack middlewares?
Is one of your Rack middlewares misbehaving in production?
Add RackTimer::Middleware
to the to of your middleware stack and figure out.
Add this line to your application's Gemfile:
gem 'rack-timer'
Add the middleware to your stack. In your config.ru
, add this before any other
middleware:
require 'rack-timer'
use RackTimer::Middleware
When your app runs, it will output timing information to standard error.
If you want to change that, you can tell rack-timer
to send data to another
file-y object, for instance:
RackTimer.output = $stdout
Run your app normally after installation, wait a while, and download your logs.
They will report the middleware starting up:
[rack-timer] assimilating: Rack::MiddlewareTimer
[rack-timer] assimilating: Rack::Lock
[rack-timer] assimilating: Airbrake::UserInformer
[rack-timer] assimilating: Rack::DetectCrawler
then timing each request:
[rack-timer] Proc took 3398135 us
[rack-timer] Rack::Cors took 54 us
[rack-timer] Rack::OutOfBandGC took 51 us
...
[rack-timer] Airbrake::UserInformer took 74 us
[rack-timer] Rack::Lock took 78 us
[rack-timer] Rack::MiddlewareTimer took 80 us
[rack-timer] queued for 5256 us
Besides middleware timing, two bits of extra information are reported:
Proc
(the first entry for each request) typically is your app itself
(excluding middleware).queued for...
will be present if your web frontend adds the X-Request-Start
HTTP header. If using Nginx+Unicorn or Apache+Passenger, this will report the
queueing time in Unicorn or Passenger.We developed this because of wierd issues with queuing time (was too high without an obvious reason).
We graphed the middleware timings:
And the queueing timings:
(horizontally: log10 of the queuing time in microseconds, ie. 3 is 1ms and 6 is 1 second)
The conlusion was that something what causing queuing in some cases. It turned out our out-of-band garbage colleciton hack was no longer compatible with Passenger, and removing it solved the issue:
git checkout -b my-new-feature
)git commit -am 'Add some feature'
)git push origin my-new-feature
)