神・羽鳥が作りしパフォーマンス計測パッケージlineprofでパフォーマンス計測
神・羽鳥が書いた聖書
を読んでる時に気がついた話。みんなRでパフォーマンス図る時はproc.time関数なりsystem.time関数とか使ってるだろうけど、もっと細かいパフォーマンス見たい時は、神・羽鳥が作ったlineprofパッケージ使ったらいいんじゃないかということです。パッケージのレポジトリは以下のGithub。
パッケージのインストールは上記のgithubから落とすので、
devtools::install_github("hadley/lineprof")
とする。このパッケージ、中でC++使ってるらしいので、Win環境ならRtoolsも忘れずにいれておく。
インストール後、パッケージを読み込んで以下のような適当な関数f, g, hを別ファイル(.R、ここではtemp.Rとした)で用意する*1。中で使っているpause関数はlineprofパッケージが提供している関数で、指定した時間(秒)だけ処理を停止する関数。マニュアルによるとSystem.sleepとほぼ同じなんだけど、pause関数がlineprofパッケージのパフォーマンス計測結果で要因としてカウントされる一方、 Sys.sleep関数はそうならないってのが違うらしい。
f <- function(){ pause(0.5) g() h() } g <- function(){ pause(0.25) h() } h <- function(){ pause(0.1) }
この関数fを実行しつつ、パフォーマンス・プロファイルを取得する。tortureって引数はなんで”拷問”って命名してるのかはこれ神のセンスの問題だと思うんだけど、メモリ確保処理の度にガベージコレクション走らせてくれて、より正確にどこでメモリが解放されているかをしらべるようにするだそうだ。計測終了後のオブジェクトを実行すればパフォーマンスがテーブル形式で取得できる。
>|r| > library(lineprof) > source("temp.R") #さっき保存した関数のファイル > x <- lineprof(f(), torture = TRUE) Zooming to (97% of total time) > x Reducing depth to 2 (from 5) Common path: time alloc release dups ref src 1 0.004 0.000 0.000 0 #2 f 2 0.511 0.000 0.000 0 #2 f/pause 3 0.002 0.000 0.000 0 #3 f 4 0.382 0.001 0.001 0 #3 f/g 5 0.001 0.000 0.000 0 #4 f 6 0.115 0.001 0.000 0 #4 f/h
これは
- fのpause実行にはおおよそ0.511秒
- f内のg呼び出しは0.382秒
- f内のh呼び出しは0.115秒
かかっていたと読めるわけだ。それぞれの関数の実行時間は、だいたい中で使っているpauseの時間((gの場合、0.25秒 + 0.1秒(h内の pause呼び出し)))と同じだぞってのも注目ポイント。
このパッケージのいい所は、この結果をshineという関数を用いてShinyで即可視化することができて、
> shine(x) Starting interactive profile explorer. Press Escape / Ctrl + C to exit
とできるとこだ。この画面をクリックして行けばより詳細なプロファイルが手に入るぞ！！！
画面上の列名である各アルファベットの意味は
- t : その行を実行するのにかかった時間
- r : ここで解放された解放されたメモリ領域量(単位MB)
- a : ここで追加取得されたメモリ領域量(単位MB)
- d : わからん。。。（the number of duplications performed byだそうだ）
ちなみに、一応、この手の話はデフォで入ってるRprof関数を使っても出来る。
> Rprof(tmp <- tempfile()) > f() > Rprof() > summaryRprof(tmp) $by.self self.time self.pct total.time total.pct ".Call" 0.94 100 0.94 100 $by.total total.time total.pct self.time self.pct ".Call" 0.94 100.00 0.94 100 "f" 0.94 100.00 0.00 0 "pause" 0.94 100.00 0.00 0 "g" 0.34 36.17 0.00 0 "h" 0.20 21.28 0.00 0 $sample.interval [1] 0.02 $sampling.time [1] 0.94
あとは好みの問題で、俺は使徒として神・羽鳥のものを使うってだけの話ですわ。
*1:以下で、shiny使った可視化してるんだけど、その時は別ファイルからの読込じゃないとだめらしい。可視化しないなら別ファイル用意しなくて同じファイルでもOK。以下を参照 https://github.com/hadley/lineprof/issues/5
