Python プロファイラ

Source code: Lib/profile.py, Lib/pstats.py, and Lib/profile/sample.py

---

プロファイラとは

Python provides both statistical profiling and deterministic profiling of Python programs. A profile is a set of statistics that describes how often and for how long various parts of the program executed. These statistics can be formatted into reports via the pstats module.

The Python standard library provides three different profiling implementations:

Statistical Profiler:

1. profiling.sampling provides statistical profiling of running Python processes using periodic stack sampling. It can attach to any running Python process without requiring code modification or restart, making it ideal for production debugging.

Deterministic Profilers:

2. cProfile is recommended for development and testing; it's a C extension with reasonable overhead that makes it suitable for profiling long-running programs. Based on lsprof, contributed by Brett Rosen and Ted Czotter.

3. profile はピュア Python モジュールで、 cProfile モジュールはこのモジュールのインターフェースを真似ています。対象プログラムに相当のオーバーヘッドが生じます。もしプロファイラに何らかの拡張をしたいのであれば、こちらのモジュールを拡張する方が簡単でしょう。このモジュールはもともと Jim Roskind により設計、実装されました。

注釈

2つのプロファイラモジュールは、与えられたプログラムの実行時プロファイルを取得するために設計されており、ベンチマークのためのものではありません (ベンチマーク用途には timeit のほうが正確な計測結果を求められます)。これは Python コードと C で書かれたコードをベンチマークするときに特に大きく影響します。プロファイラは Python コードに対してオーバーヘッドを発生しますが、C言語レベルの関数に対してはオーバーヘッドを生じません。なのでC言語で書かれたコードが、実際の速度と関係なく、Pythonで書かれたコードより速く見えるでしょう。

Profiler Comparison:

Feature	Statistical (profiling.sampling)	Deterministic (cProfile)	Deterministic (profile)
Target	Running process	Code you run	Code you run
Overhead	Virtually none	Moderate	High
Accuracy	Statistical approx.	Exact call counts	Exact call counts
Setup	Attach to any PID	Instrument code	Instrument code
Use Case	Production debugging	Development/testing	Profiler extension
Implementation	C extension	C extension	Pure Python

注釈

The statistical profiler (profiling.sampling) is recommended for most production use cases due to its extremely low overhead and ability to profile running processes without modification. It can attach to any Python process and collect performance data with minimal impact on execution speed, making it ideal for debugging performance issues in live applications.

What Is Statistical Profiling?

Statistical profiling works by periodically interrupting a running program to capture its current call stack. Rather than monitoring every function entry and exit like deterministic profilers, it takes snapshots at regular intervals to build a statistical picture of where the program spends its time.

The sampling profiler uses process memory reading (via system calls like process_vm_readv on Linux, vm_read on macOS, and ReadProcessMemory on Windows) to attach to a running Python process and extract stack trace information without requiring any code modification or restart of the target process. This approach provides several key advantages over traditional profiling methods.

The fundamental principle is that if a function appears frequently in the collected stack samples, it is likely consuming significant CPU time. By analyzing thousands of samples, the profiler can accurately estimate the relative time spent in different parts of the program. The statistical nature means that while individual measurements may vary, the aggregate results converge to represent the true performance characteristics of the application.

Since statistical profiling operates externally to the target process, it introduces virtually no overhead to the running program. The profiler process runs separately and reads the target process memory without interrupting its execution. This makes it suitable for profiling production systems where performance impact must be minimized.

The accuracy of statistical profiling improves with the number of samples collected. Short-lived functions may be missed or underrepresented, while long-running functions will be captured proportionally to their execution time. This characteristic makes statistical profiling particularly effective for identifying the most significant performance bottlenecks rather than providing exhaustive coverage of all function calls.

Statistical profiling excels at answering questions like "which functions consume the most CPU time?" and "where should I focus optimization efforts?" rather than "exactly how many times was this function called?" The trade-off between precision and practicality makes it an invaluable tool for performance analysis in real-world applications.

かんたんユーザマニュアル

この節は "マニュアルなんか読みたくない人"のために書かれています。ここではきわめて簡単な概要説明とアプリケーションのプロファイリングを手っ取り早く行う方法だけを解説します。

