Python support for the Linux perf profiler

author:

Pablo Galindo

The Linux perf profiler is a very powerful tool that allows you to profile and obtain information about the performance of your application. perf also has a very vibrant ecosystem of tools that aid with the analysis of the data that it produces.

The main problem with using the perf profiler with Python applications is that perf only gets information about native symbols, that is, the names of functions and procedures written in C. This means that the names and file names of Python functions in your code will not appear in the output of perf.

Since Python 3.12, the interpreter can run in a special mode that allows Python functions to appear in the output of the perf profiler. When this mode is enabled, the interpreter will interpose a small piece of code compiled on the fly before the execution of every Python function and it will teach perf the relationship between this piece of code and the associated Python function using perf map files.

注釈

Support for the perf profiler is currently only available for Linux on select architectures. Check the output of the configure build step or check the output of python -m sysconfig | grep HAVE_PERF_TRAMPOLINE to see if your system is supported.

例えば、次のスクリプトを考えます:

def foo(n):
    result = 0
    for _ in range(n):
        result += 1
    return result

def bar(n):
    foo(n)

def baz(n):
    bar(n)

if __name__ == "__main__":
    baz(1000000)

perf を実行して、CPU のスタックトレースを 9999 Hz でサンプリングできます。

$ perf record -F 9999 -g -o perf.data python my_script.py

続いて perf report でデータを分析します:

$ perf report --stdio -n -g

# Children      Self       Samples  Command     Shared Object       Symbol
# ........  ........  ............  ..........  ..................  ..........................................
#
    91.08%     0.00%             0  python.exe  python.exe          [.] _start
            |
            ---_start
            |
                --90.71%--__libc_start_main
                        Py_BytesMain
                        |
                        |--56.88%--pymain_run_python.constprop.0
                        |          |
                        |          |--56.13%--_PyRun_AnyFileObject
                        |          |          _PyRun_SimpleFileObject
                        |          |          |
                        |          |          |--55.02%--run_mod
                        |          |          |          |
                        |          |          |           --54.65%--PyEval_EvalCode
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     |
                        |          |          |                     |--51.67%--_PyEval_EvalFrameDefault
                        |          |          |                     |          |
                        |          |          |                     |          |--11.52%--_PyLong_Add
                        |          |          |                     |          |          |
                        |          |          |                     |          |          |--2.97%--_PyObject_Malloc
...

このように、Python 関数は出力に現れず、Python バイトコードを評価する関数 _PyEval_EvalFrameDefault だけが表示されます。 すべての Python 関数が同じ C 関数でバイトコードを評価するため、これだけではどの Python 関数に対応する評価処理か分からず、あまり役に立ちません。

一方、perf サポートを有効にして同じ実験を行うと、次のようになります:

$ perf report --stdio -n -g

# Children      Self       Samples  Command     Shared Object       Symbol
# ........  ........  ............  ..........  ..................  .....................................................................
#
    90.58%     0.36%             1  python.exe  python.exe          [.] _start
            |
            ---_start
            |
                --89.86%--__libc_start_main
                        Py_BytesMain
                        |
                        |--55.43%--pymain_run_python.constprop.0
                        |          |
                        |          |--54.71%--_PyRun_AnyFileObject
                        |          |          _PyRun_SimpleFileObject
                        |          |          |
                        |          |          |--53.62%--run_mod
                        |          |          |          |
                        |          |          |           --53.26%--PyEval_EvalCode
                        |          |          |                     py::<module>:/src/script.py
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     py::baz:/src/script.py
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     py::bar:/src/script.py
                        |          |          |                     _PyEval_EvalFrameDefault
                        |          |          |                     PyObject_Vectorcall
                        |          |          |                     _PyEval_Vector
                        |          |          |                     py::foo:/src/script.py
                        |          |          |                     |
                        |          |          |                     |--51.81%--_PyEval_EvalFrameDefault
                        |          |          |                     |          |
                        |          |          |                     |          |--13.77%--_PyLong_Add
                        |          |          |                     |          |          |
                        |          |          |                     |          |          |--3.26%--_PyObject_Malloc

perf プロファイリングサポートを有効にする方法

perf プロファイリングサポートは、環境変数 PYTHONPERFSUPPORT または -X perf オプションで起動時から有効にできます。 sys.activate_stack_trampoline() と sys.deactivate_stack_trampoline() で動的に切り替えることもできます。

sys の関数は -X オプションより優先され、-X オプションは環境変数より優先されます。

環境変数を使う例です。

