Python の新しいプロファイラ vmprof が面白い

PyPy 2.6 と同時に、 vmprof という CPython/PyPy 用のプロファイラが登場しました。

私はまだ PyPy では使っていませんが、CPythonのプロジェクトをこれでプロファイル取ってみたらなかなか面白かったので紹介します。

概要

Python にはもともと標準ライブラリとしてプロファイラ (cProfile) が付いてきていますが、これは関数の呼び出しと戻りでコールバック関数を呼び出しつつ実行時間を計測するタイプのプロファイラで、短時間でも正確なプロファイルが取れる反面、オーバーヘッドが大きく、小さい関数をたくさん呼び出す部分がオーバーヘッドでより大きく見えてしまうなどの問題がありました。

これと別の種類のプロファイラとして、定期的にサンプリングして、サンプルが多いところが実行時間も多いハズ、というプロファイラもあります。こちらはある程度の量のサンプルを集めないと正確性にかけるものの、オーバーヘッドが小さく、小さい関数をたくさん呼び出す場合も正確にプロファイルができたり、本番環境のサーバーのプロファイルを取ることができたりします。 Go 言語の pprof もそうですし、 Python では私も昔に sigprofiler というものを作ったことがあります。

vmprof もこのサンプリング型のプロファイラです。 PyPy だときっと JIT の状態が見れるなどの特長があるのでしょうが、私は今のところ CPython で使っています。 CPython 用としてみた場合の vmprof の特長は次のような感じです。

Pythonのスタックと同時にCのスタックも保存して、同時に見ることができる
Python スタックを取る部分も C で実装されており、 sigprofiler よりずっと軽い

vmprof は Python スタックを取るために、 PyEval_EvalFrameEx をトランポリン関数で置き換えます。 SIGPROF シグナルハンドラでCのスタックを解析するのですが、その際にトランポリン関数を見つけるとその引数である frame オブジェクトを見つけて、 frame オブジェクトから Python のスタックを取ります。

(ちなみに、 CPython 用の部分とそれ以外が綺麗に分かれているので、他のインタプリタ型言語でも関数呼び出しの際に呼ばれる関数をセットしたら vmprof が使えるはずです)

C の関数呼び出しは Python の関数呼び出しよりずっと軽いので、トランポリン関数が1つ挟まるだけならほとんどオーバーヘッドはありません。

vmprof-server

コマンドラインでも簡単な出力を見れますが、 vmprof の本領を発揮するにはビジュアライザである vmprof-server が必要です。これは Django REST framework とシングルページアプリケーションの組み合わせになっています。

他人に見られてもいいならデモサイトが利用できますし、見られたくないなら自分で簡単にセットアップすることができます。

$ git checkout git@github.com:vmprof/vmprof-server.git
$ cd vmprof-server
$ pip install -r requirements/base.txt
$ ./manage.py runserver

これを使って、次のようなプログラムのプロファイルを取ってみましょう。

import time

def sum1(n):
    return sum(range(n))

def sum2(n):
    return sum(range(n))

def sum12(n, m):
    z = 0
    for _ in range(1000):
        z += sum1(n) + sum2(m)
    return z

def foo():
    return sum12(10000, 100000)

def bar():
    return sum12(30000, 10000)

def main():
    t0 = time.time()
    while time.time() < t0 + 10:
        foo()
        bar()

if __name__ == '__main__':
    main()

$ python -m vmprof -n --web http://vmprof.baroquesoftware.com/ ex2.py

デモサイト

f:id:methane:20150609223332p:plain

このプログラムで、 sum12() は sum1() と sum2() を呼び出していますが、その呼び出し比率は引数によって変わります。そして foo() と bar() が sum12() を呼び出していますが、引数が違うのでその内訳が違うはずです。

vmprof と vmprof-server は sum12() の中身の内訳をまとめてしまわず、ちゃんとスタックを維持してビジュアライズしてくれるのがわかると思います。

例えば ORM を利用している場合、クエリをコンパイルしてる部分と、オブジェクトをフェッチする部分の重さの比率を見ることで、たくさんオブジェクトをロードしてるから重いのか、複雑なクエリをコンパイルしているから遅いのかを判断することができます。

まだまだ未完成なプロジェクトですが、わかって使えばとても強力なので、使ってみて足りない部分にプルリクエストを送ったりして応援していきましょう。