12.3 syscall Provider

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 by 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

This report shows which system calls are being called most often, in this case, the write() system call. You can use the syscall provider to further examine the source of all the write() system calls:

# 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 output shows that the process is executing many write() system calls with a relatively small amount of data. This ratio could be the source of the performance problem for this particular process. This example illustrates a general methodology for investigating system call behavior.