GPUを使って無線LANをクラックする話 / プロファイラの言うことがみんな違うよ編

ついにソメイヨシノも咲いて、「春」って感じですな。

梅も桜も花の形が似ていますが、それもそのはず。も、どちらもバラ科サクラ属なのだそうです。じゃ、他には?という事で調べてみたのですが、モモもそうなんだって。そういえばたしかに、さくらんぼと桃の実ってなんとなく似てますね。

というわけで(?)、今回はモモの花です。

前回までのまとめ

前回までこの「GPUを使って無線LANをクラックする話」では、Pythonの標準プロファイラcProfileを使って測定して議論していましたが、cProfileは実は普通に使う限りではメインスレッドしか測定してくれない事がわかりました(別記事)。マルチスレッドで動いているPythonプログラムのためのプロファイラはいろいろあるけれど(別記事)、C言語のスタックまでプロファイルしてくれる、vmprofというのがどうやら我らがPyritには良さそうです。というわけで、このvmprofを使って再度取り直します。

vmprofを使ってもう一回測定するぜ!→やっぱなんか変だぜ!

というわけでモクモクと測定していきます。

まず可視化のためのサーバを建てる必要があります(デフォルトだとvmprof.comを使うようになっているのですが、このサーバは落ちたまま放置されているようです)。

git clone https://github.com/vmprof/vmprof-server.git
cd vmprof-server

pip install -r requirements/development.txt
python manage.py migrate
python manage.py runserver -v 3

vmprof自体はpipで入るのでもっと簡単です。ただし、さっき自分が建てたWebサーバを指定するのを忘れずに:

pip install vmprof
python -m vmprof --web --web-url "http://127.0.0.1:8000/" pyrit benchmark

で、CPUを1コアだけ使って解くようにした結果がこちら:

全処理時間のうちrun関数が95%使っていて、さらにCPUDevice_solveというC言語の関数が2.5%使っている、などなど。

95%を使っているというrun関数はパスワードを処理するスレッドのエントリーポイントです。CPU/CUDA/OpenCLで共通で、キューから候補のパスワードを取り出し(_gather)、self.solve()を使って計算して別のキューへ投げる(_scatter)という簡単なものです:

    def run(self):
        while not self.shallStop:
            essid, pwlist = self.queue._gather(self.buffersize, timeout=0.5)
            if essid is not None:
                if not self.isTested:
                    self._testComputeFunction(101)
                    self.isTested = True
                t = time.time()
                res = self.solve(essid, pwlist)  # ←ここのメソッド呼び出しでCPU/CUDA/OpenCLが分岐する
                assert len(res) == len(pwlist)
                self.compTime += time.time() - t
                self.resCount += len(res)
                self.callCount += 1
                if self.compTime > 0:
                    # carefully move towards three seconds of execution-time
                    avg = (2 * self.buffersize +
                           (self.resCount / self.compTime * 3)) / 3
                    self.buffersize = int(max(self.minBufferSize,
                                              min(self.maxBufferSize, avg)))
                self.queue._scatter(essid, pwlist, res)

この関数と、そこから先の処理が95%を占めている、というのは理解できます。この「95%」というのは、SIGPROFの基準で95%なので、全スレッドで実際に実行された時間のうち、95%の時間という意味になるようです。言い換えると、sleepしたりしている時間は入らないということです。

しかし、CPUDevice_solveが2.5%とはどういう事か。CPUDevice_solveは、CPUのコアで実行したときに実際にOpenSSLを使ってSHA1を何度も計算する処理です。一番重い、CPUを酷使する処理のはずで、流石にたった2.5%という事はありえないはずです。

…バグかなぁ?

cProfile、ふたたび

cProfileはpython -m cProfile pyrit benchmark と実行するとメインスレッドしかプロファイルしてくれませんが、ソースコードを書き換えれば別のスレッドのプロファイルも取ることができます。これで同じ処理を測定してみます。

さきほどのrun関数の周囲を次のようなコードで囲みます:

    def run(self):
        import cProfile
        prof = cProfile.Profile()
        prof.enable()
        try:
            # ... 元々の処理 ...
        finally:
            prof.disable()
            prof.dump_stats('{}.dat'.format(threading.currentThread().ident))

threading.currentThread().ident はスレッドごとに異なる値で、これをファイル名に使っています。

次のようなコマンドで測定結果を確認してみると(pstatsのドキュメントはこちら):

$ python
Python 2.7.15rc1 (default, Nov 12 2018, 14:31:15) 
[GCC 7.3.0] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import pstats
>>> s = pstats.Stats('140487566550784.dat') # ←ファイル名は毎回異なる
>>> s.sort_stats('cumtime').print_stats()
Fri Mar 29 11:59:24 2019    140487566550784.dat

         3194 function calls in 69.366 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       28   68.735    2.455   68.735    2.455 {method 'solve' of '_cpyrit_cpu.CPUDevice' objects}
       28    0.004    0.000    0.627    0.022 /home/server01/src/Pyrit/cpyrit/cpyrit.py:637(_gather)
       10    0.001    0.000    0.622    0.062 /usr/lib/python2.7/threading.py:309(wait)
       54    0.620    0.011    0.620    0.011 {time.sleep}
        1    0.000    0.000    0.116    0.116 /home/server01/src/Pyrit/cpyrit/cpyrit.py:99(_testComputeFunction)
       27    0.003    0.000    0.004    0.000 /home/server01/src/Pyrit/cpyrit/cpyrit.py:692(_scatter)
      216    0.001    0.000    0.001    0.000 {method 'extend' of 'list' objects}
       55    0.000    0.000    0.000    0.000 /usr/lib/python2.7/threading.py:285(__enter__)
       54    0.000    0.000    0.000    0.000 /usr/lib/python2.7/threading.py:400(notifyAll)
       54    0.000    0.000    0.000    0.000 {sorted}
      139    0.000    0.000    0.000    0.000 {method 'acquire' of 'thread.lock' objects}
... (以下省略) ...

run関数の内側でprof.enable()としているので、上の結果の一覧にrun関数は出てきません。run関数以下の内訳を測定している、ということになります。処理に掛かった全時間が69.366秒、結果の1行目によるとCPUDeviceのsolveメソッドの実行に掛かった時間が68.735秒(約99%)、などなどといったことが分かります。

CPUDeviceのsolveメソッドの実態は、vmprofでCPUDevice_solveとなっていたC言語の関数です。vmprofでは処理の2.5%を占めているというこの関数が、cProfileによるとほぼ99%だそうで…えー、言ってることが、真逆ですねぇ。

まとめ

SIGPROF(アラーム・シグナル)を使った統計的プロファイラであるvmprofを使ってPyritのbenchmarkを測定してみたものの、標準の決定論的プロファイラであるcProfileとは大きく結果が異なる事がわかりました。状況証拠から言って、vmprofのバグじゃないかなぁと思います(しかし残念ながらもう開発も止まってしまった模様…)。前回のような簡単なコードでは結果が一致したからといって信用せず、常に複数のプロファイラを併用して結果を突き合わせたほうが良いのかもしれません。

…マジ、みんなどうやってプロファイル取ってるんだ?と思って調べたらTensorFlowは自分たち専用のプロファイラを作ってた。まっ、そうですよねー。

残念ながら大人の事情により、今回で一端このシリーズは最終回らしいです。機材を貸してくれた人ありがとう。…ちょっとぐらい速くしたかったなぁ。

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

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

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

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

その1:起動したスレッドごとに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に上がってる新しいよくわかんないプロダクトは嫌だなぁ、といった人にはこれが良いかもしれません。

その2: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というウェブサービスにプロファイルした結果をアップロードして表示する(!)というクラウド絶頂期のイマドキらしい中々大胆な作りになっていまして、会社で書いてるプロプライエタリなソースで利用するのにはちょっと憚られるかもしれません。まぁもっとも、ここ最近はずっと落ちているのでそもそもアップロード出来ないんですが(それはそれでどうなんだ)。

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

その3:Pyflame

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

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

その4:pprofile

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

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

その他:マルチスレッドは(そのままでは)ダメだったやつ

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

cprofilev

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

line_profiler

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

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

まとめ

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

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

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

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

Pythonの標準プロファイラ、cProfileの中身を追いかける

Python、使ってますか。

わたしは最近、諸事情により、最近PythonとC言語とCUDAを使ったソフトウェア高速化に取り組んでいます(できているとは言っていない)。ちなみに、ディープラーニングじゃないよ。

高速化するときに最も重要な道具は、ベンチマークとプロファイラであることを疑う人は居ないと思います。ベンチマークで高速化の効果を測定し、プロファイラでボトルネックを発見する。これが基本的かつ王道のサイクルですよね。

ところで、プロファイラはどのような仕組みで動いているのでしょうか。追いかけたこと、あります?

何を測っているのか知らずにプロファイラを使う者がおるか!

プロファイラは何を測っていて、何を測っていないのか。

Pythonに最初からついてくるプロファイラ「cProfile」を使ってプロファイリングを行っていたのですが(CUDAとC以前にPythonがボトルネックっぽいので)、わたしはてっきりこのプロファイラはGILを握っている全てのスレッドのそれぞれの動作を測ってるんだと思ってました。だって、「マルチスレッドだけどGILのせいで同時に動くスレッドは1つしかない」というPythonのプログラムの動作をプロファイリングする方法としては、それが一番妥当かつ自然に感じられたからです (でも、今考え直してみると、そうでもない気がしてきた…わからん)。ドキュメントにはマルチスレッドに関しては何にも書いてないし。

