2017年06月

gdb で ruby プロセスのC レベルとRubyレベルのバックトレースを表示する方法

ちょっと思いついて、sigdump gem を入れていなくても、gdb で ruby プロセスにアタッチすれば、Ruby レベルのバックトレースを簡単に取れるんじゃなかろうかと思って試してみた。C レベルのバックトレースも取りたい。

(1) rb_print_backtrace() と rb_backtrace()

CRubyの内部に、Cレベルバックトレースを出力するrb_print_backtrace関数と、Rubyレベルバックトレースを出力する rb_backtrace関数があるので、それを利用する。

gdb で ruby プロセスにアタッチして、

gdb $HOME/.rbenv/versions/2.4.1/bin/ruby [PID]

以下のようにコマンドを打つ。

call write(2, "== c backtrace ==\n", 18)
call rb_print_backtrace()
call write(2, "== ruby backtrace ==\n", 21)
call rb_backtrace()

しかし、これらではカレントスレッドのバックトレースしか出せない。
また、gdbプロセスの標準出力ではなく、対象プロセスのSTDERRに出力がでるので、どこに結果が出たのかわからなくなりそう、という懸念があった。

(2) backtrace と rb_eval_string

Cレベルバックトレースは gdb の機能である backtrace コマンドで表示できるので、スレッド一覧を info threads で取って、全スレッドに対して backtrace コマンドを打ち込めば取れる。これは何も問題ない。

Rubyレベルバックトレースを、call rb_eval_string("コード") に以下のような Ruby コードを打ち込んで取得するというアイデアを思いついた。

