RailsでSlow Queryを自動検出する方法

開発が落ち着いてくると新規開発みたいな慌ただしさが減り、使い勝手を向上させるため、SQLのチューニングをする必要が発生します。

いわゆる保守フェーズになります。

その際に、sloq queryを自動的に検出できたら、より効率的になるのですがRailsだとかなり簡単だったのでご紹介します。

SQLの改善はやり方によって、1000倍ぐらいパフォーマンスが変わり、SEOの改善が起きたりとても良いのでぜひいろんなサービスに入れて良いサービスなると良いですね。

設定方法

簡単です。initializerでActiveSupport::Notificationsを使ってsql.active_recordをsubscribeするだけでした。

# config/initializers/slow_query_logger.rb

class SlowQueryLogger
  def self.initialize!
    ActiveSupport::Notifications.subscribe('sql.active_record') do |_name, start, finish, id, payload|
      duration = finish.to_f - start.to_f
      Rails.logger.debug("slow query detected: #{payload[:sql]}, duration: #{duration}")
    end
  end
end

SlowQueryLogger.initialize!

initializerにコードを書き、railsを再度起動してみると development.logには slow query detected とでるようになります。

    slow query detected: SELECT `messages`.* FROM `messages` WHERE `messages`.`user_id` = 5 AND `messages`.`id` = 13 ORDER BY FIELD(messages.id, 13), duration: 0.004096031188964844

試しに表示しただけなので、実際に使えるコードはこんな感じになります。 3秒以上のqueryを検出してくれます。簡単ですね。

# config/initializers/slow_query_logger.rb

class SlowQueryLogger
  MAX_DURATION = 3.0

  def self.initialize!
    ActiveSupport::Notifications.subscribe('sql.active_record') do |_name, start, finish, id, payload|
      duration = finish.to_f - start.to_f

      if duration >= MAX_DURATION
        Rails.logger.debug("slow query detected: #{payload[:sql]}, duration: #{duration}")
      end
    end
  end
end

SlowQueryLogger.initialize!

他にもrender時間の計測や特定のメール送信をフックしてslackに通知させたりできます。

70