Ruby 2.0.0 の DTrace の紹介

初稿：2013-02-24

書いた人：Aaron Patterson (@tenderlove) 、翻訳：遠藤侑介 (@mametter)

はじめに

Ruby 2.0 は DTrace probe の機能を組み込みで提供します。あなたの環境が DTrace をサポートしていれば、 probe を使って Ruby のプロセスの挙動を見ることができます。本稿では、Ruby 2.0 での DTrace probe の基本的な使い方をご紹介します。

本稿の例は OS X で行ったものなので、環境によっては異なるかも知れません。

DTrace とは

DTrace は Sun Microsystems が開発したトレースフレームワークです。これにより、アプリケーションのトラブルシューティングをリアルタイムで行ったり、本番環境で動作しているプロセスのデバッグをしたりできます。

D 言語

DTrace では、実行中のプロセスに問い合わせをするために D 言語を使います。 D プログラムは以下のような文の列です。

probe /test/ { action }
probe /test/ { action }

probe が発火したら test が走り、test をパスしたら action が実行されます。テストは省略可能で、probe が発火したら常に action が実行されるようになります。

probe { action }

probe のフォーマットは以下のようになります。

provider:module:function:name

provider はプロバイダ（イベントを起こしたもの）の名前です。今回の場合は ruby です。
module はソフトウェア中の位置です。（これは使いません）
function はソフトウェアの関数です。（これも使いません）
name は probe の名前です。

今回は、”ruby” がプロバイダで、 probe の名前はこの wiki に掲載されている名前のいずれかです。

例えば、すべてのメソッドの実行開始に probe を設定したいなら、以下のようにします。

ruby:::method-entry { action }

action の節で以下のようにすれば、メソッドの実行が始まるたびに “hello world” を表示できます。

ruby:::method-entry { printf("hello world\n"); }

D プログラムは dtrace コマンドで以下のように実行します。

$ sudo dtrace -q -n'ruby$target:::method-entry { printf("hello world\n"); }' -c"ruby -e'puts :hi'"

DTrace はカーネルで動作するため、権限の昇格が必要で、そのために sudo を使わないといけません。また、$target には、 -c オプションで指示されたコマンドのプロセス ID が入ります。 $target を使わないと、DTrace はその環境で現在実行中の_すべての_ Rubyプロセスに probe を設定します。

では、例をいくつか試してみましょう。

Ruby に probe を設定する

以下のプログラムを t.rb というファイルとして保存します。

class Foo
  def hello
    puts :hello
  end
end

5.times do
  foo = Foo.new
  foo.hello
  sleep 1
end

ruby:::method-entry という probe には、呼ばれたときにクラス名とメソッド名が渡されます。以下のコードが書かれた x.d というファイルを作ります。

ruby$target:::method-entry
{
  printf("%s#%s\n", copyinstr(arg0), copyinstr(arg1));
}

そして以下のコマンドを実行します。

sudo dtrace -q -s x.d -c"ruby t.rb"

出力がたくさん表示されるはずですが、そのうち以下のような出力が始まります。

hello
Foo#hello
hello
Foo#hello
hello
Foo#hello
hello
Foo#hello

今回の D プログラムでは、 arg0 にはクラス名、arg1 にはメソッド名が入っています。 Ruby の起動時にはたくさんのメソッドが実行されるので、ファイル t.rb の結果に絞りましょう。

arg2 がファイル名なので、以下のように D プログラムを変えてテストを足せばよいです。

ruby$target:::method-entry
/copyinstr(arg2) == "t.rb"/
{
  printf("%s#%s\n", copyinstr(arg0), copyinstr(arg1));
}

すると、メソッドが t.rb に含まれる時だけ probe が発火するようになります。プログラムを再実行すると、以下のような出力だけが得られるはずです。

hello
Foo#hello
hello
Foo#hello
hello
Foo#hello
hello
Foo#hello

プロセスをトレースする

DTrace を用いると、現在実行中のプロセスにアタッチできます。 t.rb を変えて以下のようにします。

class Foo
  def hello
    puts :hello
  end
end

loop do
  foo = Foo.new
  foo.hello
  sleep 1
end

ある端末で以下のプログラムを実行します。それから別の端末でそのプロセス ID を探し、DTrace を以下のように実行します。

sudo dtrace -q -s x.d -p $PID

ただし $PID は Ruby プログラムのプロセス ID です。 DTrace から以下のような出力が得られるはずです。

Foo#hello
Foo#hello
Foo#hello
Foo#hello
Foo#hello

DTrace を使うと、実行中のプロセスがどのように振る舞っているかを見ることができるのです。

もうちょっと技

DTrace には、統計情報を集める強力な機能があります。プログラムの中でメソッドが呼ばれた回数を数えるプログラムを書いてみましょう。

Ruby プログラムはこちら。

class Foo
  def hello
  end
  def world
  end
end

foo = Foo.new
100.times   { foo.hello }
10000.times { foo.world }

D プログラムはこちら。

ruby$target:::method-entry
/copyinstr(arg2) == "t.rb"/
{
  @[copyinstr(arg0), copyinstr(arg1)] = count();
}

D プログラム中の特殊変数 @ は、Ruby のハッシュのようなものです。このハッシュのキーはターゲットのクラスとメソッドで、値はメソッドが呼ばれた回数になります。

このプログラムを実行すると、

$ sudo dtrace -q -s x.d -c"ruby t.rb"

以下のような出力が得られます。

  Foo          hello          100
  Foo          world        10000

Foo#hello が 100 回、Foo#world が 10000 回実行されたことが一目でわかります。

まとめ

DTrace と Ruby 2.0 を始めるための一助となれば幸いです。以上の例を動かすには、Ruby 2.0.0 を使わなければならないこと、 DTrace をサポートしているシステムでないといけないことを忘れないでください。

DTrace で楽しい hacking を！

著者紹介

Aaron Patterson パターソン・アーロン (1980年 (昭和 55 年) 12月16日生) は、ただ唯一人の ruby-core チームと rails-core チームの両方に在籍するプログラマーである。Ruby の使用歴は 8 年間、Rails 開発者として業務での使用歴は 6 年間になる。現在、アメリカ合衆国シアトル市ワシントン州にて AT&T のシニアーソフトウェアアーキテクトを勤める。AT&T での主な業務としては、AT&T が使用する開発者用ツールの改良に長期間に渡り従事する。プログラミングをしない日には、趣味の料理や茸狩りなどを楽しむ。

バックナンバー