タイトルと内容にズレがあり誤解を招きそうなのでタイトルを直しました。
調査に用いたSinatraのアプリケーションコード(github)
概要
Sinatra+Thin+MySQLで簡単なAPIサーバを立てることを考えよう。
Sinatraアプリは公式で紹介されている2種類の起動方法があるが、それによってマルチスレッドか否か(rack.multithread)の動作モードに違いが出た。マルチスレッド版だと、デフォルトの設定でコネクションプール数が生えてくるワーカースレッドの数より小さいため、(コネクションプール数)+1回目のアクセスでエラーが起こる。この問題は、コネクションプール数をワーカースレッド数以上に設定することで解決できる。
両者の起動方法はRackが間に挟まるかどうかが異なり、Thinに渡されているオプションが異なる可能性がある。
以下は上記結論に至るまでに調べたこと、考えたことのメモ。
前提
アプリのコード
require 'sinatra/base'
require 'active_record'
require 'mysql2'
require 'json'
require 'yaml'
class MyApp < Sinatra::Base
connection_setting = YAML.load(ERB.new(File.read('database.yml')).result)
ActiveRecord::Base.establish_connection connection_setting['development']
class User < ActiveRecord::Base
end
get '/ranking' do
User.order(score: :desc).limit(50).to_json
end
run! if app_file == $0
end
get /ranking にアクセスが行くと、登録されているユーザをscoreの降順に並べ、先頭から50件取ってJSONを返すようになっている。
今回、DBの処理そのものは本質的ではないので、(何かしらDBにアクセスしに行くコード)が入っていると考えてもらって構わない。
データベース
以下のように設定ファイルを書いて、
development:
adapter: mysql2
database: writeapp_sinatra
host: localhost
username: root
password:
encoding: utf8
データベース writeapp_sinatra と、User に対応するテーブルをMySQLにて予め作成しておく。
-- データベース作成
mysql> create database writeapp_sinatra default character set utf8mb4;
Query OK, 1 row affected (0.00 sec)
-- データベースを writeapp_sinatra に切り替え
mysql> use writeapp_sinatra;
Database changed
-- users テーブルを作成
mysql> create table users (
-> id BIGINT UNSIGNED NOT NULL AUTO_INCREMENT,
-> name VARCHAR(255) NOT NULL,
-> score BIGINT NOT NULL,
-> PRIMARY KEY(id)
-> );
Query OK, 0 rows affected (0.03 sec)
WebサーバはThin
RackおよびSinatraは Thin が利用可能である場合、それを使おうとするのでGemfileに入れておく。
source 'https://rubygems.org'
gem 'sinatra'
gem 'activerecord'
gem 'mysql2', '~> 0.3.20'
gem 'thin'
bundler を用いてインストールが終わったら、準備完了。
起動方法A
アプリを動かす
以下のようにしてSinatraアプリケーションを起動できる。
bundle exec ruby app.rb
この方法で起動すると app.rb 末尾の if app_file == $0 が真になり、 Sinatra::Base#run! が実行される。
何回か /ranking にアクセスを試みると、DBに接続できていることがわかる。しかし、6回目のアクセスで、以下のエラーが表示される。
ActiveRecord::ConnectionTimeoutError - could not obtain a database connection within 5.000 seconds (waited 5.004 seconds):
規定の秒数待ってもDBにコネクションが貼れなかった、という趣旨のエラーだ。
MySQLのプロセスを確認
このままの状態で、MySQLのコンソールに入って現在動いているプロセスを確認してみる。
mysql> show processlist;
+----+------+-----------+------------------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------------------+---------+------+-------+------------------+
| 8 | root | localhost | NULL | Query | 0 | init | show processlist |
| 39 | root | localhost | writeapp_sinatra | Sleep | 9 | | NULL |
| 40 | root | localhost | writeapp_sinatra | Sleep | 7 | | NULL |
| 41 | root | localhost | writeapp_sinatra | Sleep | 7 | | NULL |
| 42 | root | localhost | writeapp_sinatra | Sleep | 6 | | NULL |
| 43 | root | localhost | writeapp_sinatra | Sleep | 6 | | NULL |
+----+------+-----------+------------------+---------+------+-------+------------------+
このように、5つ分のコネクションが開放されないまま残っている。MySQLの最大コネクション数は100程度なので、アプリ側がコネクションを保持したままになっていることが原因だろう。
デフォルトのコネクションプール数をActiveRecordのドキュメントで調べると
Options There are several connection-pooling-related options that you can add to your database connection configuration: **pool: number indicating size of connection pool (default 5)** checkout_timeout: number of seconds to block and wait for a connection before giving up and raising a timeout error (default 5 seconds).
とあるので、この予想は正しいように思える。
起動方法B
ところで、Sinatraを動かすには別の方法がある。以下の様に config.ru というファイルを作成し、
require 'sinatra'
require File.expand_path('../app.rb', __FILE__)
run MyApp
rackup を叩くとサーバが起動する。
bundle exec rackup
アプリを動かす
こちらは、何度アクセスしてもエラーは起こらない。
MySQLのプロセスを確認
MySQLのプロセスを確認すると、
mysql> show processlist;
+----+------+-----------+------------------+---------+------+-------+------------------+
| Id | User | Host | db | Command | Time | State | Info |
+----+------+-----------+------------------+---------+------+-------+------------------+
| 91 | root | localhost | writeapp_sinatra | Sleep | 41 | | NULL |
| 92 | root | localhost | NULL | Query | 0 | init | show processlist |
+----+------+-----------+------------------+---------+------+-------+------------------+
コネクションは1つだけである。起動の仕方で、なぜこのような違いが起こるのだろうか。
何が起きているのか知る
rack envを確認
rack envはRackの動作モードが記述されている変数で、request.env で確認できる。get /ranking に出力するコードを仕込んで、両者の違いを見てみよう。
get '/ranking' do
p request.env # 追加
User.order(score: :desc).limit(50).to_json
end
すると、以下の違いが確認できた。
rack.multithread = true
rack.multithread = false
rack.multithread とは何か。ドキュメントを読むと
rack.multithread true if the application object may be simultaneously invoked by another thread in the same process, false otherwise.
とある。つまり起動方法Aだとサーバがマルチスレッドで動いている・・・？
psで確認
より状況をはっきりさせるため、起動後、何回かアクセスした後に ps -M を実行しプロセスの上で走っているスレッドを確認する。
> ps -M
hama_du 18479 s007 0.0 S 31T 0:00.11 0:00.72 /Users/hama_du/.rbenv/versions/2.2.1/bin/ruby app.rb
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.01
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.03
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.01
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
18479 0.0 S 31T 0:00.00 0:00.00
> ps -M
hama_du 18768 s007 0.0 S 31T 0:00.22 0:00.84 ruby /Users/hama_du/projects/backend-speed-experiment/sinatra-mysql/vendor/bundle/ruby/2.2.0/bin/rackup
18768 0.0 S 31T 0:00.00 0:00.00
このように、起動方法Aでは複数(1+20個)のスレッドが走っていることが確認できた。この数は何度アクセスしても増える様子はなかった。
解決法(？)
起動方法Aにおいてスレッドごとにコネクションを貼りに行き、それをしばらく持つ実装になっている、と予想。すると コネクションプール数をスレッド数以上にする ことで解決できるのでは、という勘が生えた。早速設定してみよう。
development:
adapter: mysql2
database: writeapp_sinatra
host: localhost
username: root
password:
encoding: utf8
pool: 20 # 追加
起動方法Aでサーバを動かす。今度は、コネクションプール数以上のアクセスでもエラーにはならなかった。
何故起こったかを知る
取り急ぎの解決法は分かったので、今度は視点を変えて 何故設定に違いが生じたか を見ていこう。それには、両者のアプリの起動順序について細かく確認する必要がある。
起動方法A
bundle exec ruby app.rb
app.rbの末尾には run! if app_file == $0 が書かれており、これによって Sinatra::Base#run! が走るようになっている。これは公式ドキュメントで紹介されている方法である。
require 'sinatra/base'
# (略)
class MyApp < Sinatra::Base
# (略)
run! if app_file == $0
end
Sinatra::Base#run!
def run!(options = {}, &block)
return if running?
set options
handler = detect_rack_handler
handler_name = handler.name.gsub(/.*::/, '')
server_settings = settings.respond_to?(:server_settings) ? settings.server_settings : {}
server_settings.merge!(:Port => port, :Host => bind)
begin
start_server(handler, server_settings, handler_name, &block)
rescue Errno::EADDRINUSE
$stderr.puts "== Someone is already performing on port #{port}!"
raise
ensure
quit!
end
end
start_serverの中身を見る。
def start_server(handler, server_settings, handler_name)
handler.run(self, server_settings) do |server|
unless handler_name =~ /cgi/i
$stderr.puts "== Sinatra (v#{Sinatra::VERSION}) has taken the stage on #{port} for #{environment} with backup from #{handler_name}"
end
setup_traps
set :running_server, server
set :handler_name, handler_name
server.threaded = settings.threaded if server.respond_to? :threaded=
yield server if block_given?
end
end
ここでは handler は Thin のことなので、handler.run 以降の処理は一旦 Thin に移る。サーバが準備出来たら、メッセージを出力し各種設定を行っている。
起動方法B
bundle exec rackup
rackupのコードの中身は以下のとおりである。
#!/usr/bin/env ruby
require "rack"
Rack::Server.start
Rack::Server.start が呼ばれているようなので、そのコードを読む。
def self.start(options = nil)
new(options).start
end
インスタンスの start が呼ばれているので、追う。
def start &blk
if options[:warn]
$-w = true
end
if includes = options[:include]
$LOAD_PATH.unshift(*includes)
end
if library = options[:require]
require library
end
if options[:debug]
$DEBUG = true
require 'pp'
p options[:server]
pp wrapped_app
pp app
end
check_pid! if options[:pid]
# Touch the wrapped app, so that the config.ru is loaded before
# daemonization (i.e. before chdir, etc).
wrapped_app
daemonize_app if options[:daemonize]
write_pid if options[:pid]
trap(:INT) do
if server.respond_to?(:shutdown)
server.shutdown
else
exit
end
end
server.run wrapped_app, options, &blk
end
ここで server は Thin のことである。最後の server.run でサーバを起動させていることはわかるが、ここで wrapped_app とは何だろうか。
・・・この調子でまともに追っていくのと長くなってしまうので結論だけ書くと、これは config.ru から生成される、Rack::Builder.new (を、各種middlewareでラップしたもの) のことだと分かる。
つまり、どういうことか
起動方法AではSinatraが主体となって動いているが、起動方法BではSinatraはRackの1つのmiddlewareとして扱われている。また、Thin を走らせているのは誰なのか、という点が異なる。(起動方法AではSinatra, 起動方法BではRack)
もしかしたら、このとき渡されるオプションに違いがあるため、サーバの挙動が異なるのかもしれない。(要検証)
本記事ではこれ以上深追いするのはやめておく。
感想
普段意識しない部分のコードを色々読めて楽しかった(konami)
次はスレッドごとにコネクションが張られる予想の裏を取るために、Thinのソースを読んでみたい。
あわせて読みたい
Sinatra
Rack
第23回 Rackとは何か（1）Rackの生まれた背景：Ruby Freaks Lounge｜gihyo.jp … 技術評論社
Ruby - Rack解説 - Rackの構造とRack DSL - Qiita