しかし、Profilerの出力する結果を見ているとどうにもおかしい気がしてきまして。おおむね予想通りの結果も出てくるけど、どこかおかしい気もする。わたしの予想の方が間違っているのか、プロファイラの測定の誤差や限界なのか。うーん。

なんでそんな考えが浮かんでくるのかといえば、(今回のも含めて)高速化したいプログラムというのは大抵複雑だからです。

というわけで、超単純なサンプルで測ってみました:

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):
        for i in range(0, self.n):
            self.sum += math.sin(i * i)

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

if __name__ == '__main__':
    main()

見たまんまですが、math.sin(i * i)の和を計算するという何の意味もない計算を、メインスレッドとは別のスレッドで行う、無意味だけど時間の掛かるプログラムです。

これをcProfileして出た結果は:

% python -m cProfile -s 'cumtime' test.py
         45 function calls in 21.670 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000   21.670   21.670 {built-in method builtins.exec}
        1    0.000    0.000   21.670   21.670 <string>:1(<module>)
        1    0.000    0.000   21.670   21.670 test.py:17(main)
        5   21.670    4.334   21.670    4.334 {method 'acquire' of '_thread.lock' objects}
        1    0.000    0.000   21.665   21.665 threading.py:1024(join)
        1    0.000    0.000   21.665   21.665 threading.py:1062(_wait_for_tstate_lock)
        1    0.000    0.000    0.005    0.005 threading.py:828(start)
        1    0.000    0.000    0.005    0.005 threading.py:533(wait)
        1    0.000    0.000    0.005    0.005 threading.py:263(wait)
        1    0.000    0.000    0.000    0.000 {built-in method _thread.start_new_thread}
...(略)...

無意味な計算のために20秒ほど掛かっていていますが、その計算に関わっているWorker.run関数やmath.sinは一切リストアップされておらず、スレッドのjoinのみが入っています。

…えー。つまり、cProfileはマルチスレッド対応してないんだねぇ。

…今まで計測した結果、全部無駄だねぇ。…まぁ、そういう事もあるよ。

ソースコードを追いかける

せっかくですから、この機会にソースコードを追いかけて、どのようにプロファイルをしているのか、その仕組みを掴んでおくことにします。事前に予告しておきますが、本当に眺めて見学するだけです。さらに深くソースコードを追いかけたい時のとっかかりにでも使ってください。とはいえ、プロファイラの中身について言及している記事はインターネッツ上にあんまりないので、今回このように記事を書いております。

マルチスレッドのプログラムを手っ取り早くプロファイルしたい人は、読み飛ばして次の「マルチスレッドで走るPythonプログラムをプロファイルするには?」へ進むのも良いかもしれません。

さて。コンソールからpython -m cProfile test.pyを実行すると、cProfile.Profilerの次の関数が最終的には呼ばれます:

# https://github.com/python/cpython/blob/fcd5e84a515e19409840c570730f0728e9fcfc83/Lib/cProfile.py#L97

    def runctx(self, cmd, globals, locals):
        self.enable()
        try:
            exec(cmd, globals, locals) # コマンドライン引数で指定されたファイルの中の文字列を実行する
        finally:
            self.disable()
        return self

exec関数はいわゆるeval関数の親戚で、与えられた文字列(cmd)を、所定の環境の下で実行する組み込み関数です。となると、その周囲を囲うenable/disableが重要そうです。

self.enableの実態を追いかけていくとC言語の関数に行き着きまして:

// https://github.com/python/cpython/blob/62be74290aca26d16f3f55ece7ff6dad14e60e8d/Modules/_lsprof.c#L683

static PyObject*
profiler_enable(ProfilerObject *self, PyObject *args, PyObject *kwds)
{
    int subcalls = -1;
    int builtins = -1;
    static char *kwlist[] = {"subcalls", "builtins", 0};
    if (!PyArg_ParseTupleAndKeywords(args, kwds, "|ii:enable",
                                     kwlist, &subcalls, &builtins))
        return NULL;
    if (setSubcalls(self, subcalls) < 0 || setBuiltins(self, builtins) < 0)
        return NULL;
    PyEval_SetProfile(profiler_callback, (PyObject*)self);
    self->flags |= POF_ENABLED;
    Py_RETURN_NONE;
}

いちばん重要なのは、PyEval_SetProfileの呼び出しだと思います。これはpythonインタプリタの提供するプロファイルのための関数を設定する関数で、cProfileはこの言語処理系の機能をそのまま使っています。ちょっと面白いのは、この関数は外部に公開された、つまり(中の人でなくても)誰でも使えるC言語の関数なことで、やろうと思えば誰でも「ぼくのかんがえたさいきょうのプロファイラ」が作れるということになります。

さて、そのPyEval_SetProfileのソースも見てみましょう:

// https://github.com/python/cpython/blob/8479a3426eb7d1840473f7788e639954363ed37e/Python/ceval.c#L4371

void
PyEval_SetProfile(Py_tracefunc func, PyObject *arg)
{
    PyThreadState *tstate = _PyThreadState_GET();
    PyObject *temp = tstate->c_profileobj;
    Py_XINCREF(arg);
    tstate->c_profilefunc = NULL;
    tstate->c_profileobj = NULL;
    /* Must make sure that tracing is not ignored if 'temp' is freed */
    tstate->use_tracing = tstate->c_tracefunc != NULL;
    Py_XDECREF(temp);
    tstate->c_profilefunc = func;
    tstate->c_profileobj = arg;
    /* Flag that tracing or profiling is turned on */
    tstate->use_tracing = (func != NULL) || (tstate->c_tracefunc != NULL);
}

一行目のPyThreadState_GETはスレッドごとに違うPyThreadStateオブジェクトを返す関数(参考:スレッド局所記憶)です。なので、プロファイラの関数はスレッドごとに設定されます。というわけで、python -m cProfile test.pyで測定した時は、メインスレッド以外の別のスレッドに関してはやっぱり一切計測しません

tstate->c_profilefuncに設定される関数は、C言語とPythonの関数のCALL/RETURNの時に呼ばれるようになっていまして、cProfileでプロファイルを取る時の関数もその情報を使って集計しているのがわかります。

実際にこの関数が呼ばれているところも追いかけておきましょう。

PythonからPythonの関数の呼び出し

Pyrhonの関数のCALL/RETURNに関しては、関数の本体(のバイトコード)を実行する_PyEval_EvalFrameDefaultというインタプリタの核心部みたいな関数の最初と最後で呼ばれます:

# https://github.com/python/cpython/blob/842a2f07f2f08a935ef470bfdaeef40f87490cfc/Python/ceval.c#L940

        if (tstate->c_profilefunc != NULL) {
            /* Similar for c_profilefunc, except it needn't
               return itself and isn't called for "line" events */
            if (call_trace_protected(tstate->c_profilefunc,
                                     tstate->c_profileobj,
                                     tstate, f, PyTrace_CALL, Py_None)) {
                /* Profile function raised an error */
                goto exit_eval_frame;
            }
        }
    }

# https://github.com/python/cpython/blob/842a2f07f2f08a935ef470bfdaeef40f87490cfc/Python/ceval.c#L3575

return_or_yield:
    if (tstate->use_tracing) {
        if (tstate->c_tracefunc) {
            if (call_trace_protected(tstate->c_tracefunc, tstate->c_traceobj,
                                     tstate, f, PyTrace_RETURN, retval)) {
                Py_CLEAR(retval);
            }
        }
        if (tstate->c_profilefunc) {
            if (call_trace_protected(tstate->c_profilefunc, tstate->c_profileobj,
                                     tstate, f, PyTrace_RETURN, retval)) {
                Py_CLEAR(retval);
            }
        }
    }

この関数は、Pythonで書かれた関数を実際に実行するコードです。バイトコードの実行ループがあるので(今回の話とは一切無関係ですが)読んでいて面白い関数ではあります。おすすめです。

PythonからC言語の関数呼び出しは別扱い

C言語の関数の呼び出しは、もうちょっと複雑です。Pythonの内部で使われているVMのオペコードのうち、CALL_METHOD/CALL_FUNCTION/CALL_FUNCTION_KW/CALL_FUNCTION_EX命令が実行された時に呼ばれる、次の関数からC言語の関数の実行が移譲されています:

// https://github.com/python/cpython/blob/842a2f07f2f08a935ef470bfdaeef40f87490cfc/Python/ceval.c#L4648

/* Issue #29227: Inline call_function() into _PyEval_EvalFrameDefault()
   to reduce the stack consumption. */