Statistical Profiling (Recommended for Production):

To profile an existing running process:

python -m profiling.sampling 1234

To profile with custom settings:

python -m profiling.sampling -i 50 -d 30 1234

Deterministic Profiling (Development/Testing):

1つの引数を取る関数をプロファイルしたい場合、次のようにできます:

import cProfile
import re
cProfile.run('re.compile("foo|bar")')

(お使いのシステムで cProfile が使えないときは代わりに profile を使って下さい)

上のコードは re.compile() を実行して、プロファイル結果を次のように表示します:

      214 function calls (207 primitive calls) in 0.002 seconds

Ordered by: cumulative time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.002    0.002 {built-in method builtins.exec}
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 __init__.py:250(compile)
     1    0.000    0.000    0.001    0.001 __init__.py:289(_compile)
     1    0.000    0.000    0.000    0.000 _compiler.py:759(compile)
     1    0.000    0.000    0.000    0.000 _parser.py:937(parse)
     1    0.000    0.000    0.000    0.000 _compiler.py:598(_code)
     1    0.000    0.000    0.000    0.000 _parser.py:435(_parse_sub)

The first line indicates that 214 calls were monitored. Of those calls, 207 were primitive, meaning that the call was not induced via recursion. The next line: Ordered by: cumulative time indicates the output is sorted by the cumtime values. The column headings include:

ncalls

呼び出し回数

tottime

与えられた関数に消費された合計時間 (sub-function の呼び出しで消費された時間は除外されています)

percall

tottime を ncalls で割った値

cumtime

この関数と全ての subfunction に消費された累積時間 (起動から終了まで)。この数字は再帰関数に ついても 正確です。

percall

cumtime をプリミティブな呼び出し回数で割った値

filename:lineno(function)

その関数のファイル名、行番号、関数名

最初の行に 2 つの数字がある場合 (たとえば 3/1) は、関数が再帰的に呼び出されたということです。2 つ目の数字はプリミティブな呼び出しの回数で、1 つ目の数字は総呼び出し回数です。関数が再帰的に呼び出されなかった場合、それらは同じ値で数字は 1 つしか表示されないことに留意してください。

run() 関数でファイル名を指定することで、プロファイル実行の終了時に出力を表示する代わりに、ファイルに保存することが出来ます。

import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')

pstats.Stats クラスはファイルからプロファイルの結果を読み込んで様々な書式に整えます。

Statistical Profiler Command Line Interface

The profiling.sampling module can be invoked as a script to profile running processes:

python -m profiling.sampling [options] PID

Basic Usage Examples:

Profile process 1234 for 10 seconds with default settings:

python -m profiling.sampling 1234

Profile with custom interval and duration, save to file:

python -m profiling.sampling -i 50 -d 30 -o profile.stats 1234

Generate collapsed stacks to use with tools like flamegraph.pl:

python -m profiling.sampling --collapsed 1234

Profile all threads, sort by total time:

python -m profiling.sampling -a --sort-tottime 1234

Profile with real-time sampling statistics:

python -m profiling.sampling --realtime-stats 1234

Command Line Options:

PID

Process ID of the Python process to profile (required)

-i, --interval INTERVAL

Sampling interval in microseconds (default: 100)

-d, --duration DURATION

Sampling duration in seconds (default: 10)

-a, --all-threads

Sample all threads in the process instead of just the main thread

--realtime-stats

Print real-time sampling statistics during profiling

--pstats

Generate pstats output (default)

--collapsed

Generate collapsed stack traces for flamegraphs

-o, --outfile OUTFILE

Save output to a file

Sorting Options (pstats format only):

--sort-nsamples

Sort by number of direct samples

--sort-tottime

Sort by total time

--sort-cumtime

Sort by cumulative time (default)

--sort-sample-pct

Sort by sample percentage

--sort-cumul-pct

Sort by cumulative sample percentage

--sort-nsamples-cumul

Sort by cumulative samples

--sort-name

Sort by function name

-l, --limit LIMIT

Limit the number of rows in the output (default: 15)

