使用 DTrace 和 SystemTap 檢測CPython

作者

David Malcolm

作者

?ukasz Langa

DTrace和SystemTap是監視工具，每個工具都提供了一種檢查計算機系統上的進程正在執行的操作的方法。 它們都使用特定于域的語言，允許用戶編寫以下腳本：

• 進程監視的過濾器

• 從感興趣的進程中收集數據

• 生成有關數據的報告

從Python 3.6開始，CPython可以使用嵌入式“標記”構建，也稱為“探測器”，可以通過DTrace或SystemTap腳本觀察，從而更容易監視系統上的CPython進程正在做什么。

CPython implementation detail: DTrace標記是CPython解釋器的實現細節。 不保證CPython版本之間的探針兼容性。 更改CPython版本時，DTrace腳本可能會停止工作或無法正常工作而不會發出警告。

啟用靜態標記

macOS內置了對DTrace的支持。 在Linux上，為了使用SystemTap的嵌入式標記構建CPython，必須安裝SystemTap開發工具。

在Linux機器上，這可以通過：

$ yum install systemtap-sdt-devel

或者：

$ sudo apt-get install systemtap-sdt-dev

然后必須將CPython配置為``--with-dtrace``：

checking for --with-dtrace... yes

在macOS上，您可以通過在后臺運行Python進程列出可用的DTrace探測器，并列出Python程序提供的所有探測器：

$ 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

在Linux上，您可以通過查看是否包含“.note.stapsdt”部分來驗證構建的二進制文件中是否存在SystemTap靜態標記。

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

如果您已將Python構建為共享庫（使用--enable-shared），則需要在共享庫中查找。 例如：

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

足夠現代的readelf命令可以打印元數據：

$ 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

上述元數據包含SystemTap的信息，描述如何修補策略性放置的機器代碼指令以啟用SystemTap腳本使用的跟蹤鉤子。

靜態DTrace探針

下面的 DTrace 腳本示例可以用來顯示一個 Python 腳本的調用/返回層次結構，只在調用名為 "start" 的函數內進行跟蹤。換句話說，導入時的函數調用不會被列出。

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

它可以這樣調用:

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

輸出結果會像這樣:

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

靜態SystemTap標記

使用 SystemTap 集成的底層方法是直接使用靜態標記。 這需要你顯式地說明包含它們的二進制文件。

例如，這個SystemTap腳本可以用來顯示Python腳本的調用/返回層次結構：

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

它可以這樣調用:

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

輸出結果會像這樣:

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

其中的列是：

• 腳本開始后經過的微秒數

• 可執行文件的名字

• 進程的PID

其余部分則表示腳本執行時的調用/返回層次結構。

對于 --enable-shared 構建的CPython來說，這些標記是包含在libpython共享庫中的，探針的點狀路徑需要反映這一點。比如上面例子中的這一行：

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

應改為：

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

（假設是 CPython 3.6 的調試構建）

可用的靜態標記

function__entry(str?filename, str?funcname, int?lineno)

這個標記表示一個Python函數的執行已經開始。它只對純 Python （字節碼）函數觸發。

文件名、函數名和行號作為定位參數提供給跟蹤腳本，必須使用 $arg1, $arg2, $arg3 訪問：

• $arg1 : (const char *) 文件名，使用 user_string($arg1) 訪問

• $arg2 : (const char *) 函數名，使用 user_string($arg2) 訪問

• $arg3 : int 行號

function__return(str?filename, str?funcname, int?lineno)

這個標記與 function__entry() 相反，表示Python函數的執行已經結束 (通過 return 或者異常)。 它只對純Python (字節碼) 函數觸發。

參數和 function__entry() 相同

line(str?filename, str?funcname, int?lineno)

這個標記表示一個 Python 行即將被執行。它相當于用 Python 分析器逐行追蹤。它不會在C函數中觸發。

參數和 function__entry() 相同

gc__start(int?generation)

當Python解釋器啟動一個垃圾回收循環時被觸發。 arg0 是要掃描的生成器，如 gc.collect()。

gc__done(long?collected)

當Python解釋器完成一個垃圾收集循環時被觸發。arg0 是收集到的對象的數量。

import__find__load__start(str?modulename)

在 importlib 試圖查找并加載模塊之前被觸發。arg0 是模塊名稱。

3.7 新版功能.

import__find__load__done(str?modulename, int?found)

在 importlib 的 find_and_load 函數被調用后被觸發 。arg0 是模塊名稱， arg1 表示模塊是否成功加載。

3.7 新版功能.

SystemTap Tapsets

使用SystemTap集成的更高層次的方法是使用 "tapset" 。SystemTap 的等效庫，它隱藏了靜態標記的一些底層細節。

這里是一個基于 CPython 的非共享構建的 tapset 文件。

/*
   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
}

如果這個文件安裝在 SystemTap 的 tapset 目錄下（例如``/usr/share/systemtap/tapset`` ），那么這些額外的探測點就會變得可用。

python.function.entry(str?filename, str?funcname, int?lineno, frameptr)

這個探針點表示一個Python函數的執行已經開始。它只對純Python （字節碼）函數觸發。

python.function.return(str?filename, str?funcname, int?lineno, frameptr)

這個探針點是 python.function.return() 的反義操作，表示一個Python函數的執行已經結束（通過 return 或者異常）。 它只對純Python （字節碼）函數觸發。

例子

這個SystemTap腳本使用上面的tapset來更清晰地實現上面給出的跟蹤Python函數調用層次結構的例子，而不需要直接命名靜態標記。

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

下面的腳本使用上面的tapset提供了所有運行中的CPython代碼的頂部視圖，顯示了整個系統中每一秒鐘最頻繁輸入的前20個字節碼幀。

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