Rails でシーケンシャルスキャンしているクエリを見つけて捗りたい - PostgreSQL 限定

[こちらの記事](http://qiita.com/seratch@github/items/826f1b4a89993d3b0804)の[この章](http://qiita.com/seratch@github/items/826f1b4a89993d3b0804#postgredialectqueryanalyzer--traceservicequeryinterceptor)に触発されて、[active_record-postgresql_analyzer](https://rubygems.org/gems/active_record-postgresql_analyzer) という名前で雑に gem を作って公開してみました。まさに Advent Calendar Driven Development ですね。それと思い出で終わらすにはもったいない機能だなと思ったので。

## 概要

元記事にありますように index を使わないクエリを見つけてログに書き出してくれるものです。index つけ忘れ防止に便利そうだったので、試しに社内で作って適用、実際便利だったので gem として切り出しました。
コードも github で[公開](https://github.com/m3dev/active_record-postgresql_analyzer)しています。

ちなみにエムスリーは PostgreSQL 環境がほとんどであるため、それ以外の環境は考慮していません。

作る前に Rails にもそんな機能があったのでは？と思ったのですが、実は少し前にあまり使われないということで本体から機能削除されていました。その辺りの経緯について気になる方は[こちら](http://qiita.com/yuku_t/items/3729697c50e05be6a4d3)を参照してください。


## 使い方

```ruby:Gemfile
gem 'active_record-postgresql_analyzer', group: :development
```

**development 指定を忘れずに。**

あとは勝手にログを出力してくれるようになります。
以下は user_id に index が貼られていない場合のログ出力例です。explain 結果をそのままログに載っけているので、一目で内容がわかり便利です。

```console
------------ find Seq Scan query ------------
SELECT  "todo".* FROM "todo" WHERE "todo"."user_id" = $1 LIMIT 1
                                         QUERY PLAN
---------------------------------------------------------------------------------------------
 Limit  (cost=10000000000.00..10000000001.67 rows=1 width=81)
   ->  Seq Scan on todo  (cost=10000000000.00..10000000001.67 rows=1 width=81)
         Filter: (user_id = 13)
(3 rows)
```

## 内部の仕組み

簡単に機能実現のための実装を見ていきます。先に言っておきますとコード量も少ないので(1ファイル)、そっち見た方が早いです。

sequential scan をしているかを判断するためには、explain を行う必要があります。
そのために必要となるものは実行するクエリです。ということで以下の流れを実装しています。

- クエリ取得
- explain 実行
- explain 結果が sequential scan か判定
- ログ出力

まずはクエリ取得部分です。Rails には `ActiveSupport::Notifications` という通知を受けるための便利な仕組みがあり、この機能を使うことで Rails 内部で発生する各種イベントを取得することができます。このイベントの中にはクエリ発行時に発生する `sql.active_record` というイベントがあり、このイベントを購読するコールバックには sql の情報として sql 文、bind されるパラメータが渡されます。この情報が使えそうです。ちなみにその他にも渡されるパラメータがありますが詳しくは[公式を参照](http://edgeguides.rubyonrails.org/active_support_instrumentation.html#sql-active-record)してください。

次は explain の実行です。sql 文と bind するパラメータを渡されてもどう実行すればよいやら。。という感じですが、`ActiveRecord::Base.connection.explain` にそのまま渡せるようになっているので単に渡せば実行結果を取得できます。

後は残りの部分ですが、もし sequential scan になっていれば、`Seq Scan` という文字列が出力されるので、この文字列が存在していればログを出力するというコードを書けば一通りの機能を実現できます。

ちなみに実装にあたり参考(いわゆる inspire?)にしたものは [activerecord-cause](https://github.com/joker1007/activerecord-cause)、rails のコード([この辺り](https://github.com/rails/rails/blob/cf0dc18ac34f45f0fd0aa231c0e59c994691d90f/activerecord/lib/active_record/log_subscriber.rb))などです。


## 今後

現状は全てのクエリに対して出力されてしまうので filter する機能とかあると便利かもしれません。でもログなのでそのままでもいいかなとも思って手をつけていません。
後は nested loop の検知をするとかもありかもしれませんね。

## 所感

勢いで作ったものの意外と便利だった。それと社内で先に公開したところ、native check、命名もチェックしてもらって勉強になった。

## 参考リンク

- at rubygems
  - https://rubygems.org/gems/active_record-postgresql_analyzer
- at github
  - https://github.com/m3dev/active_record-postgresql_analyzer
- Railsの計測を支えるActiveSupport::Notificationsについて
  - ActiveSupport::Notifications についてはこちらの記事がわかりやすかったです
  - http://tech.gmo-media.jp/post/105477812827/rails-active-support-notifications
- activerecord-cause
  - フック周りのコード、テストコードを参考にしています
  - https://github.com/joker1007/activerecord-cause
- ActiveRecord::LogSubscriber
  - 継承元のコードで、こちらも参考になります
  - https://github.com/rails/rails/blob/cf0dc18ac34f45f0fd0aa231c0e59c994691d90f/activerecord/lib/active_record/log_subscriber.rb
- SAStruts + S2JDBC の思い出について存分に語る #m3dev
  - Java 実装についてはこちらをチェックしてみてください
  - http://qiita.com/seratch@github/items/826f1b4a89993d3b0804