Railsで開発していく上で、パフォーマンスのチューニング作業はついて回ります。
パフォーマンスをよくする上でよく使用されているのがrack-mini-profiler、bullet等のgemだと思います。
開発期間が長く、肥大化してきたプロダクトだと１リクエストごとに長い長いログが出力され、クエリを丹念に目で追う作業は半ばめまいを覚え、目の疲労が困ぱいしてきて時々、プログラムから離れて、どこか遠くの島に行きたくなるものです。
そんな苦しみから少しでも楽になりたいのでログを綺麗に整理するgemを作りました
詳しい使用方法は下記のサイトに譲りますが、簡単な使用方法を解説しようと思います
https://github.com/fukumone/rails_log_profiling
簡単な使用法
1： gemfileに下記を記入
gem 'rails_log_profiling', :group => "development"
基本的に開発環境がdevelopmentで使うのを想定して作成しています
2： bundle install後にconfig/development.rbに下記のコードを追加
# クエリのプロファイリングを有効にします
Rails::Log::Profiling.query_profiling_enable = true
# viewのプロファイリングを有効にします
Rails::Log::Profiling.view_profiling_enable = true
パフォーマンスよくする上で、開発者が気になるのはクエリのログや、viewのレンダリングかと思います
なのでrails_log_profilingは主要な二つの機能に分けました
- クエリをプロファイリングする
- viewレンダリングをプロファイルする
3： Railsサーバーを起動
専用のログが作成され、記録されます。
クエリのプロファイリングに関してはlog/rails_log_query_profiling.logに記録されます
Identify Query Location: xxxは実際にクエリが実行されたファイルの箇所を検知します、オプションでメソッドの呼び出し状況を深く探索することができます
出力例
$ tail -f log/rails_log_query_profiling.log
# output
PostsController#index
total query count: 2, total query time: 26.6ms
1: Articles Load (21.7ms) SELECT `articles`.* FROM `articles` ORDER BY `articles`.`id` ASC LIMIT 1
Identify Query Location:
/Users/fukumone/private_repo/rails_test/app/controllers/posts_controller.rb:9:in `index'
2: Post Load (4.9ms) SELECT `posts`.* FROM `posts`
Identify Query Location:
/Users/fukumone/private_repo/rails_test/app/views/posts/index.html.erb:16:in `_app_views_posts_index_html_erb__3476269730194822991_70352062040540'
viewのプロファイリングに関してはlog/rails_log_view_profiling.logに記録されます
N+1 partial renderingの対策として、重複するpartialファイルに対してはpartial viewファイルの下にrendering page count: xxxと記述されます
出力例
$ tail -f log/rails_log_view_profiling.log
# output
Parent: 65.5ms
/Users/fukumone/private_repo/rails_test/app/views/posts/index.html.erb
Children: total time: 6.9ms, partial page count: 3, total rendering page count: 12
5.4ms: /Users/fukumone/private_repo/rails_test/app/views/articles/_show.html.erb
rendering page count: 10
0.8ms: /Users/fukumone/private_repo/rails_test/app/views/articles/_show_3.html.erb
0.7ms: /Users/fukumone/private_repo/rails_test/app/views/articles/_show_2.html.erb
どれか一方の設定でも利用可能で、rails_log_profilingはdevlopment.rbに設定がないと初期の段階ではなにも行いません。
rails_log_profilingは優れたアイデア、機能が入った以下のgemに影響を受けています