今までタイムスタンプを clock_gettime でとっていたけど、そのタイムスタンプはカーネル側でつけてくれるような気がしたので外した。それよりも、同じコンテナ管理プロセスでのイベントかどうかを見分けたいので、hpidという数字を発行することにした(といってもhaconiwa svのPIDなのだが、fork-execの間でも親と同じ値を渡すようにした。本当は、C側でuuid並みの大きな数字を発行するのが良さそう)。
いっしょにprobeの名前を変更(bpftraceでは -
を含むprobe名を利用できない模様)したり、bpftraceで動くサンプルをつけた。
Haconiwaが特定の処理を通過するとき、現在のマスターではこんな感じのbpftraceスクリプトを書くとイベントをフィルターできる。イベントの数値は、似たようなものは ~10、 11~30, 31~, 100~127 のように近づけて定義しているので。
BEGIN { printf("Starting trace...\n"); } usdt:./mruby/bin/haconiwa:haconiwa:bootstrap_phase_pass /arg0 > 10/ { printf("[%d] Pass: hpid: %d, phase: %d\n", nsecs, arg1, arg0); }
$ sudo bpftrace misc/sample.bt Attaching 2 probes... Starting trace... [1262986711] Pass: hpid: 26454, phase: 11 [1286217066] Pass: hpid: 26454, phase: 12 [1288785734] Pass: hpid: 26454, phase: 13 [1288810441] Pass: hpid: 26454, phase: 14 [1288848938] Pass: hpid: 26454, phase: 15 [1289587716] Pass: hpid: 26454, phase: 16 [1289756137] Pass: hpid: 26454, phase: 17 [1290851274] Pass: hpid: 26454, phase: 18 [1295379411] Pass: hpid: 26454, phase: 19 [1295399850] Pass: hpid: 26454, phase: 20 [1296817400] Pass: hpid: 26454, phase: 21 ...
多分、これの対応を含んだヘッダーとかを用意したら、bpftraceの --include で読み込んで人間にわかりやすく表示できると思う(そういう認識)。
これでもそれぞれの経過時間は雰囲気でわかるが(あるいは頑張って計算すればわかる)、カーネルタイマーを使って直接probeできないかなあ? というのを考えているところ。
今日はこんな感じメモ並みの内容です。