Instrumentering av CPython med DTrace och SystemTap¶

författare:: David Malcolm
författare:: Łukasz Langa

DTrace och SystemTap är övervakningsverktyg som var och en ger möjlighet att inspektera vad processerna i ett datorsystem gör. De använder båda domänspecifika språk som gör det möjligt för en användare att skriva skript som:

filtrera vilka processer som ska följas
samla in data från de processer som är av intresse
generera rapporter om data

Från och med Python 3.6 kan CPython byggas med inbäddade ”markörer”, även kända som ”prober”, som kan observeras av ett DTrace- eller SystemTap-skript, vilket gör det lättare att övervaka vad CPython-processerna på ett system gör.

DTrace-markörer är implementeringsdetaljer i CPython-tolken. Inga garantier ges om kompatibilitet mellan olika versioner av CPython. DTrace-skript kan sluta fungera eller fungera felaktigt utan förvarning när CPython-versioner ändras.

Aktivering av statiska markörer¶

macOS kommer med inbyggt stöd för DTrace. På Linux måste SystemTap-utvecklingsverktygen installeras för att CPython ska kunna byggas med de inbäddade markörerna för SystemTap.

På en Linux-maskin kan detta göras via:

$ yum install systemtap-sdt-devel

eller:

$ sudo apt-get install systemtap-sdt-dev

CPython måste då konfigureras med alternativet --with-dtrace:

checking for --with-dtrace... yes

På macOS kan du lista tillgängliga DTrace-prober genom att köra en Python-process i bakgrunden och lista alla prober som görs tillgängliga av Python-providern:

$ python3.6 -q &
$ sudo dtrace -l -P python$!  # or: dtrace -l -m python3.6

   ID   PROVIDER            MODULE                          FUNCTION NAME
python18035        python3.6          _PyEval_EvalFrameDefault function-entry
python18035        python3.6             dtrace_function_entry function-entry
python18035        python3.6          _PyEval_EvalFrameDefault function-return
python18035        python3.6            dtrace_function_return function-return
python18035        python3.6                           collect gc-done
python18035        python3.6                           collect gc-start
python18035        python3.6          _PyEval_EvalFrameDefault line
python18035        python3.6                 maybe_dtrace_line line

På Linux kan du kontrollera om de statiska SystemTap-markörerna finns i den inbyggda binärfilen genom att se om den innehåller ett avsnitt ”.note.stapsdt”.

$ readelf -S ./python | grep .note.stapsdt
[30] .note.stapsdt        NOTE         0000000000000000 00308d78

Om du har byggt Python som ett delat bibliotek (med konfigurationsalternativet --enable-shared) måste du istället leta inom det delade biblioteket. Till exempel:

$ readelf -S libpython3.3dm.so.1.0 | grep .note.stapsdt
[29] .note.stapsdt        NOTE         0000000000000000 00365b68

Tillräckligt modern readelf kan skriva ut metadata:

$ 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

Ovanstående metadata innehåller information för SystemTap som beskriver hur det kan patcha strategiskt placerade maskinkodinstruktioner för att aktivera de spårningskrokar som används av ett SystemTap-skript.

Statiska DTrace-prober¶

Följande exempel på DTrace-skript kan användas för att visa anrops-/returhierarkin i ett Python-skript, med spårning endast inom anropet av en funktion som heter ”start”. Med andra ord kommer inte anrop av importfunktioner att listas:

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;
}

Den kan anropas på följande sätt:

$ sudo dtrace -q -s call_stack.d -c "python3.6 script.py"

Utmatningen ser ut så här:

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

Statiskt systemTap-markörer¶

Lågnivåmetoden för att använda SystemTap-integrationen är att använda de statiska markörerna direkt. Detta kräver att du uttryckligen anger den binära fil som innehåller dem.

Detta SystemTap-skript kan t.ex. användas för att visa Call/Return-hierarkin i ett Python-skript:

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);
}

Den kan anropas på följande sätt:

$ stap \
  show-call-hierarchy.stp \
  -c "./python test.py"

Utmatningen ser ut så här:

python(8274):        => __contains__ in Lib/_abcoll.py:362
python(8274):         => __getitem__ in Lib/os.py:425
python(8274):          => encode in Lib/os.py:490
python(8274):          <= encode in Lib/os.py:493
python(8274):         <= __getitem__ in Lib/os.py:426
python(8274):        <= __contains__ in Lib/_abcoll.py:366

