The Rack Middleware and Heroku Request Queue occasionally spike in my Ruby/Sinatra app, which causes the app to hang until I manually restart the servers. I have made tweaks to the Rack::Timeout, Postgres Timeout, and updated the Postgres calls so that they mostly run for under 100ms. Typically, when the Request Queue increases, the servers will automatically restart and then continue without issue, but when the Middleware spikes, the app is unable to recover and the app continues to hang in the request queue until it times out. What is causing that to happen?
Here is a screenshot of New Relic showing the spike in Middleware:
And here are the files where I set the middleware and database connections:
threads_count = Integer(5)
threads threads_count, threads_count
port ENV['PORT'] || 3000
environment ENV['RACK_ENV'] || 'development'
db = URI.parse(ENV['DATABASE_URL'])
:adapter => db.scheme == 'postgres' ? 'postgresql' : db.scheme,
:host => db.host,
:username => db.user,
:password => db.password,
:database => db.path[1..-1],
:port => db.port,
:encoding => 'utf8',
:reaping_frequency => 10
:pool => 5
:timeout => 11
use Rack::Timeout, service_timeout: 16, wait_timeout: 23
gem 'puma', "~> 2.16.0"
gem "activerecord", "< 5.0.0" # h/t https://github.com/janko-m/sinatra-activerecord/pull/66
Logfile from a time when the app crashed
app/web.2: Rack app error: #<Rack::Timeout::RequestTimeoutError: Request waited 783ms, then ran for longer than 15000ms>
app/web.2: /app/vendor/bundle/ruby/2.3.0/gems/activerecord-126.96.36.199/lib/active_record/connection_adapters/postgresql/database_statements.rb:155:in `async_exec'
app/web.2: #<Rack::Timeout::RequestExpiryError: Request older than 30000ms.>
Additional Logfile with error that occasionally occurs before app crashes
app/web.2: /app/vendor/ruby-2.3.1/lib/ruby/2.3.0/monitor.rb:187:in `lock', deadlock; recursive locking