ksauzz weblog

technical note....

Erlangのデバッグツール Redbug

redbugはErlangコードのトレースに使用するデバッグ用ツールです。 eper というパフォーマンス関連ツールの一部として配布されています。 これを使うと、指定した関数のトレースがとても手軽に行えます。

redbugで出来る事

  • モジュール名、関数名、引数でのトレース対象指定(ワイルドカード可)
  • 引数の確認
  • 戻り値の確認
  • コールスタックの確認

Riakでの実行例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
(riak1@127.0.0.1)81> redbug:start({riak_kv_vnode, put,[return, stack]},[{time,5000},{msgs,4},{max_msg_size,10000
000},{print_depth,10}]).
ok

20:17:34 <{riak_kv_put_fsm,init,1}> {riak_kv_vnode,put,
                                     [[{685078892498860742907977265335757665463718379520,
                                        'riak1@127.0.0.1'},
                                       {707914855582156101004909840846949587645842325504,
                                        'riak1@127.0.0.1'}],
                                      {<<"bucket">>,<<"key1">>},
                                      {r_object,<<"buck"...>>,<<...>>,...},
                                      87431492,63534539854,[]]}
  "proc_lib:init_p_do_apply/3 "
  "gen_fsm:handle_msg/7 "

.. 略 ..

20:17:34 <{riak_kv_put_fsm,init,1}> {riak_kv_vnode,put,6} -> ok
quitting: msg_count

動作確認環境

OSX 10.8.3 R15B03, CentOS 6.3 R15B01

導入方法

rebarを使っていればrebar.configのdepsにeperを追加するだけです。

1
2
3
{deps, [
        {eper, "0.61", {git, "git://github.com/basho/eper.git", {branch, master}}}
       ]}.

TODO: rebarを使わない方法

動作確認

sampleモジュールを例に、簡単に動作確認をしてみます。

1. erlの起動

まずはErlangシェルを起動します。

1
2
3
4
5
% erl -pa ebin/ deps/*/ebin
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:4:4] [async-threads:0] [kernel-poll:false] [dtrace]

Eshell V5.9.3.1  (abort with ^G)
1>

2. redbugの起動

redbug:start/1でトレース対象のモジュール名(sample)を指定し、redbugを起動します。 ※15sec(default)でトレース処理が終了してしまうので気をつけましょう。

1
2
1> redbug:start(sample).
ok

3. トレース対象のコードを実行

トレース対象のsampleモジュールを実行し、トレースの様子を確認します。 尚、ここで実行するsample:start_link/0は間接的にsample:init/1を呼び出すコードになっています。

1
2
2> sample:start_link().
{ok,<0.41.0>}

するとコンソールに次の内容が出力されます。

1
2
3
4
20:43:07 <{erlang,apply,2}> {sample,start_link,[]}

20:43:07 <sample> {sample,init,[[]]}
quitting: timeout

これがトレース結果です。簡単ですがsample:start_link()sample:init([])がコールされた事が示されています。

使用例

redbugはトレース条件、オプションを指定することで様々なトレースを行うことができます。ここではその一部を紹介します。

Usage
-----
redbug:start(Trc)                %% トレース条件のみ指定
redbug:start(Trc, Opts)          %% トレース条件, オプション指定
redbug:start(Timeout, Msgs, Trc) %% トレース条件, タイムアウト, トレース数指定(オプション指定不能)

サンプル

riak_kv_get_fsmモジュールの呼び出しをtrace

redbug:start(riak_kv_get_fsm).

riak_kv_get_fsm:initの呼び出しをtrace

redbug:start(riak_kv_get_fsm, init).
or
redbug:start({riak_kv_get_fsm, init}).

riak_kv_get_fsmの呼び出し、戻り値をtrace

redbug:start({riak_kv_get_fsm, '_', [return]}).

riak_kv_get_fsm:initの呼び出し、戻り値、コールスタックをtrace

redbug:start({riak_kv_get_fsm, init, [return, stack]}).

riak_kv_put_fsm:execute(pw, _, default)の呼び出し、戻り値をtrace (引数によるマッチング)

redbug:start({riak_kv_put_fsm, '_', [{pw,'_',default},return]}).

riak_kv_get_fsm:initの呼び出しをtrace、Timeout 1,000msec

redbug:start({riak_kv_get_fsm, init}, [{time, 1000}]).

riak_kv_get_fsm:initの呼び出しをtrace、Timeout 1,000msec

redbug:start({riak_kv_get_fsm, init}, [{time, 1000}, {msgs, 20}]).

その他オプションとそのデフォルト値

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
time         = 15000        % ms
msgs         = 10           % unit
proc         = all          % list of procs (or 'all')
target       = node()       % target node
cookie       = ''           % target node cookie
buffered     = no           % output buffering
arity        = false        % arity instead of args
print_call   = true         % print calls (see `return_only')
print_form   = "~s~n"       % format for printing
print_file   = ""           % file to print to (standard_io)
print_msec   = false        % print milliseconds in timestamps?
print_depth  = 999999       % Limit for "~P" formatting depth
print_re     = ""           % regexp that must match to print
max_queue    = 5000         % max # of msgs before suicide
max_msg_size = 50000        % max message size before suicide
file         = ""           % file to write trace msgs to
file_size    = 1            % file size (per file [Mb])
file_count   = 8            % number of files in wrap log

ざっくりですが以上です。

余談ですが、Riakはeperを含んでいるので、riak attachするだけでredbugで内部をトレースできます。redbugはRiakの勉強にも、もってこいですね。ではでは。

Comments