LoginSignup
157

More than 5 years have passed since last update.

Pythonプロファイリング基礎

Last updated at Posted at 2015-12-06

プロファイリングとは

  • 必要十分なスピードと無駄のないリソース使用量でコードを実行するためにボトルネックになっている処理を特定すること
  • python用の有名なツール
    • Pythonとtimeit
    • cProfile
    • line_profiler
    • memory_profiler

ツールの紹介

IPythonとtimeit

  • python対話型インタンプリタの拡張版
  • timeitモジュールでテスト回数(-r)、ループ回数(-n)を指定して平均実行時間を計測
  • 短いコードを直接実行とコードファイルをインポートして実行の2パターンがある

インストール

pip install ipython

サンプルコード

profiling.py
def fn_arr():
  for i in range(1000): arr.append(i)
def fn_ls():
  for i in range(1000): ls.append(i)

測定

シングルコードの実行

ipython
In [1]:from array import array
In [2]:arr = array('I', [])
In [3]:%timeit -r 10 -n 10 for i in range(1000): arr.insert(0, i)
10 loops, best of 10: 3.02 ms per loop
In [4]:%timeit -r 10 -n 10 for i in range(1000): ls.insert(0, i)
10 loops, best of 10: 3.8 ms per loop

ファイルを実行

ipython
In [1]: from profiling import fn_arr
In [2]: from profiling import fn_ls
In [3]: %timeit -r 10 -n 10 fn_arr()
10 loops, best of 10: 68.6 µs per loop
In [4]: %timeit -r 10 -n 10 fn_ls()
10 loops, best of 10: 8.92 µs per loop

10回のループ処理を10回実行した時の1ループあたりの平均実行時間を取得

cProfile

  • 標準のプロファイリングツール
  • 実行する全ての関数の実行時間を測定

サンプルコード

profiling.py
def fn():
  l = []
  for _ in range(1000000):
    l.append('hoge')
    l.pop()
fn()

測定

ファイルを指定して実行

python -m cProfile -s cumulative index.py 

         2000004 function calls in 23.897 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000   23.897   23.897 {built-in method exec}
        1    0.000    0.000   23.897   23.897 index.py:1(<module>)
        1   12.231   12.231   23.897   23.897 index.py:3(fn)
  1000000    5.833    0.000    5.833    0.000 {method 'append' of 'list' objects}
  1000000    5.832    0.000    5.832    0.000 {method 'pop' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

測定結果を出力

python -m cProfile -o profile.stats index.py

測定結果ファイルを読み込んで表示

python
>>> import pstats
>>> p = pstats.Stats('profile.stats')
>>> p.sort_stats('cumulative')
<pstats.Stats object at 0x7f5cca3f0ef0>
>>> p.print_stats()
Sat Nov 28 06:58:28 2015    profile.stats

         2000004 function calls in 8.477 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    8.477    8.477 {built-in method exec}
        1    0.000    0.000    8.477    8.477 index.py:1(<module>)
        1    4.375    4.375    8.477    8.477 index.py:3(fn)
  1000000    2.088    0.000    2.088    0.000 {method 'pop' of 'list' objects}
  1000000    2.015    0.000    2.015    0.000 {method 'append' of 'list' objects}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}


<pstats.Stats object at 0x7fadfcc20f28>

その他にも
- print_callers() -- 呼び出し側の情報
- print_callees() -- 関数が別の関数を呼び出した時の情報
などを表示できる

line_profiler

  • 処理の実行回数と実行時間を行単位で計測するツール

インストール

pip install line_profiler
git clone https://github.com/rkern/line_profiler.git

サンプルコード

profiling
@profile
def fn():
  l = []
  for _ in range(1000000):
    l.append('hoge')
    l.pop()
fn()

測定

> python line_profiler/kernprof.py -l -v index.py

Wrote profile results to index.py.lprof
Timer unit: 1e-06 s

Total time: 8.31965 s
File: index.py
Function: fn at line 2

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     2                                             @profile
     3                                             def fn():
     4         1            6      6.0      0.0      l = []
     5   1000001      2641832      2.6     31.8      for _ in range(1000000):
     6   1000000      2806484      2.8     33.7        l.append('hoge')
     7   1000000      2871333      2.9     34.5        l.pop()
  • His -- 呼び出された回数
  • Time -- 実行時間
  • Per Hit -- 1回の実行時間
  • % Time -- 全体の実行時間に対する1行あたりの実行時間

memory_profiler

  • line_profilerのメモリ版

インストール

pip install memory_profile
pip install psutil

サンプルコード

line_profilerと同様

測定

> python -m memory_profiler index.py
Filename: index.py

Line #    Mem usage    Increment   Line Contents
================================================
     2   10.316 MiB    0.000 MiB     @profile
     3                               def fn():
     4   10.320 MiB    0.004 MiB       l = []
     5   10.320 MiB    0.000 MiB       for _ in range(1000000):
     6   10.320 MiB    0.000 MiB         l.append('hoge')
     7   10.320 MiB    0.000 MiB         l.pop()

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
157