Py_LOCAL_INLINE(PyObject *) _Py_HOT_FUNCTION
call_function(PyObject ***pp_stack, Py_ssize_t oparg, PyObject *kwnames)
{

    // ... 前処理 ...

    /* Always dispatch PyCFunction first, because these are
       presumed to be the most frequent callable object.
    */
    if (PyCFunction_Check(func)) {
        PyThreadState *tstate = _PyThreadState_GET();
        C_TRACE(x, _PyCFunction_FastCallKeywords(func, stack, nargs, kwnames));
    }
    else if (Py_TYPE(func) == &PyMethodDescr_Type) {
        PyThreadState *tstate = _PyThreadState_GET();
        if (nargs > 0 && tstate->use_tracing) {
            /* We need to create a temporary bound method as argument
               for profiling.
               If nargs == 0, then this cannot work because we have no
               "self". In any case, the call itself would raise
               TypeError (foo needs an argument), so we just skip
               profiling. */
            PyObject *self = stack[0];
            func = Py_TYPE(func)->tp_descr_get(func, self, (PyObject*)Py_TYPE(self));
            if (func != NULL) {
                C_TRACE(x, _PyCFunction_FastCallKeywords(func,
                                                         stack+1, nargs-1,
                                                         kwnames));
                Py_DECREF(func);
            }
            else {
                x = NULL;
            }
        }
        else {
            x = _PyMethodDescr_FastCallKeywords(func, stack, nargs, kwnames);
        }
    }
    else {
        // ... Pythonの関数のときの処理 ...
    }

    // ... 後処理 ...

    return x;
}

この最初の2つのif文がC言語で書かれた関数ないしメソッドの呼び出しに対応しているようです。2番めのPy_TYPE(func) == &PyMethodDescr_Type の方は、調べた限りでは、

>>> po = "po!"
>>> f = po.upper
>>> f()
'PO!'

のような感じで、メソッドにselfだけ束縛した場合に実行される分岐のようです(あんまり自信ない)。

C_TRACEというマクロの定義は次の通りで、callという引数で指定されるC言語関数呼び出しコールの前後でPyTrace_C_CALLとPyTrace_C_RETURNをプロファイラのコールバック関数に対して通知するようになっています。

// https://github.com/python/cpython/blob/842a2f07f2f08a935ef470bfdaeef40f87490cfc/Python/ceval.c#L4617

#define C_TRACE(x, call) 
if (tstate->use_tracing && tstate->c_profilefunc) { 
    if (call_trace(tstate->c_profilefunc, tstate->c_profileobj, 
        tstate, tstate->frame, 
        PyTrace_C_CALL, func)) { 
        x = NULL; 
    } 
    else { 
        x = call; 
        if (tstate->c_profilefunc != NULL) { 
            if (x == NULL) { 
                call_trace_protected(tstate->c_profilefunc, 
                    tstate->c_profileobj, 
                    tstate, tstate->frame, 
                    PyTrace_C_EXCEPTION, func); 
                /* XXX should pass (type, value, tb) */ 
            } else { 
                if (call_trace(tstate->c_profilefunc, 
                    tstate->c_profileobj, 
                    tstate, tstate->frame, 
                    PyTrace_C_RETURN, func)) { 
                    Py_DECREF(x); 
                    x = NULL; 
                } 
            } 
        } 
    } 
} else { 
    x = call; 
}

ここ以外にももっと複雑な関数呼び出しのためのdo_call_core関数もあるのですが、そっちもだいたい似た感じなので省略します。

Pythonの関数のCALL/RETURNは、呼び出された関数の中で記録されるのに対して、C言語の方は呼び出す直前なところがちょっと面白いところでしょうか。もちろん、C言語の関数はPythonのインタプリタから遠く独立していることを踏まえれば、合理的な実装だと思います。

オチはなし:意外と素朴な実装だったなぁ(小学生並みの感想)

…えー、とくにオチはないです。強いて言うなら、意外と素朴な実装でしたね。Linuxカーネルのよくわかんない機能とか使ってるのかなぁという予想も事前にしていたのですが、そんな事はなくて、地道に適当なタイミングで適切に関数を呼び出して記録しているだけでした。

cProfileとprofileの具体的な違いは?

Pythonでプロファイルを取る方法は、cProfileだけではなく、profileというのもあります。こちらは100% Pure Pythonで、cProfileが使えない環境ではこちらを使ってね、とドキュメントには書いてあります。こちらはどのような実装になっているのでしょうか?Pythonのインタプリタの奥深くにプロファイルのための機能が実装されている以上、profileもこれを使っていそうな気はするんですが…。

コードを調べると:

# https://github.com/python/cpython/blob/ad1a25f499362eaf9cbfcafa0b8e2454eb43dcf1/Lib/profile.py#L418

    def runctx(self, cmd, globals, locals):
        self.set_cmd(cmd)
        sys.setprofile(self.dispatcher)
        try:
            exec(cmd, globals, locals)
        finally:
            sys.setprofile(None)
        return self

案の定、sys.setprofileという、PyEval_SetProfileのPython版を使って、C言語の関数ではなくPythonの関数をcallbackとしているだけのように読めます。

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

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

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

Python プロファイラ — Python 3.7.3rc1

cProfileのコードはそんなにトリッキーな事をしているようには読めないので、cpythonがコンパイルできる環境ならcProfileも使えると思うんですが、cProfileが使えない環境は実際にあるのだろうか…。

いかがでしたか?

「だからなんだ」と言われればそれでオシマイなんですが、ソースコードを読むのはやっぱり重要だと痛感しました。ドキュメントにはすべては書いてないので。この記事が、いつか、cProfileの挙動に違和感を持った人の参考になりますように。

というわけで、次の記事では、マルチスレッドのPythonプログラムをプロファイルする方法を探していきます。

GPUを使って無線LANをクラックする話 / モニター、ロック、スケーラビリティ

弊社は最近、それまでの神谷町(東京タワーの近く)から、神田と秋葉原の間くらいに引っ越しをしました。とは言っても、去年の夏の終わりぐらいなので、だいぶ前なのですが。

オフィスの立地で重要なことって、何でしょう。駅からの距離?ビルの高さ?地名のブランド?歓楽街からの近さ?ランチ営業をやってるレストランの多さ?

みなさま、各々重視する点があると思うのですが、「一番近いコンビニが何か」は意外と見過ごされるところではないでしょうか。朝ちょっと寄ってコーヒーを買ったり、お弁当を買ったり。結構お世話になる所だと思います。

というわけで今月の写真は「セブンイレブンのカフェラテ・マシンの『顔』」です。いままでの所は一番近いコンビニが「セブン・イレブン」だったのが「ファミマ!」になってしまって、この眉毛のかわいい顔が見れなくちゃってさ。ちょっとさびしいよね。

…という世間話(?)をしたら、「へ、へぇ…(困惑)」って言われました。

コミュニケーション、難しいね!

前回までのあらすじ

前回分かってしまったことは、仕事を要求するCPUやGPUが増えれば増えるほど、パスワードの解析を依頼する役割を担うPythonのメイン・スレッドは、ロックの取り合いで時間を使い潰すようになってしまうということでした。ここを改善すれば、CPUやGPUがもっと活用できるかも。

このロックは、実際にはどのように使われているのでしょうか?ちょっとここで、Pyritで仕事が分配される様を眺めてみましょう。

Pyritでの「流れ作業」の様子を見学する

Pyritのベンチマークモードでは、メインのPythonスレッドで候補となるパスワードを生成した後に、それらをCPUやGPUに分配しています。で、並列に計算された結果は再度メインのスレッドでCPyritクラスが受け取る、という流れ作業になっています。その流れを見ていきましょう。

仕事の受付け

CPyrit.enqueueに渡されます。このメソッドは、パスワードを生成するPythonのメインスレッドから呼ばれます:

    def enqueue(self, essid, passwords, block=True):
        with self.cv:
            # ... 省略 ...
            passwordlist = list(passwords)
            if len(self.inqueue) > 0 and self.inqueue[-1][0] == essid:
                self.inqueue[-1][1][self.in_idx] = passwordlist
            else:
                self.inqueue.append((essid, {self.in_idx: passwordlist}))
            self.workunits.append(len(passwordlist))
            self.in_idx += len(passwordlist)
            self.cv.notifyAll()

self.cvはthreading.Conditionで、いわゆるモニターと呼ばれている排他制御のためのしくみ、です。「モニタ」って言葉は改めて聞くことはあんまり無い気がするんですが、Javaでおなじみのwait/notify/notifyAllのアレといえば通じる人もいるかもしれません。なにはともあれ、with self.cv: とすることで、このブロックの中のコードが実行されるスレッドが高々1つになるように制御しています。その後の処理は基本的には仕事をself.inqueueその他に適切にセットしているだけ、です。

適切に情報をセットしたら、self.cv.notifyAll() して他のスレッドにnotify(通知)します。具体的に何が起こるのかというと、with self.cv: の中でself.cv.wait() している他のスレッドが全て起こされます。じゃあwith self.cv: しているのは何箇所かというと、これを含めてなんと7箇所もあります。今回はそのうち、たくさん使われていそうなコードパスを眺めていきます。

仕事の受取り

inqueueに入れられた仕事は、CPUやGPUの各スレッドからCPyrit._gatherというメソッドを呼ぶことで受け取られます:

    def _gather(self, desired_size, block=True, timeout=None):
        t = time.time()
        with self.cv:
            passwords = []
            pwslices = []
            cur_essid = None
            restsize = desired_size
            while True:
                self._check_cores()
                for essid, pwdict in self.inqueue:
                   # ... passwordsを埋め、self.inqueueからそのぶん削除する処理 ...
                if len(passwords) > 0:
                    wu = (cur_essid, tuple(passwords))
                    try:
                        self.slices[wu].append(pwslices)
                    except KeyError:
                        self.slices[wu] = [pwslices]
                    self.cv.notifyAll()
                    return wu
                else:
                    if block:
                        if timeout is not None and time.time() - t > timeout:
                            return None, None
                    else:
                        return None, None
                    self.cv.wait(0.1)

