サーバー技術

マルチスレッドで走るPythonプログラムをプロファイルするには？

linkucojp

さて、前の記事では実験とソースコード読解の両方から、python -m cProfile test.pyとして測定した場合、メインスレッドで実行される部分しか計測されていない事がわかりました。

でも、「Deep LearningといえばPython」な昨今、マルチスレッドで動くPythonのプログラムは目の前にいっぱい存在するわけで、それらを測りたいわけで。どげんかせんといかん。

ある意味で本題はここからです。方法をいくつか調べました。

その１：起動したスレッドごとにcProfileを設定する

cProfile.Profileクラスを使うと、python -m cProfile test.pyのようにしてコマンドライン引数を使って行っていたプロファイリングを、コード中からもできます。この方法ならメインスレッド以外にもプロファイラを設定して計測することができます。

こんな感じ：

import threading
import cProfile
import math


class Worker(threading.Thread):
    def __init__(self, n: int):
        threading.Thread.__init__(self)
        self.n = n
        self.sum = 0

    def run(self):
        prof = cProfile.Profile() # プロファイラの作成
        prof.enable() # プロファイラの有効化
        try:
            for i in range(0, self.n):
                self.sum += math.sin(i * i)
        finally:
            prof.disable() # プロファイラを止める
            prof.print_stats('cumtime') # 結果の表示


def main():
    th = Worker(100000000)
    th.start()
    th.join()


if __name__ == '__main__':
    main()

前回と違い、今度こそはmath.sinが出てきます：

% python3 test.py
         100000001 function calls in 18.187 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
100000000   18.187    0.000   18.187    0.000 {built-in method math.sin}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

しかしながら、この方法はソースコードを書き換えなければなりません。多くの場合において不可能ではないでしょうが、若干居心地は悪いですし、run関数がC言語で書かれていたりすると、正直かなり大変です。

とはいえ、この方法では確実に枯れているであろう、そしてPython開発チームが公式にメンテナンスしている、cProfileを使うことができます。cProfileに慣れているとか、なんかgithubに上がってる新しいよくわかんないプロダクトは嫌だなぁ、といった人にはこれが良いかもしれません。

その２：vmprof

前回読んだように、cProfileは全ての関数呼び出し（とreturn）を追跡して記録しているのですが、こういうプロファイラを「決定論的プロファイラ」と呼ぶそうです。わざわざそんな名前がつくからには別の種類のプロファイラもあるわけで、vmprofは統計的プロファイラです。

具体的に何をどう測るのかというと、（Linuxも含めたUNIXでは）setitimerというOSの提供するインターバル・タイマーを使って、定期的にスレッドを全て止め、libunwindを使ってスタック上のコール・チェーンの状態（今、どの関数がどの関数を呼び出している最中なのか）を記録し、その情報を使って「測定」しているようです。

なので、cProfileと違ってすべての関数呼び出しが把握できるわけではなく、例えば短時間だけ実行されるあまり呼ばれない関数は取りこぼされることがあります。まぁ、そういう関数はプロファイルを取って突き止めたい「ホットな」関数ではないですから、測定できなくてもよい、という判断なのでしょう。

一方で、cProfileはC言語の関数に関しては前回見た通りPythonのインタプリタから呼び出す瞬間に測定していて、そこから先のC言語間の関数呼び出しは関知しない（できない）わけですが、この方法ではC言語の部分まで一緒にプロファイリングできちゃいます。CUDAやC言語の複雑に絡み合うシステムには、こっちの方が有用かもしれません。

結果のビジュアライズも中々わかりやすい。C言語の関数も、シンボル情報がある部分に関しては関数名も表示されます：

run関数でmath.sinの和を計算している処理のうち、integerをdoubleにするPyFloat_AsDoubleがどうやら11%程度使っているらしい、といった情報までわかります。

難点があるとすれば、測定するスレッドが決められない点でしょうか。ソースコードを追いかけた限りでは、必ず全てのスレッドを追いかけて結果を合算しているように読めました。同じクラスから派生するさまざまなクラスが一緒に走る場合（今回高速化しているPyritがまさにそのケースに当てはまる）、ちょっとデータの解釈に困るかもしれません。

