Handbuch zur dynamischen Ablaufverfolgung in Solaris

Aggregate

DTrace speichert die Ergebnisse von Aggregatfunktionen in einem Objekt namens Aggregat. Die Aggregatergebnisse werden ähnlich wie bei assoziativen Vektoren mit einem Tupel von Ausdrücken indiziert. Die Syntax für Aggregate in D lautet:

@Name[ Schlüssel ] = Aggfunk ( Args );

wobei Name für den Namen des Aggregats, Schlüssel für eine Liste mit Komma getrennter D-Ausdrücke, Aggfunkt für eine der DTrace-Aggregatfunktionen und Argumente für eine Liste mit Komma getrennter Argumente für die Aggregatfunktion stehen. Der Aggregatname ist ein D-Bezeichner mit dem vorangestellten Sonderzeichen @. Alle in Ihren D-Programmen benannten Aggregate sind globale Variablen. Es gibt keine thread- oder klausel-lokalen Aggregate. Die Aggregatnamen werden, getrennt von anderen globalen D-Variablen, in einem separaten Bezeichner-Namensraum geführt. Denken Sie bei der Wiederverwendung von Namen daran, dass a und @a nicht dieselbe Variable sind. Der spezielle Aggregatname @ kann in einfachen D-Programmen zum Benennen anonymer Aggregate eingesetzt werden. Der D-Compiler behandelt den Namen als Alias für den Aggregatnamen @_.

Die folgende Tabelle zeigt die Aggregatfunktionen von DTrace. Die meisten Aggregatfunktionen nehmen nur ein einziges Argument an, das die neue Information darstellt.

Tabelle 9–1 Aggregatfunktionen in DTrace

Funktionsname 

Argumente 

Ergebnis 

count

none 

Anzahl der Aufrufe. 

sum

Skalarer Ausdruck 

Gesamtwert der angegebenen Ausdrücke. 

avg

Skalarer Ausdruck 

Arithmetisches Mittel der angegebenen Ausdrücke. 

min

Skalarer Ausdruck 

Kleinster Wert in den angegebenen Ausdrücken. 

max

Skalarer Ausdruck 

Größter Wert in den angegebenen Ausdrücken. 

lquantize

Skalarer Ausdruck, Untergrenze, Obergrenze, Schrittwert 

Lineare Häufigkeitsverteilung der Werte der angegebenen Ausdrücke, beschränkt durch den angegebenen Bereich. Inkrementiert den Wert in der höchsten Menge, die kleiner als der angegebene Ausdruck ist.

quantize

Skalarer Ausdruck 

Eine Quadrat-Häufigkeitsverteilung der Werte der angegebenen Ausdrücke. Inkrementiert den Wert in der höchsten Quadratmenge, die kleiner als der angegebene Ausdruck ist.

Wenn beispielsweise die Anzahl der write(2)-Systemaufrufe im System gezählt werden sollen, könnten Sie eine informative Zeichenkette als Schlüssel und die Aggregatfunktion count() verwenden:

syscall::write:entry
{
	@counts["write system calls"] = count();
}

Der Befehl dtrace gibt die Aggregatergebnisse standardmäßig nach Abschluss des Prozesses aus, entweder als Resultat einer expliziten END-Aktion oder auf die Betätigung von Strg-C durch den Benutzer hin. Die folgende Beispielausgabe zeigt das Ergebnis nach Ausführung dieses Befehls, einer Wartezeit von einigen Sekunden und der anschließenden Betätigung von Strg-C:


# dtrace -s writes.d
dtrace: script './writes.d' matched 1 probe
^C

  write system calls                                              179
#

Mit der Variable execname als Schlüssel für ein Aggregat lassen sich die Systemaufrufe per Prozessnamen zählen:

syscall::write:entry
{
	@counts[execname] = count();
}

Die folgende Beispielausgabe zeigt das Ergebnis nach Ausführung dieses Befehls, einer Wartezeit von mehreren Sekunden und Drücken von Strg-C:


# dtrace -s writesbycmd.d
dtrace: script './writesbycmd.d' matched 1 probe
^C

  dtrace                                                            1
  cat                                                               4
  sed                                                               9
  head                                                              9
  grep                                                             14
  find                                                             15
  tail                                                             25
  mountd                                                           28
  expr                                                             72
  sh                                                              291
  tee                                                             814
  def.dir.flp                                                    1996
  make.bin                                                       2010
#

Alternativ können die Schreibzugriffe nach Prozessnamen und Dateibezeichner zusammen organisiert werden. Der Dateibezeichner ist das erste Argument für write(2). Im folgenden Beispiel wird also ein aus execname und arg0 zusammengesetzter Schlüssel verwendet:

syscall::write:entry
{
	@counts[execname, arg0] = count();
}

Die Ausführung dieses Befehls ergibt eine Tabelle wie in folgendem Beispiel, mit Prozessnamen und Dateibezeichner:


# dtrace -s writesbycmdfd.d
dtrace: script './writesbycmdfd.d' matched 1 probe
^C

  cat                                                               1      58
  sed                                                               1      60
  grep                                                              1      89
  tee                                                               1     156
  tee                                                               3     156
  make.bin                                                          5     164
  acomp                                                             1     263
  macrogen                                                          4     286
  cg                                                                1     397
  acomp                                                             3     736
  make.bin                                                          1     880
  iropt                                                             4    1731
#

Im nächsten Beispiel wird die durchschnittlich im write-Systemaufruf verbrachte Zeit je Prozess angezeigt. Dabei wird der Aggregatfunktion avg() der Ausdruck als Argument übergeben, aus dem der Durchschnitt berechnet werden soll. In diesem Beispiel wird der Durchschnitt der im Systemaufruf abgelaufenen Gesamtzeit berechnet:

syscall::write:entry
{
	self->ts = timestamp;
}

syscall::write:return
/self->ts/
{
	@time[execname] = avg(timestamp - self->ts);
	self->ts = 0;
}

Die folgende Beispielausgabe zeigt das Ergebnis nach Ausführung dieses Befehls, einer Wartezeit von mehreren Sekunden und Drücken von Strg-C:


# dtrace -s writetime.d
dtrace: script './writetime.d' matched 2 probes
^C

  iropt                                                         31315
  acomp                                                         37037
  make.bin                                                      63736
  tee                                                           68702
  date                                                          84020
  sh                                                            91632
  dtrace                                                       159200
  ctfmerge                                                     321560
  install                                                      343300
  mcs                                                          394400
  get                                                          413695
  ctfconvert                                                   594400
  bringover                                                   1332465
  tail                                                        1335260
#

Ein Durchschnittswert kann zwar nützlich sein, liefert aber häufig nicht genug Detailinformationen zum Verstehen der Verteilung von Datenpunkten. Um die Verteilung genauer zu verstehen, setzen wir wie folgt die Aggregatfunktion quantize() ein:

syscall::write:entry
{
	self->ts = timestamp;
}

syscall::write:return
/self->ts/
{
	@time[execname] = quantize(timestamp - self->ts);
	self->ts = 0;
}

Da aus jeder Ausgabezeile ein Häufigkeitsverteilungsdiagramm wird, fällt die Ausgabe dieses Skripts bedeutend länger aus als die vorherigen. Dieses Beispiel zeigt nur eine Auswahl der Beispielausgabe:


  lint
           value  ------------- Distribution ------------- count
            8192 |                                         0
           16384 |                                         2
           32768 |                                         0
           65536 |@@@@@@@@@@@@@@@@@@@                      74
          131072 |@@@@@@@@@@@@@@@                          59
          262144 |@@@                                      14
          524288 |                                         0

  acomp
           value  ------------- Distribution ------------- count
            4096 |                                         0
            8192 |@@@@@@@@@@@@                             840
           16384 |@@@@@@@@@@@                              750
           32768 |@@                                       165
           65536 |@@@@@@                                   460
          131072 |@@@@@@                                   446
          262144 |                                         16
          524288 |                                         0
         1048576 |                                         1
         2097152 |                                         0

  iropt
           value  ------------- Distribution ------------- count
            4096 |                                         0
            8192 |@@@@@@@@@@@@@@@@@@@@@@@                  4149
           16384 |@@@@@@@@@@                               1798
           32768 |@                                        332
           65536 |@                                        325
          131072 |@@                                       431
          262144 |                                         3
          524288 |                                         2
         1048576 |                                         1
         2097152 |                                         0        

Beachten Sie, dass die Zeilen der Häufigkeitsverteilung immer Zweierpotenzen darstellen. Jede Zeile gibt die Anzahl der Elemente an, die größer gleich dem entsprechenden Wert, aber kleiner als der Wert der nächsthöheren Zeile sind. So zeigt beispielsweise die obige Ausgabe, dass iropt 4.149 Schreibzugriffe mit einer Dauer von 8.192 bis 16.383 (einschließlich) Nanosekunden hatte.

quantize() eignet sich für einen schnellen Einblick in die Daten, aber nicht so sehr, wenn Sie eine Verteilung über lineare Werte untersuchen müssen. Zum Anzeigen einer linearen Werteverteilung verwenden Sie die Aggregatfunktion lquantize. () Die Funktion lquantize() nimmt zusätzlich zu einem D-Ausdruck drei Argumente an: eine Untergrenze, eine Obergrenze und eine Schrittweite. Zur Betrachtung der Verteilung der Schreibzugriffe nach Dateibezeichner wäre eine Zweierpotenz-Quantisierung beispielsweise nicht wirkungsvoll. Gehen Sie hierzu stattdessen mit einer linearen Quantisierung und kleinem Wertebereich vor, wie im nächsten Beispiel dargestellt:

syscall::write:entry
{
	@fds[execname] = lquantize(arg0, 0, 100, 1);
}

Wenn Sie dieses Skript einige Sekunden lang ausführen, erhalten Sie eine große Menge an Informationen. Dieses Beispiel zeigt einen Ausschnitt einer typischen Ausgabe:


  mountd
           value  ------------- Distribution ------------- count
              11 |                                         0
              12 |@                                        4
              13 |                                         0
              14 |@@@@@@@@@@@@@@@@@@@@@@@@@                70
              15 |                                         0
              16 |@@@@@@@@@@@@                             34
              17 |                                         0

  xemacs-20.4
           value  ------------- Distribution ------------- count
               6 |                                         0
               7 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  521
               8 |                                         0
               9 |                                         1
              10 |                                         0

  make.bin
           value  ------------- Distribution ------------- count
               0 |                                         0
               1 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  3596
               2 |                                         0
               3 |                                         0
               4 |                                         42
               5 |                                         50
               6 |                                         0

  acomp
           value  ------------- Distribution ------------- count
               0 |                                         0
               1 |@@@@@                                    1156
               2 |                                         0
               3 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@         6635
               4 |@                                        297
               5 |                                         0

  iropt
           value  ------------- Distribution ------------- count
               2 |                                         0
               3 |                                         299
               4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@  20144
               5 |                                         0        

Die Funktion lquantize() ermöglicht außerdem die Zusammenfassung der Zeit ab einem bestimmten Punkt in der Vergangenheit. Mit dieser Technik können Sie Änderungen des Verhaltens im Verlauf der Zeit beobachten. Das folgende Beispiel zeigt die Änderung im Systemaufruf-Verhalten über die Lebensdauer eines Prozesses, der den Befehl date(1) ausführt:

syscall::exec:return,
syscall::exece:return
/execname == "date"/
{
	self->start = vtimestamp;
}

syscall:::entry
/self->start/
{
	/*
	 * We linearly quantize on the current virtual time minus our
	 * process's start time.  We divide by 1000 to yield microseconds
	 * rather than nanoseconds.  The range runs from 0 to 10 milliseconds
	 * in steps of 100 microseconds; we expect that no date(1) process
	 * will take longer than 10 milliseconds to complete.
	 */
	@a["system calls over time"] =
	    lquantize((vtimestamp - self->start) / 1000, 0, 10000, 100);
}

syscall::rexit:entry
/self->start/
{
	self->start = 0;
}

Je mehr date(1)-Prozesse ausgeführt werden, desto tiefer der Einblick in das Systemaufruf-Verhalten, das das obige Skript bietet. Um das Ergebnis zu sehen, führen Sie sh -c 'while true; do date >/dev/null; done' in einem Fenster und das D-Skript in einem anderen aus. Das Skript erzeugt ein Profil des Systemaufruf-Verhaltens des Befehls date(1):


# dtrace -s dateprof.d
dtrace: script './dateprof.d' matched 218 probes
^C

  system calls over time
           value  ------------- Distribution ------------- count
             < 0 |                                         0
               0 |@@                                       20530
             100 |@@@@@@                                   48814
             200 |@@@                                      28119
             300 |@                                        14646
             400 |@@@@@                                    41237
             500 |                                         1259
             600 |                                         218
             700 |                                         116
             800 |@                                        12783
             900 |@@@                                      28133
            1000 |                                         7897
            1100 |@                                        14065
            1200 |@@@                                      27549
            1300 |@@@                                      25715
            1400 |@@@@                                     35011
            1500 |@@                                       16734
            1600 |                                         498
            1700 |                                         256
            1800 |                                         369
            1900 |                                         404
            2000 |                                         320
            2100 |                                         555
            2200 |                                         54
            2300 |                                         17
            2400 |                                         5
            2500 |                                         1
            2600 |                                         7
            2700 |                                         0        

Diese Ausgabe gibt einen groben Eindruck der verschiedenen Phasen des Befehls date(1) in Bezug auf die vom Kernel benötigten Dienste. Zum besseren Verständnis dieser Phasen kann es nützlich sein, festzustellen, welche Systemaufrufe wann stattfinden. Dafür könnten wir das D-Skript so abändern, dass die Aggregation an der Variable probefunc anstatt an einer konstanten Zeichenkette erfolgt.