DTrace

どんなセンサーもとえプローブが埋めこまれているかリストしてみます。

# dtrace -l | head
   ID   PROVIDER            MODULE                          FUNCTION NAME
    1     dtrace                                                     BEGIN
    2     dtrace                                                     END
    3     dtrace                                                     ERROR
    4        fbt            kernel                camstatusentrycomp entry
    5        fbt            kernel                camstatusentrycomp return
    6        fbt            kernel            cam_compat_handle_0x19 entry
    7        fbt            kernel            cam_compat_handle_0x19 return
    8        fbt            kernel            cam_compat_handle_0x17 entry
    9        fbt            kernel            cam_compat_handle_0x17 return
dtrace: failed to write to <stdout>: Broken pipe
# dtrace -l | wc
   63368  315990 4812317

提供者、モジュール、関数と名前で、特定できる様になってるとな。

#!/bin/sh
awk '{cnt[$2]++ }
     END {for (i in cnt) { print i, cnt[i] } }
     '

ならば、awkの連想配列を利用して、集約してみましょう。$2で集約って事は、 プロバイダーを列挙するんだな。

# dtrace -l | ./cnt.awk | sort -nr -k2
fbt 60663
syscall 1152
dtmalloc 818
mac_framework 242
vfs 183
nfscl 172
lockstat 26
 :

その結果、fbtってのが断トツで、銀メダルはsyscallってなった。

# dtrace -l | ./cnt.awk | sort -nr -k2 | head
kernel 60479
freebsd 1152
vmci 255
vop 158
nfs4 84
opensolaris 71
hidbus 58
nfs3 46
usbhid 44
nfs2 34

今度は、$3でモジュール毎に集約してみた。

-d        Debug.  Send dtrace(1) script to stdout instead of executing.

面白いオプションが有るので試してみる。

# dwatch -d exec >dcode
# less dcode
#!/usr/sbin/dtrace -s
#pragma D option quiet
#pragma D option dynvarsize=16m
#pragma D option switchrate=10hz

int console;

dtrace:::BEGIN { console = 0 } /* probe ID 1 */

/*********************************************************/

proc:kernel:none:exec /* probe ID 2 */
{
        /*
         * Examine process, parent process, and grandparent process details
         */

        /******************* CURPROC *******************/

        this->proc = curthread->td_proc;
        this->uid0 = this->proc ? this->proc->p_ucred->cr_uid : -1;
        this->gid0 = this->proc ? this->proc->p_ucred->cr_rgid : -1;
        this->pid0 = this->proc ? this->proc->p_pid : -1;
        :
proc:kernel:none:exec /* probe ID 3 */
{
        /***********************************************/

        printf("%s%Y%s ",
                console ? "\033[32m" : "",
                walltimestamp,
                console ? "\033[39m" : "");

        /****************** EVENT_TAG ******************/

        printf("%d.%d %s[%d]: ",
                this->uid0, this->gid0, execname, this->pid0);

        /**************** EVENT_DETAILS ****************/

        printf("%s", this->args0);

        /***********************************************/

        printf("\n");

}

こんな風に翻訳されて、それがdtraceに渡るんだな。ならば、これを実行。

# chmod 755 dcode
# ./dcode
2024 Aug 18 08:12:25 1001.1001 sh[14102]: -sh
2024 Aug 18 08:12:25 1001.1001 sh[14103]: /bin/sh /usr/bin/man ls
2024 Aug 18 08:12:25 1001.1001 sh[14104]: /bin/sh /usr/bin/man ls
2024 Aug 18 08:12:25 1001.1001 sh[14105]: /bin/sh /usr/bin/man ls
 :

ふむ、しっかり日時が付いていて、ログの形式になってる。

# cat LOG | awk '{print $6, $7, $8}' | uniq | less

日時を除くなら、awkに喰わせればいいか。それとも、ソースを変更しちゃう のも手だな。

::open: /* probe ID 3 */
/execname == "date"/
{
        printf("%d.%d %s[%d]: ",
                this->uid0, this->gid0, execname, this->pid0);

        printf("%s", this->args0);

        printf("\n");
}

こんな風に、プローブするコマンドを特定な者に制限できる。

# ./dcode
1001.1001 date[14252]: date -r 12345
1001.1001 date[14252]: date -r 12345
1001.1001 date[14252]: date -r 12345
 :

openなプローブって、どんなの？ そんな時は、下記のようにする。

# dwatch -l open
PROVIDER:MODULE:FUNCTION:NAME
nfscl:nfs4:open:done
nfscl:nfs4:open:start
syscall:freebsd:open:entry
syscall:freebsd:open:return

profile用のスクリプトは、まとめて置いてある。どんなのがあるか、いちど 参照してみる。例として、多用しそうな、procを確認。

sakae@fb:/usr/libexec/dwatch $ ls proc*
proc                    proc-exec-success       proc-signal-discard
proc-create             proc-exit               proc-signal-send
proc-exec               proc-signal             proc-status
proc-exec-failure       proc-signal-clear

こんな系列も有るけど、真実はひとつならぬ、カメレオン・モードを実現する ためみたいです。

# $Title: dwatch(8) module for dtrace_proc(4) activity $

case "$PROFILE" in
proc)
        : ${PROBE:=$( echo \
                proc:::create, \
                proc:::exec, \
                proc:::exec-failure, \
                proc:::exec-success, \
                proc:::exit, \
                proc:::signal-clear, \
                proc:::signal-discard, \
                proc:::signal-send )}
        ;;
proc-signal)
  :