--no-summary

Disable the summary section in the output

Understanding Statistical Profile Output:

The statistical profiler produces output similar to deterministic profilers but with different column meanings:

Profile Stats:
       nsamples  sample%     tottime (ms)  cumul%    cumtime (ms)  filename:lineno(function)
          45/67     12.5        23.450     18.6        56.780     mymodule.py:42(process_data)
          23/23      6.4        15.230      6.4        15.230     <built-in>:0(len)

Column Meanings:

• nsamples: direct/cumulative - Times function was directly executing / on call stack

• sample%: Percentage of total samples where function was directly executing

• tottime: Estimated time spent directly in this function

• cumul%: Percentage of samples where function was anywhere on call stack

• cumtime: Estimated cumulative time including called functions

• filename:lineno(function): Location and name of the function

profiling.sampling Module Reference

This section documents the programmatic interface for the profiling.sampling module. For command-line usage, see Statistical Profiler Command Line Interface. For conceptual information about statistical profiling, see What Is Statistical Profiling?

profiling.sampling.sample(pid, *, sort=2, sample_interval_usec=100, duration_sec=10, filename=None, all_threads=False, limit=None, show_summary=True, output_format='pstats', realtime_stats=False)

Sample a Python process and generate profiling data.

This is the main entry point for statistical profiling. It creates a SampleProfiler, collects stack traces from the target process, and outputs the results in the specified format.

パラメータ:

• pid (int) -- Process ID of the target Python process

• sort (int) -- Sort order for pstats output (default: 2 for cumulative time)

• sample_interval_usec (int) -- Sampling interval in microseconds (default: 100)

• duration_sec (int) -- Duration to sample in seconds (default: 10)

• filename (str) -- Output filename (None for stdout/default naming)

• all_threads (bool) -- Whether to sample all threads (default: False)

• limit (int) -- Maximum number of functions to display (default: None)

• show_summary (bool) -- Whether to show summary statistics (default: True)

• output_format (str) -- Output format - 'pstats' or 'collapsed' (default: 'pstats')

• realtime_stats (bool) -- Whether to display real-time statistics (default: False)

例外:

ValueError -- If output_format is not 'pstats' or 'collapsed'

Examples:

# Basic usage - profile process 1234 for 10 seconds
import profiling.sampling
profiling.sampling.sample(1234)

# Profile with custom settings
profiling.sampling.sample(1234, duration_sec=30, sample_interval_usec=50, all_threads=True)

# Generate collapsed stack traces for flamegraph.pl
profiling.sampling.sample(1234, output_format='collapsed', filename='profile.collapsed')

class profiling.sampling.SampleProfiler(pid, sample_interval_usec, all_threads)

Low-level API for the statistical profiler.

This profiler uses periodic stack sampling to collect performance data from running Python processes with minimal overhead. It can attach to any Python process by PID and collect stack traces at regular intervals.

パラメータ:

• pid (int) -- Process ID of the target Python process

• sample_interval_usec (int) -- Sampling interval in microseconds

• all_threads (bool) -- Whether to sample all threads or just the main thread

sample(collector, duration_sec=10)

Sample the target process for the specified duration.

Collects stack traces from the target process at regular intervals and passes them to the provided collector for processing.

パラメータ:

• collector -- Object that implements collect() method to process stack traces

• duration_sec (int) -- Duration to sample in seconds (default: 10)

The method tracks sampling statistics and can display real-time information if realtime_stats is enabled.

参考

Statistical Profiler Command Line Interface

Command-line interface documentation for the statistical profiler.

Deterministic Profiler Command Line Interface

ファイル cProfile と profile は他のスクリプトをプロファイルするためのスクリプトとして起動することも出来ます。例えば:

python -m cProfile [-o output_file] [-s sort_order] (-m module | myscript.py)

-o <output_file>

Writes the profile results to a file instead of to stdout.

-s <sort_order>

Specifies one of the sort_stats() sort values to sort the output by. This only applies when -o is not supplied.

-m <module>

Specifies that a module is being profiled instead of a script.

Added in version 3.7: Added the -m option to cProfile.

