ローファイ日記

出てくるコード片、ぼくが書いたものは断りがない場合 MIT License としています http://udzura.mit-license.org/

Ruby (MRI) に新しい Probe を定義する

Rubyで利用できるUSDTは probes.d というファイルに定義されている。

USDTとは:

udzura.hatenablog.jp

以下の記事はbpftraceとUSDTを理解している前提で書いていきます。

Rubyにおけるprobeの定義箇所

probes.d は以下のような記法。

provider ruby {
  /*
     ruby:::method-entry(classname, methodname, filename, lineno);

     This probe is fired just before a method is entered.

     * `classname` name of the class (a string)
     * `methodname` name of the method about to be executed (a string)
     * `filename` the file name where the method is _being called_ (a string)
     * `lineno` the line number where the method is _being called_ (an int)
  */
  probe method__entry(const char *classname, const char *methodname, const char *filename, int lineno);
  /*
     ruby:::method-return(classname, methodname, filename, lineno);

     This probe is fired just after a method has returned. The arguments are
     the same as "ruby:::method-entry".
  */
  probe method__return(const char *classname, const char *methodname, const char *filename, int lineno);
  //...
}

Linux環境の場合、 dtrace というコマンド（systemtap-sdt-dev あるいはそれに準じたパッケージと一緒に入る）を噛ませることでCのヘッダファイルに変換される。

$ dtrace -h -s probes.d -o /dev/stdout | head -24
/* Generated by the Systemtap dtrace wrapper */


#define _SDT_HAS_SEMAPHORES 1


#define STAP_HAS_SEMAPHORES 1 /* deprecated */


#include <sys/sdt.h>

/* RUBY_METHOD_ENTRY ( const char *classname, const char *methodname, const char *filename, int lineno ) */
#if defined STAP_SDT_V1
#define RUBY_METHOD_ENTRY_ENABLED() __builtin_expect (method__entry_semaphore, 0)
#define ruby_method__entry_semaphore method__entry_semaphore
#else
#define RUBY_METHOD_ENTRY_ENABLED() __builtin_expect (ruby_method__entry_semaphore, 0)
#endif
__extension__ extern unsigned short ruby_method__entry_semaphore __attribute__ ((unused)) __attribute__ ((section (".probes")));
#define RUBY_METHOD_ENTRY(arg1, arg2, arg3, arg4) \
DTRACE_PROBE4 (ruby, method__entry, arg1, arg2, arg3, arg4)

*.d ファイルから、sys/sdt.hで定義される DTRACE_PROBE* マクロをラップしたマクロを定義している。実際のRubyのビルドでは、マクロの名前をsedで置き換えているようだ。

./configure --enable-dtrace したRubyの中間生成物である probes.h は以下のようになっている。

//...
/* RUBY_DTRACE_METHOD_ENTRY ( const char *classname, const char *methodname, const char *filename, int lineno ) */
#if defined STAP_SDT_V1
#define RUBY_DTRACE_METHOD_ENTRY_ENABLED() __builtin_expect (method__entry_semaphore, 0)
#define ruby_method__entry_semaphore method__entry_semaphore
#else
#define RUBY_DTRACE_METHOD_ENTRY_ENABLED() __builtin_expect (ruby_method__entry_semaphore, 0)
#endif
__extension__ extern unsigned short ruby_method__entry_semaphore __attribute__ ((unused)) __attribute__ ((section (".probes")));
#define RUBY_DTRACE_METHOD_ENTRY(arg1, arg2, arg3, arg4) \
DTRACE_PROBE4 (ruby, method__entry, arg1, arg2, arg3, arg4)
//...
#define RUBY_DTRACE_METHOD_RETURN(arg1, arg2, arg3, arg4) \
DTRACE_PROBE4 (ruby, method__return, arg1, arg2, arg3, arg4)
//...
#define RUBY_DTRACE_CMETHOD_ENTRY(arg1, arg2, arg3, arg4) \
DTRACE_PROBE4 (ruby, cmethod__entry, arg1, arg2, arg3, arg4)
//...

ただ、実際にコードではこのマクロが直接使われるというより、さらに一段噛ませたマクロを使っている模様。