self.inqueueからself.slicesに情報を移しつつ(self.slices[wu] = … )、WorkUnitである(ESSID, passwords)のタプルをCPUやGPUのために返します。この情報を使って、CPUはSSEを、GPUはCUDAやOpenCLを使って結果(results )を計算します。今回は情報のやり取りだけに注目するので、実際にどのように計算をするのかは省略する三分クッキング方式で次に進みましょう。

計算した結果を通知するために使われるのが次の_scatter メソッドです:

結果の受付け

CPUやGPUの各スレッドで計算された結果は、CPyrit._scatterメソッドを使って集められます:

    def _scatter(self, essid, passwords, results):
        assert len(results) == len(passwords)
        with self.cv:
            wu = (essid, passwords)
            slices = self.slices[wu].pop(0)
            if len(self.slices[wu]) == 0:
                del self.slices[wu]
            ptr = 0
            for idx, length in slices:
                self.outqueue[idx] = list(results[ptr:ptr + length])
                ptr += length
            for idx in sorted(self.outqueue.iterkeys(), reverse=True)[1:]:
                res = self.outqueue[idx]
                o_idx = idx + len(res)
                if o_idx in self.outqueue:
                    res.extend(self.outqueue[o_idx])
                    del self.outqueue[o_idx]
            self.cv.notifyAll()

self.slicesの情報を消費・削除しつつ、self.outqueue に結果を載せています。難しいところはないですね。

結果の受取り

最後に、Pythonのメインスレッドが、CPyrit.dequeueメソッドを使ってCPUやGPUの各スレッドがパスワードを受取ります:

    def dequeue(self, block=True, timeout=None):
        t = time.time()
        with self.cv:
            if len(self.workunits) == 0:
                return None
            while True:
                wu_length = self.workunits[0]
                if self.out_idx not in self.outqueue 
                 or len(self.outqueue[self.out_idx]) < wu_length:
                    self._check_cores()
            # ... 十分な数の結果が得られない時に待つ処理 ...
                else:
                    reslist = self.outqueue[self.out_idx]
                    del self.outqueue[self.out_idx]
                    results = reslist[:wu_length]
                    self.out_idx += wu_length
                    self.outqueue[self.out_idx] = reslist[wu_length:]
                    self.workunits.pop(0)
                    self.cv.notifyAll()
                    return tuple(results)

self.outqueue から結果を適切に取り出してself.outqueue から削除して、結果をreturnするだけです。

ここから更にCrackerがクラックに成功したかの判定をするわけですが、benchmarkではその処理は省略されているので、今回もここで止めておきます。

ここまでの観察

self.inqueue とself.outqueue の2本のキューがあることがわかりました。inqueueはパスワードを、outqueueにはパスワードから計算した結果をやり取りするために使われています。

しかし、それらを保護するためのthreading.Conditionは2つ…ではなく、1つのself.cv だけです。つまり、実際にはself.inqueueしかいじっていなくても、self.outqueueのための保護も同時に行っていることになります。…なんだか、無駄な感じがしませんか?それぞれのために2つthreading.Conditionを作って管理できないんでしょうか?

しかしながら、これは言うのは簡単なんですが、実際にやるのは難しそうです。まず、self.inqueueとself.outqueueは実は完全に独立しているわけではありません。_scatterや_gatherでいじられるself.slicesを介して微妙に両者は繋がっています。なので、実はCondition変数を2つそのまま使うだけでは正しくモニターを分割できません。self.slices用の排他制御も作りこめば分割できます。が、そういう事をするとデッドロックが起きがちなので、正直避けたい。

Pythonはシングルスレッドでしか動かないので、それぞれのQueueのためにthreading.Conditionを2つにわけられたとしても、Javaの時と違って2スレッドが並列で動くようになったりはしません。が、同じConditionを取り合うことはなくなるので、性能の向上が見込まれる…かもしれません。ロックは一般にスケーラブルではない(待機するスレッドの数が増えれば性能が悪化する)からです。

今回はプロファイリングの結果から言ってあまり実益は無さそうなのですが、もしConditionが2つに分割できればself.cv.wait() が無駄に起こされる回数が減るのは間違いない、ということはコメントさせてください。上のself.cv.wait() をしているコードを丹念に眺めてもらうと分かるのですが、無駄に起こされる事に備えて、特定の条件が満たされているかチェックして、条件が満たされてなかったら「やっぱ駄目じゃん!」と叫びながらもう一度眠りにつくようになっています(これ自体は一般的な使い方です)。さらに余談ながら、この「無駄に起こされるスレッド」が存在するので、self.cv.notify() ではなく、self.cv.notifyAll() を使わねばなりません。もしself.cv.notify()を使ってしまったら、運悪く無関係なスレッドだけが起きて、もう一度self.cv.wait() で眠りにつき、その後は何も起こらなくなり、永遠に応答しなくなってしまう可能性があります。

待機するのは最大何スレッド?

ついでに、with self.cv:self.cv.wait()で待つことになるスレッドの数を概算しましょう。CPUは48スレッド、GPUは4スレッドと仮定します。

  • enqueue:たかだか1スレッド(Pythonのメインスレッド)
  • _gather:最大52スレッド(CPU48コア + GPU4コア)
  • _scatter:最大52スレッド(CPU48コア + GPU4コア)
  • dequeue:たかだか1スレッド(Pythonのメインスレッド)

各スレッドが同時に2つのメソッドで待機することはないので、全体でもself.cvを取り合うのは最大53スレッドと思って間違いないと思います。

ふーむ。ここまで観察したので、次はwith self.cv:self.cv.wait()で待つ時、なにが行われているのか観察しましょう。このthreading.Conditionのソースは、Python本体にあるのでそちらを参照していきます。

threading.Conditionの中を眺める

with self.cv:って具体的に何をしているの?

この↑文字列を書いた時、実際にはself.cv.__enter__という関数が呼ばれます(これはPythonでのお約束です)。で、実装はこんな感じです

    def __enter__(self):
        return self._lock.__enter__()

self._lockはRLock(再入可能ロック)で、この関数はさらにC言語で実装されておりまして

static PyMethodDef rlock_methods[] = {
    {"acquire",      (PyCFunction)(void(*)(void))rlock_acquire,
     METH_VARARGS | METH_KEYWORDS, rlock_acquire_doc},
//....
    {"__enter__",    (PyCFunction)(void(*)(void))rlock_acquire,
     METH_VARARGS | METH_KEYWORDS, rlock_acquire_doc},
// ...
};

__enter__はacquireと同じ関数で、rlock_acquireです。

その先の実装は結構複雑そうですので一端置いておきます。pthreadとか適当にwrapしてるだけかと思ったけどそんなことは無い。

self.cv.wait()は実際には何を待っているのか?

with self.cv:の中では必ずself.cv.wait()を呼ぶことで他のスレッドが処理するのを待っています。この処理は何をしているのかというと

    def wait(self, timeout=None):
        # ... 前処理 ...
        waiter = _allocate_lock()
        waiter.acquire()
        self._waiters.append(waiter)
        saved_state = self._release_save()
        gotit = False
        try:    # restore state no matter what (e.g., KeyboardInterrupt)
            if timeout is None:
                waiter.acquire()
                gotit = True
            else:
                if timeout > 0:
                    gotit = waiter.acquire(True, timeout)
                else:
                    gotit = waiter.acquire(False)
            return gotit
        finally:
            self._acquire_restore(saved_state)
            if not gotit:
                try:
                    self._waiters.remove(waiter)
                except ValueError:
                    pass

新しくlockを作り、このロックに対して二度acquireをしています。このロックは再入可能ではないので、この2度めのacquireでスレッドは必ず中断されて、ほかのスレッドが代わりに起こされます。で、その起こされた別のスレッドがnotifyした時にロックがreleaseされて、二度目のロック以降の中断されたプログラムが実行される、という仕組みになっている、と。

notify/notifyAllするときにはロックに対するacquireは行われません。releaseだけ行います。前回ロックのacquireで時間を使い切っていることがわかりましたが、つまり、時間を食ってるのはこのwith self.cv:の中のacquireか、self.cv.wait()の中のacquireのどちらか、ということになります。

ロックに掛かる時間の内訳を見る

条件lockのacquireをした回数(掛かった時間)with self.cv:した回数(掛かった時間)self.cv.wait()を呼び出した回数(掛かった時間)
1cpu/0gpu1963回(0.514秒)204回(0.002秒)51回(69.438秒)
48cpu/0gpu7355回(3.202秒)1781回(1.988秒)756回(66.133秒)
0cpu/4gpu5689回(7.122秒)5645回(6.685秒)8回(0.762回)
48cpu/4gpu5113回(44.287秒)4676回(43.910秒)309回(3.161 秒)