Added in version 3.8: Added the -m option to profile.

pstats モジュールの Stats クラスにはプロファイル結果のファイルに保存されているデータを処理して出力するための様々なメソッドがあります。

import pstats
from pstats import SortKey
p = pstats.Stats('restats')
p.strip_dirs().sort_stats(-1).print_stats()

strip_dirs() メソッドによって全モジュール名から無関係なパスが取り除かれました。sort_stats() メソッドにより、出力される標準的な モジュール/行/名前 文字列にしたがって全項目がソートされました。print_stats() メソッドによって全統計が出力されました。以下のようなソート呼び出しを試すことができます:

p.sort_stats(SortKey.NAME)
p.print_stats()

最初の行ではリストを関数名でソートしています。2行目で情報を出力しています。さらに次の内容も試してください:

p.sort_stats(SortKey.CUMULATIVE).print_stats(10)

このようにすると、関数が消費した累計時間でソートして、さらにその上位10件だけを表示します。どのアルゴリズムが時間を多く消費しているのか知りたいときは、この方法が役に立つはずです。

ループで多くの時間を消費している関数はどれか調べたいときは、次のようにします:

p.sort_stats(SortKey.TIME).print_stats(10)

上記はそれぞれの関数で消費された時間でソートして、上位10件の関数の情報が表示されます。

次の内容も試してください:

p.sort_stats(SortKey.FILENAME).print_stats('__init__')

このようにするとファイル名でソートされ、そのうちクラスの初期化メソッド (メソッド名 __init__) に関する統計情報だけが表示されます:

p.sort_stats(SortKey.TIME, SortKey.CUMULATIVE).print_stats(.5, 'init')

上記は時間 (time) をプライマリキー、累計時間 (cumulative time) をセカンダリキーにしてソートした後でさらに条件を絞って統計情報を出力します。 .5 は上位 50% だけを選択することを意味し、さらにその中から文字列 init を含むものだけが表示されます。

どの関数がどの関数を呼び出しているのかを知りたければ、次のようにします (p は最後に実行したときの状態でソートされています):

p.print_callers(.5, 'init')

このようにすると、関数ごとの呼び出し側関数の一覧が得られます。

さらに詳しい機能を知りたければマニュアルを読むか、次の関数の実行結果から内容を推察してください:

p.print_callees()
p.add('restats')

スクリプトとして起動した場合、 pstats モジュールはプロファイルのダンプを読み込み、分析するための統計ブラウザとして動きます。シンプルな行指向のインターフェース (cmd を使って実装) とヘルプ機能を備えています。

リファレンスマニュアル -- profile と cProfile

profile および cProfile モジュールは以下の関数を提供します:

profile.run(command, filename=None, sort=-1)

この関数は exec() 関数に渡せる一つの引数と、オプション引数としてファイル名を指定できます。全ての場合でこのルーチンは以下を実行します:

exec(command, __main__.__dict__, __main__.__dict__)

そして実行結果からプロファイル情報を収集します。 ファイル名が指定されていない場合は、 Stats のインスタンスが自動的に作られ、簡単なプロファイルレポートが表示されます。 sort が指定されている場合は、 Stats インスタンスに渡され、結果をどのように並び替えるかを制御します。

profile.runctx(command, globals, locals, filename=None, sort=-1)

This function is similar to run(), with added arguments to supply the globals and locals mappings for the command string. This routine executes:

exec(command, globals, locals)

そしてプロファイル統計情報を run() 同様に収集します。

class profile.Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)

このクラスは普通、プロファイリングを cProfile.run() 関数が提供するもの以上に正確に制御したい場合にのみ使われます。

timer 引数に、コードの実行時間を計測するためのカスタムな時刻取得用関数を渡せます。これは現在時刻を表す単一の数値を返す関数でなければなりません。もしこれが整数を返す関数ならば、 timeunit には単位時間当たりの実際の持続時間を指定します。たとえば関数が 1000 分の 1 秒単位で計測した時間を返すとすると、 timeunit は .001 でしょう。

Profile クラスを直接使うと、プロファイルデータをファイルに書き出すことなしに結果をフォーマット出来ます:

import cProfile, pstats, io
from pstats import SortKey
pr = cProfile.Profile()
pr.enable()
# ... do something ...
pr.disable()
s = io.StringIO()
sortby = SortKey.CUMULATIVE
ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
ps.print_stats()
print(s.getvalue())

The Profile class can also be used as a context manager (supported only in cProfile module. see コンテキストマネージャ型):

import cProfile

with cProfile.Profile() as pr:
    # ... do something ...

    pr.print_stats()

バージョン 3.8 で変更: コンテキストマネージャーサポートが追加されました。

enable()

Start collecting profiling data. Only in cProfile.

disable()

Stop collecting profiling data. Only in cProfile.

create_stats()

プロファイリングデータの収集を停止し、現在のプロファイルとして結果を内部で記録します。

print_stats(sort=-1)

現在のプロファイルに基づいて Stats オブジェクトを作成し、結果を標準出力に出力します。

The sort parameter specifies the sorting order of the displayed statistics. It accepts a single key or a tuple of keys to enable multi-level sorting, as in Stats.sort_stats.

Added in version 3.13: print_stats() now accepts a tuple of keys.

dump_stats(filename)

現在のプロファイルの結果を filename に書き出します。

run(cmd)

exec() を用いて cmd をプロファイルします。

runctx(cmd, globals, locals)

exec() を用いて指定されたグローバルおよびローカルな環境で cmd をプロファイルします。

runcall(func, /, *args, **kwargs)

func(*args, **kwargs) をプロファイルします。

Note that profiling will only work if the called command/function actually returns. If the interpreter is terminated (e.g. via a sys.exit() call during the called command/function execution) no profiling results will be printed.

Stats クラス

Stats クラスを使用してプロファイラデータを解析します。

class pstats.Stats(*filenames or profile, stream=sys.stdout)

このコンストラクタは filename で指定した (単一または複数の) ファイルもしくは Profile のインスタンスから "統計情報オブジェクト" のインスタンスを生成します。出力は stream で指定したストリームに出力されます。

上記コンストラクタで指定するファイルは、使用する Stats に対応したバージョンの profile または cProfile で作成されたものでなければなりません。将来のバージョンのプロファイラとの互換性は 保証されておらず 、他のプロファイラで生成されたファイルや異なるオペレーティングシステムで実行される同じプロファイルとの互換性もないことに注意してください。複数のファイルを指定した場合、同一の関数の統計情報はすべて合算され、複数のプロセスで構成される全体をひとつのレポートで検証することが可能になります。既存の Stats オブジェクトに別のファイルの情報を追加するときは、 add() メソッドを使用します。

プロファイルデータをファイルから読み込む代わりに、 cProfile.Profile または profile.Profile オブジェクトをプロファイルデータのソースとして使うことができます。

Stats には次のメソッドがあります:

strip_dirs()

Stats クラスのこのメソッドは、ファイル名の前に付いているすべてのパス情報を取り除くためのものです。出力の幅を80文字以内に収めたいときに重宝します。このメソッドはオブジェクトを変更するため、取り除いたパス情報は失われます。パス情報除去の操作後、オブジェクトが保持するデータエントリは、オブジェクトの初期化、ロード直後と同じように "ランダムに" 並んでいます。 strip_dirs() を実行した結果、2つの関数名が区別できない (両者が同じファイルの同じ行番号で同じ関数名となった) 場合、一つのエントリに合算されされます。

add(*filenames)

Stats クラスのこのメソッドは、既存のプロファイリングオブジェクトに情報を追加します。引数は対応するバージョンの profile.run() または cProfile.run() によって生成されたファイルの名前でなくてはなりません。関数の名前が区別できない (ファイル名、行番号、関数名が同じ) 場合、一つの関数の統計情報として合算されます。

dump_stats(filename)

Stats オブジェクトに読み込まれたデータを、ファイル名 filename のファイルに保存します。ファイルが存在しない場合は新たに作成され、すでに存在する場合には上書きされます。このメソッドは profile.Profile クラスおよび cProfile.Profile クラスの同名のメソッドと等価です。

sort_stats(*keys)