där kolumnerna är:

tid i mikrosekunder sedan skriptets start
namn på körbar fil
PID för process

och resten visar hierarkin för anrop/retur när skriptet körs.

För en --enable-shared-byggnad av CPython finns markörerna i det delade biblioteket libpython, och probens prickade sökväg måste återspegla detta. Till exempel den här raden från exemplet ovan:

probe process("python").mark("function__entry") {

bör istället lyda:

probe process("python").library("libpython3.6dm.so.1.0").mark("function__entry") {

(antar en debug build av CPython 3.6)

Tillgängliga statiska markörer¶

function__entry(str filename, str funcname, int lineno)

Denna markör anger att exekveringen av en Python-funktion har påbörjats. Den utlöses endast för rena Python-funktioner (bytecode).

Filnamnet, funktionsnamnet och radnumret skickas tillbaka till spårningsskriptet som positionella argument, som måste nås med hjälp av $arg1, $arg2, $arg3:

$arg1 : (const char *) filnamn, tillgängligt med user_string($arg1)

$arg2 : (const char *) funktionsnamn, tillgängligt med user_string($arg2)

$arg3 : int radnummer

function__return(str filename, str funcname, int lineno)

Denna markör är motsatsen till function__entry() och anger att exekveringen av en Python-funktion har avslutats (antingen via return eller via ett undantag). Den utlöses endast för rena Python-funktioner (bytecode).

Argumenten är desamma som för function__entry()

line(str filename, str funcname, int lineno)

Denna markör indikerar att en Python-rad är på väg att exekveras. Det motsvarar spårning rad för rad med en Python-profilerare. Den utlöses inte inom C-funktioner.

Argumenten är desamma som för function__entry().

gc__start(int generation): Utlöses när Python-tolken startar en skräpinsamlingscykel. arg0 är den generation som ska skannas, som gc.collect().

gc__done(long collected): Utlöses när Python-tolken avslutar en garbage collection-cykel. arg0 är antalet insamlade objekt.

import__find__load__start(str modulename): Startas innan importlib försöker hitta och ladda modulen. arg0 är modulens namn.

Tillagd i version 3.7.

import__find__load__done(str modulename, int found): Startas efter att importlib’s find_and_load-funktion har anropats. arg0 är modulnamnet, arg1 indikerar om modulen laddades framgångsrikt.

Tillagd i version 3.7.

audit(str event, void *tuple): Startar när sys.audit() eller PySys_Audit() anropas. arg0 är händelsens namn som C-sträng, arg1 är en PyObject-pekare till ett tuple-objekt.

Tillagd i version 3.8.

SystemTap Kranar¶

Det mer avancerade sättet att använda SystemTap-integrationen är att använda ett ”tapset”: SystemTaps motsvarighet till ett bibliotek, som döljer några av de statiska markörernas detaljer på lägre nivå.

Här är en tapset-fil, baserad på en icke-delad version av 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
}

Om den här filen installeras i SystemTaps tapset-katalog (t.ex. /usr/share/systemtap/tapset) blir dessa ytterligare probepoints tillgängliga:

python.function.entry(str filename, str funcname, int lineno, frameptr): Denna probepunkt indikerar att exekveringen av en Python-funktion har påbörjats. Den utlöses endast för rena Python-funktioner (bytecode).

python.function.return(str filename, str funcname, int lineno, frameptr): Denna probepunkt är motsatsen till python.function.return och anger att exekveringen av en Python-funktion har avslutats (antingen via return eller via ett undantag). Den utlöses endast för rena Python-funktioner (bytecode).

Exempel¶

Detta SystemTap-skript använder tapset ovan för att på ett renare sätt implementera exemplet ovan med spårning av Pythons funktionsanropshierarki, utan att direkt behöva namnge de statiska markörerna:

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);
}

Följande skript använder tapset ovan för att ge en toppliknande vy över all CPython-kod som körs och visar de 20 mest frekvent inmatade bytekodsramarna varje sekund i hela systemet:

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;
}

Instrumentering av CPython med DTrace och SystemTap¶

Aktivering av statiska markörer¶

Statiska DTrace-prober¶

Statiskt systemTap-markörer¶

Tillgängliga statiska markörer¶

SystemTap Kranar¶

Exempel¶

Innehåll

Föregående ämne

Nästa ämne

Denna sidan