誰得記事ですみませんが、PythonのcProfileモジュールの備忘録です。
プロファイルモジュールについては以下の説明が分かりやすいです。
cProfileはコンテキストマネージャー(with)を使えるためコードが簡潔になります。
以下のコードでNumPyのソート関数のプロファイルをとってみました。
import cProfile
import numpy as np
l: np.array = np.array(range(1, 2 << 24))
np.random.shuffle(l)
with cProfile.Profile() as pr:
sorted = np.sort(l, kind='quicksort')
sortby = pstats.SortKey.CUMULATIVE
ps = pstats.Stats(pr, stream=sys.stdout).sort_stats(sortby)
ps.print_stats()
print(sorted[0])
↓
14 function calls in 2.187 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 2.187 2.187 ..python3.12/site-packages/numpy/_core/fromnumeric.py:915(sort)
1 2.166 2.166 2.166 2.166 {method 'sort' of 'numpy.ndarray' objects}
1 0.021 0.021 0.021 0.021 {method 'copy' of 'numpy.ndarray' objects}
:
デフォルトは出力がfilename順でソートされた状態になりますが、ここはpstatsのSortKeyで目的に合わせ並べ替える事ができます。上ではcumtime順に並べています。
表の見出しはユーザーマニュアルに以下のように書かれていました。
ncalls: 呼び出し回数
tottime: 与えられた関数に消費された合計時間 (sub-function の呼び出しで消費された時間は除外)
percall: tottime を ncalls で割った値
cumtime: この関数と全ての subfunction に消費された累積時間
percall: cumtime をプリミティブな呼び出し回数で割った値
filename:lineno(function): その関数のファイル名、行番号、関数名
因みに上のコードではソートが呼ばれている回数は1回（ncallsは1）でしたが、2回呼ぶようにするとncallsは2になり、percallは1回分になりました。
19 function calls in 4.368 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
2 0.000 0.000 4.368 2.184 ..python3.12/site-packages/numpy/_core/fromnumeric.py:915(sort)
2 4.325 2.163 4.325 2.163 {method 'sort' of 'numpy.ndarray' objects}
2 0.043 0.021 0.043 0.021 {method 'copy' of 'numpy.ndarray' objects}
:
また、再帰関数だとncallsがn/m（nは総呼び出し回数、mはプリミティブな呼び出し回数、再帰なのでここでは1）のようになるようです。
ncalls tottime percall cumtime percall filename:lineno(function)
5/1 0.000 0.000 5.025 5.025 rec.py:4(rec)
5 5.025 1.005 5.025 1.005 {built-in method time.sleep}
time.sleepが見えているのは、再帰関数がsleepで時間稼ぎしている適当な実装だからです。
def rec(i: int) -> int:
time.sleep(1)
i = i - 1
if i > 0:
return rec(i)
return 1
折角なので最初のコードでnumpy.sortのアルゴリズム(kind)を変えてとってみました。
クイックソート、マージソート、ヒープソートの
{method 'sort' of 'numpy.ndarray' objects}のcumtimeを31回測定した中央値です。
| kind | cumtime |
|---|---|
| quicksort | 2.161 |
| mergesort | 2.272 |
| heapsort | 10.698 |
環境
macOS: Sonoma v14.5
CPU: Apple M1