inline string probealias[string name] =
        name == "create" ?              "FORK" :
        name == "exec" ?                "EXEC" :
        name == "exec-failure" ?        "FAIL" :
        name == "exec-success" ?        "INIT" :
        name == "exit" ?                "EXIT" :
 :
proc:::create /* probe ID $(( $ID + 1 )) */
{${TRACE:+
        printf("<$(( $ID + 1 ))>");
}
        $( pproc -P _create "(struct proc *)args[0]" )

        /* details = "pid <pid of args[0]> -- <proc args of args[0]>" */
        this->details = strjoin(
                strjoin("pid ", lltostr(this->pid_create)),
                strjoin(" -- ", this->args_create));
}
 :

シェルスクリプトですねぇ。注目は冒頭付近のコメントにさりげなく案内され てる、 dtrace_proc(4) です。

# dwatch -X proc -o LOG
INFO Sourcing proc profile [found in /usr/libexec/dwatch]
INFO Watching 'proc:::create, proc:::exec, proc:::exec-failure, proc:::exec-success, proc:::exit, proc:::signal-clear, proc:::signal-discard, proc:::signal-send' ...
INFO Setting output: LOG
^C

manの動作を追跡しようと思っていたらcronの動作もキャプチャーしてくれて いたので、そちらに焦点をあててみる。近頃は、あちこちに監視カメラやらド ラレコがついていて、油断も隙もない世界になっちまった。1984年が現実です。

# cat LOG | cut -b22-
2.5 cron[14493]: EXEC /bin/sh
2.5 sh[14493]: INIT /bin/sh -c /usr/libexec/save-entropy
2.5 sh[14493]: EXEC /usr/libexec/save-entropy
2.5 sh[14493]: INIT /bin/sh /usr/libexec/save-entropy
2.5 sh[14493]: FORK pid 14496 -- /bin/sh /usr/libexec/save-entropy
:
2.5 sh[14493]: FORK pid 14498 -- /bin/sh /usr/libexec/save-entropy
2.5 sh[14498]: EXEC /bin/dd
2.5 dd[14498]: INIT dd if=/dev/random of=saved-entropy.8 bs=4096 count=1
2.5 dd[14498]: EXIT child exited
2.5 dd[14498]: SEND SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy
2.5 dd[14498]: DISCARD SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy
2.5 sh[14493]: FORK pid 14499 -- /bin/sh /usr/libexec/save-entropy
2.5 sh[14499]: EXEC /bin/chflags
2.5 chflags[14499]: INIT chflags nodump saved-entropy.8
2.5 chflags[14499]: EXIT child exited
2.5 chflags[14499]: SEND SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy
2.5 chflags[14499]: DISCARD SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy
2.5 sh[14493]: FORK pid 14500 -- /bin/sh /usr/libexec/save-entropy
2.5 sh[14500]: EXEC /usr/bin/fsync
2.5 fsync[14500]: INIT fsync saved-entropy.8 .
2.5 fsync[14500]: EXIT child exited
2.5 fsync[14500]: SEND SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy
2.5 fsync[14500]: DISCARD SIGCHLD[20] pid 14493 -- /bin/sh /usr/libexec/save-entropy

ログの冒頭の日時は、cutしました。冒頭の 2.5 はpid.gidです。翻訳すると operator.operatorになります。

カメレオン・モードって表現したのは、こんな事です。

# dwatch -X proc-exec-success -o LOG
INFO Sourcing proc-exec-success profile [found in /usr/libexec/dwatch]
INFO Watching 'proc:::exec-success' ...
INFO Setting output: LOG
^C

特定なプローブだけをログする、すなわちS/N比を向上させます。なお、同一 名のログだと追記になるんで注意。

1001.1001 sh[14595]: INIT /bin/sh /usr/bin/man ls
1001.1001 sysctl[14596]: INIT /sbin/sysctl -n hw.machine_arch
1001.1001 sysctl[14597]: INIT /sbin/sysctl -n hw.machine
1001.1001 locale[14598]: INIT /usr/bin/locale
1001.1001 gzcat[14600]: INIT /usr/bin/gzcat /usr/share/man/man1/ls.1.gz
1001.1001 head[14601]: INIT head -1
1001.1001 gzcat[14602]: INIT /usr/bin/gzcat /usr/share/man/man1/ls.1.gz
1001.1001 mandoc[14603]: INIT mandoc -Tlint -Wunsupp
1001.1001 gzcat[14604]: INIT /usr/bin/gzcat /usr/share/man/man1/ls.1.gz
1001.1001 mandoc[14605]: INIT mandoc
1001.1001 less[14606]: INIT less

dtrace_proc(4) なんてのを見付けてしまったものだから、他にも有るだろ うと推測。やっぱり有った。分類上は、デバイス若しくは、デバドラ扱い。ま あ、センサーと見做せるから、当然か。

sakae@fb:/usr/share/man/man4 $ ls dtrace*
dtrace_audit.4.gz       dtrace_proc.4.gz        dtrace_udp.4.gz
dtrace_io.4.gz          dtrace_sched.4.gz       dtrace_udplite.4.gz
dtrace_ip.4.gz          dtrace_sctp.4.gz
dtrace_lockstat.4.gz    dtrace_tcp.4.gz

sakae@fb:/usr/src/cddl/usr.sbin/dwatch $ ls
Makefile        dwatch*         dwatch.1        examples/       libexec/

dwatchのソースは、こんな所にあった。cddlってのは、ライセンス名。GNUラ イセンスとは犬猿の仲なんで、リナは指を咥えて▼みんちょうたい