SpringOnionというRailsの遅そうなEXPLAINをログ出力するgemを作りました。
某kamopoさんのMySQLCasualLog.pmの移植?です。
以前の移植とは異なって、Arproxyを必要とせず、単体で動きます。
何年前の話だよといわれそうですが、未だにスロークエリと戦っていたりするので…
Rails 3以前に搭載されていた、遅かったクエリを自動的にEXPLAINする機能とは異なり、フィルタで選別されたすべてのクエリに対してEXPLAINを実行し、まずそうなキーワードが出現したらログに出力します。
また、EXPLAINの実行先は開発用のDBだけでなく任意のDBに向けられます(例: ステージング環境のDBなど)。
使い方
Gemfile
にSpringOnionを追加して
group :development, :test do gem 'spring_onion' end
enviroments/*.rb
やinitializers
にSpringOnionのEXPLAIN実行先DB情報を記述します。
if Rails.env.development? || Rails.env.test? # EXPLAINを実行するDB SpringOnion.connection = Mysql2::Client.new(host: 'my-host', ...) # ActiveRecordの接続先と同じにする場合は↓な感じで #SpringOnion.connection = ActiveRecord::Base.connection.raw_connection end
SpringOnion.enabled = true
にするかSPRING_ONION_ENABLED=1
で、遅そうなEPLAINがログ出力されるようになります。
実行例
#!/usr/bin/env ruby require 'active_record' require 'spring_onion' ActiveRecord::Base.establish_connection( adapter: 'mysql2', host: 'db', username: 'root', database: 'sakila' ) SpringOnion.enabled = true # or `SPRING_ONION_ENABLED=1` SpringOnion.connection = ActiveRecord::Base.connection.raw_connection SpringOnion.source_filter_re = // class Actor < ActiveRecord::Base self.table_name = 'actor' self.primary_key = 'actor_id' end Actor.all.to_a
root@d786c737d8a4:/mnt# bundle exec ./test.rb SpringOnion INFO 2020-07-19 03:19:05 +0000 {"sql":"SELECT `actor`.* FROM `actor`","explain":[{"line":1,"select_type":"SIMPLE","table":"actor","partitions":null,"type":"ALL","possible_keys":null,"key":null,"key_len":null,"ref":null,"rows":16,"filtered":100.0,"Extra":null}],"warnings":{"line 1":["slow_type"]},"backtrace":["/mnt/lib/spring_onion/explainer.rb:6:in `execute'","/mnt/test.rb:21:in `<top (required)>'"]}
SPRING_ONION_JSON_PRETTY=1
で見やすく。
root@d786c737d8a4:/mnt# SPRING_ONION_JSON_PRETTY=1 bundle exec ./test.rb SpringOnion INFO 2020-07-19 03:19:43 +0000 { "sql": "SELECT `actor`.* FROM `actor`", "explain": [ { "line": 1, "select_type": "SIMPLE", "table": "actor", "partitions": null, "type": "ALL", "possible_keys": null, "key": null, "key_len": null, "ref": null, "rows": 16, "filtered": 100.0, "Extra": null } ], "warnings": { "line 1": [ "slow_type" ] }, "backtrace": [ "/mnt/lib/spring_onion/explainer.rb:6:in `execute'", "/mnt/test.rb:21:in `<top (required)>'" ] }
上記の場合、"type": "ALL"
が引っかかってwarningが出ています。
warning
warningにはMySQLCasualLog.pmと同じルールを設定していますが、新しく追加することも可能です。
例えば、rows
が10,000行を超えていたら、warningするなど。
SpringOnion.warnings[:too_many_rows] = lambda do |exp| exp['rows'] > 10000 end
フィルタ
SQLとbacktraceのソースコードのパスでフィルタリング可能です。
たとえばSPRING_ONION_SQL_FILTER_RE=actor bundle exec ./test.rb
と実行すると、actor
が含まれるクエリだけEXPLAINします。
また、SPRING_ONION_SOURCE_FILTER_RE=my_path bundle exec ./test.rb
と実行すると、パスにmy_path
が含まれるソースコード経由で実行されたクエリだけEXPLAINします。(デフォルトは/app/
)
その他
ログ出力先は標準出力がデフォルトですが、ファイルなどに変更可能です。
SpringOnion.logger = Logger.new('/foo/bar/zoo.log')