ruby - 是什么导致我的 Rack 中间件出现峰值？

Question

Rack Middleware 和 Heroku Request Queue 偶尔会在我的 Ruby/Sinatra 应用程序中出现峰值，这会导致应用程序挂起，直到我手动重新启动服务器。我对 Rack::Timeout、Postgres Timeout 进行了调整，并更新了 Postgres 调用，以便它们的运行时间大多低于 100 毫秒。通常，当请求队列增加时，服务器会自动重启，然后继续正常运行，但当中间件达到峰值时，应用程序无法恢复，应用程序会继续卡在请求队列中，直到超时。是什么导致了这种情况？

这是 New Relic 的屏幕截图，显示了中间件的峰值:

下面是我设置中间件和数据库连接的文件:

config/puma.rb

threads_count = Integer(5)
threads threads_count, threads_count

preload_app!

rackup      DefaultRackup
port        ENV['PORT']     || 3000
environment ENV['RACK_ENV'] || 'development'

on_worker_boot do
    ActiveSupport.on_load(:active_record) do
        db = URI.parse(ENV['DATABASE_URL'])
        ActiveRecord::Base.establish_connection(
            :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
        )
    end
end

config.ru

require "rack-timeout"
use Rack::Timeout, service_timeout: 16, wait_timeout: 23

require './web'

run Sinatra::Application
use ActiveRecord::ConnectionAdapters::ConnectionManagement

rakefile.rb

require "./web"
require "sinatra/activerecord/rake"

gem 文件

source 'https://rubygems.org'
ruby '2.3.1'
gem 'rack-timeout'
gem 'rake'
gem 'sinatra'
gem 'puma', "~> 2.16.0"
gem 'pg'
gem "activerecord", "< 5.0.0" # h/t https://github.com/janko-m/sinatra-activerecord/pull/66
gem 'activesupport'
gem 'sinatra-activerecord'
gem 'redis'
gem 'tilt'

应用崩溃时的日志文件

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-4.2.7.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:155:in `async_exec' 
app/web.2:  #<Rack::Timeout::RequestExpiryError: Request older than 30000ms.> 

在应用程序崩溃之前偶尔会出现错误的附加日志文件

app/web.2: /app/vendor/ruby-2.3.1/lib/ruby/2.3.0/monitor.rb:187:in `lock', deadlock; recursive locking

Answer 1

基于超时错误回溯的这一行:

/app/vendor/bundle/ruby/2.3.0/gems/activerecord-4.2.7.1/lib/active_record/connection_adapters/postgresql/database_statements.rb:155:in `async_exec'

在请求被强制超时 (Rack::Timeout) 的那一刻，事件记录似乎正在对您的数据库进行 async_exec 调用。

根据您发布的其他错误:

/app/vendor/ruby-2.3.1/lib/ruby/2.3.0/monitor.rb:187:in `lock', deadlock; recursive locking

我会说很明显 postgres 连接适配器遇到了死锁。

目前尚不清楚死锁是发生在 postgres 中并冒泡到事件记录中，还是死锁发生在连接适配器代码中。您是否在 postgres 中记录了任何缓慢的查询？死锁错误可能只是一个 symptom of using Rack::Timeout (or just the Timeout ruby class) while using threads .可能是线程由于查询缓慢而超时，引发了 Timeout::Error 并且连接管理中的连接/互斥锁变得不稳定/管理不善。