File.open('/tmp/dump', 'a') {|f|
  Thread.list.each {|th|
    f.write %Q[  Thread #{th} status=#{th.status} priority=#{th.priority}\n]
    th.backtrace.each {|bt|
      f.write %Q[      #{bt}\n]
    }
  }
}

実際にやってみると、gdb を detach してもプロセスが復帰しなくなってしまった。。。 gdb から ruby コードを実行するとなんやかんやあって壊れる。

メモ: perl なら gdb から perl コードを実行できるのか ... ? 羨ましい => 追記: この任意の perl コードを gdb から実行するやつは、安全にperlコードを実行できるように perl のイベントループの特定の箇所に breakpoint を貼ってから perl コードを実行する工夫をしているらしい。ただそれでも centos 5.8 の system perl だと segv 起きたりしたとのこと by hirose31

(3) rubyレポジトリにある .gdbinit で定義されている rb_ps を使う

もうすでにアイデア倒れだった感があるのだが、rubyレポジトリに .gdbinitというデバッグ用 gdb スクリプトがあり、そこに C レベルおよび Ruby レベルのスタックトレースを表示する rb_ps という関数が実は定義されているので、それを使うことができる。

gdb -x .gdbinit $HOME/.rbenv/versions/2.4.1/bin/ruby [PID]
(gdb) rb_ps
* #<Thread:0x7f46bb0a5ee8 rb_thread_t:0x7f46bb0725d0 native_thread:0x7f46ba514740>
0x7f46ba16d700 <thread_join_m at thread.c:980>:in `join'
loop.rb:17:in `<main>'
* #<Thread:0x7f46bb202750 rb_thread_t:0x7f46bb3e03d0 native_thread:0x7f46b89c0700>
0x7f46ba0e4f30 <rb_f_sleep at process.c:4388>:in `sleep'
loop.rb:6:in `block (2 levels) in <main>'
0x7f46ba1a72b0 <rb_f_loop at vm_eval.c:1137>:in `loop'
loop.rb:4:in `block in <main>'
* #<Thread:0x7f46bb202660 rb_thread_t:0x7f46bb3e47e0 native_thread:0x7f46b87be700>
0x7f46ba0e4f30 <rb_f_sleep at process.c:4388>:in `sleep'
loop.rb:13:in `block (2 levels) in <main>'
0x7f46ba1a72b0 <rb_f_loop at vm_eval.c:1137>:in `loop'
loop.rb:11:in `block in <main>'

表示に 2.6 sec ぐらいかかってちょっと遅い感はあったが、しっかり動く。
rb_ps は関数呼び出しを使ってないので、core ファイルに対しても使える。便利。

結論

CRuby の C level interaface の変更に追随するのは大変なので、ruby core team にメンテナンスされている .gdbinit を持ってきて使うのが一番楽、という結論に至ってしまった。

gdb を live process に対してアタッチすると、その間プロセスが止まってしまうので注意。固まったプロセスの調査に使うとか、rb_ps は core ファイルに対しても使えるので gcore コマンドで core を吐かせてからゆっくり調査する、とかやると良いだろう。

追記: gem にしました > https://github.com/sonots/gdbdump-ruby

CアプリケーションからRubyスクリプトを呼び出す方法

Cアプリケーションから libruby を使ってRubyコードに定義されている関数を呼び出す方法について記載する。
対象の Ruby バージョンは 2.4.1。

libruby の生成

libruby は rbenv で ruby をインストールすると、実はすでにできているのでご利用いただける。

~/.rbenv/versions/2.4.1/lib
~/.rbenv/versions/2.4.1/include/ruby-2.4.0/

ここに libruby-static.a とヘッダファイルがある。

利用中の ruby から lib と include パスを動的に取り出す

以下のコマンドでビルドに必要なパスを動的に取り出せる

$ ruby -e 'puts RbConfig::CONFIG["libdir"]'
/Users/seo.naotoshi/.rbenv/versions/2.4.1/lib

$ ruby -e 'puts RbConfig::CONFIG["LIBS"] + " " +  RbConfig::CONFIG["LIBRUBYARG_STATIC"]'
-lpthread -ldl -lobjc -lruby-static -framework CoreFoundation

$ ruby -e 'puts RbConfig::CONFIG["rubyhdrdir"] + File::SEPARATOR + RbConfig::CONFIG["arch"]'
/Users/seo.naotoshi/.rbenv/versions/2.4.1/include/ruby-2.4.0/x86_64-darwin16

$ ruby -e 'puts RbConfig::CONFIG["rubyhdrdir"]'
/Users/seo.naotoshi/.rbenv/versions/2.4.1/include/ruby-2.4.0

これを利用して Makefile を書くとこんなかんじになる。

TARGET = sample
LIBS = -L $(shell ruby -e 'puts RbConfig::CONFIG["libdir"]') $(shell ruby -e 'puts RbConfig::CONFIG["LIBS"] + " " +  RbConfig::CONFIG["LIBRUBYARG_STATIC"]')
INCLUDE = -I $(shell ruby -e 'puts RbConfig::CONFIG["rubyhdrdir"] + File::SEPARATOR + RbConfig::CONFIG["arch"]') -I $(shell ruby -e 'puts RbConfig::CONFIG["rubyhdrdir"]')

all : $(TARGET)

$(TARGET) : sample.c
        gcc $(INCLUDE) $(LIBS) -o $(TARGET) sample.c

clean :
        rm -f $(TARGET)

Cアプリケーションからrubyコードを呼び出す例

呼び出し対象のRubyコードが以下のようなものだとして、Test::Callee.new#foo を呼び出したいとする。

callee.rb
module Test
  class Callee
    def foo(a)
      puts a
    end
  end
end

Cアプリケーションは以下のように書けば良い。

sample.c
#include "ruby.h"
#include "ruby/encoding.h"


VALUE $kernel;

void init()
{
    // Ruby初期化のおまじない
    ruby_init();
    ruby_init_loadpath();
    rb_enc_find_index("encdb"); // encodingライブラリの初期化
    rb_require("rubygems");
    rb_require("./callee");
}

void run()
{
    VALUE module = rb_const_get(rb_cObject, rb_intern("Test"));
    VALUE klass = rb_const_get(module, rb_intern("Callee"));
    VALUE obj = rb_class_new_instance(0, NULL, klass); // Test::Callee.new
    VALUE str = rb_str_new2("こんにちは");
    rb_funcall(obj, rb_intern("foo"), 1, str); // obj.foo(str)
}

int main()
{
    init();
    run();
}

コメントに書いているのだが、一応解説しておくと、

    ruby_init();
    ruby_init_loadpath();
    rb_enc_find_index("encdb");

が Ruby 初期化のおなじないである。Ruby のスタートアップ処理については usa さんが詳細な記事を書いていたので読むと良い(かもしれない)。

    rb_require("rubygems");
    rb_require("./callee");

次にここで rubygems を require しつつ、今回読み込みたい ruby スクリプトを require している。require_relative 相当のものは使えなかったので、./ をつけているが、カレントディレクトリが変わると動かなくなるので実は微妙な気はしている。

rb_require("callee") として、ビルド後

RUBYLIB=. ./sample

のようにして RUBYLIB を指定しながら実行する方が良いかもしれない。いや、面倒だな。宿題。

    VALUE module = rb_const_get(rb_cObject, rb_intern("Test"));
    VALUE klass = rb_const_get(module, rb_intern("Callee"));
    VALUE obj = rb_class_new_instance(0, NULL, klass);

これは ruby で書くと obj = Test::Callee.new に相当する。

    rb_funcall(obj, rb_intern("foo"), 1, str);

最後にこれで、obj.foo(str) を呼び出している。完。

今回のコード

https://github.com/sonots/libruby-sample においてあります。

How OOM killer determines a process to kill

カーネルのバージョンによって挙動が異なる

kernel 2.4.31

http://lxr.linux.no/linux-old+v2.4.31/kernel/sched.c#L130

この頃は sched.c に goodness という関数があり、そこで決まっている。

 130 /*
 131 * This is the function that decides how desirable a process is..
 132 * You can weigh different processes against each other depending
 133 * on what CPU they've run on lately etc to try to handle cache
 134 * and TLB miss penalties.
 135 *
 136 * Return values:
 137 *       -1000: never select this
 138 *           0: out of time, recalculate counters (but it might still be
 139 *              selected)
 140 *         +ve: "goodness" value (the larger, the better)
 141 *       +1000: realtime process, select this.
 142 */
...
 160        if (p->policy == SCHED_OTHER) {
 161                /*
 162                 * Give the process a first-approximation goodness value
 163                 * according to the number of clock-ticks it has left.
 164                 *
 165                 * Don't do any other calculations if the time slice is
 166                 * over..
 167                 */
 168                weight = p->counter;
 169                if (!weight)
 170                        goto out;
...
 178
 179                /* .. and a slight advantage to the current MM */
 180                if (p->mm == this_mm || !p->mm)
 181                        weight += 1;
 182                weight += 20 - p->nice;
 183                goto out;
 184        }

scheduler にわりあてられた tick が余っている量と、nice値による優先度が高ければ goodness が上がる。

kernel 2.6.32

mm/oom_kill.c の badness という関数で決めている

  54/**
  55 * badness - calculate a numeric value for how bad this task has been
  56 * @p: task struct of which task we should calculate
  57 * @uptime: current uptime in seconds
  58 *
  59 * The formula used is relatively simple and documented inline in the
  60 * function. The main rationale is that we want to select a good task
  61 * to kill when we run out of memory.
  62 *
  63 * Good in this context means that:
  64 * 1) we lose the minimum amount of work done
  65 * 2) we recover a large amount of memory
  66 * 3) we don't kill anything innocent of eating tons of memory
  67 * 4) we want to kill the minimum amount of processes (one)
  68 * 5) we try to kill the process the user expects us to kill, this
  69 *    algorithm has been meticulously tuned to meet the principle
  70 *    of least surprise ... (be careful when you change it)
  71 */

実装コードのコメントを見るべき http://lxr.linux.no/linux+v2.6.32/mm/oom_kill.c#L55

  • プロセスのメモリサイズが badness のベース
  • swapoff(2)を呼んでるプロセスであれば、badness を最高値にして return
    • /proc/sys/vm/swappiness の設定とは別の話
  • 子プロセスがあれば、その子プロセスのメモリサイズ/2 を badness に加算
  • badness /= sqrt(cpu_time)
    • cpuを使うプロセスであればあるほど小さくなる (cpu_time は 10秒単位)
  • badness /= sqrt(sqrt(run_time))
    • 起動時間がながければながいほど小さくなる (run_time は1000秒単位)

kernel 3.7.6

oom_kill.c の oom_badness という関数で決めている

   /**
175 * oom_badness – heuristic function to determine which candidate task to kill
176 * @p: task struct of which task we should calculate
177 * @totalpages: total present RAM allowed for page allocation
178 *
179 * The heuristic for determining which task to kill is made to be as simple and
180 * predictable as possible. The goal is to return the highest value for the
181 * task consuming the most memory to avoid subsequent oom failures.
182 */

実装コードのコメントを見るべき http://lxr.linux.no/linux+v3.7.6/mm/oom_kill.c#L175

  • プロセスのメモリ割合が badness のベース
  • rootプロセスに3%のボーナス
  • oom_score_adj の全体からの割合を出して加算

すごいシンプルになってる。OOM Killer に賢さを期待するな感が出ている。
kernel 4系もほぼ同じ。

Debugging with GDB を読んだメモ

今までgdbを騙し騙し使ってきたが一度全体的に学びたかったのでドキュメントを読んだ。

↓以下は自分用のメモ

(gdb) shell ls のようにすると gdb からシェルコマンドを叩ける

条件付き break point

関数の引数に対する break であれば以下のようにできる。引数じゃない場合は、break で行数を指定するしかない。

break foo if x>0
commands
  silent
  printf "x is %d\n",x
cont
end

スレッド番号を指定しながらの break

break linespec thread threadno if ...

1マシン命令の実行

  • stepi
  • nexti

スタック・フレーム

呼び出しスタックは、 スタック・フレーム、 または短縮してフレームと呼ばれる、 連続した小部分に分割される。bt でバックトレースを表示した時の左の番号がフレーム番号。

(gdb) bt
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x00007f023ab610ef in native_cond_timedwait (ts=<optimized out>, mutex=<optimized out>, cond=<optimized out>) at thread_pthread.c:361
#2  native_sleep (th=0x7f023c8075d0, timeout_tv=0x7ffe8eb70490) at thread_pthread.c:1149
#3  0x00007f023ab6171b in sleep_timeval (th=0x7f023c8075d0, tv=..., spurious_check=1) at thread.c:1134
#4  0x00007f023ab65405 in rb_thread_wait_for (time=...) at thread.c:1202
#5  0x00007f023aad3f60 in rb_f_sleep (argc=1, argv=0x7f023a90b090) at process.c:4397
#6  0x00007f023ab9a0a1 in vm_call_cfunc_with_frame (ci=0x7f023cb782b0, cc=<optimized out>, calling=<optimized out>, reg_cfp=0x7f023aa0af50, th=0x7f023c8075d0) at vm_insnhelper.c:1752
#7  vm_call_cfunc (th=0x7f023c8075d0, reg_cfp=0x7f023aa0af50, calling=<optimized out>, ci=0x7f023cb782b0, cc=<optimized out>) at vm_insnhelper.c:1847
#8  0x00007f023aba1dc1 in vm_exec_core (th=th@entry=0x7f023c8075d0, initial=initial@entry=0) at insns.def:1066
#9  0x00007f023aba6057 in vm_exec (th=th@entry=0x7f023c8075d0) at vm.c:1727
(gdb) fame 8
(gdb) up
(gdb) down

info line 関数 で関数の最初の行に対応するオブジェクト・コードの位置を知ることができる

(gdb) info line m4_changecom
Line 895 of "builtin.c" starts at pc 0x634c and ends at 0x6350.
A Ruby and Fluentd committer working at DeNA. 記事本文および記事中のコード片は引用および特記あるものを除いてすべて修正BSDライセンスとします。 #ruby #fluentd #growthforecast #haikanko #yohoushi #specinfra #serverspec #focuslight
はてぶ人気エントリー