C言語のスタックまで計測出来る点は素晴らしいのですが、普通に実行しただけでは必ずしも関数名が見えるとは限らない点はちょっと残念です。python3-dbgパッケージを入れてデバッグ用pythonでも実行してみたのですが、内部の全ての関数シンボルまでは残っていないようでした。VMの中身を深く掘らないといけない時は、pythonを自分でビルドする必要があるでしょう。

このWebインターフェイスなのですが、デフォルトではvmprof.comというウェブサービスにプロファイルした結果をアップロードして表示する（！）というクラウド絶頂期のイマドキらしい中々大胆な作りになっていまして、会社で書いてるプロプライエタリなソースで利用するのにはちょっと憚られるかもしれません。まぁもっとも、ここ最近はずっと落ちているのでそもそもアップロード出来ないんですが（それはそれでどうなんだ）。

もちろん、サーバのソースコードも公開はされていて比較的簡単には使えるので、自分で立てればそのへんは解決可能（というかそうしないと使えない）です。

その３：Pyflame

上のvmprofと同じ統計的プロファイラですが、こちらはLinuxでデバッガを実装するときに使われるシステムコールであるptraceを使っているらしいです（よってLinux専用）。ptraceを使っているおかげで、すでに動いているプロセスに対してアタッチ出来るのが強みだそうな。

Python3.7には未対応な上でIssueには進捗がなく、Python2.7で試してみた限り、Cのスタックも追いかけてくれませんでした（ptraceの力をもってすれば原理的には可能だと思うんですが…）。2019年3月現在は、あんまりおすすめできない選択肢だと思います。

その４：pprofile

こちらは決定論的プロファイラと統計的プロファイラの両方の実装が含まれています。ドキュメントに書いてあるとおり、決定論的・統計的プロファイラをのどちらでもマルチスレッドに対応していて、しかもPythonだけで書かれています。どうなっているのか調べてみたところ、threading.settraceというsys.settraceのマルチスレッド対応版みたいなAPIがあって、それをそのまま利用しているようです。

全てがPythonで書かれている都合上オーバーヘッドが少々大きいのと、C言語のプロファイルは取れません。ただ、著者の主張している通り、動かすのはすごく楽です。測定対象のソースコードを書き換える必要性も一切ありません。

その他：マルチスレッドは（そのままでは）ダメだったやつ

DISるつもりは無いんですが、マルチスレッドはダメそうだったやつも記録しておきます。シングルスレッドのPythonプログラムをデバッグしているときは便利なんじゃないでしょうか。

cprofilev

cProfileの便利なラッパー、だそうな。しかしソースを読んだ限り、便利になった代償として、マルチスレッドでこれを使うのはさらに難しくなっているようです。

line_profiler

cProfileと違って１行ごとに測定できる、というのが売りの決定論的プロファイラ。仕組みもcProfileとだいたい同じで、違いはPyEval_SetProfileの代わりにPyEval_SetTraceを使っていること。この関数を使うとPythonの関数の呼び出しの記録だけでなく、Pythonの命令が１行実行されるごとにcallbackが呼ばれるそうな（逆に、C言語の関数のCALL/RETURNは記録されない）。

ここ以外の事情も概ねcProfileと同じ感じでして、コードを修正しなくてもプロファイルを取ってくれるというkernprofコマンドのmain関数はメインスレッドしか測らないものの、手動で測定コードを挿入すればマルチスレッドでも測れるようになっているように読めます（段々めんどくさくなってきて実験はしてません）。

まとめ

プロファイラもまさに十人十色といった感じでした。プロファイラを使う前に、時間を掛けてソースコード読んで、何をどう測っているのか、調べる価値はあると思います。

どれが良いのかは、正直なところ、測定対象のプログラムによると思います。

  • とりあえず動かしたいだけならpprofが一番楽です。
  • pyflameはおすすめできないと書きましたが、今すでに動いているPythonのプログラムをプロファイルできるのはpyflameだけです。
  • Cのコールスタックまでプロファイルを取れるのは、vmprofだけです。
  • cProfileは公式でメンテナンスされていて、枯れているでしょう。

今回ターゲットにしている、CとCUDAとPythonのアマルガムであるPyritの場合は、vmprofが適切かなぁと思います。CaffeやTensorFlowの人たちは何使ってプロファイル取ってるんだろう…。