Handbuch zur dynamischen Ablaufverfolgung in Solaris

Beispiel

Betrachten Sie die folgende Ausgabe von mpstat(1M):

CPU minf mjf xcal  intr ithr  csw icsw migr smtx  srw syscl  usr sys  wt idl
 12   90  22 5760   422  299  435   26   71  116   11  1372    5  19  17  60
 13   46  18 4585   193  162  431   25   69  117   12  1039    3  17  14  66
 14   33  13 3186   405  381  397   21   58  105   10   770    2  17  11  70
 15   34  19 4769   109   78  417   23   57  115   13   962    3  14  14  69
 16   74  16 4421   437  406  448   29   77  111    8  1020    4  23  14  59
 17   51  15 4493   139  110  378   23   62  109    9   928    4  18  14  65
 18   41  14 4204   494  468  360   23   56  102    9   849    4  17  12  68
 19   37  14 4229   115   87  363   22   50  106   10   845    3  15  14  67
 20   78  17 5170   200  169  456   26   69  108    9  1119    5  21  25  49
 21   53  16 4817    78   51  394   22   56  106    9   978    4  17  22  57
 22   32  13 3474   486  463  347   22   48  106    9   769    3  17  17  63
 23   43  15 4572    59   34  361   21   46  102   10   947    4  15  22  59

Aus dieser Ausgabe könnte man schließen, dass das Feld xcal, insbesondere angesichts des relativen Leerlaufs des Systems, zu hoch ausfällt. mpstat bestimmt den Wert im Feld xcal über das Feld xcalls in der sys-Kernelstatistik. Diese Abweichung lässt sich deshalb problemlos durch Aktivierung des Prüfpunkts xcalls sysinfo untersuchen, wie das nächste Beispiel zeigt:

# dtrace -n xcalls'{@[execname] = count()}'
dtrace: description 'xcalls' matched 4 probes
^C
  dtterm                                                            1
  nsrd                                                              1
  in.mpathd                                                         2
  top                                                               3
  lockd                                                             4
  java_vm                                                          10
  ksh                                                              19
  iCald.pl6+RPATH                                                  28
  nwadmin                                                          30
  fsflush                                                          34
  nsrindexd                                                        45
  in.rlogind                                                       56
  in.routed                                                       100
  dtrace                                                          153
  rpc.rstatd                                                      246
  imapd                                                           377
  sched                                                           431
  nfsd                                                           1227
  find                                                           3767

Die Ausgabe zeigt, wo nach der Quelle der gegenseitigen Aufrufe zu suchen ist. Einige find(1)-Prozesse verursachen den Großteil der gegenseitigen Aufrufe. Das nächste D-Skript hilft, dem Problem weiter auf den Grund zu gehen:

syscall:::entry
/execname == "find"/
{
	self->syscall = probefunc;
	self->insys = 1;
}

sysinfo:::xcalls
/execname == "find"/
{
	@[self->insys ? self->syscall : "<none>"] = count();
}

syscall:::return
/self->insys/
{
	self->insys = 0;
	self->syscall = NULL;
}

In diesem Skript wird der Provider syscall dazu verwendet, gegenseitige Aufrufe aus find einem bestimmten Systemaufruf zuzuordnen. Einige gegenseitige Aufrufe, wie solche, die aus Seitenfehlern entstehen, gehen nicht von Systemaufrufen aus. In diesen Fällen gibt das Skript „<none>” aus. Die Ausführung dieses Skripts erzeugt eine Ausgabe wie in folgendem Beispiel:

# dtrace -s ./find.d
 dtrace: script './find.d' matched 444 probes
^C
  <none>                                                            2
  lstat64                                                        2433
  getdents64                                                    14873

Diese Ausgabe deutet darauf hin, dass die Mehrheit der von find bewirkten gegenseitigen Aufrufe ihrerseits durch getdents(2)-Systemaufrufe verursacht wurden. Für eine weitere Untersuchung wäre die gewünschte Richtung ausschlaggebend. Wenn Sie verstehen möchten, weshalb find-Prozesse getdents-Aufrufe tätigen, könnten Sie ein D-Skript schreiben, das ustack() aggregiert, wenn find einen gegenseitigen Aufruf verursacht. Wenn es Sie interessiert, weshalb getdents-Aufrufe gegenseitige Aufrufe verursachen, bietet sich ein D-Skript an, das ustack() aggregiert, wenn find einen gegenseitigen Aufruf verursacht. Welche Richtung Sie auch immer einschlagen, hat Ihnen der Prüfpunkt xcalls die Möglichkeit gegeben, die Ursache der ungewöhnlichen Überwachungsausgabe aufzudecken.