[ruby on rails3.2]発行SQLの監視＋SQLの呼び出し元特定

標題のものを探していました。
そしたらちょうど最近公開されたばかりの代物がありました。感謝

Gemfileに

  gem "arproxy", "~> 0.1.1"

を記載して、bundle install しましょう。


◎「できること」

・railsから発行されるSQLは通常アダプターを経由して、DBに送られるが、
そのアダプター中のSQL発信メソッドの途中でこざいく（ログの発信や、callerによる呼び出し元のトレース）をいれられる



◎準備

・  gem "arproxy", "~> 0.1.1"
・　config/initializersの配下に適当なファイルを作成し下記を記述

Rails.root/config/initializers/arproxy.rb


class QueryTracer < Arproxy::Base
  def execute(sql, name=nil)
#    Rails.logger.debug sql　
#    Rails.logger.debug caller(1).join("\n")

    puts "log.sql:#{sql}"
#トレースの中から正規表現で「gemファイル直下のライブラリ名」「rbファイル名」「rbファイルの実行メソッド」を取得して、直前の１～５番目を表示させるようにしています。
    puts "log.place:#{caller.map{|n|"#{n.scan(/[^\/]+/)[6]}:#{n.scan(/[^\/]+/).last}"}[1..5]}"

    super(sql, name)
  end
end

Arproxy.configure do |config|
  config.adapter = "mysql2" # A DB Apdapter name which is used in your database.yml
  config.use QueryTracer
end
Arproxy.enable!


以上。実行してみましょう。
loggerの場合、実行したタイミングではなくあとでまとめて出力される仕様のようですので、私は puts だと実行したタイミングで出力されるので、コンソール出力ですがputsを利用しています。

◎実行結果

便利！！


log.sql:SHOW FULL FIELDS FROM `users`
log.place:["activerecord-3.2.2:abstract_mysql_adapter.rb:257:in `execute_and_free'", "activerecord-3.2.2:abstract_mysql_adapter.rb:424:in `columns'", "activerecord-3.2.2:schema_cache.rb:12:in `block in initialize'", "activerecord-3.2.2:model_schema.rb:228:in `yield'", "activerecord-3.2.2:model_schema.rb:228:in `default'"]

log.sql:SELECT  `users`.* FROM `users`  WHERE `users`.`id` = 4 LIMIT 1
log.place:["activerecord-3.2.2:mysql2_adapter.rb:215:in `exec_query'", "activerecord-3.2.2:mysql2_adapter.rb:224:in `select'", "activerecord-3.2.2:database_statements.rb:18:in `select_all'", "activerecord-3.2.2:query_cache.rb:61:in `block in select_all'", "activerecord-3.2.2:query_cache.rb:75:in `cache_sql'"]