$ grep RUBY_DTRACE_ -r *.c | head -20
array.c:    RUBY_DTRACE_CREATE_HOOK(ARRAY, 0);
array.c:    RUBY_DTRACE_CREATE_HOOK(ARRAY, capa);
array.c:    RUBY_DTRACE_CREATE_HOOK(ARRAY, capa);
eval.c: RUBY_DTRACE_HOOK(RAISE, rb_obj_classname(ec->errinfo));
gc.c:#define RUBY_DTRACE_GC_HOOK(name) \
gc.c:    do {if (RUBY_DTRACE_GC_##name##_ENABLED()) RUBY_DTRACE_GC_##name();} while (0)
gc.c:    RUBY_DTRACE_GC_HOOK(MARK_BEGIN);
gc.c:    RUBY_DTRACE_GC_HOOK(MARK_END);
gc.c:    RUBY_DTRACE_GC_HOOK(SWEEP_BEGIN);
gc.c:    RUBY_DTRACE_GC_HOOK(SWEEP_END);
hash.c:    RUBY_DTRACE_CREATE_HOOK(HASH, 0);
load.c:    RUBY_DTRACE_HOOK(LOAD_ENTRY, RSTRING_PTR(orig_fname));
load.c:    RUBY_DTRACE_HOOK(LOAD_RETURN, RSTRING_PTR(orig_fname));
load.c:    RUBY_DTRACE_HOOK(REQUIRE_ENTRY, RSTRING_PTR(fname));
load.c: RUBY_DTRACE_HOOK(FIND_REQUIRE_ENTRY, RSTRING_PTR(fname));
load.c: RUBY_DTRACE_HOOK(FIND_REQUIRE_RETURN, RSTRING_PTR(fname));
load.c:    RUBY_DTRACE_HOOK(REQUIRE_RETURN, RSTRING_PTR(fname));
object.c:    RUBY_DTRACE_CREATE_HOOK(OBJECT, rb_class2name(klass));
parse.c:#define RUBY_DTRACE_PARSE_HOOK(name) \
parse.c:    if (RUBY_DTRACE_PARSE_##name##_ENABLED()) { \

大体以下のようなマクロを噛ませている。詳細は probes_helper.h / internal/vm.h / gc.c などにある。

  • メソッドのentry, return - RUBY_DTRACE_(C)?METHOD_(ENTRY|RETURN)_HOOK()
  • オブジェクトや特定のクラス（Arrayなど）のオブジェクトの生成 - RUBY_DTRACE_CREATE_HOOK()
  • そのほか、トレースしたいイベント - RUBY_DTRACE_HOOK()
  • GCに関するイベント - RUBY_DTRACE_GC_HOOK()

probes.d をいじってコンパイルしてみる

で、今回以下のような ruby::ractor__create というProbeを追加した。

provider ruby {
  // ...
  /*
     ruby:::gc-sweep-end();

     Fired at the end of a sweep phase.
  */
  probe gc__sweep__end();
  
  probe ractor__create(int ractor_id, const char *filename, int lineno); // added
};

この状態でmakeし直すとprobes.hに新しいマクロが定義されている。

$ tail probes.h
#if defined STAP_SDT_V1
#define RUBY_DTRACE_RACTOR_CREATE_ENABLED() __builtin_expect (ractor__create_semaphore, 0)
#define ruby_ractor__create_semaphore ractor__create_semaphore
#else
#define RUBY_DTRACE_RACTOR_CREATE_ENABLED() __builtin_expect (ruby_ractor__create_semaphore, 0)
#endif
__extension__ extern unsigned short ruby_ractor__create_semaphore __attribute__ ((unused)) __attribute__ ((section (".probes")));
#define RUBY_DTRACE_RACTOR_CREATE(arg1, arg2, arg3) \
DTRACE_PROBE3 (ruby, ractor__create, arg1, arg2, arg3)

ただ、この状態ではバイナリにはUSDTの情報はない。

他の定義よろしく RUBY_DTRACE_CREATE_HOOK(RACTOR, id) を適切な場所に挿入する。執筆時点のmasterでは以下の関数内に定義すれば良さそう。

ruby/ractor.c at 7b9476fbfab738d1eb01b4b4c4af9a1680513019 · ruby/ruby · GitHub

こう書き換えた。

#include "probes.h"

//...

static VALUE
ractor_create(rb_execution_context_t *ec, VALUE self, VALUE loc, VALUE name, VALUE args, VALUE block)
{
    VALUE rv = ractor_alloc(self);
    rb_ractor_t *r = RACTOR_PTR(rv);
    ractor_init(r, name, loc);

    // can block here
    r->pub.id = ractor_next_id();
    RUBY_DEBUG_LOG("r:%u", r->pub.id);
    RUBY_DTRACE_CREATE_HOOK(RACTOR, r->pub.id); // ここに追加した

    r->r_stdin = rb_io_prep_stdin();
    r->r_stdout = rb_io_prep_stdout();
    r->r_stderr = rb_io_prep_stderr();

    rb_ractor_t *cr = rb_ec_ractor_ptr(ec);
    r->verbose = cr->verbose;
    r->debug = cr->debug;

    rb_thread_create_ractor(r, args, block);

    RB_GC_GUARD(rv);
    return rv;
}

これでコンパイルが通り、バイナリ側でも ruby:ractor__create というUSDTが定義される。

$ readelf -n ./ruby | grep -C 2 ractor__create
  stapsdt              0x00000049       NT_STAPSDT (SystemTap probe descriptors)
    Provider: ruby
    Name: ractor__create
    Location: 0x000000000013d0f8, Base: 0x00000000003950c0, Semaphore: 0x00000000003fc2cc
    Arguments: 4@8(%rbp) 8@%rax -4@16(%rsp)

新しいProbeの動作確認

Ubuntu Groovyで bpftrace パッケージを入れる。バージョンは v0.11.0 。

$ sudo apt install bpftrace

bpftraceからは usdt:/path/to/miniruby:ruby:ractor__create でアタッチできるらしい。ちなみにminirubyにも同じUSDTがあるので、いったんminirubyで試す。

$ sudo bpftrace -l 'usdt:./miniruby'
usdt:./miniruby:ruby:array__create
usdt:./miniruby:ruby:raise
usdt:./miniruby:ruby:gc__sweep__end
usdt:./miniruby:ruby:gc__sweep__begin
usdt:./miniruby:ruby:gc__mark__begin
usdt:./miniruby:ruby:gc__mark__end
usdt:./miniruby:ruby:hash__create
usdt:./miniruby:ruby:load__return
usdt:./miniruby:ruby:load__entry
usdt:./miniruby:ruby:find__require__return
usdt:./miniruby:ruby:require__entry
usdt:./miniruby:ruby:find__require__entry
usdt:./miniruby:ruby:require__return
usdt:./miniruby:ruby:object__create
usdt:./miniruby:ruby:parse__end
usdt:./miniruby:ruby:parse__begin
usdt:./miniruby:ruby:ractor__create
usdt:./miniruby:ruby:string__create
usdt:./miniruby:ruby:symbol__create
usdt:./miniruby:ruby:cmethod__entry
usdt:./miniruby:ruby:cmethod__return
usdt:./miniruby:ruby:method__return
usdt:./miniruby:ruby:method__entry

公式ドキュメント のサンプルにあるような以下のコードを実行する。

puts "Pid: #{$$}"
gets # block until keyhit

pipe = Ractor.new do
  loop do
    Ractor.yield Ractor.receive
  end
end

RN = 10
rs = RN.times.map{|i|
  Ractor.new pipe, rand(RN*128) do |pipe, i|
    pipe << i
  end
}

p RN.times.map{
  pipe.take
}.sort

あるターミナルでサンプルコードを実行する。PIDを吐き出してブロックするので、

$ ./miniruby ractor-sample.rb 
Pid: 80186

そのPIDに対して別のターミナルでアタッチする。

$ sudo bpftrace -p 80186 \
  -e 'usdt:./miniruby:ruby:ractor__create {
    printf("Ractor created: id=%d file=%s:L%d\n", arg0, str(arg1), arg2) }'
Attaching 1 probe...

ブロックした方のターミナルでリターンキーを押し、動かすと、生成されたRactorの情報が取得できる。ただ、ロケーション情報はinternalで、 racrot.rb の __builtin_ractor_create が呼ばれた行番号になってしまう。ArrayやHashと比べ初期化が特殊なようなので何か考慮する必要がある模様。

Ractor created: id=2 file=<internal:ractor>:L267
Ractor created: id=3 file=<internal:ractor>:L267
Ractor created: id=4 file=<internal:ractor>:L267
Ractor created: id=5 file=<internal:ractor>:L267
Ractor created: id=6 file=<internal:ractor>:L267
Ractor created: id=7 file=<internal:ractor>:L267
Ractor created: id=8 file=<internal:ractor>:L267
Ractor created: id=9 file=<internal:ractor>:L267
Ractor created: id=10 file=<internal:ractor>:L267
Ractor created: id=11 file=<internal:ractor>:L267
Ractor created: id=12 file=<internal:ractor>:L267

まとめや所感

  • probes.d を加工すればRubyに新しいUSDTのProbeを導入できる
  • 生成されたマクロそのままではなくRuby内の規約に沿って記述する必要がある（いくつかの規約はundocumented）。
  • （苦労して）USDTじゃなくて、内部関数のエントリポイントは普通にuprobe/uretprobeが存在する模様なので、それをトレースしてもいい。
    • ただ、それではractor idが簡単に取れないかも？
$ sudo bpftrace -l 'uprobe:./miniruby' | grep ':ractor' | head -20
uprobe:./miniruby:ractor_basket_accept
uprobe:./miniruby:ractor_basket_accept.cold
uprobe:./miniruby:ractor_close_outgoing.constprop.0
uprobe:./miniruby:ractor_create
uprobe:./miniruby:ractor_create.cold
uprobe:./miniruby:ractor_free
uprobe:./miniruby:ractor_init
uprobe:./miniruby:ractor_local_storage_free_i
uprobe:./miniruby:ractor_local_storage_mark_i
uprobe:./miniruby:ractor_local_value
uprobe:./miniruby:ractor_local_value.cold
uprobe:./miniruby:ractor_local_value_set
uprobe:./miniruby:ractor_local_value_set.cold
uprobe:./miniruby:ractor_mark
uprobe:./miniruby:ractor_memsize
uprobe:./miniruby:ractor_moved_missing
uprobe:./miniruby:ractor_queue_enq.constprop.0
uprobe:./miniruby:ractor_receive_if
uprobe:./miniruby:ractor_receive_if.cold
uprobe:./miniruby:ractor_receive_wait.isra.0