PythonでPerfをとってみた

追記：コメントより設定ミスが分かったため、記事を改版しました。
以下をご参照ください。
https://qiita.com/joule/items/cc1f504414d81ce30e67

Python3.12からPythonスクリプトでPerfが取れるようになったそうなので試してみました。

事前準備

システムのPythonがPerfに対応しているかはsysconfigのPY_HAVE_PERF_TRAMPOLINEを確認するとわかるようです。

$ python3 -m sysconfig | grep HAVE_PERF_TRAMPOLINE

また、Perfを使うためにシステムのkptr_restrictとperf_event_paranoidを変更しておきます。

$ echo 0 | sudo tee  /proc/sys/kernel/kptr_restrict > /dev/null
$ echo 0 | sudo tee  /proc/sys/kernel/perf_event_paranoid > /dev/null

---

筆者の環境ではPythonのバージョンが古かったのでアップデートしました。(今回はCPythonをビルドしたものを使いました)
PY_HAVE_PERF_TRAMPOLINEを確認すると有効になっていました。

$ /usr/local/bin/python3.12 -m sysconfig | grep HAVE_PERF_TRAMPOLINE
PY_HAVE_PERF_TRAMPOLINE = "1"

Perfの取得

サンプルコード（出典）でPerfを取得してみました。

sample.py

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(10000000)

perf recordを取ることができました。

$ perf record -F 9999 -g -o perf.data /usr/local/bin/python3.12 sample.py 
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.229 MB perf.data (2957 samples) ]

stat情報を取得することができました👏

$ perf stat --cpu 0 taskset -c 0 /usr/local/bin/python3.12 sample.py 

 Performance counter stats for 'CPU(s) 0':

            291.73 msec cpu-clock                        #    1.000 CPUs utilized             
                11      context-switches                 #   37.706 /sec                      
                 2      cpu-migrations                   #    6.856 /sec                      
               912      page-faults                      #    3.126 K/sec                     
     1,296,699,734      cycles                           #    4.445 GHz                       
     4,970,280,033      instructions                     #    3.83  insn per cycle            
       930,501,018      branches                         #    3.190 G/sec                     
           348,197      branch-misses                    #    0.04% of all branches           

       0.291710341 seconds time elapsed

コールグラフは筆者のシステムでは一部アドレス解決できていないところがありました。
出典では入っているので今回のPythonの環境因子だと思います。

DWARFなどに疎いので、解決できない理由は分かりません...

$ $ perf report --stdio -n -g

# Children      Self       Samples  Command     Shared Object         Symbol                      >
# ........  ........  ............  ..........  ....................  ............................>
#
    63.68%     0.00%             0  python3.12  [unknown]             [.] 0x0000631877b4b1e0
            |
            ---0x631877b4b1e0
               |          
                --63.41%--0x72b348fae0e8
                          |          
                          |--30.79%--_PyEval_EvalFrameDefault
                          |          
                          |--17.88%--_PyObject_Free
                          |          
                          |--6.52%--long_dealloc
                          |          
                          |--4.16%--_PyLong_Add
                          |          
                          |--2.11%--PyLong_FromLong
                          |          
                           --1.94%--PyObject_Free
:

環境

CPU: Intel(R) Core(TM) i7-9700 CPU @ 3.00GHz
OS: Ubuntu-22.04
Kernel: 6.5.0-41-generic
Python: v3.12（ソースビルド）

参考・引用

• Python support for the Linux perf profiler