言語 - デバッグやボトルネックを発見するテクニック

17717 ワード
analytics R bigdata statistics R テキストリンク

はじめに

　R に限った話ではありませんが、プログラミングでは、変数に意図した値が格納されていることを確認したり、むやみに時間のかかるプログラミングになっていないかを確認することがあります。R にも、デバッグやボトルネックを見つけるテクニックがあります。

browser 関数を使ったデバッグ手法

　関数内でのデバッグを有効にするには browser() 関数を使います。次の例は、引数で与えられた数値に対して、和差積商を計算するユーザー関数に、browser()関数を使用したサンプルスクリプトです。デバッグ実行の開始条件として、「一番目の引数が 8 以上」ということを browser() 関数に指定しています。

関数の作成

▼サンプルスクリプト

R
func_calc <- function(x,y){
+ a <- x
+ b <- y
+ browser(expr = x <= 8)
+ print("和")
+ print(sum(a,b))
+ print("差")
+ print(a - b)
+ print("積")
+ print(a * b)
+ print("商")
+ print(a / b)
+ }

デバッグの実行

▼サンプルスクリプト

R
# 変数xが8以上を指定してデバッグを開始します
func_calc(8,2)

▼実行結果例

実行結果例
Called from: func_calc(8, 2)
Browse[1]> a       # 変数aを確認します
[1] 8
Browse[1]> b       # 変数bを確認します
[1] 2
Browse[1]> n       # 次のコードに進みます
debug at #5: print("和")
Browse[2]> n       # 次のコードに進みます
[1] "和"
debug at #6: print(sum(a, b))
Browse[2]> n       # 次のコードに進みます
[1] 10

デバッグを継続して実行

▼実行結果例

実行結果例
Browse[2]> c      # 以降の全てのステップを実行します
[1] "差"
[1] 6
[1] "積"
[1] 16
[1] "商"
[1] 4
[1] "平均値"
[1] 5
[1] "中央値"
[1] 5
[1] "分散値"
[1] 18

browser 関数のコマンドは、次の通りです。
コマンド 説明
N 次のステップを実行する
C 以降の全てのステップを実行する
where スタックを出力する
Q browser() 関数を終了する

Rprof 関数を使ったボトルネックを見つける手法

　R の命令実行時間のプロファイルを有効 / 無効にするには、Rprof() 関数を使います。コード中の各実行単位の使用回数を、一定のサンプリング間隔毎にチェックし、レポートします。プロファイルのサマリ表示は、summaryRprof()関数で参照します。次の例は、Rprof 関数で、「Oracle R Enterprise パッケージの読み込み→ Database へ接続→ gc() 実行→ sys.rq_config テーブルの参照→ gc() 実行 」のプロファイルを取得するサンプルスクリプトです。library() 関数で読み込むパッケージは、install.packages() 関数等で事前にインストールが必要です。。なお、Oracle R Enterprise(以下、ORE)の利用は、Oracle Database Enterprise Edition のオプションである Oracle Advanced Analytics が必要です。次のサンプルスクリプトで、Rprof() 関数でプロファイルを開始します。

▼サンプルスクリプト

R
# プロファイルを開始します
Rprof( filename = "Rprof.out", append = FALSE, interval = 0.02, memory.profiling = TRUE )
# ライブラリパスを指定します 
.libPaths("<パッケージ格納先のパスを指定>")
# データベースに接続するため、パッケージ「ORE(注1)」を読み込みます
library( ORE )
# データベースへ接続します
ore.connect( user = "ruser", sid = "orcl", host = "localhost",
password = "ruser", port = 1521, all = TRUE )
# gc()関数を実行します
gc( reset = TRUE )
# SYS.RQ_CONFIG表を参照します
getMemorySettings <- function() {
  con <- dbConnect(Extproc())
  rs <- dbSendQuery( con, "SELECT NAME, VALUE FROM SYS.RQ_CONFIG" )
  dat <- fetch( rs )
  dat
}
ore.doEval( getMemorySettings, ore.connect = TRUE )
# gc()関数を再実行します
gc()
# プロファイルを終了します
Rprof( NULL )

▼サンプルスクリプト
次のサンプルスクリプトで、プロファイル結果のサマリを表示します。

R
# メモリ使用量と実行時間を含めてサマリを表示します
summaryRprof( filename = "Rprof.out", memory = "both" )

▼実行結果例

summaryRprof() 関数の memory オプションには、次のパラメータがあります。
オプション 説明
none メモリ情報は表示されない
stats メモリ情報の統計を表示する
tseries 時系列でのメモリ情報の表示
both メモリ使用量と実行時間の表示

ご参考

OS の strace コマンドも強力なツール
　OS の strace コマンドを使うと、システムコールごとにかかった時間を出力する事ができます。ここでは、strace コマンドを利用したボトルネックの調査方法を紹介します。Tips で紹介した Rprof() 関数と合わせて使うことで、効率的にボトルネックを特定することができます。

▼実行例

実行例
# 1. プロセス番号を調べる
> ps -ef | grep R
oracle    3588  3558  6 19:10 pts/3    00:00:00 /usr/lib64/R/bin/exec/R
# 2. strace を root ユーザで実行（-c で時間統計を出力）
> strace -p 3588 -c
# 3. 処理を実行
> gc(reset=TRUE)
         used (Mb) gc trigger   (Mb) max used (Mb)
Ncells 170235  9.1     350000   18.7   170235  9.1
Vcells 270347  2.1  840423198 6412.0   270347  2.1
>
# 4. strace を終了（ctrl+c）させて、結果を出力

▼実行結果例

注釈

注 1 サンプルスクリプトは、Oracle R Enterprise 1.3.1 を使用しています。