Help us understand the problem. What is going on with this article?

Pythonのプロファイリング

More than 1 year has passed since last update.

プロファイラ

  • cProfile
    • プログラムが、どの関数でどれぐらい時間がかかっているかをプロファイリングしてくれます。
    • ざっくり関数レベルでのプロファイルを調べるのに使います。

参考:https://docs.python.jp/3/library/profile.html

  • line_profile
    • 行ごとにどの程度の時間がかかっているのかを調べます。
    • cProfileであたりをつけた関数のプロファイルを調べるのに使います。
      • 全体(main)に使うことも可能ですが、行ごとに結果が出てきます。

参考:https://github.com/rkern/line_profiler

以下では、それぞれについて、
- 実行する方法:コマンドラインから行う場合とコードに組み込んで実行する場合
- 確認する方法:標準出力とファイル出力の場合
について説明します。

cProfile

プログラムが、どの関数でどれぐらい時間がかかっているかをプロファイリングしてくれます。ざっくり関数レベルでのプロファイルを調べるのに使います。

出力情報

      197 function calls (192 primitive calls) in 0.002 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 re.py:212(compile)
     1    0.000    0.000    0.001    0.001 re.py:268(_compile)
     1    0.000    0.000    0.000    0.000 sre_compile.py:172(_compile_charset)
     1    0.000    0.000    0.000    0.000 sre_compile.py:201(_optimize_charset)
     4    0.000    0.000    0.000    0.000 sre_compile.py:25(_identityfunction)
   3/1    0.000    0.000    0.000    0.000 sre_compile.py:33(_compile)
  • 1行目:呼び出した関数の数と実行時間
  • Ordered by: 出力のソート方法
  • ncalls: 呼び出し回数
  • tottime: subfunctionの実行時間を除いた時間
  • percall: tottimeをncallsで割った値
  • cumtime: この関数とそのsubfuntionに消費された累積時間
  • percall: cumtimeを呼び出し回数で割った値

使い方

1. コマンドラインから実行する場合

以下のように -m cProfileを指定して実行します。

python -m cProfile [-o output_file] [-s sort_order] myscript.py

なお、コマンドラインから実行した場合、プログラム内の全関数のプロファイルが出力されます。

1.1 標準出力する場合

-o オプションを指定しないで実行します。 -sで結果のソート方法を指定します。デフォルトでのソート方法 standard nameになります。

  • ソート方法の一覧
有効な引数 意味
'calls' 呼び出し数
'cumulative' 累積時間
'cumtime' 累積時間
'file' ファイル名
'filename' ファイル名
'module' ファイル名
'ncalls' 呼び出し数
'pcalls' プリミティブな呼び出し回数
'line' 行番号
'name' 関数名
'nfl' 関数名/ファイル名/行番号
'stdname' 標準名
'time' 内部時間
'tottime' 内部時間
1.2 ファイル出力する場合

-o オプションを指定して実行します。

$ python -m cProfile -o main.prof myscript.py

出力ファイルはバイナリになっているので、pythonから呼び出して可視化します。

$ python
>> import pstats
>> sts = pstats.Stats('main.prof')
>> sts.strip_dirs().sort_stats(-1).print_stats()

2. コードに組み込む場合

コードに組み込むことで、特定の関数のprofileのみ出力することができます。

2.1 標準出力する場合

ざっと調べた感じ、なさそう。

2.2 ファイル出力する場合

例えば、以下のように記載することで、ファイルにプロファイル結果を出力します。

import cProfile
if __name__ == '__main__':
   cProfile.run('main()', filename='main.prof')

なお、runをする関数を限定させる場合は、以下のようにします
(runは、mainで実行する場合のみになるため)

import cProfile
def main():
    cProfile.runctx('hoge()', globals(), locals(), filename='hoge.prof')

line_profile

行ごとにどの程度の時間がかかっているのかを調べます。cProfileであたりをつけた関数のプロファイルを調べるのに使います。全体(main)に使うことも可能ですが、行ごとに結果が出てきます。

