Handbuch zur dynamischen Ablaufverfolgung in Solaris

Der Provider syscall

Der Provider syscall ermöglicht die Ablaufverfolgung jedes Eintritts in einen und jeder Rückkehr von einem Systemaufruf. Systemaufrufe stellen häufig einen guten Ausgangspunkt zum Verstehen des Verhaltens eines Prozesses dar, insbesondere dann, wenn der Prozess eine lange Ausführungszeit aufweist oder lange im Kernel blockiert bleibt. Mit dem Befehl prstat(1M) lässt sich beobachten, wo Prozesse Zeit verbringen:


$ 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

Dieses Beispiel zeigt, dass der Prozess sehr viel Systemzeit verbraucht. Eine mögliche Erklärung für dieses Verhalten ist, dass der Prozess zahlreiche Systemaufrufe ausführt. Ein einfaches, in der Befehlszeile angegebenes D-Programm zeigt uns, welche Systemaufrufe am häufigsten vorkommen:


# 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

Aus diesem Bericht geht der häufigste Systemaufruf hervor. Das ist in diesem Fall der write(2)-Systemaufruf. Mithilfe des Providers syscall lässt sich nun der Ursprung all dieser write()-Systemaufrufe ergründen:


# dtrace -n syscall::write:entry'/pid == 31337/{ @writes[arg2] = 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
            2048 |                                         0        

Die Ausgabe zeigt, dass der Prozess viele write()-Systemaufrufe mit relativ geringen Datenmengen ausführt. Dieses Verhältnis könnte die Ursache des Leistungsproblems für diesen bestimmten Prozess darstellen. Dies ist ein Beispiel für eine allgemeine Methode zur Erkundung des Systemaufrufverhaltens.