DTrace – The hidden treasure
Die Echtzeit-Analyse sowohl von Anwendungen, als auch des Kernels gewinnt – besonders durch die weiterhin stark zunehmende Virtualisierung – noch mehr an Bedeutung als schon in den vergangenen Jahren. Hierbei stehen im Zeitalter von großen multitenant Wirtsystemen und Big Data vor allem die weitreichenden Wechselwirkungen zwischen einer Vielzahl unterschiedlichster virtualisierter Gastsysteme, deren Anwendungen und den Kernel Subsystemen, die wesentliche Aufgaben zu erfüllen haben, im Vordergrund. In der genannten Umgebung sind dies in erster Linie das IO-Subsystem und der Netzwerk-Stack. Die Überwachung von CPU-Performance-Charakteristiken hat hier oft geringere Priorität.
Seit ihrem Erscheinen in Solaris 10 in 2005 hat die dynamic tracing facility (DTrace) neue Maßstäbe im Bereich der Echtzeitanalyse von UNIX-Systemen gesetzt und ist auch heute noch das Tool, an dem sich andere Werkzeuge messen lassen müssen. Darüber hinaus wird es im Solaris-Umfeld von Oracle aktiv weiter ausgebaut und insbesondere an die Weiterentwicklungen im Solaris-Kernel – etwa dem in Version 11 komplett überarbeiteten Netzwerk-Stack – angepasst. DTrace ist heute auch in FreeBSD und MacOS verfügbar wenngleich nicht im selben Funktionsumfang wie in Solaris [1].
Zu unrecht gehen jedoch auch heute viele Systemadministratoren, Anwender und auch Entwickler immer noch fälschlicherweise davon aus, dass DTrace nur für Kernel-Hacker zu bedienen und zu nutzen ist. Dem ist mitnichten so, wobei ein Grundverständnis für die Funktionalität von UNIX-Kerneln allerdings hilfreich ist. Belegt wird dies durch zahlreiche Beispiele aus den Bereichen Performance-Analyse und Systemadministration aber auch aus der Anwendungsentwicklung. Oft reichen wenige Zeilen D – der Programmiersprache von DTrace – um eine Vielfalt an Informationen zu gewinnen, die anderweitig nicht zugänglich wären. Durch die Berücksichtigung des Gesamtsystems erreichen Entwickler zudem eine höhere Qualität bei der Ermittlung von Performancedaten ihrer Anwendung.
Historie
Die Erfassung von System- und insbesondere Performance-Daten, ist für die Planung und zur Analyse von Problem- und Fehlerfällen unerlässlich für den Betrieb einer zentralen IT-Infrastruktur. Entsprechende Tools sind daher – wenngleich in unterschiedlicher Qualität – seit jeher Bestandteil der zum Einsatz kommenden Betriebssysteme bzw. deren Distributionen. Diese Tools lassen sich, charakterisiert durch die zu Grunde liegende Technik, in folgende Gruppen einteilen:
Statistische Tools
Anwendungen dieser Gruppe, etwa iostat(1m) und netstat(1m), liefern statistische Aussagen, wie Mittelwerte für Zeitintervalle, basierend auf exakt ermittelten Werten wie etwa der Anzahl übertragener Bytes. Im Solaris Umfeld ist kstat(1m) ein wenig bekanntes, jedoch sehr mächtiges Tool dieser Gattung, das den Zugriff auf alle statistischen Daten des Solaris Kernels über eine C-API, perl-Module oder mittels Kommandozeile ermöglicht. Das Beispiel demonstriert den einfachen Zugriff auf die aktuelle Größe des ZFS ARC Caches.
neo# kstat -p ::arcstats:data_size ::arcstats:c 5 zfs:0:arcstats:data_size 28731798784 zfs:0:arcstats:c 34324350096 zfs:0:arcstats:data_size 28676683008 zfs:0:arcstats:c 34209666896
Auch Mike Harsch's arcstat.pl-Tool verwendet die perl-kstat-Schnittelle [2].
neo# arcstat.pl 5 Time read miss miss% dmis dm% pmis pm% mmis mm% arcsz c 12:01:12 2G 92M 3 30M 1 61M 76 70M 3 31G 31G 12:01:17 331 2 0 1 0 1 1 0 0 31G 31G ...
Vorteilhaft ist die Tatsache, dass sich mit dieser Gruppe von Tools sehr schnell ein grober Überblick über den Zustand einzelner Kernelkomponenten verschaffen lässt. Gravierend ist jedoch, dass sich kritische Werte nicht Anwendungen oder Nutzern zuordnen lassen.
Sampling Tools
Die beiden bekanntesten Vertreter, top(1) und prstat(1m), unterliegen wie alle anderen Vertreter dieser Gruppe den Beschränkungen ähnlich denen des Nyquist-Shannon Abtasttheorems [3]. Das gezielte periodische sampling erlaubt die Erfassung einer Vielzahl von Parametern und deren Korrelation beispielsweise mit Anwendungen oder Nutzern. Kurzlebige Spitzenlasten sind jedoch mit dieser Gruppe von Tools im Allgemeinen nicht erfassbar, da typische Samplingraten nahezu immer mehrere Größenordnungen über der Dauer einzelner Events liegen können. Abb.1 verdeutlicht die Diskrepanz zwischen aufaddierter CPU-Zeit und der Last des Systems im Sinne des load-Parameters.
Eventbasierte Tools
Zu diesen gehören neben Debuggern auch Tools wie truss(1), strace(1) aber insbesondere auch die moderneren dtrace(1) und perf(1). Allen gemeinsam ist die Instrumentierung von Anwendungen und ggf. auch des Kernels dahingehend, dass bestimmte Ereignisse eine Monitoring-Funktion auslösen. Im Falle der beiden erstgenannten beschränkt sich dies auf System- oder Funktionsaufrufe in Bibliotheken. Erschwerend kommt hinzu, dass für das Auslesen einiger Prozessdaten dieser gestoppt und anschließend fortgesetzt werden muss. Das hat erheblichen Einfluss auf das zeitliche Verhalten einer Anwendung und kann die Erkennung von transienten Fehlern oder Störungen unmöglich machen. Auch die Korrelation von Daten unterschiedlicher Prozesse ist hierbei nur mangelhaft möglich. Die beiden letztgenannten Tools hingegen haben diese Schwachstellen nicht, sondern bieten viel weitreichendere Möglichkeiten.
Die Lösung: DTrace
A process cannot be understood by stopping it. Understanding must move with the flow of the process, must join it and flow with it. [4]
Durch seine dynamische Struktur bietet DTrace in den allermeisten Fällen eine Lösung für die im vorherigen Abschnitt beschriebenen Probleme und erlaubt eine kombinierte Sicht auf Anwendung und Kernel.
Probes
Erreicht wird dies durch sogenannte probes – Triggerpunkte –, die dynamisch im Kernel, seinen Modulen, aber auch der Anwendung und gelinkten Bibliotheken zur Laufzeit (de)aktiviert werden können. Die Aktivierung hat im Allgemeinen nur einen zu vernachlässigenden Einfluss auf die Performance des Systems.
Wird im Programmfluss eine aktivierte probe ausgelöst, sind vielfältige Aktionen möglich. Diese reichen von der einfachen Sammlung bzw. Ausgabe von Werten bis hin zur Manipulation derselben.
Abb.2 zeigt die Grobstruktur der DTrace-Integration in den Solaris-Kernel. Vergleichbares gilt auch für FreeBSD oder MacOS. Erwähnenswert ist, dass die Nutzung vieler DTrace-Techniken ohne root-Rechte möglich ist. Die Autorisierung geschieht im Falle von Solaris über privileges bei gleichzeitiger Einschränkung des sichtbaren scope.
Provider
Provider – DTrace-Kernkomponenten mit dedizierten Aufgaben – stellen bei Solaris 11-Systemen 100.000 und mehr probes zur Verfügung und gruppieren diese funktionell. Etwa 90% dieser probes sind dem function boundary trace provider (FBT) zuzuordnen, der die Einsprung- und Rückkehrpunkte der Solaris Kernel Routinen widerspiegelt.
Die wichtigste Aufgabe der provider ist jedoch die Bereitstellung der Daten in aufbereiteter Form. Etwa stehen IP-Adressen als string und nicht in Binärform zur Verfügung. Neben den üblichen Datenstrukturen lassen sich auch User- und Kernel-Stacks sowie ganze Speicherbereiche sichern. Dies geschieht pro CPU – im Sinne des Kernels – in Datenbereichen innerhalb des Kernels. Deren Größe und Organisation, etwa als Ringpuffer, ist individuell zur Laufzeit konfigurierbar. DTrace stellt auch die notwendigen Funktionen zur Verfügung, um Daten zwischen den Adressbereichen des Kernels und der Anwendung zu kopieren. Ein schreibender Zugriff auf Datenstrukturen ist nur in Einzelfällen möglich, um die Sicherheitsfunktionen und die Datenintegrität des Kernels nicht zu unterlaufen.
Neue provider werden im Rahmen von major-releases eingeführt. Hier lohnt ein Blick in die release notes. In Solaris 11 waren dies u. a. die ip-, tcp-, udp- und iscsi-provider. Neu ist auch der Zugriff auf die Hardware performance-counter moderner CPUs mit Hilfe des cpc-providers. Die hardwarenahe Natur bringt allerdings auch einige Randbedingungen hinsichtlich der Verfügbarkeit von probes mit sich.
| Name | Funktion |
|---|---|
| io | Liefert detaillierte Informationen über IO-Operationen auf Platten, Bändern und NFS-Servern, darunter File- und Gerätenamen sowie Größe und Richtung der Datenübertragung. |
| ip | Liefert aufbereitete Daten auf Basis des IP-headers, v4 und v6 und stellt ein mächtiges Werkzeug zur Server- oder Client-seitigen Analyse der Netzlast dar. Ergänzt snoop(1m), tcpdump(1) und wireshark(1m), deren Schwerpunkt auf der weitgehenden Protokoll-Analyse liegt. |
| syscall | Stellt probes für Einsprung- und Rückkehrpunkte von Systemaufrufen bereit und bietet Zugriff auf die in beide Richtungen übergebenen Daten. |
| proc | Der proc-provider erfasst alle Informationen bezüglich der Erzeugung von Prozessen und Threads sowie der Abarbeitung von Signalen. Dies ermöglicht u. a. die Analyse von Prozessketten wie sie beispielsweise bei Login-Vorgängen auftreten. |
| sched | Die probes des sched-providers dienen häufig als Ergänzung zu den Daten des proc-providers, da sie Informationen über das Laufzeitverhalten aus Sicht des Kerns enthalten. Dazu gehören das CPU-Scheduling-Verhalten, aber auch Thread-Synchronisationsmechanismen. |
| profile | Kein provider im herkömmlichen Sinn, gestattet dieser jedoch DTrace-Anwendungen die periodische Ausführung von Aktionen und erlaubt damit die Nachbildung von sampling und die regelmäßige Ausgabe von Daten à la prstat(1m). |
Consumer
Für das asynchrone Lesen der Daten aus den Puffern des Kernels sind consumer, etwa auch das dtrace(1m)-Tool, verantwortlich. Die Schnittstelle zum Kern bilden wie in UNIX üblich Gerätetreiber und die Routinen der libdtrace-Bibliothek. Durch den asychronen Zugriff und die begrenzte Größe der Puffer sind Überläufe möglich. Diese werden vom System gemeldet und können meist durch die Anpassung von Parametern im D-Skript behoben werden. Abb.2 verdeutlicht, dass immer mehr Tools auf der DTrace-Technik aufsetzen, Tendenz steigend.
"D", die Skriptsprache von DTrace
DTrace bedient sich zur Steuerung einer einfachen an "C" angelehnten Sprache namens "D". Das Compilieren und Laden des erzeugten Codes in den Kernel wird vom Kommando dtrace(1m) übernommen. Dieses tritt auch gleichzeitig als consumer für das Skript auf. Sprungbefehle stehen ebenso wenig zur Verfügung wie Schleifenkonstrukte da diese unter Umständen – etwa durch Endlos-Schleifen – die Stabilität des Systems gefährden würden. Ansonsten sind alle von "C" bekannten Operatoren und Typen verfügbar wenngleich wie im Falle von uintptr_t gelegentlich unter einer anderen Bezeichnung. Ergänzend bietet "D" eine integrierte limitierte String-Verarbeitung, assoziative Arrays – vergleichbar mit perl-Hashes – und vor allem Aggregationen, eines der mächtigsten DTrace-Features.
Variable
Vordefinierte Variable bieten einen einfachen Zugriff auf Prozess- und Thread-IDs, Credentials, Kernel-Variablen, Timer und vieles mehr. Das fds[]-array hat sich als sehr hilfreich erwiesen, da es die zu einem file-descriptor zugehörigen Daten der fileinfo_t-Struktur bereitstellt. Dadurch ist bei read(2)- und write(2)-Zugriffen einfach der zugehörige Dateiname zu ermitteln.
typedef struct fileinfo {
string fi_name; /* name (basename of fi_pathname) */
string fi_dirname; /* directory (dirname of fi_pathname) */
string fi_pathname; /* full pathname */
offset_t fi_offset; /* offset within file */
string fi_fs; /* filesystem */
string fi_mount; /* mount point of file system */
} fileinfo_t;Struktur
"D"-Skripte bestehen aus Code-Blöcken, die eher im Sinne von Funktionen agieren, die bei der Auslösung einer probe aufgerufen werden. Der Aufruf mehrerer Blöcke – dann von oben nach unten – durch einen event ist möglich. Im einzelnen setzen sich die Blöcke jeweils durch eine probe-Definition, einer optionalen Bedingung, sowie den Aktionen zusammen. Das nachfolgende Code-Segment, eine if-then-else-Nachbildung, macht dies deutlich.
probe1, probe2, … /* if Zweig */
/ Bedingung /
{
Aktionen
}
probe1, probe2, … /* else Zweig */
/ ! (Bedingung) /
{
Aktionen
}probe-Syntax
Die Namens-Syntax zur Definition von probes folgt dem Schema
provider:module:function:name
wobei "*", "?" und "[…]" in der gewohnten Weise als Platzhalter verwendet werden können. Ein Komma hat die Bedeutung eines "oder".
sysinfo:genunix:pread64:readch profile:::tick-5s syscall::open*: syscall:*:open*:* syscall::open: , syscall::open64:
Die verfügbaren probes – diese hängen u. a. von den geladenen Kernel-Modulen wie nfs, ... ab – liefert dtrace -l dessen Ausgabe sich mit weiteren Optionen filtern lässt.
# dtrace -l -f opendir ID PROVIDER MODULE FUNCTION NAME 25340 fbt unix opendir entry 25341 fbt unix opendir return
Ausgabe von Daten
Generell obliegt die Ausgabe der Daten dem jeweiligen consumer. Die jeweiligen provider stellen die Daten lediglich in den angesprochenen Puffern bereit. Die beiden einfachsten Funktionen, trace() und tracemem(), kopieren hierbei lediglich einfache Ausdrücke oder Speicherbereiche unformatiert. stack(), ustack() und jstack() stellen die call-stacks im Addressbereich des Kernels, eines Prozesses oder für Java-Anwendungen zur Verfügung. Die Auflösung der Adressen ist hierbei Aufgabe des consumers und ist nicht unter allen Umständen erfolgreich durchführbar. Durch den asynchronen Ansatz von DTrace kann z. B. ein Prozess beendend sein, bevor der consumer die gesammelten Daten auswertet. Ein Zugriff auf Symboltabellen ist damit unmöglich. Wege, dies zu umgehen finden sich im DTrace User Guide1.
Die formatierte Ausgabe von Werten ist mit printf() möglich. Die Formatierungsoptionen sind die aus "C" bekannten, um einige nützliche erweitert. So wandelt etwa %a einen Zeiger in den Namen eines Kernel-Symbols um. Äußerst hilfreich ist %S für die formatierte Ausgabe von Zeichenketten da hier nicht-druckbare Zeichen durch eine \-Quotierung dargestellt werden.
Ein erstes D-Skript
Die bisher vorgestellten Möglichkeiten sind bereits für ein einfaches Skript ausreichend. Dieses listet alle Lesezugriffe im gesamten System auf, die der Nutzer root ausführt.
# dtrace -q -n 'syscall::read*:entry
/ uid == 0 /
{
printf("%-12s %10s %s\n",
execname, probefunc, fds[arg0].fi_pathname );
}'
sshd read /zones/andromeda/root/dev/ptmx
init read /etc/inittab
init read /etc/inittab
init read /etc/inittab
init read /etc/inittab
sshd read /zones/andromeda/root/etc/hosts.allow
sshd read /zones/andromeda/root/proc/6808/psinfo
…
Da mehrere Systemaufrufe – neben read() auch readlinkat() und readv() – dem Muster entsprechen, wird die von DTrace definierte Variable probefunc mit ausgegeben. Diese enthält neben probeprov, probemod und probename eine Komponente des vollständigen Namens der probe, die für den event verantwortlich zeichnet. Um den Code innerhalb eines Skriptes mit Parametern verwenden zu können, ist nur eine minimale Änderung notwendig. Hierbei soll jetzt nicht auf eine UID sondern auf den Namen der Anwendung gefiltert werden.
# cat example_reads.d
#!/usr/sbin/dtrace -s
#pragma D option quiet
syscall::read*:entry
/ execname == $$1 / /* filter based on argument passed in */
{
printf("%-16s %10s %s\n",
execname, probefunc, fds[arg0].fi_pathname);
}
# ./example_reads.d httpd
httpd read /www/cms/fileadmin/img/.htaccess
httpd read /www/cms/fileadmin/img/.htaccess
httpd read /www/cms/typo3temp/llxml/xml_ed2fec5f68.en.utf-8.cache
httpd read /www/cms/typo3temp/llxml/xml_ed2fec5f68.en.utf-8.cache
httpd read /www/cms/typo3temp/llxml/xml_ed2fec5f68.en.utf-8.cache
…Der Name der Anwendung (hier httpd) kann jetzt als Kommandozeilen Argument übergeben werden. Im Skript selber ist jedoch eine Maskierung ($$1) notwendig.
Das verwendete Pragma quiet verbessert die Lesbarkeit, da es die Ausgaben von dtrace(1m) auf die print- bzw. trace-Befehle im Skript beschränkt. Mit Hilfe weiterer Pragmas lassen sich u. a. auch die in Abschnitt Consumer angesprochenen Puffer konfigurieren.
Neben dem Storage-Bereich ist insbesondere der Netzwerk-Bereich von herkömmlichen Tools bestenfalls statistisch erfassbar. DTrace stellt in Solaris 11.2 einige spezifische provider für diesen Bereich bereit, nämlich ip, tcp, udp, iscsi, nfsv3, nfsv4 und srp. Die Frage, welcher Klient gerade welche Dateien vom NFS-Server liest, ist damit einfach zu beantworten, hier während eines login via ssh.
# dtrace -q -n 'nfsv4:::op-read-start {
printf("%-16s %6d %s\n",
args[0]->ci_remote,
args[2]->count,
args[1]->noi_curpath);
}'
134.60.1.143 8192 /pool1/home/kiz/nau/.bashrc
134.60.1.143 8192 /pool1/home/kiz/nau/.ssh/authorized_keys
134.60.1.143 8192 /pool1/home/kiz/nau/.bash_profile
134.60.1.143 8192 /pool1/home/kiz/nau/.profile
134.60.1.143 8192 /pool1/home/kiz/nau/.bash_history
134.60.1.143 24576 /pool1/home/kiz/nau/.bash_historyDas Beispiel demonstriert die Vorteile der durch die provider aufbereiteten Daten die in Form von Zeigern auf Strukturen übergeben werden. So zeigt z. B. das erste Argument – Index 0 – auf die zur Verbindung gehörende conninfo_t-Struktur:
typedef struct conninfo {
string ci_local; /* local host address */
string ci_remote; /* remote host address */
string ci_protocol; /* protocol (ipv4, ipv6, etc) */
} conninfo_t;Neben dieser Datenaufbereitung sind besonders die im folgenden Abschnitt beschrieben aggregations von zentraler Bedeutung.
Aggregations
Allen Aggregationsfunktionen ist eine mathematische Eigenschaft gemeinsam. Diese besteht darin, dass die Funktion angewendet auf Teilmengen der Daten im ersten Schritt und auf die Zwischenergebnisse im zweiten Schritt das identische Ergebnis liefert wie die Anwendung auf die Gesamtmenge aller Daten in einem Zug. Beispiele hierfür sind Minima und Maxima, aber auch die Summen-Funktion (s.Abb.3).
Die Verwendung von aggregations reduziert den Speicherbedarf erheblich und verbessert damit die Skalierung bezüglich der potentiellen Menge an Daten. Ein dem Namen vorangestellte "@"-Zeichen definiert eine aggregation. Vergleichbar mit hashes in perl(1) unterstützt DTrace nahezu beliebige, auch mehrfache, Indizes wie etwa call-stacks und ist nicht auf numerische Werte oder Strings beschränkt. Beispielsweise zählt
@name[ustack()] = count();
die Anzahl der events pro user-stack also in Abhängigkeit des Programmflusses. In Solaris 11.2 sind derzeit folgende aggregations verfügbar:
| Name | Funktion |
|---|---|
| count | zählt die Zahl der Aufrufe |
| sum | Gesamtsumme der Ausdrücke |
| min, max | kleinster und größter Wert der Ausdrücke |
| avg, stddev | arithmetisches Mittel und Standardabweichung |
| lquantize | lineare Verteilung mit vorgegebenem Intervall und Grenzen |
| quantize | 2n-Verteilung |
| llquantize | log-lineare Verteilung |
Aufgaben wie Latenz- oder Größenanalysen lassen sich mit den Verteilungsfunktionen ideal lösen. Die Sortierung der Ausgabe – voreingestellt ist "nach Wert" – lässt sich durch
setopt("aggsortkey", true)auf die Sortierung nach den Indizes umstellen. Sofern mehrere verwendet werden, kann die Option aggsortkeypos auf die Nummer des Indexes gesetzt werden, nach dem sortiert werden soll.
setopt("aggsortrev", true);kehrt die Reihenfolge um. Da DTrace auch die gleichzeitige Ausgabe mehrerer aggregations durch printa() (Ausgabe von aggregations) unterstützt, ist ggf. das Setzen der Option aggsortpos auf die Position der aggregation, die als Sortierbasis dienen soll, notwendig.
Hilfsfunktionen für aggregations
| Funktion | Aufgabe |
|---|---|
| trunc( @aggr [, n] ) |
Löscht eine aggregation vollständig, bzw. Teile dieser n > 0 erhält die obersten n-Einträge n < 0 erhält die untersten n-Einträge |
| clear( @aggr ) | Setzt alle Werte auf Null, Indizes bleiben erhalten |
| normalize( @aggr, fac) | Setzt einen "Normalisierungsfaktor", jedoch ohne die Werte zu verändern |
| denormalize( @aggr ) | Macht die Normalisierung rückgängig |
Ausgabe von aggregations
Analog zu printf() (Ausgabe von Daten) dient printa() der Ausgabe von aggregations. Es erweitert hierzu die Funktionalität durch eingebaute Iteration über alle verwendeten Indizes, da DTrace ja selbst keine Schleifen-Konstrukte bereitstellt. Dabei ist es nicht zwingend für jeden Index, ein Format-Argument anzugeben, jedoch sind keine Lücken möglich. Die Formatierung der Werte der aggregation wird durch den speziellen Format-Operator %@ eingeleitet. Dieser kann mehrfach vorkommen. Die Ergebnisse der Quantisierungs-aggregations werden als ASCII-Tabelle dargestellt.
Darüber hinaus versteht sich printa() auf die Verknüpfung mehrerer aggregations bei der Ausgabe über die gemeinsamen Indizes und auf die Ausgabe von Verteilungen. Das folgende Code-Beispiel nutzt viele der Funktionen, um ein einfaches iostat(1m) unter Berücksichtigung der Anwendung nachzubilden.
#!/usr/sbin/dtrace -s
#pragma D option quiet
BEGIN {
setopt("aggsortkey", "true"); /* sort by dev or app */
setopt("aggsortkeypos", "1"); /* sort by dev */
ts = timestamp;
}
io:::start /* trace physical read-IO */
/ args[0]->b_flags & B_READ /
{
@r[execname, args[1]->dev_statname] = sum(args[0]->b_bcount);
}
io:::start /* trace physical write-IO /*
/ args[0]->b_flags & B_WRITE /
{
@w[execname, args[1]->dev_statname] = sum(args[0]->b_bcount);
}
/* tick-provider fires on single CPU to trigger
* output of data; makes use of passed argument
* to set rate
*/
tick-$1 {
/* normalize to seconds and kilo-bytes */
fact = 1024 * (timestamp - ts) / 1000000000;
normalize(@r, fact);
normalize(@w, fact);
/* print header, data and reset counters/timestamp */
printf("\n%-16s %-10s %16s %16s\n",
"executable", "device", "read[kb/s]", "write[kb/s]");
printa("%-16s %-10s %@16d %@16d\n", @r, @w);
clear(@r);
clear(@w);
ts = timestamp;
} Da die Zeitperiode als Argument mit Einheit an das Skript übergeben wird, muss der Normalisierungsfaktor aus der vergangenen Zeit – DTrace-Timer liefern Nanosekunden – berechnet werden. Damit erhält man folgende Ausgabe:
# ./iostat_demo.d 5s executable device read[kb/s] write[kb/s] zpool-rpool sd1 0 158 zpool-rpool sd2 0 158 httpd sd4 32 0 imapd sd4 70 0 zpool-mail sd4 0 4423 zpool-mail sd5 0 4423 imapd sd6 0 0 smmapd sd6 0 0
Mit den probes io:::start und io:::done lassen sich auch einfach Latenz-Profile erstellen. Die printa()-Ausgabe einer 2n liefert beispielsweise
value ------- Distribution ------- count 4096 | 0 8192 | 3 16384 | 3 32768 | 0 65536 | 3 131072 |@@@@@@@ 46 262144 |@@@@@@@@ 48 524288 | 1 1048576 | 0 2097152 | 1 4194304 |@ 6 8388608 |@@@@@@@@@@ 61 16777216 |@@@@@@@@@ 59 33554432 |@@ 14 67108864 |@ 9 134217728 | 2
Gute erkennbar sind die beiden Latenz-Maxima, die rund zwei Größenordnungen auseinander liegen. Erklärt werden sie durch das Layout des zu Grunde liegenden ZFS-Pools. Neben Festplatten – einem Zugriff auf diese entspricht das Maximum mit den höheren Werten – kommen SSDs als L2ARC cache devices zum Einsatz. Diese erfüllen Lesewünsche deutlich zügiger.
DTrace für Entwickler
DTrace ist mitnichten ein Tool das sich nur an SysAdmins richtet. Analyse von Anwendungen ist damit auch ohne Zugriff auf die Quellen oder einen Debugger möglich.
Der pid-provider
Dieser provider nimmt insofern eine Sonderstellung ein, als dass seine probes nicht vordefiniert sind, sondern erst zur Laufzeit eines Programms dynamisch erzeugt werden. Damit werden sie auch von dtrace -l nicht erfasst. Ob ein Programm unter DTrace-Kontrolle neu gestartet wird oder bereits läuft, ist unerheblich. Die Verfolgung des Codes ist bis auf die Ebene von Assembler-Befehlen möglich, was eine erhöhte Vorsicht bei der Spezifikation nötig macht, um unerwünschte Nebenwirkungen zu vermeiden. So löst
pid10000:libc.so.1:str*:entry
Aktionen beim Aufruf einer String-Funktion der libc aus, sofern dies vom Prozess mit der pid 10000 geschieht. An Stelle von entry kann auch return oder ein numerischer Wert im Sinne eines Befehls-Offset verwendet werden. Da die Prozess-ID im Vorfeld nicht immer bekannt ist, stellt DTrace das Makro $target bereit. Sein Wert wird zur Zeit des Aufrufs durch die Prozess-ID ersetzt, die via -p an dtrace(1m) übergeben wurde oder die zu dem mit -c neu erzeugten Prozess gehört. Damit lässt sich das Beispiel allgemeingültig so schreiben:
pid$target:libc.so.1:str*:entry
Natürlich können auch Teile der Definition via Kommandozeile angepasst werden. In
pid$target:libc.so.1:$1:entry
wird die zu überwachende Funktion dynamisch beim Start des Skriptes übergeben.
"DTrace-ready"
Um die Standardfunktionen um essentielle Daten aus der eigenen Anwendung zu ergänzen, bietet DTrace einfache Möglichkeiten, eigene Anwendungsprovider zu erstellen. Dies wurde bereits für perl, den Apache Web-Server, MySQL, PostgreSQL und andere Anwendungen umgesetzt. Dazu sind lediglich die provider-Definition, das Einbinden einer zusätzlichen Header-Datei, die Nutzung der dort definierten Makros, sowie kleine Änderungen im build-Prozess notwendig. Die folgende Anwendung liest einzelne Zeichen von stdin und stellt diese DTrace über den keypress-provider zur Verfügung.
# cat keypress.c
#include <stdio.h>
#include <sys/sdt.h>
int main (int argc, char *argv[]) {
int c;
while ((c = getchar()) != EOF) {
DTRACE_PROBE1(kp, read, c);
/* more application code */
}
}
# cat keypress_d.d
provider kp {
probe read(int);
};
Übersetzen und Aufruf
# cc -O -c keypress.c
# dtrace -32 -G -s keypress_d.d keypress.o
# cc -O -o keypress keypress_d.o keypress.o -ldtrace
# cat keypress_d.d keypress.c |
dtrace -q -c ./keypress -n '
kp$target:::read { @ = lquantize(arg0, 0, 255, 32); }'
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@ 22
32 |@@@@@@@@@@@@ 70
64 |@@@ 17
96 |@@@@@@@@@@@@@@@@@@@@@ 120
128 | 0 Das Ergebnis zeigt die Verteilung der ASCII-Codes der beiden Dateien in Gruppen zu je 32 Bytes. Deutlich sichtbar ist die Häufung der Kleinbuchstaben ab dem Wert 96.
Casestudy
Problem
Bei pre-production-Tests einer neuen, in der Zwischenzeit an der Universität Ulm eingeführten, Backup-Software, traten erhebliche Abweichungen zwischen der erwarteten und der gemessenen Datentransferrate disk-to-tape auf. In Einzelmessungen erreichen die Bandlaufwerke (IBM 3592-E07) ihre nominelle Transferrate von 250 MB/s für nicht komprimierbare Daten. Der auf 60 SAS2 Platten aufgebaute RAIDZ2 zpool erzielt mit filebench gemessene Datenraten von über 3,5 GB/s sowohl lesend als auch schreibend. Dahinter bleibt die durchschnittliche Datenrate von nur 61 MB/s für die Migration von 6TB an Daten deutlich zurück und ist nur wenig besser als die Datenübertragung direkt vom Klienten.
Analyse
Die Vermutung, die CPU wäre – etwa auch durch die aktivierte ZFS Komprimierung – für den Engpass verantwortlich, ließ sich einfach durch ein hot-spot-sampling [5] des Kernels widerlegen. Dabei wird mit DTrace mehr als 1.000mal pro Sekunde für jede CPU die derzeit aktive Kernelroutine bestimmt. Der zu Grunde liegende Code ist gewohnt einfach:
profile:::profile-1001hz
/arg0/
{
@pc[arg0] = count();
}
dtrace:::END
{
trunc(@pc, 5);
printa("%a %@d\n", @pc);
}Das Ergebnis:
Routine calls prct. SPARC-T4`copyin 8630 0.2% zfs`fletcher_4_native 10902 0.3% zfs`vdev_raidz_generate_parity_pq 19815 0.5% zfs`lzjb_compress 234676 5.9% unix`cpu_halt 3670636 91.8%
Da hier klar die CPU als Quelle des Problems verworfen werden konnte, wurde im nächsten Schritt das IO-Verhalten mittels IO-Provider untersucht. Eine quantize()-Auswertung der Blockgrößen – b_bcount-Feld der bufinfo_t-Struktur auf die vom provider ein Zeiger bereitgestellt wird – zeigt die der Konfiguration entsprechenden IO-Größen von 256 kB. Allerdings zeigt der zeitliche Verlauf der Transferrate im 15-Sekunden-Durchschnitt (hier die ersten beiden Stunden in Abb.4) ein unerwartetes Verhalten.
- B. Gregg, J. Mauro, P. Hall (2011): DTrace
- Mike Harsch's arcstat.pl-Tool
- Wikipedia: Nyquist-Shannon-Abtasttheorem
- "Erste Regel von Mentat" aus "Dune – Der Wüstenplanet"
- hot-spot-sampling
