書いたスクリプトが、思ったより遅い。そんなとき、どこから手をつけていますか。
多くの人はコードを上から眺めて、あやしそうな場所にあたりをつけます。私もずっとそうしていました。
けれど、その勘はかなりの確率で外れます。今回は、遅い場所を推測ではなく計測で見つける道具、cProfileを紹介します。
標準ライブラリなので、インストールは要りません。コマンドに一言足すだけで、今日から始められます。
遅い原因は、たいてい思っている場所にない¶
まず、なぜわざわざ計測するのかという話をさせてください。
プログラムの処理時間は、コード全体に均等に散らばっているわけではありません。ほとんどの時間が、ごく一部の行に集中しています。
私は10年ほどエンジニアとして開発に関わってきましたが、これで何度も遠回りをしました。集計バッチが遅いと聞いてSQLを何日もチューニングしたのに、本当の原因は集計のあとでPython側がリストを何度も走査していた20行だった、ということがあります。
測らずに直した数日分の作業は、まるごと無駄になりました。直す前に測る。順番を変えるだけで、この遠回りは減らせます。
そもそもPythonという言語自体の速さが気になっている方は、こちらもあわせてどうぞ。【関連記事】Pythonは本当に遅い？初心者にもわかる原因と対処法を徹底解説
プロファイリングは、処理時間の内訳を出すこと¶
プロファイリングという言葉は、処理時間の内訳を記録して一覧にすること、と考えてください。
どの関数が何回呼ばれ、そこで何秒使ったのか。プロファイラはそれを表にして見せてくれます。
家計簿に似ているかもしれません。今月は出費が多いと感じたとき、費目ごとの金額がわかれば、削る場所はすぐ決まります。
自分でストップウォッチを当てるのとは何が違うのか¶
処理時間を測るだけなら、開始と終了の時刻の差をとる方法もあります。
ただしその方法では、測りたい場所を自分で決めなければいけません。つまり、あたりがついていることが前提になります。
プロファイラは動いた関数をまとめて測ってくれるので、あたりがついていなくても使えます。時間の測り方そのものは、こちらの記事で整理しました。【関連記事】Pythonのtimeモジュールとは？sleepで待つ・処理時間を測る基本を初心者向けに解説
cProfileは、Pythonに最初から入っている¶
cProfileは標準ライブラリなので、pip installは必要ありません。
使い方はかんたんです。いつもの実行コマンドのpythonのあとに、-m cProfileを足すだけです。
例として、注文の一覧にVIP判定を付けて出力する、こんなスクリプトを用意しました。
# report.py
import random
def load_orders(n=20000):
return [f'ORD-{i:05d}' for i in range(n)]
def load_vip_ids(n=3000):
return [f'ORD-{random.randrange(20000):05d}' for _ in range(n)]
def is_vip(order_id, vip_ids):
return order_id in vip_ids
def build_report(orders, vip_ids):
lines = []
for order_id in orders:
mark = 'VIP' if is_vip(order_id, vip_ids) else '-'
lines.append(f'{order_id},{mark}')
return '\n'.join(lines)
if __name__ == '__main__':
print(len(build_report(load_orders(), load_vip_ids())))
手元のPython 3.11で実行すると、0.4秒ほどかかりました。この0.4秒がどこで使われたのかを、cProfileに聞いてみます。
python -m cProfile -s tottime report.py
-sは並べ替えの指定です。tottimeを渡すと、その関数の中だけで使った時間が長い順に並びます。
出てきた表の先頭は、次のようになりました。
57753 function calls (57725 primitive calls) in 0.404 seconds
Ordered by: internal time
ncalls tottime percall cumtime percall filename:lineno(function)
20000 0.361 0.000 0.361 0.000 report.py:12(is_vip)
1 0.017 0.017 0.383 0.383 report.py:16(build_report)
1 0.011 0.011 0.011 0.011 report.py:5(<listcomp>)
20000 0.003 0.000 0.003 0.000 {method 'append' of 'list' objects}
原因は1行目に出ていました。is_vipが20000回呼ばれ、そこだけで0.361秒、全体の9割近くを使っています。
出てくる数字の読み方を覚える¶
列の名前が見慣れないので、意味を確認しておきましょう。
| 列 | 意味 |
|---|---|
ncalls |
その関数が呼ばれた回数。100/5のような表記は再帰で、左が総回数、右が再帰を除いた回数 |
tottime |
その関数の中だけで使った時間。呼び出した先の関数の時間は含まない |
percall（左側） |
tottimeをncallsで割った値 |
cumtime |
その関数と、そこから呼んだ関数すべてを合わせた時間 |
percall（右側） |
cumtimeを再帰を除いた呼び出し回数で割った値 |
filename:lineno(function) |
その関数がある場所と名前 |
tottimeとcumtimeを取り違えない¶
この2つの違いが、プロファイルを読むときのいちばんの山場です。
tottimeはその関数が自分の手で働いた時間、cumtimeはその関数を呼んだせいでかかった時間の合計だと考えてください。
いちばん外側にある関数は、cumtimeが必ず大きくなります。全部の処理がそこにぶら下がっているからで、そこを直しても速くはなりません。
手を入れる価値があるのは、tottimeが大きい関数です。並べ替えにtottimeを選んだのは、そのためでした。
ではcumtimeはいつ見るのか。重い処理がどの経路から呼ばれているかを知りたいときに役立ちます。
見つけた場所を直して、もう一度測る¶
原因がわかったので直します。is_vipは、リストの中を先頭から順に探していました。
リストに対するinは、要素が増えるほど時間がかかります。集合に変えるだけで、この探し方が根本から変わります。
def build_report(orders, vip_ids):
vip_ids = set(vip_ids) # 足したのはこの1行だけ
lines = []
for order_id in orders:
mark = 'VIP' if is_vip(order_id, vip_ids) else '-'
lines.append(f'{order_id},{mark}')
return '\n'.join(lines)
同じ条件で測り直すと、0.415秒だった実行時間が0.039秒になりました。10倍ほど速くなった計算です。
書き換えたのは1行です。測ってから直すと、直す量はたいてい小さくて済みます。
なぜ集合だと速いのかという話は、計算量につながっていきます。【関連記事】「実行時間が終わらない…」を卒業する！あなたのコードを100倍速くする計算量の考え方
全体ではなく、気になる範囲だけ測る¶
Webアプリのように起動が重いプログラムでは、全体を測ると出力が長すぎて読みきれません。
そんなときは、測りたい範囲だけをwithで囲みます。プロファイラをコードの中から呼ぶ書き方です。
import cProfile
import pstats
from report import build_report, load_orders, load_vip_ids
orders = load_orders()
vip_ids = load_vip_ids()
with cProfile.Profile() as profiler:
build_report(orders, vip_ids)
pstats.Stats(profiler).sort_stats('tottime').print_stats(5)
print_stats(5)の数字は、表示する行数です。上位だけ見たいときに指定します。
結果をあとで見返したいときは、-oを付けてファイルに保存できます。保存しておけば、pstatsで何度でも並べ替え直せます。
python -m cProfile -o report.prof report.py
行数が多いときは、ブラウザで眺める¶
関数の数が増えると、文字の表を目で追うのがつらくなります。
そこで使えるのがSnakeVizという外部ツールです。-oで保存したファイルを、ブラウザ上の図として見せてくれます。
pip install snakeviz
snakeviz report.prof
円を何重にも重ねたような図が出て、外側へ行くほど呼び出しの深い関数になります。幅がそのまま時間なので、太いところを探すだけで済みます。
Python 3.15で、プロファイラの置き場所が変わる¶
ここからは最新の動きです。2026年10月1日に予定されているPython 3.15で、プロファイラまわりが整理されます。
PEP 799によって、profilingという新しいパッケージが作られます。cProfileはprofiling.tracingの別名という位置づけになり、純Python版のprofileのほうは非推奨になります。
あわせてprofiling.samplingという別方式のプロファイラが入ります。こちらは全部の呼び出しを記録するのではなく、一定の間隔で今どこを実行しているかを覗く方式です。
動いているプロセスにあとから接続できるのが、いちばんの違いです。本番で遅くなっているサーバーを、止めずに調べられます。
とはいえ、cProfileという名前が急になくなるわけではありません。今覚えた書き方は、これからもそのまま使えます。
つまずきやすいところ¶
最後に、初心者がひっかかりやすい点を3つ挙げておきます。
ひとつめは、プロファイラを通した実行は素の実行より遅くなるということ。表示された秒数を絶対的な速さとして受け取らず、どこに何割使ったかという割合で読んでください。
ふたつめは、通信やtime.sleepの待ち時間もcumtimeに含まれる点です。CPUが働いていない時間まで数えられるので、待ちの多い処理では数字の意味を考える必要があります。
みっつめは、プロファイラはバグ探しの道具ではないということ。処理の流れを1行ずつ追いたいときは、デバッガのほうが向いています。【関連記事】Pythonのpdbとは？breakpoint()でprintデバッグを卒業する方法を初心者向けに解説
まとめと、次の一歩¶
cProfileは、遅いという感覚を数字に変えてくれる道具です。
覚えることは多くありません。python -m cProfile -s tottimeで実行し、tottimeの大きい関数から疑う。まずはこれだけで十分です。
次の一歩として、今あなたの手元でいちばん時間のかかるスクリプトに、この1行を試してみてください。予想していた場所と違うところが1位に出てきたら、それがこの道具の価値です。
速くする作業は、当てものではありません。測って、直して、また測る。その繰り返しに変えていきましょう。
ここまでお読みいただきありがとうございました。
