The syscall
provider enables you to trace every
system call entry and return. System calls can be a good starting
point for understanding the behavior of a process, especially if
the process seems to be spending a large amount of time executing
or blocked in the kernel, as shown in the output of commands such
as ps and top.
For example, consider a process with a process ID of 31337 that is consuming a large amount of system time. One possible explanation for this behavior is that the process is executing a large number of system calls. You can specify a simple D program on the command line to see which system calls are happening most often:
#dtrace -n syscall:::entry'/pid == 31337/{ @syscalls[probefunc] = count(); }'
dtrace: description ’syscall:::entry’ matched 215 probes^C
kill 1 clone 4 pipe 4 setpgid 4 rt_sigreturn 6 sendmsg 7 socket 7 access 8 getegid 8 geteuid 8 getgid 8 getuid 8 wait4 12 close 15 read 23 newstat 25 write 42 ioctl 65 rt_sigaction 168 rt_sigprocmask 198 write 1092
The previous report shows the system calls that are being called
most often, which in this case, is the write()
system call.
You can use the syscall
provider to further
examine the source of all of the write()
system
calls, for example:
#dtrace -n syscall::write:entry'/pid == 31337/{ @writes = quantize(arg2); }'
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
The previous output shows that the process is executing many
write()
system calls with a relatively small
amount of data. The ratio could be the source of the performance
problem for this particular process. This example illustrates a
general methodology for investigating system call behavior.