Dtrace pid provider 跟踪CPU指令
此文默认读者已经对Dtrace有所了解。
使用Solaris中Dtrace的pid provider，可跟踪用户进程中函数的进入和返回，以及按绝对地址或函数偏移量指定的任何指令。
具体使用方式，用一个小例子来说明，跟踪并统计特定CPU指令的执行。
写一个被探测程序
[c]
#include <stdio.h>
int main(int argc, char* argv[])
{
long long i = 0;
for (i = 1; i; i++) {
printf("%d", i);
getchar();
}
return 0;
}
[/c]
./a.out运行，使用pid provider对此进程涉及的函数进行统计。
[bash]
dtrace -n 'pid$target:::entry {}' -p `pgrep a.out`
[/bash]
pid$target是进程标识，-p 后面参数是被探测进程的pid（进程号），这里用pgrep a.out获得。
在a.out执行界面，敲一个回车，让程序调用一些函数。回到dtrace界面，查看结果
[plain]
dtrace: description 'pid$target:::entry ' matched 3630 probes
CPU ID FUNCTION:NAME
0 71956 printf:entry
0 71949 _ndoprnt:entry
0 72067 _realbufend:entry
0 72065 getxfdat:entry
0 70784 memchr:entry
0 72050 ferror:entry
0 72050 ferror:entry
0 72031 _filbuf:entry
0 72067 _realbufend:entry
0 72065 getxfdat:entry
0 72062 _flushlbf:entry
0 72073 _fflush_u:entry
0 72070 _xflsbuf:entry
0 72067 _realbufend:entry
0 72065 getxfdat:entry
0 72729 write:entry
0 73257 __write:entry
0 72728 read:entry
0 73205 __read:entry
[/plain]
可以看到dtrace捕获了很多函数，选取memchr进行示范。使用mdb对memchar反汇编，获得汇编指令序列。
[bash]
echo memchr::dis | mdb -p `pgrep a.out`
[/bash]
结果
[plain]
libc_hwcap1.so.1`memchr: pushl %edi
libc_hwcap1.so.1`memchr+1: movl 0x8(%esp),%eax
libc_hwcap1.so.1`memchr+5: movl 0xc(%esp),%ecx
libc_hwcap1.so.1`memchr+9: movl 0x10(%esp),%edi
libc_hwcap1.so.1`memchr+0xd: cmpl $0x4,%edi
libc_hwcap1.so.1`memchr+0x10: jb +0x2a <libc_hwcap1.so.1`memchr+0x3c>
libc_hwcap1.so.1`memchr+0x12: testl $0x3,%eax
libc_hwcap1.so.1`memchr+0x17: jne +0x37 <libc_hwcap1.so.1`memchr+0x50>
libc_hwcap1.so.1`memchr+0x19: nop
libc_hwcap1.so.1`memchr+0x1a: nop
libc_hwcap1.so.1`memchr+0x1b: nop
libc_hwcap1.so.1`memchr+0x1c: movl (%eax),%edx
libc_hwcap1.so.1`memchr+0x1e: cmpb %dl,%cl
libc_hwcap1.so.1`memchr+0x20: je +0x4d <libc_hwcap1.so.1`memchr+0x6f>
libc_hwcap1.so.1`memchr+0x22: cmpb %dh,%cl
libc_hwcap1.so.1`memchr+0x24: je +0x48 <libc_hwcap1.so.1`memchr+0x6e>
libc_hwcap1.so.1`memchr+0x26: shrl $0x10,%edx
libc_hwcap1.so.1`memchr+0x29: cmpb %dl,%cl
libc_hwcap1.so.1`memchr+0x2b: je +0x40 <libc_hwcap1.so.1`memchr+0x6d>
libc_hwcap1.so.1`memchr+0x2d: cmpb %dh,%cl
libc_hwcap1.so.1`memchr+0x2f: je +0x3b <libc_hwcap1.so.1`memchr+0x6c>
libc_hwcap1.so.1`memchr+0x31: subl $0x4,%edi
libc_hwcap1.so.1`memchr+0x34: addl $0x4,%eax
libc_hwcap1.so.1`memchr+0x37: cmpl $0x4,%edi
libc_hwcap1.so.1`memchr+0x3a: jae -0x20 <libc_hwcap1.so.1`memchr+0x1c>
libc_hwcap1.so.1`memchr+0x3c: cmpl $0x0,%edi
libc_hwcap1.so.1`memchr+0x3f: je +0xb <libc_hwcap1.so.1`memchr+0x4c>
libc_hwcap1.so.1`memchr+0x41: cmpb (%eax),%cl
libc_hwcap1.so.1`memchr+0x43: je +0x2a <libc_hwcap1.so.1`memchr+0x6f>
libc_hwcap1.so.1`memchr+0x45: decl %edi
libc_hwcap1.so.1`memchr+0x46: incl %eax
libc_hwcap1.so.1`memchr+0x47: jmp -0xd <libc_hwcap1.so.1`memchr+0x3c>
libc_hwcap1.so.1`memchr+0x49: nop
libc_hwcap1.so.1`memchr+0x4a: nop
libc_hwcap1.so.1`memchr+0x4b: nop
libc_hwcap1.so.1`memchr+0x4c: xorl %eax,%eax
libc_hwcap1.so.1`memchr+0x4e: popl %edi
libc_hwcap1.so.1`memchr+0x4f: ret
libc_hwcap1.so.1`memchr+0x50: cmpl $0x0,%edi
libc_hwcap1.so.1`memchr+0x53: je -0x9 <libc_hwcap1.so.1`memchr+0x4c>
libc_hwcap1.so.1`memchr+0x55: cmpb (%eax),%cl
libc_hwcap1.so.1`memchr+0x57: je +0x16 <libc_hwcap1.so.1`memchr+0x6f>
libc_hwcap1.so.1`memchr+0x59: incl %eax
libc_hwcap1.so.1`memchr+0x5a: decl %edi
libc_hwcap1.so.1`memchr+0x5b: testl $0x3,%eax
libc_hwcap1.so.1`memchr+0x60: jne -0x12 <libc_hwcap1.so.1`memchr+0x50>
libc_hwcap1.so.1`memchr+0x62: cmpl $0x4,%edi
libc_hwcap1.so.1`memchr+0x65: jae -0x4b <libc_hwcap1.so.1`memchr+0x1c>
libc_hwcap1.so.1`memchr+0x67: jmp -0x2d <libc_hwcap1.so.1`memchr+0x3c>
libc_hwcap1.so.1`memchr+0x69: nop
libc_hwcap1.so.1`memchr+0x6a: nop
libc_hwcap1.so.1`memchr+0x6b: nop
libc_hwcap1.so.1`memchr+0x6c: incl %eax
libc_hwcap1.so.1`memchr+0x6d: incl %eax
libc_hwcap1.so.1`memchr+0x6e: incl %eax
libc_hwcap1.so.1`memchr+0x6f: popl %edi
libc_hwcap1.so.1`memchr+0x70: ret
[/plain]
mdb反汇编的结果证明程序中包含这些代码片段，但并不是这里所有的CPU指令都会被执行，很多地方出现这种指令，先cmpb，然后je，有跳转，对于一般的程序都有很多分支序列。所以mdb看到的结果，并不代表这些指令在CPU上运行了。
[plain]
libc_hwcap1.so.1`memchr+0x1e: cmpb %dl,%cl
libc_hwcap1.so.1`memchr+0x20: je +0x4d <libc_hwcap1.so.1`memchr+0x6f>
[/plain]
我们还需要用dtrace动态的跟踪探测。挑选这条必定被执行的指令。相对函数入口偏移0xd。
先来看看这条指令是否被执行了，这步不是必须的，可以帮助理解。(在a.out执行界面再敲一次回车，让其继续运行)
[bash]
dtrace -n 'pid$target:libc_hwcap1:memchr: {}' -p `pgrep a.out`
[/bash]
这里展示了memchr从entry到return的整个CPU指令执行序列，可以看到函数内部的所有执行过程，memchr:d行的存在说明 0xd 位置的 cmpl $0x4,%edi 被执行了，而 0x12 位置的libc_hwcap1.so.1`memchr+0x12: testl $0x3,%eax 并没有出现，进程从 10 位置直接跳转到了 3c 位置，是libc_hwcap1.so.1`memchr+0x10: jb +0x2a 指令运行的结果。
[plain]
dtrace: description 'pid$target:libc_hwcap1:memchr: ' matched 59 probes
CPU ID FUNCTION:NAME
0 70784 memchr:entry
0 73752 memchr:0
0 73753 memchr:1
0 73754 memchr:5
0 73755 memchr:9
0 73756 memchr:d
0 73757 memchr:10
0 73777 memchr:3c
0 73778 memchr:3f
0 73779 memchr:41
0 73780 memchr:43
0 73781 memchr:45
0 73782 memchr:46
0 73783 memchr:47
0 73777 memchr:3c
0 73778 memchr:3f
0 73787 memchr:4c
0 73788 memchr:4e
0 73789 memchr:4f
0 73751 memchr:return
[/plain]
看完了函数内部的运行方式，接下来只对0xd 位置的 cmpl $0x4,%edi进行单独探测。
[bash]
dtrace -n 'pid$target:libc_hwcap1:memchr:3c {}' -p `pgrep a.out`
[/bash]
pid$target:libc_hwcap1:memchr:3c，3c是偏移量，跟踪memchr偏移3c位置的指令(a.out界面回车)
[plain]
dtrace: description 'pid$target:libc_hwcap1:memchr:3c ' matched 1 probe
CPU ID FUNCTION:NAME
0 73777 memchr:3c
0 73777 memchr:3c
[/plain]
可以看到memchr:3c位置的指令cmpl运行了两次
本想用dtrace自带的功能对执行次数进行统计，暂时只能对memchr函数的运行次数进行统计，稍后将查下资料，再回来补充，有人指点下更是感谢。
(将hello.c中的getchar();去掉，让其成为自动循环。编译，运行a.out，进行探测)
[bash]
dtrace -n 'pid$target:libc_hwcap1:memchr:3c {@[probefunc]=count()} profile:::tick-1s {exit(0)}' -p `pgrep a.out`
[/bash]
profile:::tick-1s {exit(0)}让脚本在运行1s后退出，统计1s内memchr运行的次数。
[plain]
dtrace: description 'pid$target:libc_hwcap1:memchr:3c ' matched 2 probes
CPU ID FUNCTION:NAME
0 73809 :tick-1s
memchr 511244
[/plain]
显示在1s内，memchr被调用了511244次
评论