Was ist dtrace überhaupt? Der beste Vergleich den ich kenne ist wie folgt:
Stell dir vor du hast Probleme mit deinem Auto. Es macht komische Geräusche wenn du schnell fährst. Und nun stell dir vor du fährst auf die Autobahn, beschleunigst auf 200 Sachen und steigst gemütlich aus, öffnest die Motorhaube und baust die Kiste auseinander ohne das diese aufhört zu arbeiten. Du kannst dir jede Schraube jeden Schlauch und jedes noch so komplexe Teil ansehen und herausfinden wo es Probleme gibt. Genau das macht Dtrace mit deinem Betriebssystem und alle Programmen die darauf laufen.
Jetzt kann man sicherlich sagen. Naja in meine Programme konnte ich aber schon immer mit einem Debugger reingucken. Klar konnte man das, aber nur in einzelne Prozesse. Dtrace ermöglicht systemweites Debuggen ohne das man das System in ein großes Performanceloch schmeißt wie das mit Tools wie strace und truss z.B. der Fall ist.
Wie funktioniert das Ganze? Dtrace verfügt über sogenannte Provider, welche in der Lage sind das System zu "instrumentalisieren". Das heißt: Sie kennen Punkte im System an dem sie Messungen durchführen können.
Listen wir erst mal unsere Messpunkte auf:
raichoo@itzkoatl:~# dtrace -l
ID PROVIDER MODULE FUNCTION NAME
1 dtrace BEGIN
2 dtrace END
3 dtrace ERROR
4 fbt fcsm fcsm_job_cache_destructor entry
5 fbt fcsm fcsm_job_cache_destructor return
6 fbt fcsm fcsm_job_cache_constructor entry
7 fbt fcsm fcsm_job_cache_constructor return
8 fbt fcsm fcsm_display entry
9 fbt fcsm fcsm_display return
...
69649 lockstat genunix lock_clear_splx spin-release
69650 lockstat genunix CLOCK_UNLOCK spin-release
69651 lockstat genunix rw_enter rw-acquire
69652 lockstat genunix rw_enter rw-block
69653 lockstat genunix rw_exit rw-release
69654 lockstat genunix rw_tryenter rw-acquire
69655 lockstat genunix rw_tryupgrade rw-upgrade
69656 lockstat genunix rw_downgrade rw-downgrade
69657 lockstat genunix thread_lock thread-spin
69658 lockstat genunix thread_lock_high thread-spin
Ok, hier wurden wir gerade mit verdammt vielen Messpunkten oder auch Probes erschlagen. Wie man sieht ist jede Probe einem Provider, einem Modul, einer Funktion und einem Namen zugeordnet. Mit diesen Tupeln sind wir in der Lage jeden Messpunkt zu spezifizieren und damit anzusprechen. Gucken wir einfach mal wie viele Probes uns unser System so zur Verfügung stellt.
raichoo@itzkoatl:~# uname -a
SunOS itzkoatl 5.11 snv_95 i86pc i386 i86pc
raichoo@itzkoatl:~# dtrace -l | wc -l
69659
Alleine auf meinem System stehen mir fast 70.000 Probes zur Verfügung. Und das sind noch lange nicht alle, es gibt noch ein paar spezielle Provider (z.B. den PID-Provider und auch Provider für so ziemlich jedes Skriptsprache z.B. Python, Ruby, PHP, JavaScript und und und) die einem noch mehr Transparenz geben.
Ok, jetzt da wir wissen das wir wirklich viel messen können wollen wir mal loslegen! Als Einführungsbeispiel will ich hier den Syscallprovider vorstellen. Dieser Provider weiß wie man Systemcalls instrumentalisiert. Systemcalls sind Funktionen bei deren Ausführung ein Programm ein Aufgabe an den Kernel abgibt z.B. öffne eine Datei, mappe mir etwas in den virtuellen Speicher, schicke ein Signal an einen anderen Prozess.
Als erstes wollen wir erst mal jeden Syscall-Entry anzeigen lassen.
raichoo@itzkoatl:~# dtrace -n syscall:::entry
...
0 69480 pollsys:entry
0 69166 write:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69164 read:entry
0 69480 pollsys:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69166 write:entry
0 69480 pollsys:entry
0 69166 write:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69164 read:entry
0 69480 pollsys:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69166 write:entry
Jetzt werden uns in Echtzeit alle Systemcall-Entrys auf dem System gezeigt ohne das das System ausgebremst wird. Diese Information ist allerdings eher unspannend. Wir wollen ja auch wissen WER das macht, also erweitern wir unser Kommando:
raichoo@itzkoatl:~# dtrace -n 'syscall:::entry{trace(execname);}'
...
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69258 ioctl:entry dtrace
0 69352 mmap:entry dtrace
0 69286 lwp_park:entry dtrace
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69164 read:entry sshd
0 69480 pollsys:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69166 write:entry sshd
0 69480 pollsys:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69164 read:entry sshd
0 69480 pollsys:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69166 write:entry sshd
0 69480 pollsys:entry sshd
0 69330 sigpending:entry dtrace
0 69450 lwp_sigmask:entry dtrace
0 69332 setcontext:entry dtrace
0 69166 write:entry dtrace
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69164 read:entry sshd
0 69480 pollsys:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69450 lwp_sigmask:entry sshd
0 69166 write:entry sshd
0 69480 pollsys:entry sshd
0 69258 ioctl:entry dtrace
Mit trace(execname) geben wir an das wir uns für das Programm interessieren das den Systemcall tätigt. execname ist eine vordefinierte Variable von der es eine ganze Menge gibt.
Aber was genau sehen wir da jetzt? Einige werden es sicher schon ahnen. Ich bin über SSH mit meinem Solarisrechner verbunden und alles was wir jetzt sehen sind die Systemcalls die das System braucht um all die Informationen für mich sichtbar zu machen. Wir gucken also dem System zu wie es uns sagt das es etwas sagt.
Wollen wir also unsere "Observation" weiter einschränken. Wir können ein Bedingung angeben die uns nur in bestimmeten Fällen einen Messwert liefert. Das geht wie folgt.
raichoo@itzkoatl:~# dtrace -n 'syscall:::entry/execname == "gdm-binary"/{}'
dtrace: description 'syscall:::entry' matched 233 probes
CPU ID FUNCTION:NAME
0 69164 read:entry
0 69164 read:entry
0 69164 read:entry
0 69166 write:entry
0 69412 yield:entry
0 69164 read:entry
0 69164 read:entry
0 69486 c2audit:entry
0 69368 xstat:entry
0 69312 readlink:entry
0 69486 c2audit:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69450 lwp_sigmask:entry
0 69356 munmap:entry
0 69356 munmap:entry
...
Hier werden uns nur Informationen ausgegeben wenn das ausführende Programm gdm-binary ist.
Unsere Abfrage ist also wie folgt aufgebaut:
dtrace -n probe-tupel
/Bedingung/
{
Funktionskörper
}
Wie man sieht stellt dtrace eine kleine Programmiersprache zur Verfügung. Diese Sprache hat den Namen D und ist stark mit AWK und C verwand.
Das war nur ein extrem kleiner Einblick in das was dtrace kann. Als nächstes werde ich mich mit Probe-Argumenten, dem FBT-Provider (welcher jede Funktion im Kernel tracen kann) und dtrace-Skripten befassen. Wer bis dahin nicht warten kann, kann sich auch den Vortrag von Brian Cantrill über dtrace ansehen (SEHR SEHENSWERT!) oder einfach mal im Dtrace User's Guide schmöckern.
Dtrace kann man auch auf der OpenSolaris LiveCD benutzen. Als Anmerkung gilt zu sagen das man root-Rechte braucht (oder bestimmte RBAC-Rechte auf einem Produktivsystem)
Keine Kommentare:
Kommentar veröffentlichen