$ PYTHONPERFSUPPORT=1 perf record -F 9999 -g -o perf.data python my_script.py
$ perf report -g -i perf.data

-X オプションを使う例です。

$ perf record -F 9999 -g -o perf.data python -X perf my_script.py
$ perf report -g -i perf.data

example.py で sys API を使う例です:

import sys

sys.activate_stack_trampoline("perf")
do_profiled_stuff()
sys.deactivate_stack_trampoline()

non_profiled_stuff()

続いて次を実行します。

$ perf record -F 9999 -g -o perf.data python ./example.py
$ perf report -g -i perf.data

最良の結果を得る方法

For best results, Python should be compiled with CFLAGS="-fno-omit-frame-pointer -mno-omit-leaf-frame-pointer" as this allows profilers to unwind using only the frame pointer and not on DWARF debug information. This is because as the code that is interposed to allow perf support is dynamically generated it doesn't have any DWARF debugging information available.

このフラグを使ってコンパイルされたかどうかは、次を実行して確認できます。

$ python -m sysconfig | grep 'no-omit-frame-pointer'

何も表示されなければ、インタープリタはフレームポインタなしでコンパイルされています。 その場合、perf の出力に Python 関数を表示できない可能性があります。

フレームポインタなしで使う方法

フレームポインタなしでコンパイルした Python インタープリタでも perf は使えますが、オーバーヘッドは少し大きくなります。 Python 関数の呼び出しごとに、スタックをたどるための情報をその場で生成する必要があるためです。 さらに perf は DWARF デバッグ情報を使ってスタックをたどる必要があり、この処理は遅いため、データの処理にも時間がかかります。

このモードを有効にするには、環境変数 PYTHON_PERF_JIT_SUPPORT または -X perf_jit オプションを使います。 これにより perf プロファイラ用の JIT モードが有効になります。

注釈

perf ツールのバグのため、JIT モードで動作するのは v6.8 より後のバージョンだけです。 修正は v6.7.2 にもバックポートされています。

perf version でバージョンを確認するときは、一部のディストリビューションが - を含む独自のバージョン番号を追加する点に注意してください。 perf 6.7-3 は必ずしも perf 6.7.3 を意味しません。

perf の JIT モードでは、perf report の前に一つ手順が必要です。 perf inject で JIT 情報を perf.data ファイルに組み込みます。

$ perf record -F 9999 -g -k 1 --call-graph dwarf -o perf.data python -Xperf_jit my_script.py
$ perf inject -i perf.data --jit --output perf.jit.data
$ perf report -g -i perf.jit.data

環境変数を使う場合は次のようになります。

$ PYTHON_PERF_JIT_SUPPORT=1 perf record -F 9999 -g --call-graph dwarf -o perf.data python my_script.py
$ perf inject -i perf.data --jit --output perf.jit.data
$ perf report -g -i perf.jit.data

perf inject --jit command will read perf.data, automatically pick up the perf dump file that Python creates (in /tmp/perf-$PID.dump), and then create perf.jit.data which merges all the JIT information together. It should also create a lot of jitted-XXXX-N.so files in the current directory which are ELF images for all the JIT trampolines that were created by Python.

警告

--call-graph dwarf を指定すると、perf は対象プロセスのスタックのスナップショットを取得し、perf.data に保存します。 スタックダンプのサイズはデフォルトで 8192 バイトですが、--call-graph dwarf,16384 のようにカンマの後に指定すると変更できます。

スタックダンプのサイズは重要です。 小さすぎると perf がスタックをたどれず、出力が不完全になります。 大きすぎるとオーバーヘッドが増え、希望する頻度でサンプリングできなくなります。

-O0 のような低い最適化レベルでコンパイルした Python をプロファイリングする場合は、スタックフレームが大きくなりやすいため、特にサイズが重要です。 -O0 でコンパイルした Python の関数が出力に現れない場合は、スタックダンプのサイズを最大の 65528 バイトに増やしてみてください。

$ perf record -F 9999 -g -k 1 --call-graph dwarf,65528 -o perf.data python -Xperf_jit my_script.py

コンパイルフラグはスタックのサイズに大きく影響することがあります:

  • 通常、-O0 のビルドは -O1 以上のビルドよりも、スタックフレームがはるかに大きくなります。

  • 通常、最適化 (-O1、-O2 など) を有効にするとスタックのサイズが小さくなります。

  • フレームポインタ (-fno-omit-frame-pointer) を使うと、一般にスタックをより確実にたどれます。