DTrace (2)

オイラーがいの一番で知りたいのは、プローブがどのように埋め込まれている かだ。適切な資料が見付かったぞ。

DTrace SDT Kernel Probes

実例が出てた。

#include <sys/param.h>
#include <sys/queue.h>
#include <sys/sdt.h>

SDT_PROVIDER_DEFINE(foobar);
SDT_PROBE_DEFINE2(foobar, source_file1, foo, entry, entry, "int", "char *");
SDT_PROBE_DEFINE1(foobar, source_file1, foo, return, return, "int");
SDT_PROBE_DEFINE(foobar, source_file2, bar, entry, entry);
SDT_PROBE_DEFINE(foobar, source_file2, bar, my_error_condition_name, my-error-condition-name);
SDT_PROBE_DEFINE(foobar, source_file2, bar, return, return);

こんなマクロを使って、定義するとな。

int
foo(int a, const char *b) {
    int c;

    SDT_PROBE2(foobar, source_file1, foo, entry, a, b);

    if (a == 3) {
         SDT_PROBE1(foobar, source_file1, foo, return, 1);
         return 1;
    }

    c = a*a;
    printf("%s\f", b);

    SDT_PROBE1(foobar, source_file1, foo, return, c);
    return (c);
}

void
bar(void) {

    SDT_PROBE0(foobar, source_file2, bar, entry);

    ...
    if (trigger_error()) {
        /*
         * Some kind of "milestone", we want to be able
         * to trigger a dtrace action in case this happens.
         */
        SDT_PROBE0(foobar, source_file2, bar, my_error_condition_name);
        return;
    }
    ...

    SDT_PROBE0(foobar, source_file2, bar, return);
}

これが実例だ。

大文字はマクロって慣習なんで、どんな風に展開されるか確認だな。cc -E example.cとして展開させるも、そのまま表われてくる。マクロじゃない別の 使われ方をしてるの？ 悩んでいてもしょうがない。

実際のカーネルで埋め込みを確認。

sakae@fb:/sys $ grep SDT_PROVIDER_DEFINE -r .
./fs/ext2fs/ext2_alloc.c:SDT_PROVIDER_DEFINE(ext2fs);
./fs/fuse/fuse_main.c:SDT_PROVIDER_DEFINE(fusefs);
./security/mac/mac_framework.c:SDT_PROVIDER_DEFINE(mac);
./security/mac/mac_framework.c:SDT_PROVIDER_DEFINE(mac_framework);
./contrib/dev/iwlwifi/iwl-devtrace.c:SDT_PROVIDER_DEFINE(iwlwifi);
./netinet/in_kdtrace.c:SDT_PROVIDER_DEFINE(ip);
./netinet/in_kdtrace.c:SDT_PROVIDER_DEFINE(tcp);
 :
./kern/kern_priv.c:SDT_PROVIDER_DEFINE(priv);
./kern/sched_ule.c:SDT_PROVIDER_DEFINE(sched);
./kern/kern_proc.c:SDT_PROVIDER_DEFINE(proc);
./kern/kern_lockstat.c:SDT_PROVIDER_DEFINE(lockstat);
./kern/sched_4bsd.c:SDT_PROVIDER_DEFINE(sched);
 :

そして、実際にrandomを検出するプローブの埋め込み先。

sakae@fb:/sys $ grep SDT_PROBE_DEFINE -r . | grep random
./dev/random/fortuna.c:SDT_PROBE_DEFINE2(random, fortuna, event_processor, debug, "u_int", "struct fs_pool *");

実際には、こんな風に定義されてた。

/* Probes for dtrace(1) */
#ifdef _KERNEL
SDT_PROVIDER_DECLARE(random);
SDT_PROVIDER_DEFINE(random);
SDT_PROBE_DEFINE2(random, fortuna, event_processor, debug, "u_int", "struct fs_pool *");
#endif /* _KERNEL */

random_fortuna_pre_read(void)
{
   :
#ifdef _KERNEL
        SDT_PROBE2(random, fortuna, event_processor, debug, fortuna_state.fs_reseedcount, fortuna_state.fs_pool);
#endif

こんな駆動方法で、とりあえず実行。

# dwatch -d -P random >dd
# less dd
# dtrace -s dd
2024 Aug 29 07:28:26 0.0 gdb141[7922]: gdb -q dtrace -p 7920

アタッチして、待機場所を特定。

(gdb) bt
#0  _umtx_op_err () at /usr/src/lib/libthr/arch/i386/i386/_umtx_op_err.S:37
#1  0x207136e7 in _thr_umtx_timedwait_uint (mtx=0x2071735c, id=0, clockid=0,
    abstime=0xffbfecac, shared=0) at /usr/src/lib/libthr/thread/thr_umtx.c:234
#2  0x207098c6 in _thr_sleep (curthread=0x207bb000, clockid=0,
    abstime=0xffbfecac) at /usr/src/lib/libthr/thread/thr_kern.c:197
#3  0x2070488d in cond_wait_user (cvp=0x207c0020, mp=0x20a00004,
    abstime=<optimized out>, cancel=<optimized out>)
    at /usr/src/lib/libthr/thread/thr_cond.c:318
#4  cond_wait_common (cond=<optimized out>, mutex=<optimized out>,
    abstime=0xffbfecac, cancel=0) at /usr/src/lib/libthr/thread/thr_cond.c:378