This method modifies the Stats object by sorting it according to the supplied criteria. The argument can be either a string or a SortKey enum identifying the basis of a sort (example: 'time', 'name', SortKey.TIME or SortKey.NAME). The SortKey enums argument have advantage over the string argument in that it is more robust and less error prone.

2つ以上のキーが指定された場合、2つ目以降のキーは、それ以前のキーで等価となったデータエントリの再ソートに使われます。たとえば sort_stats(SortKey.NAME, SortKey.FILE) とした場合、まずすべてのエントリが関数名でソートされた後、同じ関数名で複数のエントリがあればファイル名でソートされます。

For the string argument, abbreviations can be used for any key names, as long as the abbreviation is unambiguous.

The following are the valid string and SortKey:

Valid String Arg	Valid enum Arg	意味
'calls'	SortKey.CALLS	呼び出し数
'cumulative'	SortKey.CUMULATIVE	累積時間
'cumtime'	N/A	累積時間
'file'	N/A	ファイル名
'filename'	SortKey.FILENAME	ファイル名
'module'	N/A	ファイル名
'ncalls'	N/A	呼び出し数
'pcalls'	SortKey.PCALLS	プリミティブな呼び出し回数
'line'	SortKey.LINE	行番号
'name'	SortKey.NAME	関数名
'nfl'	SortKey.NFL	関数名/ファイル名/行番号
'stdname'	SortKey.STDNAME	標準名
'time'	SortKey.TIME	内部時間
'tottime'	N/A	内部時間

すべての統計情報のソート結果は降順 (最も多く時間を消費したものが一番上に来る) となることに注意してください。ただし、関数名、ファイル名、行数に関しては昇順 (アルファベット順) になります。 SortKey.NFL と SortKey.STDNAME には微妙な違いがあります。標準名 (standard name) とは表示された名前によるソートで、埋め込まれた行番号のソート順が特殊です。たとえば、 (ファイル名が同じで) 3、20、40という行番号のエントリがあった場合、20、3、40 の順に表示されます。一方 SortKey.NFL は行番号を数値として比較します。要するに、 sort_stats(SortKey.NFL) は sort_stats(SortKey.NAME, SortKey.FILENAME, SortKey.LINE) と指定した場合と同じになります。

後方互換性のため、数値を引数に使った -1, 0, 1, 2 の形式もサポートしています。それぞれ 'stdname', 'calls', 'time', 'cumulative' として処理されます。引数をこの旧スタイルで指定した場合、最初のキー (数値キー) だけが使われ、複数のキーを指定しても2番目以降は無視されます。

Added in version 3.7: Added the SortKey enum.

reverse_order()

Stats クラスのこのメソッドは、オブジェクト内の情報のリストを逆順にソートします。デフォルトでは選択したキーに応じて昇順、降順が適切に選ばれることに注意してください。

print_stats(*restrictions)

Stats クラスのこのメソッドは、 profile.run() の項で述べたプロファイルのレポートを出力します。

出力するデータの順序はオブジェクトに対し最後に行った sort_stats() による操作に基づきます (add() と strip_dirs() による制限にも支配されます)。

The arguments provided (if any) can be used to limit the list down to the significant entries. Initially, the list is taken to be the complete set of profiled functions. Each restriction is either an integer (to select a count of lines), or a decimal fraction between 0.0 and 1.0 inclusive (to select a percentage of lines), or a string that will be interpreted as a regular expression (to pattern match the standard name that is printed). If several restrictions are provided, then they are applied sequentially. For example:

print_stats(.1, 'foo:')

上記の場合まず出力するリストは全体の10%に制限され、さらにファイル名の一部に文字列 .*foo: を持つ関数だけが出力されます:

print_stats('foo:', .1)

こちらの例の場合、リストはまずファイル名に .*foo: を持つ関数だけに制限され、その中の最初の 10% だけが出力されます。

print_callers(*restrictions)

Stats クラスのこのメソッドは、プロファイルのデータベースの中から何らかの関数呼び出しを行った関数をすべて出力します。出力の順序は print_stats() によって与えられるものと同じです。出力を制限する引数も同じです。各呼び出し側関数についてそれぞれ一行ずつ表示されます。フォーマットは統計を作り出したプロファイラごとに微妙に異なります:

• profile の場合、呼び出し側関数の後に括弧で囲まれて表示される数値はその呼び出しが何回行われたかを示しています。利便性のため、 2番目の括弧なしで表示される数値によって、関数が消費した累積時間を表しています。

• cProfile の場合、各呼び出し側関数の後に3つの数字が付きます。呼び出しが何回行われたかと、この呼び出し側関数からの呼び出しによって現在の関数内で消費された合計時間および累積時間です。

print_callees(*restrictions)

Stats クラスのこのメソッドは、指定した関数から呼び出された関数のリストを出力します。呼び出し側、呼び出される側の方向は逆ですが、引数と出力の順序に関しては print_callers() と同じです。

get_stats_profile()

This method returns an instance of StatsProfile, which contains a mapping of function names to instances of FunctionProfile. Each FunctionProfile instance holds information related to the function's profile such as how long the function took to run, how many times it was called, etc...

Added in version 3.9: Added the following dataclasses: StatsProfile, FunctionProfile. Added the following function: get_stats_profile.

決定論的プロファイリングとは

Deterministic profiling is meant to reflect the fact that all function call, function return, and exception events are monitored, and precise timings are made for the intervals between these events (during which time the user's code is executing). In contrast, statistical profiling (which is provided by the profiling.sampling module) periodically samples the effective instruction pointer, and deduces where time is being spent. The latter technique traditionally involves less overhead (as the code does not need to be instrumented), but provides only relative indications of where time is being spent.

Python の場合、実行中は必ずインタプリタが動作しているため、決定論的プロファイリングを行うために計測用のコードを追加する必要はありません。 Python は自動的に各イベントに フック (オプションのコールバック) を提供します。加えて Python のインタプリタという性質によって、実行時に大きなオーバーヘッドを伴う傾向がありますが、それに比べると一般的なアプリケーションでは決定論的プロファイリングで追加される処理のオーバーヘッドは少ない傾向にあります。結果的に、決定論的プロファイリングは少ないコストで Python プログラムの実行時間に関する詳細な統計を得られる方法となっているのです。

呼び出し回数はコード中のバグ発見にも使用できます (とんでもない数の呼び出しが行われている部分)。インライン拡張の対象とすべき部分を見つけるためにも使えます (呼び出し頻度の高い部分)。内部時間の統計は、注意深く最適化すべき"ホットループ"の発見にも役立ちます。累積時間の統計は、アルゴリズム選択に関連した高レベルのエラー検知に役立ちます。なお、このプロファイラは再帰的なアルゴリズム実装の累計時間を計ることが可能で、通常のループを使った実装と直接比較することもできるようになっています。

制限事項

一つの制限はタイミング情報の正確さに関するものです。決定論的プロファイラには正確さに関する根本的問題があります。最も明白な制限は、 (一般に) "クロック"は .001 秒の精度しかないということです。これ以上の精度で計測することはできません。仮に充分な精度が得られたとしても、"誤差"が計測の平均値に影響を及ぼすことがあります。この最初の誤差を取り除いたとしても、それがまた別の誤差を引き起こす原因となります。

もう一つの問題として、イベントを検知してからプロファイラがその時刻を実際に 取得 するまでに "いくらかの時間がかかる" ことです。同様に、イベントハンドラが終了する時にも、時刻を取得して (そしてその値を保存して) から、ユーザコードが処理を再開するまでの間に遅延が発生します。結果的に多く呼び出される関数または多数の関数から呼び出される関数の情報にはこの種の誤差が蓄積する傾向にあります。このようにして蓄積される誤差は、典型的にはクロックの精度を下回ります (1クロック以下) が、一方でこの時間が累計して非常に大きな値になることも あり得ます 。

この問題はオーバーヘッドの小さい cProfile よりも profile においてより重要です。そのため、 profile は誤差が確率的に (平均値で) 減少するようにプラットフォームごとに補正する機能を備えています。プロファイラに補正を施すと (最小二乗の意味で) 正確さが増しますが、ときには数値が負の値になってしまうこともあります (呼び出し回数が極めて少なく、確率の神があなたに意地悪をしたとき :-) )。プロファイルの結果に負の値が出力されても 驚かないでください 。これは補正を行った場合にのみ生じることで、補正を行わない場合に比べて計測結果は実際にはより正確になっているはずだからです。

