CPython mit DTrace und SystemTap instrumentieren¶
- Autor:
David Malcolm
- Autor:
Łukasz Langa
DTrace und SystemTap sind Überwachungswerkzeuge, die jeweils eine Möglichkeit bieten, zu inspizieren, was die Prozesse auf einem Computersystem tun. Beide verwenden domänenspezifische Sprachen, die es einem Benutzer ermöglichen, Skripte zu schreiben, die
filtern, welche Prozesse beobachtet werden sollen
Daten von den interessierenden Prozessen sammeln
Berichte über die Daten generieren
Seit Python 3.6 kann CPython mit eingebetteten „Markern“, auch „Probes“ genannt, erstellt werden, die von einem DTrace- oder SystemTap-Skript beobachtet werden können. Dies erleichtert die Überwachung, was CPython-Prozesse auf einem System tun.
CPython Implementierungsdetail: DTrace-Marker sind Implementierungsdetails des CPython-Interpreters. Es werden keine Garantien für die Probenkompatibilität zwischen CPython-Versionen übernommen. DTrace-Skripte können beim Wechseln der CPython-Versionen ohne Vorwarnung nicht mehr funktionieren oder falsch funktionieren.
Statische Marker aktivieren¶
macOS verfügt über integrierte Unterstützung für DTrace. Unter Linux müssen die SystemTap-Entwicklungswerkzeuge installiert sein, um CPython mit den eingebetteten Markern für SystemTap zu erstellen.
Auf einem Linux-Computer kann dies erfolgen über
$ yum install systemtap-sdt-devel
oder
$ sudo apt-get install systemtap-sdt-dev
CPython muss dann mit der Option --with-dtrace konfiguriert werden
checking for --with-dtrace... yes
Unter macOS können Sie verfügbare DTrace-Probes auflisten, indem Sie einen Python-Prozess im Hintergrund ausführen und alle vom Python-Anbieter bereitgestellten Probes auflisten.
$ python3.6 -q &
$ sudo dtrace -l -P python$! # or: dtrace -l -m python3.6
ID PROVIDER MODULE FUNCTION NAME
29564 python18035 python3.6 _PyEval_EvalFrameDefault function-entry
29565 python18035 python3.6 dtrace_function_entry function-entry
29566 python18035 python3.6 _PyEval_EvalFrameDefault function-return
29567 python18035 python3.6 dtrace_function_return function-return
29568 python18035 python3.6 collect gc-done
29569 python18035 python3.6 collect gc-start
29570 python18035 python3.6 _PyEval_EvalFrameDefault line
29571 python18035 python3.6 maybe_dtrace_line line
Unter Linux können Sie überprüfen, ob die statischen SystemTap-Marker im erstellten Binärprogramm vorhanden sind, indem Sie prüfen, ob es einen Abschnitt „.note.stapsdt“ enthält.
$ readelf -S ./python | grep .note.stapsdt
[30] .note.stapsdt NOTE 0000000000000000 00308d78
Wenn Sie Python als gemeinsam genutzte Bibliothek erstellt haben (mit der Konfigurationsoption --enable-shared), müssen Sie stattdessen in der gemeinsam genutzten Bibliothek nachsehen. Zum Beispiel
$ readelf -S libpython3.3dm.so.1.0 | grep .note.stapsdt
[29] .note.stapsdt NOTE 0000000000000000 00365b68
Hinreichend modernes `readelf` kann die Metadaten ausgeben
$ readelf -n ./python
Displaying notes found at file offset 0x00000254 with length 0x00000020:
Owner Data size Description
GNU 0x00000010 NT_GNU_ABI_TAG (ABI version tag)
OS: Linux, ABI: 2.6.32
Displaying notes found at file offset 0x00000274 with length 0x00000024:
Owner Data size Description
GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring)
Build ID: df924a2b08a7e89f6e11251d4602022977af2670
Displaying notes found at file offset 0x002d6c30 with length 0x00000144:
Owner Data size Description
stapsdt 0x00000031 NT_STAPSDT (SystemTap probe descriptors)
Provider: python
Name: gc__start
Location: 0x00000000004371c3, Base: 0x0000000000630ce2, Semaphore: 0x00000000008d6bf6
Arguments: -4@%ebx
stapsdt 0x00000030 NT_STAPSDT (SystemTap probe descriptors)
Provider: python
Name: gc__done
Location: 0x00000000004374e1, Base: 0x0000000000630ce2, Semaphore: 0x00000000008d6bf8
Arguments: -8@%rax
stapsdt 0x00000045 NT_STAPSDT (SystemTap probe descriptors)
Provider: python
Name: function__entry
Location: 0x000000000053db6c, Base: 0x0000000000630ce2, Semaphore: 0x00000000008d6be8
Arguments: 8@%rbp 8@%r12 -4@%eax
stapsdt 0x00000046 NT_STAPSDT (SystemTap probe descriptors)
Provider: python
Name: function__return
Location: 0x000000000053dba8, Base: 0x0000000000630ce2, Semaphore: 0x00000000008d6bea
Arguments: 8@%rbp 8@%r12 -4@%eax
Die obigen Metadaten enthalten Informationen für SystemTap, die beschreiben, wie strategisch platzierte Maschinencode-Instruktionen gepatcht werden können, um die von einem SystemTap-Skript verwendeten Tracing-Hooks zu aktivieren.
Statische DTrace-Probes¶
Das folgende Beispiel-DTrace-Skript kann verwendet werden, um die Aufruf-/Rückrufhierarchie eines Python-Skripts anzuzeigen, wobei nur die Aufrufe einer Funktion namens „start“ verfolgt werden. Mit anderen Worten, Funktionsaufrufe zur Importzeit werden nicht aufgelistet.
self int indent;
python$target:::function-entry
/copyinstr(arg1) == "start"/
{
self->trace = 1;
}
python$target:::function-entry
/self->trace/
{
printf("%d\t%*s:", timestamp, 15, probename);
printf("%*s", self->indent, "");
printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
self->indent++;
}
python$target:::function-return
/self->trace/
{
self->indent--;
printf("%d\t%*s:", timestamp, 15, probename);
printf("%*s", self->indent, "");
printf("%s:%s:%d\n", basename(copyinstr(arg0)), copyinstr(arg1), arg2);
}
python$target:::function-return
/copyinstr(arg1) == "start"/
{
self->trace = 0;
}
Es kann wie folgt aufgerufen werden:
$ sudo dtrace -q -s call_stack.d -c "python3.6 script.py"
Die Ausgabe sieht so aus:
156641360502280 function-entry:call_stack.py:start:23
156641360518804 function-entry: call_stack.py:function_1:1
156641360532797 function-entry: call_stack.py:function_3:9
156641360546807 function-return: call_stack.py:function_3:10
156641360563367 function-return: call_stack.py:function_1:2
156641360578365 function-entry: call_stack.py:function_2:5
156641360591757 function-entry: call_stack.py:function_1:1
156641360605556 function-entry: call_stack.py:function_3:9
156641360617482 function-return: call_stack.py:function_3:10
156641360629814 function-return: call_stack.py:function_1:2
156641360642285 function-return: call_stack.py:function_2:6
156641360656770 function-entry: call_stack.py:function_3:9
156641360669707 function-return: call_stack.py:function_3:10
156641360687853 function-entry: call_stack.py:function_4:13
156641360700719 function-return: call_stack.py:function_4:14
156641360719640 function-entry: call_stack.py:function_5:18
156641360732567 function-return: call_stack.py:function_5:21
156641360747370 function-return:call_stack.py:start:28
Statische SystemTap-Marker¶
Der Low-Level-Weg zur Nutzung der SystemTap-Integration ist die direkte Verwendung der statischen Marker. Dies erfordert, dass Sie die Binärdatei, die sie enthält, explizit angeben.
Zum Beispiel kann das folgende SystemTap-Skript verwendet werden, um die Aufruf-/Rückrufhierarchie eines Python-Skripts anzuzeigen:
probe process("python").mark("function__entry") {
filename = user_string($arg1);
funcname = user_string($arg2);
lineno = $arg3;
printf("%s => %s in %s:%d\\n",
thread_indent(1), funcname, filename, lineno);
}
probe process("python").mark("function__return") {
filename = user_string($arg1);
funcname = user_string($arg2);
lineno = $arg3;
printf("%s <= %s in %s:%d\\n",
thread_indent(-1), funcname, filename, lineno);
}
Es kann wie folgt aufgerufen werden:
$ stap \
show-call-hierarchy.stp \
-c "./python test.py"
Die Ausgabe sieht so aus:
11408 python(8274): => __contains__ in Lib/_abcoll.py:362
11414 python(8274): => __getitem__ in Lib/os.py:425
11418 python(8274): => encode in Lib/os.py:490
11424 python(8274): <= encode in Lib/os.py:493
11428 python(8274): <= __getitem__ in Lib/os.py:426
11433 python(8274): <= __contains__ in Lib/_abcoll.py:366
wobei die Spalten sind
Zeit in Mikrosekunden seit Beginn des Skripts
Name der ausführbaren Datei
PID des Prozesses
und der Rest die Aufruf-/Rückrufhierarchie während der Ausführung des Skripts angibt.
Für eine `--enable-shared`-Build von CPython befinden sich die Marker in der gemeinsam genutzten Bibliothek libpython, und der gepunktete Pfad der Probe muss dies widerspiegeln. Zum Beispiel muss diese Zeile aus dem obigen Beispiel
probe process("python").mark("function__entry") {
stattdessen lauten:
probe process("python").library("libpython3.6dm.so.1.0").mark("function__entry") {
(unter der Annahme eines Debug-Builds von CPython 3.6)
Verfügbare statische Marker¶
- function__entry(str filename, str funcname, int lineno)
Dieser Marker zeigt an, dass die Ausführung einer Python-Funktion begonnen hat. Er wird nur für reine Python-Funktionen (Bytecode) ausgelöst.
Der Dateiname, der Funktionsname und die Zeilennummer werden dem Tracing-Skript als positionelle Argumente zurückgegeben, auf die über
$arg1,$arg2,$arg3zugegriffen werden muss.$arg1:(const char *)Dateiname, zugänglich überuser_string($arg1)$arg2:(const char *)Funktionsname, zugänglich überuser_string($arg2)$arg3:intZeilennummer
- function__return(str filename, str funcname, int lineno)
Dieser Marker ist das Gegenteil von
function__entry()und zeigt an, dass die Ausführung einer Python-Funktion beendet wurde (entweder überreturnoder über eine Ausnahme). Er wird nur für reine Python-Funktionen (Bytecode) ausgelöst.Die Argumente sind die gleichen wie für
function__entry().
- line(str filename, str funcname, int lineno)
Dieser Marker zeigt an, dass eine Python-Zeile ausgeführt wird. Er ist das Äquivalent der zeilenweisen Verfolgung mit einem Python-Profiler. Er wird nicht innerhalb von C-Funktionen ausgelöst.
Die Argumente sind die gleichen wie für
function__entry().
- gc__start(int generation)
Wird ausgelöst, wenn der Python-Interpreter einen Garbage-Collection-Zyklus startet.
arg0ist die zu scannende Generation, wie beigc.collect().
- gc__done(long collected)
Wird ausgelöst, wenn der Python-Interpreter einen Garbage-Collection-Zyklus abschließt.
arg0ist die Anzahl der gesammelten Objekte.
- import__find__load__start(str modulename)
Wird ausgelöst, bevor
importlibversucht, das Modul zu finden und zu laden.arg0ist der Modulname.Hinzugefügt in Version 3.7.
- import__find__load__done(str modulename, int found)
Wird ausgelöst, nachdem die Funktion `find_and_load` von
importlibaufgerufen wurde.arg0ist der Modulname,arg1gibt an, ob das Modul erfolgreich geladen wurde.Hinzugefügt in Version 3.7.
- audit(str event, void *tuple)
Wird ausgelöst, wenn
sys.audit()oderPySys_Audit()aufgerufen wird.arg0ist der Ereignisname als C-String,arg1ist ein Zeiger aufPyObjectauf ein Tupelobjekt.Hinzugefügt in Version 3.8.
SystemTap Tapsets¶
Der höherstufige Weg zur Nutzung der SystemTap-Integration ist die Verwendung eines „Tapsets“: Das Äquivalent einer Bibliothek von SystemTap, das einige der Low-Level-Details der statischen Marker verbirgt.
Hier ist eine Tapset-Datei, basierend auf einem Nicht-Shared-Build von CPython
/*
Provide a higher-level wrapping around the function__entry and
function__return markers:
\*/
probe python.function.entry = process("python").mark("function__entry")
{
filename = user_string($arg1);
funcname = user_string($arg2);
lineno = $arg3;
frameptr = $arg4
}
probe python.function.return = process("python").mark("function__return")
{
filename = user_string($arg1);
funcname = user_string($arg2);
lineno = $arg3;
frameptr = $arg4
}
Wenn diese Datei im Tapset-Verzeichnis von SystemTap (z. B. /usr/share/systemtap/tapset) installiert ist, werden die folgenden zusätzlichen Probenpunkte verfügbar:
- python.function.entry(str filename, str funcname, int lineno, frameptr)
Dieser Probenpunkt zeigt an, dass die Ausführung einer Python-Funktion begonnen hat. Er wird nur für reine Python-Funktionen (Bytecode) ausgelöst.
- python.function.return(str filename, str funcname, int lineno, frameptr)
Dieser Probenpunkt ist das Gegenteil von
python.function.returnund zeigt an, dass die Ausführung einer Python-Funktion beendet wurde (entweder überreturnoder über eine Ausnahme). Er wird nur für reine Python-Funktionen (Bytecode) ausgelöst.
Beispiele¶
Dieses SystemTap-Skript verwendet das obige Tapset, um das obige Beispiel der Verfolgung der Python-Funktionsaufrufhierarchie sauberer zu implementieren, ohne die statischen Marker direkt benennen zu müssen.
probe python.function.entry
{
printf("%s => %s in %s:%d\n",
thread_indent(1), funcname, filename, lineno);
}
probe python.function.return
{
printf("%s <= %s in %s:%d\n",
thread_indent(-1), funcname, filename, lineno);
}
Das folgende Skript verwendet das obige Tapset, um eine Top-ähnliche Ansicht aller laufenden CPython-Codes bereitzustellen, die die Top 20 der am häufigsten aufgerufenen Bytecode-Frames pro Sekunde im gesamten System anzeigt.
global fn_calls;
probe python.function.entry
{
fn_calls[pid(), filename, funcname, lineno] += 1;
}
probe timer.ms(1000) {
printf("\033[2J\033[1;1H") /* clear screen \*/
printf("%6s %80s %6s %30s %6s\n",
"PID", "FILENAME", "LINE", "FUNCTION", "CALLS")
foreach ([pid, filename, funcname, lineno] in fn_calls- limit 20) {
printf("%6d %80s %6d %30s %6d\n",
pid, filename, lineno, funcname,
fn_calls[pid, filename, funcname, lineno]);
}
delete fn_calls;
}