#5  0x20704c0a in _thr_cond_timedwait (cond=0x207e5004, mutex=0x207e5000,
    abstime=0xffbfecac) at /usr/src/lib/libthr/thread/thr_cond.c:406
#6  0x205a0335 in pthread_cond_timedwait_exp (p0=0x207e5004, p1=0x207e5000,
    p2=0xffbfecac) at /usr/src/lib/libc/gen/_pthread_stubs.c:279
#7  0x204cb3d1 in dtrace_sleep (dtp=0x207d4000)
    at /usr/src/cddl/contrib/opensolaris/lib/libdtrace/common/dt_work.c:110
#8  0x00405810 in main (argc=3, argv=0xffbfed98)
    at /usr/src/cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:1971

最初から丁寧に見ていくなら、下記。

# gdb -q dtrace
Reading symbols from dtrace...
Reading symbols from /usr/lib/debug//usr/sbin/dtrace.debug...
(gdb) b main
Breakpoint 1 at 0x40495c: file /usr/src/cddl/contrib/opensolaris/cmd/dtrace/dtrace.c, line 1313.
(gdb) r -n random:::
Starting program: /usr/sbin/dtrace -n random:::

Breakpoint 1, main (argc=3, argv=0xffbfecdc)
    at /usr/src/cddl/contrib/opensolaris/cmd/dtrace/dtrace.c:1313
1313            g_ofp = stdout

もう少し詳細にって事で、コンパイルの辺り。

for (i = 0; i < g_cmdc; i++)
        exec_prog(&g_cmdv[i]);

(gdb) p g_cmdv[0]
$2 = {
  dc_func = 0x406070 <compile_str>,
  dc_spec = DTRACE_PROBESPEC_NAME,
  dc_arg = 0xffbfee58 "random:::",
  dc_name = 0xffbfee58 "random:::",
  dc_desc = 0x401900 "description",
  dc_prog = 0x207c0880,
  dc_ofile = '\000' <repeats 1023 times>
}

コンパイルされるのか。大変だな。

                default:
=>                      if (!g_impatient && dtrace_errno(g_dtp) != EINTR)
                                dfatal("processing aborted");
                }

このあたりで、情報を受信して、結果を表示してるっぽい。もう少し詳細をつ めたいな。

もう少し簡単そうなのを調べてみる。

static void
cache_neg_hit_finish(struct namecache *ncp)
{

        SDT_PROBE2(vfs, namecache, lookup, hit__negative, ncp->nc_dvp, ncp->nc_name);
        counter_u64_add(numneghits, 1);
}

こんな風に展開された。

00001330 <cache_neg_hit_finish>:
; {
    1330: 55                            pushl   %ebp
    1331: 89 e5                         movl    %esp, %ebp
    1333: 53                            pushl   %ebx
    1334: 57                            pushl   %edi
    1335: 56                            pushl   %esi
    1336: 83 e4 f8                      andl    $-0x8, %esp
    1339: 83 ec 10                      subl    $0x10, %esp
;       SDT_PROBE2(vfs, namecache, lookup, hit__negative, ncp->nc_dvp, ncp->nc_name);
    133c: 80 3d 00 00 00 00 00          cmpb    $0x0, 0x0
    1343: 75 7c                         jne     0x13c1 <cache_neg_hit_finish+0x91>
;       counter_u64_add(numneghits, 1);
    1345: 8b 35 4c 00 00 00             movl    0x4c, %esi
          :
;       SDT_PROBE2(vfs, namecache, lookup, hit__negative, ncp->nc_dvp, ncp->nc_name);
    13c1: a1 24 00 00 00                movl    0x24, %eax
    13c6: 85 c0                         testl   %eax, %eax
    13c8: 0f 84 77 ff ff ff             je      0x1345 <cache_neg_hit_finish+0x15>
    13ce: 8d 51 1e                      leal    0x1e(%ecx), %edx
    13d1: 6a 00                         pushl   $0x0
    13d3: 6a 00                         pushl   $0x0
    13d5: 6a 00                         pushl   $0x0
    13d7: 52                            pushl   %edx
    13d8: ff 71 14                      pushl   0x14(%ecx)
    13db: 50                            pushl   %eax
    13dc: ff 15 00 00 00 00             calll   *0x0
    13e2: 83 c4 18                      addl    $0x18, %esp
    13e5: e9 5b ff ff ff                jmp     0x1345 <cache_neg_hit_finish+0x15>
    13ea: 90                            nop

最初のSDTは、プローブするか否かの判定。アセンブラーにして2命令たらずの 軽いコード。これでdtrace導入のオーバーヘッドを軽減してんだな。

2回目の奴が本命。コンパイラーが 一気に大文字で始まる関数を展開。まあ、ユーザーから見ればマクロの様に扱 かえるんだな。説明では、この部分をオブジェクトと呼んでいる。オブジェク ト指向が花だった時代の名残。

オブジェトの定義に先立って、クラス名に相当するのを SDT_PROVIDER_DEFINE で指定しなさい。具体的(?)なクラスは、 SDT_PROBE_DEFINE1 等で定義しておきなさいって方針なんだな。

SDT_PROVIDER_DEFINE(foobar);
SDT_PROBE_DEFINE2(foobar, source_file1, foo, entry, entry, "int", "char *");
SDT_PROBE_DEFINE1(foobar, source_file1, foo, return, return, "int");

後は型が決まっているので、実装あるのみ。 SDT_PROBE2() とかで、オブジェ クトを量産してね。。これぞ、Solaris流だな。