| 跳过导航链接 | |
| 退出打印视图 | |
|
DTrace 用户指南 Oracle Solaris 10 8/11 Information Library (简体中文) |
| 跳过导航链接 | |
| 退出打印视图 | |
|
|
DTrace 用户指南 Oracle Solaris 10 8/11 Information Library (简体中文) |
本节重点介绍了用于跟踪用户进程活动的 DTrace 工具，并提供了示例来说明其用途。
DTrace 探测器在 Solaris 内核中执行。探测器使用 copyin() 或 copyinstr() 子例程将用户进程数据复制到内核的地址空间中。
请考虑下面的 write() 系统调用：
ssize_t write(int fd, const void *buf, size_t nbytes);
下面的 D 程序显示了一个试图输出传递给 write 系统调用的字符串内容的错误尝试：
syscall::write:entry
{
printf("%s", stringof(arg1)); /* incorrect use of arg1 */
}
当您运行该脚本时，DTrace 会生成类似于下例的错误消息。
dtrace: error on enabled probe ID 1 (ID 37: syscall::write:entry): \
invalid address (0x10038a000) in action #1
arg1 变量是一个地址，它引用正在执行系统调用的进程中的内存。请使用 copyinstr() 子例程来读取位于该地址的字符串。使用 printf() 操作来记录结果：
syscall::write:entry
{
printf("%s", copyinstr(arg1)); /* correct use of arg1 */
该脚本的输出将显示传递给 write 系统调用的所有字符串。
copyin() 和 copyinstr() 子例程无法从尚未触及的用户地址进行读取。如果包含某个有效地址的页面尚未由某个访问尝试引发错误，则该有效地址可能会导致错误。以下面的示例为例：
# dtrace -n syscall::open:entry'{ trace(copyinstr(arg0)); }'
dtrace: description 'syscall::open:entry' matched 1 probe
CPU ID FUNCTION:NAME
dtrace: error on enabled probe ID 2 (ID 50: syscall::open:entry): invalid address
(0x9af1b) in action #1 at DIF offset 52
在上例的输出中，应用程序的运行正常且 arg0 中的地址有效。不过，arg0 中的地址引用了相应的进程尚未访问的一个页面。为解决此问题，在跟踪数据之前请等待内核或应用程序使用该数据。例如，您可以等到系统调用返回时再应用 copyinstr()，如以下示例所示：
# dtrace -n syscall::open:entry'{ self->file = arg0; }' \ -n syscall::open:return'{ trace(copyinstr(self->file)); self->file = 0; }'
dtrace: description 'syscall::open:entry' matched 1 probe
CPU ID FUNCTION:NAME
2 51 open:return /dev/null
如果跟踪对 write 系统调用的每个调用，将会产生级联输出。对 write() 函数的每个调用都会导致 dtrace 命令在显示输出时调用 write() 函数。此反馈循环是一个有关 dtrace 命令如何干扰所需数据的较好示例。您可以使用一个简单的谓词来避免此行为，如下例所示：
syscall::write:entry
/pid != $pid/
{
printf("%s", stringof(copyin(arg1, arg2)));
}
$pid 宏变量扩展为已启用探测器的进程的进程标识符。pid 变量包含其线程正在触发了探测器的 CPU 上运行的进程的进程标识符。谓词 /pid != $pid/ 可确保脚本不跟踪与该脚本自身的运行相关的任何事件。
通过 syscall 提供器，可以跟踪每个系统调用的进入和返回。可以使用 prstat(1M) 命令来查看 examine 进程行为。
$ prstat -m -p 31337 PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/NLWP 13499 user1 53 44 0.0 0.0 0.0 0.0 2.5 0.0 4K 24 9K 0 mystery/6
此示例表明该进程占用了大量系统时间。对该行为的一种可能的解释是，进程正在执行大量系统调用。可以使用在命令行中指定的简单 D 程序，查看哪些系统调用出现的频率最高：
# dtrace -n syscall:::entry'/pid == 31337/{ @syscalls[probefunc] = count(); }'
dtrace: description 'syscall:::entry' matched 215 probes
^C
open 1
lwp_park 2
times 4
fcntl 5
close 6
sigaction 6
read 10
ioctl 14
sigprocmask 106
write 1092
此报告表明，存在对 write() 函数的大量系统调用。您可以使用 syscall 提供器，进一步检查所有 write() 系统调用的起因：
# dtrace -n syscall::write:entry'/pid == 31337/{ @writes[arg2] = quantize(); }'
dtrace: description 'syscall::write:entry' matched 1 probe
^C
value ------------- Distribution ------------- count
0 | 0
1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1037
2 |@ 3
4 | 0
8 | 0
16 | 0
32 |@ 3
64 | 0
128 | 0
256 | 0
512 | 0
1024 |@ 5
2048 | 0
以上输出表明，该进程正在执行多个数据量相对较少的 write() 系统调用。
ustack() 操作跟踪用户线程的栈。如果在 open() 系统调用中，打开多个文件的某个进程偶尔失败，则可使用ustack() 操作来查明执行失败的 open() 的代码路径：
syscall::open:entry
/pid == $1/
{
self->path = copyinstr(arg0);
}
syscall::open:return
/self->path != NULL && arg1 == -1/
{
printf("open for '%s' failed", self->path);
ustack();
}
该脚本还说明了 $1 宏变量的用途。该宏变量接受在 dtrace 命令行上指定的第一个操作数的值：
# dtrace -s ./badopen.d 31337
dtrace: script './badopen.d' matched 2 probes
CPU ID FUNCTION:NAME
0 40 open:return open for '/usr/lib/foo' failed
libc.so.1`__open+0x4
libc.so.1`open+0x6c
420b0
tcsh`dosource+0xe0
tcsh`execute+0x978
tcsh`execute+0xba0
tcsh`process+0x50c
tcsh`main+0x1d54
tcsh`_start+0xdc
ustack() 操作记录栈的程序计数器 (PC ) 值。dtrace 命令通过查看进程的符号表将那些 PC 值解析为符号名称。dtrace 命令输出无法解析为十六进制整数的 PC 值。
如果进程在 ustack() 数据针对输出进行格式化之前退出或者被终止，则 dtrace 命令可能无法将栈跟踪中的 PC 值转换为符号名称。在这种情况下，dtrace 命令将这些值显示为十六进制整数。为绕过此限制，请使用 dtrace 的 -c 或 -p 选项指定需关注的进程。如果事先不知道进程 ID 或命令，可使用以下 D 程序示例来绕过限制：示例使用了 open 系统调用探测器，但此方法可以用于使用 ustack 操作的任何脚本。
syscall::open:entry
{
ustack();
stop_pids[pid] = 1;
}
syscall::rexit:entry
/stop_pids[pid] != 0/
{
printf("stopping pid %d", pid);
stop();
stop_pids[pid] = 0;
}
如果 ustack() 操作已应用于进程中的某个线程，则上面的脚本在进程退出前的那一刻停止该进程。此方法确保 dtrace 命令能够将 PC 值解析为符号名称。在清除动态变量后，stop_pids[pid] 的值被设置为 0。
使用 pid 提供器，可以跟踪进程中的任何指令。与大多数其他提供器不同，pid 探测器是基于 D 程序中的探测器说明按需创建的。
对于 pid 提供器，最简单的操作模式是作为与 fbt 提供器类似的用户空间。以下示例程序将跟踪通过单个函数产生的所有函数进入和返回。$1 宏变量扩展为命令行上的第一个操作数。该宏变量是要跟踪的进程的进程 ID。$2 宏变量扩展为命令行上的第二个操作数。该宏变量是从其中跟踪所有函数调用的函数的名称。
示例 4-3 userfunc.d：跟踪用户函数的进入和返回
pid$1::$2:entry
{
self->trace = 1;
}
pid$1::$2:return
/self->trace/
{
self->trace = 0;
}
pid$1:::entry,
pid$1:::return
/self->trace/
{
}
此脚本生成类似于下例的输出：
# ./userfunc.d 15032 execute dtrace: script './userfunc.d' matched 11594 probes 0 -> execute 0 -> execute 0 -> Dfix 0 <- Dfix 0 -> s_strsave 0 -> malloc 0 <- malloc 0 <- s_strsave 0 -> set 0 -> malloc 0 <- malloc 0 <- set 0 -> set1 0 -> tglob 0 <- tglob 0 <- set1 0 -> setq 0 -> s_strcmp 0 <- s_strcmp ...
pid 提供器只能用于已在运行的进程。利用 dtrace 工具，可以使用 $target 宏变量以及 dtrace 选项 -c 和 -p 来创建和检测需关注的进程。下面的 D 脚本用于确定由某个特定的主题进程对 libc 进行的函数调用的分布：
pid$target:libc.so::entry
{
@[probefunc] = count();
}
要确定由 date(1) 命令执行的此类调用的分布，请执行以下命令：
# dtrace -s libc.d -c date dtrace: script 'libc.d' matched 2476 probes Fri Jul 30 14:08:54 PDT 2004 dtrace: pid 109196 has exited pthread_rwlock_unlock 1 _fflush_u 1 rwlock_lock 1 rw_write_held 1 strftime 1 _close 1 _read 1 __open 1 _open 1 strstr 1 load_zoneinfo 1 ... _ti_bind_guard 47 _ti_bind_clear 94
您可以使用 pid 提供器跟踪用户函数中的任何指令。pid 提供器根据需要为函数中的每条指令创建探测器。每个探测器的名称即函数中与其对应的，以十六进制整数表示的指令的偏移量。在 PID 为 123 的进程中，要启用 bar.so 模块的 foo 函数中与偏移量 0x1c 处的指令关联的探测器，可使用以下命令。
# dtrace -n pid123:bar.so:foo:1c
要启用函数 foo 中的所有探测器（包括每条指令的探测器），可使用以下命令：
# dtrace -n pid123:bar.so:foo:
下面的示例说明了如何组合使用 pid 提供器与推理跟踪来跟踪函数中的每条指令。
示例 4-4 errorpath.d：跟踪用户函数调用错误路径
pid$1::$2:entry
{
self->spec = speculation();
speculate(self->spec);
printf("%x %x %x %x %x", arg0, arg1, arg2, arg3, arg4);
}
pid$1::$2:
/self->spec/
{
speculate(self->spec);
}
pid$1::$2:return
/self->spec && arg1 == 0/
{
discard(self->spec);
self->spec = 0;
}
pid$1::$2:return
/self->spec && arg1 != 0/
{
commit(self->spec);
self->spec = 0;
}
执行 errorpath.d 时，该脚本的输出类似于下例。
# ./errorpath.d 100461 _chdir dtrace: script './errorpath.d' matched 19 probes CPU ID FUNCTION:NAME 0 25253 _chdir:entry 81e08 6d140 ffbfcb20 656c73 0 0 25253 _chdir:entry 0 25269 _chdir:0 0 25270 _chdir:4 0 25271 _chdir:8 0 25272 _chdir:c 0 25273 _chdir:10 0 25274 _chdir:14 0 25275 _chdir:18 0 25276 _chdir:1c 0 25277 _chdir:20 0 25278 _chdir:24 0 25279 _chdir:28 0 25280 _chdir:2c 0 25268 _chdir:return
|