出力情報

ある関数について、 行ごとにどれくらい時間がかかっているのかその割合はどうなのか を出力します。

Pystone(1.1) time for 50000 passes = 2.48
This machine benchmarks at 20161.3 pystones/second
Wrote profile results to pystone.py.lprof
Timer unit: 1e-06 s

File: pystone.py
Function: Proc2 at line 149
Total time: 0.606656 s

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
   149                                           @profile
   150                                           def Proc2(IntParIO):
   151     50000        82003      1.6     13.5      IntLoc = IntParIO + 10
   152     50000        63162      1.3     10.4      while 1:
   153     50000        69065      1.4     11.4          if Char1Glob == 'A':
   154     50000        66354      1.3     10.9              IntLoc = IntLoc - 1
   155     50000        67263      1.3     11.1              IntParIO = IntLoc - IntGlob
   156     50000        65494      1.3     10.8              EnumLoc = Ident1
   157     50000        68001      1.4     11.2          if EnumLoc == Ident1:
   158     50000        63739      1.3     10.5              break
   159     50000        61575      1.2     10.1      return IntParIO
  • Line: 全体の中の行数
  • Hits: 呼び出し回数
  • Time: かかった時間
  • Per Hit: 1呼び出しあたりにかかった時間
  • % Time: その関数内でかかった時間の割合
  • Line Contents: その行の内容

使い方

1. コマンドラインから実行する場合

まず、@profileデコレータを関数につけます。(クラス内の関数にも適用できます)

@profile
def hoge():
    hogehoge

そして、以下のように実行します

$ kernprof -l script_to_profile.py
1.1 標準出力する場合

ざっと調べた感じ、なさそう。

1.2 ファイル出力する場合

script_to_profile.py.lprof というファイルが作られます。これを以下の通り実行すると、プロファイル結果が出力されます。

$ python -m line_profiler script_to_profile.py.lprof

2. コードに組み込む場合

以下のように記載することで、標準出力で、プロファイリング結果を出力することができます。

if __name__ == "__main__":
    prf = LineProfiler()                                                                                         
    prf.add_module(hoge_class)                                                                                          
    prf.add_function(main)                                                                                       
    prf.runcall(main)                                                                                            

add_function(hoge)によって、プロファイリングする関数を追加できます。クラス内の関数も add_function(hoge_class.hoge) で追加できます。また、 add_module(hoge_class) によって、クラス全体のプロファイルを追加できます。

また、以下のように記載することで、特定の関数についてプロファイリング結果を出力することができます。

from line_profiler import LineProfiler
def main():
    prf = LineProfiler()                                                                                         
    prf.add_module(hoge_class)                                                                                          
    prf.add_function(hoge)                                                                                       
    prf.runctx('hoge()', globals(), locals())                                                                                            
2.1 標準出力する場合

標準出力する場合は、上記に加えて、LineProfiler().print_stats() を使用すると、と標準出力されます。

例)
from line_profiler import LineProfiler
if __name__ == "__main__":
    prf = LineProfiler()                                                                                         
    prf.add_module(hoge_class)                                                                                          
    prf.add_function(main)                                                                                       
    prf.runcall(main)                                                                                            
    prf.print_stats()
2.2 ファイル出力する場合

ファイル出力する場合は、上記に加えて、LineProfiler().dump_stats() を使用すると、と標準出力されます。

例)
from line_profiler import LineProfiler
if __name__ == "__main__":
    prf = LineProfiler()                                                                                         
    prf.add_module(hoge_class)                                                                                          
    prf.add_function(main)                                                                                       
    prf.runcall(main)                                                                                            
    prf.dump_stats('line_profiler.prof')
Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
Comments
No comments
Sign up for free and join this conversation.
If you already have a Qiita account
Why do not you register as a user and use Qiita more conveniently?
You need to log in to use this function. Qiita can be used more conveniently after logging in.
You seem to be reading articles frequently this month. Qiita can be used more conveniently after logging in.
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away
ユーザーは見つかりませんでした