回数がいまいち釣り合わない気がするんですが(0cpu/4gpuのself.cv.wait()の呼び出しがたった「8回」って本当かいな??)、仕事をとりあえば取り合うようになるほどwith self.cv: を実行する回数が増え、実行時間も掛かるようになっていくことが読み取れます。で、このwith self.cv:は、新しく生成したロックに対して獲得(acquire)しようとするwait()の時と違って、1つのself.cv._lock を獲得しようとしています。

これらの観察結果から、次の仮定を立てます:「with self.cv: したときに起こるself.cv._lock の取り合いがボトルネックの1つである」。

ここ、なんとかならないんでしょうか。次回実験してみましょう。

余談ですが、CPUだけで実行している時、どちらもself.cv.waitに60秒以上掛かっていますが、これらは実際には概ねthread.Sleepの実行に費やされています(つまりスレッドがやることなくて完全に遊んでいる)。

今月のまとめ

  • Pyritのパスワード候補と結果のリスト(inqueue/outqueue)は、threading.Condition(モニター)を使って排他制御されている
  • モニターは複数のロックを使って制御されている:
    • モニター自体のロック(cv._lock)
    • 待機しているスレッドを起こすためのロック(cv.wait()の中で生成されるwaiterという名前のロック)
  • プロファイリングの結果、モニター自体のロックを獲得しようとするスレッドが増えた結果として時間を使い潰していそう
    • このモニターでの排他制御を改善したら全体の性能も改善してくれないかなぁ

明日から東京では花粉が飛散しはじめるそうです。花粉症の方も、まだそうでない方も、みなさまお気をつけて!

GPUを使って無線LANをクラックする話:帰ってきたPyrit

次から次へと生まれ続ける「新技術」。今日もまた、「今後ITエンジニアに必要な技術はこれだ!」「キャッチアップ!」「未来が変わる!」と迫ってきます。たしかに、どれもすごい技術なのには間違いなさそうです。

しかしながら、疲弊してきているのも正直なところ本音ではないでしょうか。

…本当に身に付けたい能力ってなんだろう。

このタンポポの隣を通るたびに、いつもわたしは思うのです。

コンクリートの間のわずかな土で、光合成をしながら、冬の寒さにも負けずに、花を咲かせて生きる。

うん、わたしにもこの能力が欲しい!

こう書いてみると、そこらのラノベの主人公のチートな能力よりチートですね、タンポポ。

帰ってきたPyrit

というわけで、前々回山の上で瞑想して考えた「ぼくの考えた最強のベンチマーク・ルール」にしたがってガンガンPyritを書き換えていきましょう。この影響でPyritのリポジトリの構成が諸々変わっているので、使ってる人がいたら気をつけてください(居ないと思うけど)。

現状の問題を煮詰めると、次の2つでした:

  • 以下の処理が、すべてCPUを取り合っている:
    • ランダムなパスワードを生成する処理
    • パスワードをSHA1とかごにょごにょして変形するsolveの処理(GPUにもオフロードされるたぶん一番重い処理)
    • solveした結果とパケットダンプを突き合わせて、パスワードが正解かチェックするCrackerの処理(CPUのみ)
    • GPUのためにデータを詰めて渡す処理
  • CPUとGPUのsolverが、シングルスレッドで生成される「パスワード」の仕事を奪い合っている

というものでした。最初の問題のせいで、CPUやGPUの真の実力がわからず、2つめの問題のせいでマシン全体の実力がわかりません。GPUが1%ぐらいしか使われていなかった衝撃を思い出しておきましょう。

後者のほうはかなり厄介な問題な気がします。というのも、現在のパスワード生成処理は次の極めて簡素なコードで書かれており、小手先の最適化では立ち向かえそうにないからです:

            while time.time() - t < timeout:
                pws = ["barbarbar%s" % random.random() for i in xrange(bsize)]
                cp.enqueue('foo', pws)
                r = cp.dequeue(block=False)
                if r is not None:
                    perfcounter += len(r)
                self.tell("rRunning benchmark (%.1f PMKs/s)... %s" % 
                        (perfcounter.avg, cycler.next()), end=None)

これ1.5倍速くするのは…まぁ…ギリギリ可能かもしれませんが…100倍は無理じゃん?

これらを踏まえつつ、今日はCPUやGPUだけ単体で走らせて測定してみて、何がどうボトルネックになっているのか探っていきましょう。そうすれば、パスワードを今の何倍の速度で生成してやればいいのかのヒントも得られるはずです。

CPUに本気を出してもらう

ベンチマークで測っているのは、一番重い(であろう)solveの処理です。デフォルトではsolveの処理スレッドはCPUのコア数分立ち上がるのですが、CPUは他の処理もしないといけないので、CPUを占有してsolveに専念することができませんし、同じようにCPUで生成されているパスワードも取り合ってしまうでしょう。そこで、立ち上げるスレッドの数を減らします。

.pyrit/configにあるlimit_ncpusでその設定が出来るので、これを減らしていって何が起こるのか調べます:

~/.pyrit$ cat config 
default_storage = file://
limit_ncpus = 0
rpc_announce = true
rpc_announce_broadcast = false
rpc_knownclients = 
rpc_server = false
use_CUDA = false
use_OpenCL = false
workunit_size = 75000

オリジナルのバージョンはlimit_ncpus = 0を指定したときは「デフォルト」扱いになってCPUのコア数分(このマシンでは48個)立ち上がるようになっていたのですが、後でGPUだけで実行するときのために、0を指定したときは本当に0個スレッドを立ち上げる(つまりCPUを一切使わない)ように変更しました(ちなみに、CUDAもCPUも使わない場合、フリーズします)。

測ってみた結果がこちら(PMKというのがいわゆる「パスワード」です):

ncputotal PMK/saverage PMK/s
1989.66989.66
22015.591007.795
43811.58952.895
87264.9908.1125
1613800.76862.5475
3217994.36562.32375
4818600.49387.5102083

で、グラフにするとこんな感じ:

16コアくらいまではだいたいスケールする(16倍とはいかないが、13倍くらいにはなる)んですが、32コアで突然頭打ちになって、コアあたりのパフォーマンスががくっと下がり、だいたい1.8万PMK/secぐらいで張り付きます。というわけで、これが現在のパスワード生成処理の限界なのでは?という仮説が立ち上がります。

GPUに本気を出してもらう

PyritはCUDAをデフォルトでは「全部使う」ようになっているので、これも1台ずつだけ使えるようにしてみました。CPUも一切使わず、GPU1台だけでクラックしていただきます。

で、やってみた結果がこちら:

デバイス名PMK/sec
Tesla V100-PCIE-16GB#1236335
Tesla V100-PCIE-16GB#2232217.35
GeForce GTX 1080 Ti#1222854.14
GeForce GTX 1080 Ti#2222457.37
全部一緒に動かす256639.55
CPUも全部同時に動かす136911.19

桁が多くて目が痛いのですが、単体で走らせた時に22〜23万PMK/sec、全部一緒に動かした時には25万PMK/secぐらい出ております。

これはつまり、あのパスワード生成コードは25万PMK/secは生成できているという事ですね。

…あれ?

ついでにいうと、CPUもGPUも同時に動かすと13万PMK/secという事で半分の速度にまで遅くなってしまいます。CPUとGPUで同時に処理して加速するはずだったのに、足を引っ張りあうのか、減速しております。

…あれ?デフォルトではCPUなしで実行できないし、ひょっとして、これ、誰も気づいてないんでは…。

結局、システム全体のポテンシャルはどれぐらいあるのか?

前に使ったProfilerをもっかい動かして、GPUを何割使ってるのか計測します:

Computed 225057.65 PMKs/s total.
CUDA:
#1: 'CUDA-Device #1 'Tesla V100-PCIE-16GB'': 237348.4 PMKs/s (RTT 0.5)
==41597== Profiling application: venv/bin/python pyrit benchmark
==41597== Profiling result:
            Type  Time(%)      Time     Calls       Avg       Min       Max  Name
 GPU activities:   99.08%  26.9879s       116  232.65ms  27.573ms  270.97ms  cuda_pmk_kernel
                    0.53%  143.46ms       116  1.2367ms  2.1760us  2.9881ms  [CUDA memcpy HtoD]
                    0.40%  108.18ms       116  932.60us  2.3360us  2.7747ms  [CUDA memcpy DtoH]
      API calls:   96.48%  27.1509s       116  234.06ms  27.585ms  272.31ms  cuMemcpyDtoH
                    1.88%  530.46ms         1  530.46ms  530.46ms  530.46ms  cuCtxCreate
                    0.54%  153.24ms       116  1.3211ms  27.996us  3.5144ms  cuMemcpyHtoD
                    0.47%  133.17ms         1  133.17ms  133.17ms  133.17ms  cuCtxDestroy
...

ベンチマークの時間は45秒、そのうちの27秒ほどを使っており、なかなかいい感じです。皮算用をしてみると、理想的な状況下ではGPU一枚あたり30万PMK/secぐらい出てもおかしくないと思います。で、4台あるので全体では120万PMK/sec出てほしい。

CPUは全体で理想的には4.8万PMK/sec出そうでしたから、合計すると125万PMK/secぐらいが理論的な限界値ではないかと皮算用できます。

あくまで皮算用ですけど。

原理的にパスワードはどれくらいの速度で生成できるのか?

ボトルネックだと思っていたパスワード生成はどうやらボトルネックではなさそうです。それを確かめるために、Pyritのコードから抜き出して加工した次のソースで測定します:

import time
import random

cnt = 0
t = time.time()
timeout = 30
while time.time() - t < timeout:
  pws = ["barbarbar%s" % random.random() for i in xrange(50000)]
  cnt += len(pws)

total = time.time()-t
print(cnt / total)

結果は268万PMK/secと出ました。うん、ボトルネックじゃないよここ…「推測はよくない」の例がまた一個増えましたね。…orz

とはいえ、皮算用したボトルネックのだいたい倍ぐらいの速度でしかなく、Pythonとその周辺コードはシングルスレッドでしか走らないことを踏まえると、最終的にボトルネックとして立ちはだかる可能性はまだ十分残されているでしょうな。

今月のまとめと来月の予告

  • CPUだけで走らせると、16コアと32コアの間で速度が頭打ちになる
  • GPUだけで走らせると、CPUとGPUを同時に走らせるより速い
  • 理想的なシステム全体のパフォーマンスは125万PMK/sec程度だと思われるが、パスワードの生成速度はそれをはるかに上回っているのでボトルネックではなさそう

以上の観察を踏まえるに、どうやら問題は最初の問題、つまり「CPUを取り合っている」の問題に尽きそうです。

次回はPythonのプロファイラーを使って、どこで詰まっているのかを調べましょう。

よいお年を〜。たんぽぽには、人間の暦なんか、関係ないけどね。

GPUを使って無線LANを(略) 番外編 GPUなしでCUDAは動かせるのか?

紅葉への切り替わり中です。秋って感じですね。

でも町を歩いていると、8月末くらいには紅葉のポスターが貼られだして、ハロウィン一色になったなぁ、と思ったら、今はもうクリスマス一色です。町から紅葉の絵はなくなり、雪の結晶やクリスマスツリーの絵ばかり。気が早えぇなぁ、人間。

わたしは最近こういう「イメージ」も「拡張現実」の一種なんじゃ無いかと感じています。ARゴーグルだけが「拡張現実」では、ないんじゃない?

みなさんはどう思います?

…と聞いてみるにもコメント欄ないんだったわ、このブログ。トラックバックもない。…時代は変わってしまったなぁ。

GPUサーバがない!

というわけで、前回山の上で瞑想して考えた「ぼくの考えた最強のベンチマーク・ルール」にしたがってガンガンPyritを書き換えていきたいところ…なのですが、なんと今回はオトナの事情により、GPUサーバは使えないらしいのです。かなしい。

しかし、案ずることなかれ。

こんな事もあろうかと、もう2枚ほどGeForce 1080を用意しておきました。

これをどこのご家庭にもある、PCI-Express用の電源ポートがなぜか10個あってPCI-Express x16のスロットがなぜか4つあるデスクトップパソコンに刺してPyritの改造をしていきましょう。

がっちゃん(GPUを突き刺す音)

カチッ(電源を押す音)

ブワー(電源がつきファンが回る音)

ピカピカピカ(1680万色に光るゲーミングマザーボードのLED)

…(しかしモノリスのように真っ黒なまま沈黙するモニタ)

…(その前でなす術もなく立ち尽して一緒に沈黙する筆者)

…(なす術もなく立ち尽くす筆者)

……(立ち尽くす筆者)

…………

……………はぁ〜〜〜〜〜〜〜

なんで画面が出ないんだよ〜〜〜〜〜〜〜〜

グラフィック・ボード」じゃなかったのかよ〜〜〜〜〜〜〜

…嘆いていてもしょうがないので、GPUなしでなんとかする方法を考えましょう。

遅くてよいので、CPUだけでCUDAのコードを動かせないものか…。

原理的には可能なはずですよね。CUDAはただ計算が早くなったり(ならなかったり)するだけの技術ですから。同じPCIeの拡張カードでも、真の乱数発生ボードと違って、原理的にはエミュレーションできる事は明らかです。原理的には、だけどね。

わたくし結構macでノマドもするので、できればLinuxだけじゃなくてmacでも動いて欲しいなぁ(欲を出しておく)。

あーそうそう、画面が出ない理由ですが、Radeonと一緒に刺すとダメみたいです。グラボのバグなのか、Linuxのバグなのか、その辺は、よくわからない。

代案を調べる

代案 その1:gpuocelot

gpuocelot公式サイトより引用

gpuocelotは、CUDAの実行ファイルであるPTXをnVidiaのGPUだけでなく、AMDのGPUやCPUで直接実行したり、エミュレーションしたり、ネットワーク経由で他のマシンのGPU(やCPU)で実行したりできるようにするぜ!というそのものズバリわたしが求めていたソフトウェアです。

が、公式サイトいわく「The GPU Ocelot project is no longer actively maintained.」ということで開発終了。まぁ大学製ソフトなので、資金が尽きたのか論文書き尽くしたのか、まぁ、そんな所でしょうか。しかも最後の論文が2014年なのであまり期待はできなさそうです。

あと個人的なプログラマ、あるいは大学院生しての直感が告げているのですが、こんな野心的なソフト、本当に安定して動くのかな…論文書くための機能が一応動いてるだけじゃないかな…という疑念が正直あります。

はい次。

代案 その2: MCUDA

The MCUDA translation framework is a linux-based tool designed to effectively compile the CUDA programming model to a CPU architecture.

IMPACT: MCUDA Toolset

こちらも大学製。何か書くにも、一切ドキュメントがない。

はい次。

代案 その3:CUDA Waste

GPUocelotはLinux専用らしく(gpuocelotのページにはそんな事書いてなかったけどな!)、そのためにWindows用に同じようなソフトウェアを開発したのがこちらだそうです。こちらもだいぶ前から更新がないので実用は難しそう。あとわたしWindows持ってない。

はい次。

代案その4: CU2CL

CUDAのソースコードをOpenCLのソースコードに変換するというソフトウェア。今までのソフトウェアに比べると大分「現実的」な落とし所なような気はします。

が、実際にこれを使おうとすると、CUDAを実行していた部分をOpenCLを実行するためのコードにモリモリ書き換えないといけませんし、そもそもPyritにはOpenCLのコードは最初から入っています。

悪くは無いんだけど、今回の場合は色々な意味で本末転倒。

はい次。

代案その5: NVEmulate

これはなんとNVIDIA公式。古いGPUのマシンでも、新しいGPUを要求するソフトウェアを動かせるようにするためのソフトウェアだそうです。しかし2014年から更新がなく、ついでに言えばWindows専用。よしんばWindowsを持っていたとして、CUDAが動くかどうかは怪しいです。ゲーム開発者のデバッグ用っぽい。

「非常に低速」であることには違いないが,例えば,GeForce FXシリーズのマシンでGeForce 6800のデモであるNaluやTimburyが動いてしまうという素晴らしいツールだ(普通の人用には,これ以外の用途を思いつかないのが残念だが)。
手持ちのGeForce FX 5900搭載マシンでは,Naluが0.1fps程度で動いている。

4Gamer.net ― 君のマシンでNaluが動く! GPUエミュレータNVemulate公開

はい次。

代案その6: nvcc -deviceemu

nvcc –deviceemu <filename>.cu

  • デバイスエミュレーションモードでビルド
  • デバッグシンボルなし、CPUですべてのコードを実行

NVIDIA – CUDA実践エクササイズ

こちらも公式。CUDAコンパイラであるnvccが、CUDAソースコードのうち、GPUで走るはずの部分も全部CPUで走るようにコンパイルしてくれるんだそうな。

これはかなり理想的かつ現実的なアプローチに思えます。PyritのCUDAモジュールをコンパイルする時にこのオプションをつけておくだけでいいのでラクチンですし、mac用のnvccもあるのでノマドワーカーにも優しい。そしてPTXを動的に変換するような大道芸はしない、安定したアプローチ。

しかし

 % cd /Developer/NVIDIA/CUDA-9.2/bin
 % ./nvcc --help | grep deviceemu
 %

とっくの昔にそんなものは無くなっていたのであった。

CUDA Emulation Modeというのもあった(GPUの代わりにCPUのエミュレータが出てくる)というのも昔はあったようなのですが、これも今はもうなさそう。

NVIDIAからの「GPU買ってね!」という熱いメッセージだと思っていいのかな…。でもそれ以前に動かないんだけど。

gpuocelotを試す

現実的に使えそうなものはgpuocelotぐらいなので、これちょっと試してみましょう。Instlationページによると、WindowsはExperimental(もう二度とExperimentalが外れることはなさそうだけど)で、macは最初から言及すらないので、ノマドは諦めてLinuxでやりましょう。

Ubuntu 18.04でやる事にします。

ビルド・インストラクションに沿って(かつGCC4.8では動かないなどの諸々の注意書きを見なかった事にして)やってみると:

ocelot/ir/implementation/Module.cpp:712:46: error: enum constant in boolean context [-Werror=int-in-bool-context]
     if (prototypeState == PS_ReturnParams || PS_Params) {
                                              ^~~~~~~~~
cc1plus: all warnings being treated as errors
scons: *** [.release_build/ocelot/ir/implementation/Module.os] Error 1
Build failed...
Build failed

「PS_Paramsはenumなのでboolの値としては使えないんだけど…!」という、もっともなエラー。しかしどう直せばいいのか。||の前を見る限り、”prototypeState == “を忘れたんですかね?

…これ…コンパイルエラーじゃなかったら、常に”true”になるif文としてコンパイルされてたんじゃないかな…。それでいいのかな…この世はコワイネ。

とりあえず追加してビルド再開。

In file included from ./ocelot/parser/interface/PTXLexer.h:11:0,
                 from ./ocelot/parser/interface/PTXParser.h:16,
                 from ocelot/ir/implementation/Module.cpp:10:
.release_build/ptxgrammar.hpp:354:22: error: 'PTXLexer' is not a member of 'parser'
 int yyparse (parser::PTXLexer& lexer, parser::PTXParser::State& state);
                      ^~~~~~~~
...(略)...
.release_build/ptxgrammar.hpp:354:47: error: 'parser::PTXParser' has not been declared
 int yyparse (parser::PTXLexer& lexer, parser::PTXParser::State& state);
                                               ^~~~~~~~~
...(略)...

scons: *** [.release_build/ocelot/ir/implementation/Module.os] Error 1
Build failed...
Build failed

parser::PTXLexerや、parser::PTXParser::Stateを宣言していないのに、yyparse関数のパラメータとして使ってるぞ!という、これまたもっともなコンパイルエラー。

ptxgrammar.hppはyaccから生成されるファイルで、NVIDIAのGPUの命令セット、PTXのパーサーのようです。で、このパーサーがparse::PTXParser::Stateを利用すると。

で、PTXParserを見ると次のようになっていて、プログラムの他の部分から使うための外面の実装のようです。そのため、ptxgrammar.hppにガッツリ依存しております。

namespace parser
{
	/*! brief An implementation of the Parser interface for PTX */
	class PTXParser : public Parser
	{
		public:
			class State
			{
				public:
					class OperandWrapper
...(略)...

必然的に、循環参照が発生しています。

PTXParserはyaccの生成したコードに依存していて、yaccの生成したコードはPTXParser::Stateに依存している。

で、コンパイラは、どちらを先に読み込んだとしても、知らないクラスや知らない定数がいきなり出てくるので、よくわかんなくなって、困ってしまう、と。

こういうシチュエーションはC++ではよくあることで、そのためにクラスの前方宣言という機能が用意されております:

namespace hoge{
class Fuga; // これが前方宣言。
}

// ポインタ、もしくは参照としてなら使える
int foo(hoge::Fuga& fuga);

namespace hoge {
// 実際の宣言
class Fuga {
...(略)...
}
}

こんな感じで最初に「hogeというネームスペースの中にFugaというクラスがあるぞ!」とコンパイラに教えておいてあげると、foo関数の定義を見たコンパイラは、「よくわかんないけど、そういうクラスがあるんやな」となんとなく察してコンパイルを続行することが出来ます(逆に、前方宣言をしないと「hoge::Fugaって何?」とエラーを吐いて止まってしまいます)。ただ、あくまで「なんとなく」なので、ポインタか参照としてでしか使えません(もっと詳しくはコンパイラの本かC++の本を読んでね)。

じゃあ今回もそうするか…と言いたいところなのですが、parser::PTXLexerはともかく、parser::PTXParser::Stateクラスはふつうのクラスではありません。上で見たとおり、Parserクラスの中に存在するクラス、「インナークラス」です。C++では、残念ながらインナークラスの前方宣言は出来ません。もしできれば万事解決しそうなのですが、C++の仕様上できないので仕方がない(どうしてそういう仕様なのかは、謎)。

まぁ、このインナークラスが前方宣言できなくて困るシチュエーションも、C++ではよくあることです。じゃあ、そういう時はどうするのかというと、普通に設計を見直してリファクターします

…はぁ…。まぁ、「動かない」ってことで、いいか…。でも、なんで今までこれでコンパイル通ってたんだろう?

今回のまとめと次回のPyrit

GPUなしでCUDAの実行をするのは、現実的にはどうやら難しいらしいことがわかりました。

CUDA用の純正コンパイラ「nvcc」に、CPUでエミュレートするためのコンパイルフラグが、過去には存在していたようですが、現在は跡形もなく無くなってしまいました。CUDAの使えるGPUが非常に限られていた時代ならいざしらず、NVIDIAのカードならどれでもCUDAが使える昨今ではあんまり需要は無くなったからなのか、…それともCUDAがGPGPUとしての覇権を取ったから、傲慢になったのか。その辺はわかりませんが。

ちなみにTensorFlowとかCaffeはCPU用とGPU用のコードが両方ともゴリゴリ書いてあったと記憶しております。大変だねぇ。資本を上げて人月で殴れ!

次回の月刊Pyritの頃にはGPUサーバが使えるようになるはずなので、素直にGPU使って開発しようと思います。

GPUを使って無線LANをクラックする話:Pyritの考古学/倫理学

拝啓。

自販機にたまにホット飲料を見かける季節となりましたが皆さまいかがおすごしでしょうか。

秋ですね。気まぐれと勢い 旅行で行った九州では彼岸花が咲いておりました。

今回は咲きかけギリギリのヒガンバナくんの写真です。

これぐらいのをお散歩中に見つけたら、だいたい翌日か翌々日ぐらいには咲きますので、翌日もぜひ見に行ってあげてくだせぇ。ヒガンバナくんは、写真で見るより実物のほうが絶対いいです。雨が降ってない事を祈ります。

あーでも。毒性があるので持ち帰って食べたりしちゃダメですよ。持ち帰るのは思い出だけ。山と一緒かな。

前回までのPyrit

じゃーまた、WiFiのパスワードでも、クラックしてきますか。

前回わかった事は、最初取ったベンチマークで「GPUはCPUより速くてすごーい!!」とか喜んでたけど、実はGPUは10%も使っていないし、CPUも全部は使いきってはいなかった…というなかなか衝撃的な事実でした。さらに言えば、そのベンチはGPUの分と称してCPUも使っている、公平かどうかは正直怪しいと言わざるを得ないものでありました。

言うなれば我々は…ただの幻を見て一喜一憂していたのです。

どうしてこうなった(AA略)

うーん。悲しい。

実際に何か手を動かす前に、どうしてこんなことになってしまったのか想像してみましょう。Pyritのクラスターを組んでいたみなさんは、実はほとんど寝てるだけのGPUを前に、ドヤっていたのか。まさか、そんな。

Pyritの考古学

Pyritが活発に開発されていたのは2009〜2010年ごろです。DeepLearningブームが始まったのが2012年とかなのでそれよりも前だし、その頃に生まれた子供は、今小学校で九九を覚えてる頃。それぐらい大昔です。そんな古代のソフトウェアを今動かそうというのですから、歴史を踏まえなければ、目の前の状況を理解することはできないでしょう。

まず、GPUをなんでこんなに遊ばせてしまっているのか。

ひょっとすると、前回使ったVisual Profilerが実はその頃なかったのかもしれません。だから使い切ってない事に誰も気づかなかったとか。が、しかし、NVIDIAの公式ページによると2008年から作ってるとの事なので(頑張ってるなNVIDIA)、この線は無い…と思いたい。つまり、「昔はGPUを全部使い切ってたけど、時間が経ったら状況が変わった」可能性が高い。

あの頃のGPU:GTX480が出た頃(買えたとは言ってない)

2010年といえば、GPUならGeForce GTX 295(2009年6月)とか、GTX 480(2010年3月)の頃です。…もう何も覚えてない…。まーとりあえず表でも書いてみますか。CUDAとは直接は関係ないですが、参考程度にPassMarkのベンチマークの数値も貼っときます。グラフィクスを描く時もCUDAコアが走るそうなので、無関係ではあるまい。

GPU発売時期CUDAコアクロックCUDAコア数PassMarkベンチ
GTX 2952009/061242MHz240×21052
GTX 4802010/031401MHz4804358
GTX 1080 Ti2017/021480MHz358414057

GTX480ではGPGPUへの最適化も進んだそうで、一気に性能が上がっていますが、曰く

最初のロットの歩留まりは、嘘か真かは不明だが2%ほどだったという。その後もステッピングを重ねてできる範囲での改良を施したものの、最終的に2010年3月のGeForce GTX 480発表時点で出荷可能な枚数は全世界を合わせて数千枚程でしかなかった。

ロードマップでわかる!当世プロセッサー事情 ― 第146回
GPU黒歴史 DX11への遅れが生んだ駄作 GeForce GTX 480

だそうで、2010年のゲーマーたちはだいたいGTX295を使っていたんじゃないかと思います。つまり、今の1080 Tiは当時に比べて10倍以上、逆に言えば、GTX295は今に比べたら1/10以下の文字通り「桁違い」の性能だったと思われます。…ところで、10%弱しか走ってなかったんですよね?

あの頃のCPU: Core i7が初めて出た頃

じゃあ一方CPUはどうなんだ。2010年にPCパーツショップに並んでいたのは、Core iシリーズの最初、Nehalem世代です。これももう覚えてないですねぇ。せいぜい登場時に「3と5と7って何?Core i7には7コア載ってるのか?」と思ったのを覚えている程度です(答え:載ってない)。

同じように表を書いてみましょう。

GPU発売時期クロック(ターボ)コア数(スレッド数)PassMarkベンチ(マルチ/シングル)
Core i7 9602009/103.2GHz(3.46GHz)4(8)5828/1389
Core i7 8700K2017/103.7GHz(4.7GHz)6(12)15969/2704
Xeon Silver
4116
2017/022.1GHz(3.0GHz)12(24)15131/1599

ターボクロックはカッコの中に一応書いてはいますが、ターボブーストは「一時的に加速できる」という機能ですので、ずっと負荷を掛け続けるベンチマークではベースクロックの方が重要です。

ベンチに使ってるサーバに乗ってるのが最後のXeon Silver 4116です。PassMarkのベンチマーク的にはなんとシングルコア性能自体は2009年のCPUである960と大して変わらないという結果になってます。もちろん周波数は960よりかなり低いので、「周波数あたりの性能は上がってる」と言えるのは間違いなく事実なんですけどね。

最近のサーバ用CPUトレンドはこのようにそこまでの性能ではない低い 周波数のコアをたくさん束ねて全体としての性能を確保する戦略らしく、結果としてCPU全体では10年前のCPUの三倍ぐらいの性能は出るようになっています。という所は観察できました。

時を経ても変わらないもの―Pythonはシングルスレッド

GPUもCPUも速くなってはいるけれど、一つだけ変わらない事があります。

それは、Pythonはシングルスレッドでしか動かないという事実です。PythonにはGIL(Global Interpreter Lock)という仕組みがあるので、いくらthreading.Thread()してスレッドを作っても、同時に動くPythonのスレッドはたった1つだけです。100コア積んでも5000兆コア積んでも1つだけ。

ちょっと待て。じゃあなんでPythonで書かれてるはずのPyritはマルチコア対応してるんだ?もっというとDeepLearningはみんなPythonでやってるんじゃ無いのか?シングルスレッドなのか?

もちろんそんな事あるわけなくて、PythonからC言語の拡張を呼んだ時は、C言語で処理しつつPythonの他のスレッドを起こす事ができます。その時はPy_BEGIN_ALLOW_THREADS;Py_END_ALLOW_THREADS;で囲めばマクロがよしなにスレッドの面倒を見てくれます。

実際にPyritでCPUでクラックする時もこんな感じになってます:

    Py_DECREF(passwd_seq);

    if (arraysize > 0)
    {
        Py_BEGIN_ALLOW_THREADS;
        i = 0;
        do
            i += finalize_pmk(&pmk_buffer[i]);
        while (i < arraysize);
        Py_END_ALLOW_THREADS;

        result = PyTuple_New(arraysize);
        for (i = 0; i < arraysize; i++)
            PyTuple_SetItem(result, i, PyString_FromStringAndSize((char*)pmk_buffer[i].e1, 32));
    } else {
        result = PyTuple_New(0);
    }

    PyMem_Free(pmk_buffer);

    return result;
}

これを使う事で1つ以上のCPUコアを使う事が可能になっていますが、しかし、他の部分は全部シングルスレッドでしか動かないことは記しておく価値があると思います。C言語のコードでも、PythonのオブジェクトからCの値に変換したり、その逆をしたりするところはシングルスレッドでやらないといけません。

CPUを全コア使いきれていない理由は、前回書いた通り、ここだと思います。パスワードを生成する部分がPythonで書かれているので、そこがボトルネックになっているんだと思います。

Pyritの倫理学:「公平なベンチマーク」ってなんじゃらほい

まぁ、だいたい状況は掴めました。次にルールを考えましょう。

「ベンチマーク」という「勝負」のルールを、です。

現在のPyritのbenchmarkコマンドのルールでは、「CPU」と「GPU」の勝負のはずが、「GPUのために準備するCPUのコード」も同時に別々のCPUのスレッドで走っています。

CPUのスレッドはランダムなタイミングで割り込まれる可能性がありますから、CPUがクラックしているコード上の「行間」でGPUの為に準備するスレッドのコードが実行されて、CPUの性能が見かけ上悪くなってる可能性はかなり高いです。わたしはこんなんじゃあ、公平なベンチマークとは到底言えない思います。

「公平」とはなんじゃらほい??

ほう、「公平」ねぇ。ところで、「公平」ってなんでしょう?試しに「公平な社会」とか書いて見ると、これがいかにも政治家さんや官僚さんの口から出てきそうな単語な事からも分かるように、「公平」とは人によって意見が別れうる、一筋縄ではいかない手強い単語なわけです。

まぁ、「公平な社会」が何なのかは置いておいて(わたしにはわからん)、今回は「公平なPyritのベンチマーク」とは何なのかのわたしなりの意見を書いておきます。

CPUとGPUは明らかに対等な立場ではありません。というのも、CPUだけでパスワードのクラックはできるけれど、GPUだけではできないからです。CPUがGPUの処理しやすい問題の形式に整えてから、GPUが一気に処理をする。そういう、協力関係で計算を進めるのがGPGPUです。 こういうのを一般的かつかっちょいい言葉では「ヘテロジニアス・コンピューティング」といいます。

そういう意味では、同じ勝負でも「サッカー」とはだいぶ雰囲気が違います。サッカーみたいに、お互いが対称なルール、例えば「GPUめ、CPUに頼らずクラックしてみろ。CPUもお前には頼らないから平等だよな?」みたいなルールでは、単にGPUが何もできなくて降参して終わりです。

そもそも勝負のルールってどうして必要なんだ?

サッカーという勝負のルールは、選手や観客が楽しく、かつ安全に遊ぶためのルールですが(たぶん)、じゃあ、Pyritのベンチマークという勝負のルールは何の為のルールでしょう?

まぁ結局は同じ、「面白いかどうか」が基準でいいと思うんですが、それをもうちょっと具体的に言えば、「GPUとCPU同士の本気の勝負が見たい」に尽きると思います。もうちょっと大人じみた言葉で言えば、「GPUの得意な処理をCPUからGPUにオフロードした時に、そこがCPUと比べてどれぐらい速くなるか?」の限界が見たい。

もちろん、一部だけ高速化できても全体で速くなるとは限りません。全体の10%がGPUで10倍速くなっても、1.1倍ぐらいしか速くなりません(アムダールの法則)。例えば、GPUがCPUに比べてそこまで得意ではない処理もGPUに持って言って「並列化」する事で、その部分はそこまで高速化しなくとも、システム全体としては高速化する可能性はあります。…が、個人的にそこはあんまり面白くないなぁ…GPUの最高性能、つまり「ガチ」が見たいなぁ…と思ったので独断により今後はこの上に書いた方針で行きたいと思います。Pyrit全体よりも局所的な情報の方が、他のシステムについて見積もる時に便利そうだし。まぁこのいかにもな理由の方は後付けなんですが。

流石にこれだけではGPUに甘々な感じがするので、今邪魔されているCPUにも救いの手を差し伸べましょう。CPUが邪魔されている原因は、結局CPUとGPUを同時に走らせてクラックしていることです。これは単にベンチマークをとる時に、別々に走らせれば邪魔されずにすみます。

ベンチマークのルールは与えられるものじゃない、考えるものだ

というわけで考えた「面白い勝負」のためのルールをまとめると:

  • GPUの一番得意な処理をCPUからGPUにオフロードする
    • そこが全く同じ処理をするCPUと比べ、どれぐらい速くなるかを測定
  • CPUとGPUは別々に走らせて、お互いに邪魔しあう事を防ぐ

そろそろ長くなってきたので、もっと具体的な話は次回で。

本当に今のルールは「公平」ではないのか?

一応擁護しておくと、今のPyritのベンチマークのルールも「公平」だと言えなくもありません。

というのも、今のPyritのベンチマークは会社でよくある「成果主義」そのものだ、と捉えることも出来るからです。会社というのも協力関係がお互いにあるわけですが、「成果主義」の会社ではお給料を決めたりする時はその上で「そいつが、会社の利益に、どれくらい貢献したか?」みたいなのを(定量的にじゃないにしても)測ります。Pyritの今のベンチマークは、それと似たような事を測っている、と捉えることは可能だと思います。

で、この「成果主義」をどう思うか、具体的にどうするか、色々意見があることと、上でわたしがベンチマークのルールをどうするか悩んでいるのと、対応がつくわけです。もちろん、人とコンピュータの世界では前提が色々違うので全く同じというわけではありませんが、「一筋縄ではいかないねぇ〜」「意見が別れるだろうね〜」という点では全く同じです。

まとめ

Pyritが想像以上に大昔のソフトウェアだったので、歴史を調べました。

Pyritが盛んに開発されていた頃のGPUはCUDAへの最適化が進む一歩手前で今とは桁違いの性能差がありそうなこと。

シングルコア性能は今のサーバのXeonは昔のハイエンドCore i7と同じぐらいの性能だけれどマルチコアにすることで性能を稼いでいること、Pythonは相変わらずシングルスレッドなこと。そんなことがわかりました。

そして、わたしの興味に応じた「ぼくのかんがえたベンチマークのルール」も考えました。意外と人の仔の世界とも通じるものが有るんじゃのぅ。

さ〜て次回のPyritは?

このルールに応じてPyritを書き換えて、測定しなおしましょう!

山の上の石に日が暮れるまで座って色々考えてると今回みたいな記事になりまして。
まぁ、たまにはこういうのをじっくり考えるのも大事なんじゃないかなぁ、って最近思うんですよ。