プロファイラーについて
この記事はパーフェクトRuby Advent Calendar 2013 - Adventar の21日目です。 前の日のエントリーは パーフェクトRuby の次に読む本 です。
2013/12/24 Array#<<の結果が出ない件追記しました
パーフェクトRuby
パーフェクトRubyをやっと読み終わりました。。。。
- 作者: Rubyサポーターズ,すがわらまさのり,寺田玄太郎,三村益隆,近藤宇智朗,橋立友宏,関口亮一
- 出版社/メーカー: 技術評論社
- 発売日: 2013/08/10
- メディア: 大型本
- この商品を含むブログ (10件) を見る
まだまだ知らないことが多いなあと痛感しました。
ObjectSpace#_id2refでobject_idから実際のobjectを取得できたり、gem prinstine
でgemパッケージを元に戻せるのとかは知らなかった。。。。
自分の知らなかった部分を紹介しようと思ったのですが既出のものが多かったので、パーフェクトRubyに載っていなかったプロファイラーについて少し紹介しようと思います。
プロファイラー
プロファイラーとは、各メソッドの実行時間を計測するためのツールです。
プロファイラーの結果を見ると、実行したrubyスクリプトで呼ばれる各メソッドの実行時間がわかります。
今回、プロファイルをとるスクリプトは下記です。
sample scriptarray_push_vs_arrows.rb
また、これをプロファイラーを仕込まず実行した結果は下記のとおりです。
profile
Rubyには標準添付ライブラリにprofileというプロファイルを取得できるモジュールが入ってます。
profileを使ったプロファイル結果はこんな感じです。
項目の見方は、http://docs.ruby-lang.org/ja/2.0.0/library/profile.htmlに書いてありますが抜き出してみます。
% time | cumulative seconds | self seconds | calls | self ms/call | total ms/call | name |
---|---|---|---|---|---|---|
全体時間のパーセンテージ | 全体時間の総和(秒) | 正味時間の総和(秒) | 呼び出された回数 | 1回の呼び出し当たりの平均正味時間(ミリ秒) | 1回の呼び出し当たりの平均全体時間(ミリ秒) | メソッド名 |
- 全体時間(総時間) : メソッド呼び出しの合計時間
- 正味時間 : 全体時間から他の全てのメソッドの実行時間を除いた時間
実行時間を見てもらうとわかると思うのですが、profileってめっちゃくちゃ重い!!
これでは、とてもカジュアルには使えません。
ということで、標準添付ではありませんが、もう少し軽量に動作するruby-profというライブラリを紹介しようと思います。
ruby-prof
ruby-profはprofileモジュールよりも軽量に動作するプロファイラーです。
ruby-profは
gem install ruby-prof
でインストールすることができます。
ruby-profをいれると、ruby-profコマンドを使えるようになります。
このruby-profコマンドを使ってサンプルコードのプロファイルを取ってみます。
項目の見方は下記の通りです。
%self | total | self | wait | child | calls | name |
---|---|---|---|---|---|---|
全体時間のパーセンテージ | メソッド呼び出しとそのメソッドから呼び出されたメソッドの合計時間(秒) | メソッド呼び出しの時間(秒) | スレッドの待機時間(秒) | メソッドから更に呼び出されたメソッドの呼び出し時間(秒) | 呼び出された回数 | メソッド名 |
実行時間を見てみると、profileよりは早く動作していますが、それでも実行に時間がかかってしまいますね。
あと、Array#<<の結果が何故かでていない。。。。
とりあえす、ruby-profにissueは投げてみました。
今自分でもコード読んで確認しているところです。。。
まとめ
重いスクリプトがある場合は、プロファイルを取ってボトルネックを探してみると良いと思います。
実際にプロファイルを取るときは、動作が重くなっても問題ないか確認してから仕込んでください!
追記
ruby-profのissueでArray#<<の結果がでないことを聞いてみたら、コンパイルオプションの問題だよって返答頂きまた。
https://github.com/ruby-prof/ruby-prof/issues/132
bin/ruby-profに
RubyVM::InstructionSequence.compile_option = { :trace_instruction => true, :specialized_instruction => false }
を書いて、実行したところ、
ruby-prof with option settings
ちゃんと出るようになりました!