キャリブレーション (補正)

profile のプロファイラは time 関数呼び出しおよびその値を保存するためのオーバーヘッドを補正するために、各イベントの処理時間から定数を引きます。デフォルトでこの定数の値は 0 です。以下の手順で、プラットフォームに合った、より適切な定数が得られます (制限事項 参照)。

import profile
pr = profile.Profile()
for i in range(5):
    print(pr.calibrate(10000))

calibrate メソッドは引数として与えられた数だけ Python の呼び出しを行います。直接呼び出す場合と、プロファイラを使って呼び出す場合の両方が実施され、それぞれの時間が計測されます。その結果、プロファイラのイベントに隠されたオーバーヘッドが計算され、その値は浮動小数として返されます。たとえば、 1.8 GHz の Intel Core i5 で macOS を使用、 Python の time.process_time() をタイマとして使った場合、値はおよそ 4.04e-6 となります。

この手順で使用しているオブジェクトはほぼ一定の結果を返します。 非常に 早いコンピュータを使う場合、もしくはタイマの性能が貧弱な場合は、一定の結果を得るために引数に 100000 や 1000000 といった大きな値を指定する必要があるかもしれません。

一定の結果が得られたら、それを使う方法には3通りあります:

import profile

# 1. Apply computed bias to all Profile instances created hereafter.
profile.Profile.bias = your_computed_bias

# 2. Apply computed bias to a specific Profile instance.
pr = profile.Profile()
pr.bias = your_computed_bias

# 3. Specify computed bias in instance constructor.
pr = profile.Profile(bias=your_computed_bias)

選択肢がある場合は、補正値は小さめに設定した方が良いでしょう。プロファイルの結果に負の値が表われる"頻度が低く"なるはずです。

カスタムな時刻取得用関数を使う

プロファイラが時刻を取得する方法を変更したいなら (たとえば、実測時間やプロセスの経過時間を使いたい場合)、時刻取得用の関数を Profile クラスのコンストラクタに指定することができます:

pr = profile.Profile(your_time_func)

この結果生成されるプロファイラは時刻取得に your_time_func() を呼び出すようになります。 profile.Profile と cProfile.Profile のどちらを使っているかにより、 your_time_func の戻り値は異なって解釈されます:

profile.Profile

your_time_func() は単一の数値、あるいは (os.times() と同じように) その合計が累計時間を示すリストを返すようになっていなければなりません。関数が1つの数値、あるいは長さ2の数値のリストを返すようになっていれば、ディスパッチルーチンには特別な高速化バージョンが使われます。

Be warned that you should calibrate the profiler class for the timer function that you choose (see キャリブレーション (補正)). For most machines, a timer that returns a lone integer value will provide the best results in terms of low overhead during profiling. (os.times() is pretty bad, as it returns a tuple of floating-point values). If you want to substitute a better timer in the cleanest fashion, derive a class and hardwire a replacement dispatch method that best handles your timer call, along with the appropriate calibration constant.

cProfile.Profile

your_time_func() は単一の数値を返すようになっていなければなりません。単一の整数を返すのであれば、クラスコンストラクタの第二引数に単位時間当たりの実際の持続時間を渡せます。例えば your_integer_time_func が 1000 分の 1 秒単位で計測した時間を返すとすると、 Profile インスタンスを以下のように構築出来ます:

pr = cProfile.Profile(your_integer_time_func, 0.001)

As the cProfile.Profile class cannot be calibrated, custom timer functions should be used with care and should be as fast as possible. For the best results with a custom timer, it might be necessary to hard-code it in the C source of the internal _lsprof module.

Python 3.3 で time に、プロセス時間や実時間の精密な計測に使える新しい関数が追加されました。 例えば、 time.perf_counter() を参照してください。