Brute-force attack against NTLMv2 Response

2016 年 9 月の Windows Update で、NTLM SSO の動作に関連する脆弱性 CVE-2016-3352 が修正されたようです。

Microsoft Security Bulletin MS16-110 – Important
https://technet.microsoft.com/library/security/MS16-110

An information disclosure vulnerability exists when Windows fails to properly validate NT LAN Manager (NTLM) Single Sign-On (SSO) requests during Microsoft Account (MSA) login sessions. An attacker who successfully exploited the vulnerability could attempt to brute force a user’s NTLM password hash.

To exploit the vulnerability, an attacker would have to trick a user into browsing to a malicious website, or to an SMB or UNC path destination, or convince a user to load a malicious document that initiates an NTLM SSO validation request without the consent of the user.

CVE – CVE-2016-3352
http://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2016-3352

Microsoft Windows 8.1, Windows RT 8.1, and Windows 10 Gold, 1511, and 1607 do not properly check NTLM SSO requests for MSA logins, which makes it easier for remote attackers to determine passwords via a brute-force attack on NTLM password hashes, aka "Microsoft Information Disclosure Vulnerability."

"NTLM SSO" などのキーワードで適当にインターネット検索すると、今年 8 月に書かれた以下の記事が見つかります。

The Register – Reminder: IE, Edge, Outlook etc still cough up your Windows, VPN credentials to strangers
http://www.theregister.co.uk/2016/08/02/smb_attack_is_back/?mt=1474231650819

画面キャプチャーを見ると、なんと Microsoft アカウントのパスワードが解析されてしまっています。そして Youtube の埋め込み動画では、SMB パケットがブラウザーからリークしていることを示しています。つまり、SMB パケットに埋め込まれた NTLM メッセージに対して brute-force 攻撃をしかけることで Microsoft アカウントのパスワードを解析できる、ことを示しているようです。

これは理論的に可能でしょう。が、もしそれが 「簡単に」 できるのであれば、それは NTLM プロトコルの死を意味するべきであり、パッチとして一朝一夕に対応できるものではないはずです。SSLv3 や RC4 と同様にそのプロトコルの使用を止めるべきですが、非ドメイン環境において NTLM の代わりとなるような認証プロトコルは Windows には実装されていないはずです。

というわけで、NTLM に対する brute-force がどれぐらい簡単なのかを調べることにしました。まず、NTLM プロトコルがどうやってユーザー認証を行っているかを説明します。と言っても以下の PDF を読み解くだけです。

[MS-NLMP]: NT LAN Manager (NTLM) Authentication Protocol
https://msdn.microsoft.com/en-us/library/cc236621.aspx

NTLM が混乱を招く点として、一つのプロトコルが複数のプロトコル バージョン (LanMan, NTLMv1, NTLMv2) に対応していることです。Wiki の情報を見ると NTLMv2 は NT 4.0 SP4 から採用されているので、 NTLMv2 だけで現在は問題なく生きていけるはずです。ただし XP などの古い OS において、さらに古い OS との互換性のために NTLMv1 や Lanman に fallback するような動作が有効になっている場合があります。このへんの細かい話は長くなりそうなので、以下の KB に丸投げします。

NT LAN Manager – Wikipedia, the free encyclopedia
https://en.wikipedia.org/wiki/NT_LAN_Manager

How to prevent Windows from storing a LAN manager hash of your password in Active Directory and local SAM databases
https://support.microsoft.com/en-us/kb/299656

Security guidance for NTLMv1 and LM network authentication
https://support.microsoft.com/en-us/kb/2793313

NTLM は Challenge Reponse Authentication の一つで、簡単に書くとサーバーとクライアントが以下 3 つのメッセージを交換することで認証が行われます。(仕様によると Connectionless モードの場合は Negotiate が存在しないようですが、見たことがないのでパス。)

Client: "I want you to authenticate me."
(= Negotiate Message)

Server: "Sure. Challenge me. Use 0x0123456789abcdef as a ServerChallenge."
(= Challenge Message)

Client: "My response is !@#$%^&*()_+…"
(= Authenticate Message)

NTLM は単体で使われるプロトコルではなく、必ず別のプロトコルに埋め込まれて使われます。例えば SMB の中で使われる場合には、SMB Session Setup コマンドに埋め込まれます。ダイレクト SMB ポートである 445/tcp をキャプチャーしたときの Network Monitor 上での見え方は以下の通りです。

01
SMB packets over 445/tcp (Lines highlited in purple contain NTLM messages)

02
NTLM Negotiate Message

03
NTLM Challenge Message

04
NTLM Authenticate Message

セクション 3.3.2 NTLMv2 Authentication から、パスワードを解析するのに必要な疑似コードの計算式だけを抜き出すと以下の通りです。

[MS-NLMP]: NTLM v2 Authentication – 3.3.2 NTLM v2 Authentication
https://msdn.microsoft.com/en-us/library/cc236700.aspx

Define NTOWFv2(Passwd, User, UserDom) As
  HMAC_MD5(MD4(UNICODE(Passwd)),
           UNICODE(ConcatenationOf(Uppercase(User), UserDom)))
EndDefine

Set temp to ConcatenationOf(Responserversion,
                            HiResponserversion,
                            Z(6),
                            Time,
                            ClientChallenge,
                            Z(4),
                            ServerName, Z(4))
Set NTProofStr to HMAC_MD5(ResponseKeyNT,
                           ConcatenationOf(CHALLENGE_MESSAGE.ServerChallenge,
                                           temp))
Set NtChallengeResponse to ConcatenationOf(NTProofStr, temp)

使用しているハッシュ関数は HMAC_MD5 と MD4 のみ。入力データはいろいろあって面倒そうに見えますが、それほど難しくありません。特に、疑似コードの中で temp として扱われているバージョンやタイムスタンプなどのメタ情報が、ハッシュ値である NTProofStr と連結してそのまま Authenticate Message の NtChallengeResponse になっているからです。図示したものを ↓ に示します。図中の Metainfo が、上記擬似コードで言うところの temp です。

実際に処理するときは、パスワードを UTF-16 に変換する点と、ユーザー名を大文字に変換する点に注意が必要です。

05
Calculation of NtChallengeResponse in NTLMv2

これで材料が出揃ったのでコードを書きます。まずサーバー側のコードとして、Samba サーバーが NTLM メッセージを処理しているときに、brute-force に必要となる情報をテキスト ファイルとして書き出すようにします。これによって、前述の Youtube 動画がやっていることとほぼ同じことができます。

Yandex SMB hash capture on IE with email message – YouTube
https://www.youtube.com/watch?v=GCDuuY7UDwA

msmania/samba at ntlm-hack
https://github.com/msmania/samba/tree/ntlm-hack

テキスト ファイルと同じ内容をレベル 0 のデバッグ メッセージとしても出力するようにしました。gdb を使って smbd を実行しておくと、SMB 経由で NTLM 認証が行なわれたときにコンソールにログが記録されます。出力される情報はこんな感じです。後でまとめて grep できるようにあえてテキスト ファイルにしました。

Domain:
User: ladyg
Client: LIVINGROOM-PC
UserAndDomain=4c004100440059004700
Challenge=ae65c9f0192d64b9
Auth=0101000000000000b62acefc2d11d201ea3017d2f290d64e00..(長いので省略)
Response=39329a4a4e9052fe3d4dea4ea9c79ac5

次に、Samba サーバーが書き出したテキスト ファイルに対して実際に brute-force を行うプログラムを書きます。hashcat に新しいモードを付け足すことができればベストだったのですが、OpenCL を勉強する時間がなかったので、OpenSSL の関数を呼び出すだけの簡単なプログラムになりました。

msmania/ntlm-crack
https://github.com/msmania/ntlm-crack

このプログラムは Samba が生成したテキスト ファイルに対して、別の引数として指定したのテキスト ファイルの各行をパスワードとして NTLMv2 Reponse を生成し、Samba が出力したデータと一致するかどうかを比較します。パスワード一覧ファイルは、ネット上で探せば簡単に見つかります。ntlm-crack リポジトリにサンプルとして入れてある 10_million_password_list_top_1000.txt は、以下のリポジトリからコピーしたものです。

GitHub – danielmiessler/SecLists
https://github.com/danielmiessler/SecLists

では実際にコマンドを実行して brute-force の速度を計測します。マシン スペックは以下の通り。Windows マシンであればもっと新しいマシンで hashcat をぶん回せたのですが・・無念。

  • OS: Ubuntu 16.04.1 LTS (GNU/Linux 4.4.0-36-generic x86_64)
  • CPU: Intel(R) Core(TM) i5-2520M CPU @ 2.50GHz (Sandy Bridge)

とりあえず 100 万通りのパスワードを試してみます。

$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 3343 msec.
$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 3372 msec.
$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 3344 msec.

大体 3 秒ちょいです。特に工夫をしたわけでもないのですが、予想していたより速いです。UTF-16 変換の処理を予め済ませて、かつ並列処理をすれば 1M/s は軽く越えられそう。

もちろん実際に使われているのはこんな子供騙しではありません。参考として 4 年前の記事ですが、25-GPU を使って 95^8 通りのハッシュを 5.5 時間で生成できたと書かれています。ここでいう NTLM cryptographic algorithm が厳密に何を意味するのかは書かれていません。巷では、UTF-16 エンコードしたパスワードの MD4 ハッシュを NTLM ハッシュと呼ぶことが多く、仮にそうだとすると、5.5 時間という数字には HMAC-MD5 を 2 回計算する部分が含まれていません。試しに、今回作った ntlm-crack から HMAC-MD5 の演算を飛ばして再度実行してみます。

$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 347 msec.
$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 347 msec.
$ ./t -f sample.in -l /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt
No matching password in /data/src/SecLists/Passwords/10_million_password_list_top_1000000.txt.
Tried 999999 strings in 346 msec.

計算時間が約 1/10 で済んでしまいました。この比率が 25-GPU マシンにも適用されるとすると、8 文字のパスワードをクラックするのに 4 年前は 55 時間かかっていたはずです。怪しい概算ですが。

25-GPU cluster cracks every standard Windows password in <6 hours | Ars Technica
http://arstechnica.com/security/2012/12/25-gpu-cluster-cracks-every-standard-windows-password-in-6-hours/

今年は AlphaGo のニュースが衝撃でしたが、そのときの Nature 論文では 1,920 CPUs + 280 GPUs のマシンで AlphaGo を動かしたという実績が書かれているので、個人での所有は難しいにしても、あるべきところ (Google や NSA?) には 4 桁のプロセッサーを動かせるマシンが存在していると仮定できます。これで 2 桁分稼げるので、10 桁程度のパスワードであれば数日で解ける恐れがあります。12 桁のパスワードにしておけば年単位の時間が必要になるので安心かも・・・?

話が逸れておきましたが、冒頭の CVE-2016-3352 の話に戻ります。Security Bulletin には、以下のような修正がなされたと書かれています。つまり、誰彼構わず NTLM SSO 認証のための SMB パケットを送るのは止めた、ということでしょうか。

The security update addresses the vulnerability by preventing NTLM SSO authentication to non-private SMB resources when users are signed in to Windows via a Microsoft Account network firewall profile for users who are signed in to Windows via a Microsoft account (https://www.microsoft.com/account) and connected to a “Guest or public networks” firewall profile.

この修正ができたということは、 「不特定多数のサーバーに SMB パケットを送ってしまう動作があったため、本来できないはずの brute-force 攻撃の標的になってしまう」 ことが問題とされていたわけです。これでようやく、Security Bulletin の "An attacker who successfully exploited the vulnerability could attempt to brute force" という部分が腑に落ちました。この件に関して言えば、brute-force の成功が現実的かどうかは関係なく、brute-force が可能であることそのものが問題だったわけです。NTLM はまだ生きていていいんだ。

あえてケチをつけるならば、CVE の方の記述における "to determine passwords via a brute-force attack on NTLM password hashes" でしょうか。NTLM は複数のハッシュ (MD4 と HMAC-MD5) を使いますが、NTLM password hash と書くと、パスワードのハッシュ、すなわち一段階目の MD4 ハッシュを想定するのが普通です。しかし、MD4 ハッシュは一回目の HMAC-MD5 の鍵として使われるだけで、ネットワーク上を流れることはなく、brute-force の攻撃対象にはなりません。Microsoft 側の Security Bulletin では "attempt to brute force a user’s NTLM password hash" となっており、こちらの記述のほうがより正確な気がします。最近の流行は pass-the-hash 攻撃なので、平文のパスワードに替えて、ハッシュ値が brute-force の標的であってもおかしくはありません。

ところで、なぜ Microsoft アカウントに関する言及があるかというと、冒頭で紹介した The Register の記事にもありますが、Microsoft アカウントのユーザー名がユーザーのメール アドレスであり、OneDrive や MSDN などのサービスのアカウントとしても使われているからです。世界のどこかにあるパソコンのユーザー アカウント "Mike" のパスワードが分かってもできることは限られていますが、Microsoft アカウントのパスワードが解析されると大変なことになります。だからこそ今までこの古いバグが放置されてきたのかもしれません。ただ、ユーザー名が平文で SMB として流れるのは気持ち悪いですが。

(2016/9/19 追記)

9 月のアップデート後に、LAN ディスクや SAMBA にアクセスできなくなったというツイートやフォーラムを幾つか見つけましたが、おそらく CVE-2016-3352 に対する修正が原因と思われます。どうするんでしょうかね。

update kb3185614の不具合について、LANDISKへの接続やリモートアクセスができなくなる – マイクロソフト コミュニティ
http://answers.microsoft.com/ja-jp/windows/forum/windows_10-update/update/f5219540-a2a5-4b09-b9b6-e944dcbbed38

広告

SUDO for Windows

Windows で動く Linux の sudo コマンド的なものを作って GitHub で公開しました。

msmania/sudo: SUDO for Windows
https://github.com/msmania/sudo

Windows でコンソールを使った作業をする場合、必要がない限りは、管理者権限のない制限付きトークンのコマンド プロンプト (もしくは PowerShell) で作業すると思います。Windows の困ったところは、管理者権限が必要なコマンドを実行するときには、新しいコンソールを別途起動しないといけないことです。しかし、1 コマンド実行したいだけなのに、わざわざ新しくコンソールを開いて使い終わったら閉じるのは時間がもったいないのです。というわけで、通常のコンソールと管理者権限のコンソールの二窓体制で作業する、というのが日常かと思います。しかし、最近の Windows は無駄にグラフィカルで、ウィンドウを切り替えるときの Alt+Tab やタスクバー アイコンのプレビューがいちいち大袈裟です。今度はこれをレジストリで無効にしておく、というような具合に、理不尽なカスタマイズが次々と必要になります。そこで、sudo を作ることにしました。

代替策も探しましたが、意外とありません。例えば、runas.exe を使って built-in の Administrator ユーザーでログオンすれば管理者権限は使えます。しかし次の 2 点において不満があり使えません。

  • runas.exe で cmd.exe を起動すると、結局新しいコンソールが起動する
  • Build-in の Administrator 以外では管理者権限にならない

SysInternals の psexec.exe を使うと runas みたいなことができますが、こちらはそもそも管理者権限がないと実行できないので本末転倒です。

sudo に求めたい要件は以下の通りです。

  1. 通常のコンソール上でそのまま作業できる (= 新しいコンソールは開かない)
  2. Administrator ではなく、管理者グループに所属している作業ユーザーで管理者権限を使える
  3. .NET やスクリプト経由ではなく、ネイティブの sudo.exe が欲しい

GitHub 上を "sudo windows" などで検索すると、幾つかそれっぽいプロジェクトは見つかりますが、1. の要件を満たしてくれません。

maxpat78/Sudo: Executes a command requesting for elevated privileges in Windows Vista and newer OS.
https://github.com/maxpat78/Sudo

jpassing/elevate: elevate — start elevated processes from the command line
https://github.com/jpassing/elevate

どちらも動作原理は同じで、ShellExecute API を lpVerb="runas" で実行しています。UAC プロンプトを表示させて管理者権限を得るには一番簡単な方法なのですが、コンソールから cmd.exe を起動すると別のコンソールが開いてしまうのでこれは使えません。

ShellExecute function (Windows)
https://msdn.microsoft.com/en-us/library/windows/desktop/bb762153(v=vs.85).aspx

ShellExecute が駄目となると CreateProcess でプロセスを作るしかありません (他に WinExec という化石のような API もありますが)。が、以下のブログに記載があるように、CreateProcess で権限昇格が必要なプロセスを起動することはできません。

Dealing with Administrator and standard user’s context | Windows SDK Support Team Blog
https://blogs.msdn.microsoft.com/winsdk/2010/05/31/dealing-with-administrator-and-standard-users-context/

CreateProcess() and CreateProcessWithLogonW do not have new flags to launch the child process as elevated. Internally, CreateProcess() checks whether the target application requires elevation by looking for a manifest, determining if it is an installer, or if it has an app compat shim. If CreateProcess() determines the target application requires elevation, it simply fails with ERROR_ELEVATION_REQUIRED(740). It will not contact the AIS to perform the elevation prompt or run the app.

最後の AIS というのは Application Information Service (AppInfo サービス) という UAC を司る憎いやつです。いや、実際はお世話になっているのですが。

Understanding and Configuring User Account Control in Windows Vista
https://technet.microsoft.com/en-us/library/cc709628(v=ws.10).aspx

となると残された道は 1 つしかなく、sudo.exe を昇格させて実行し、そこから CreateProcess で子プロセスを作る方法です。権限は自動的に継承されるので、子プロセスも昇格されたままになるはずです。

さらに要件 1. を満たすためには、もう一捻り必要です。sudo.exe をコンソール アプリケーション、すなわち /SUBSYSTEM:CONSOLE オプションを使ってリンクした場合、そのコンソール プログラムを昇格していないコンソール上から起動すると、UAC プロンプトの後にやはり新たなコンソールが起動して、プログラム終了時にコンソールが破棄される動作になるので、標準出力が見えません。したがって、sudo.exe は /SUBSYSTEM:WINDOWS を使ってリンクしなければなりません。この場合、単純にプログラムから printf などで標準出力に文字を出力しても、データは破棄されるだけでどこにも表示されません。そこで、プログラムの標準出力を親プロセスのコンソールに関連付けて、小プロセスからの標準出力を受け取って親プロセスの標準出力にリダイレクトするようにします。うう面倒くさい・・。

小プロセスの標準入出力をパイプとして受け取る部分は、以下のサンプルのコードを流用できます。

Creating a Child Process with Redirected Input and Output (Windows)
https://msdn.microsoft.com/en-us/library/windows/desktop/ms682499(v=vs.85).aspx

親プロセスのコンソールを自分の標準出力に関連付ける部分は、AttachConsole API に ATTACH_PARENT_PROCESS を渡すことで簡単に実現できます。

AttachConsole function (Windows)
https://msdn.microsoft.com/en-us/library/windows/desktop/ms681952(v=vs.85).aspx

sudo.exe 起動時に UAC プロンプトを表示させるには、マニフェスト XML で requestedExecutionLevel を highestAvailable に設定するだけです。Mt.exe を使うと、exe にマニフェストを埋め込むことが出来るので、Makefile の中でリンカーの後に Mt.exe を実行するように記述します。

Mt.exe (Windows)
https://msdn.microsoft.com/en-us/library/aa375649(v=vs.85).aspx

これらを組み合わせれば、基本の動きはほぼ達成できますが、最初の MSDN のサンプルには若干問題があります。サンプルをそのままコピーして標準出力に文字を出力するだけの簡単なプロセス (ipconfig.exe など) を実行すると、文字は出力されるのですが、ipconfig.exe が終了しても sudo.exe が終わりません。ReadFromPipe における ReadFile の呼び出しで、子プロセスが終了しているにも関わらず制御が返ってこないためです。原因は、STARTUPINFO 構造体に渡した子プロセス用のパイプへのハンドル、すなわち g_hChildStd_OUT_Wr と g_hChildStd_IN_Rd を閉じていないためと考えられます。ちゃんと確かめていないのですが、STARTUPINFO 構造体に渡したハンドルは、複製されてから小プロセスに渡されるので、子プロセス側で標準入出力のハンドルを破棄しても、複製元の g_hChildStd_OUT_Wr と g_hChildStd_IN_Rd を自分で保持している限りパイプが有効で、ReadFile はそれを待ち続けているのだと思います。じゃあ単純に CreateProcess の後でをさっさとハンドルをクローズしてしまえばよいかというと、大方のシナリオでは動くとは思いますが、微妙だと思います。子プロセスによっては、すぐに標準出力にデータを出力しない動作をするものがあってもおかしくありません。しかし、sudo.exe 側はパイプにデータが残っているかどうかだけで出力を続けるかどうかを判断しているので、子プロセスが動作中にも関わらずループを抜けてしまうかもしれません。

現時点のバージョンの sudo.exe では、単純に CreateProcess のあと子プロセスが終了するまで WaitForSingleObject で待って、その後でじっくりとパイプの中を読み出すようにしました。この実装も微妙で、子プロセスの出力量が膨大であったときにパイプが溢れる可能性がありますし、そもそも子プロセスが終わるまで待っているのは美しくありません。そのうち、子プロセスの状態を監視するようなスレッドを作って対応します。

WaitForSingleObject は使うものの、INIFINITE を渡して永遠に待ち続けるのはさすがに嫌だったので、タイムアウト値を設けることにしました。初め、このタイムアウト値は環境変数経由で設定しようと思っていました。そうすれば、CreateProcess の第二引数には WinMain の引数の pCmdLine をそのまま渡すだけで済むので、楽ができるのです。しかし、ここでも Windows のコマンド プロンプトの困った仕様が立ちはだかります。コマンドを実行している時だけに有効になる一時的な環境変数が使えないのです。正式に何というのかわかりませんが、つまり以下のようなことができません。make を実行するときによく使いますね。

$ cat test.sh
echo $HOGE

$ echo $HOGE

$ HOGE=1 ./test.sh
1

$ echo $HOGE

$

一応、似たようなことはできます。それが以下のフォーラムで出てきているやり方で、cmd /C を使って子プロセスの中で set コマンドを実行してから目的のコマンドを実行する方法です。

Setting environment variable for just one command in Windows cmd.exe – Super User
http://superuser.com/questions/223104/setting-environment-variable-for-just-one-command-in-windows-cmd-exe

ちなみにこの中で紹介されている、/V オプションを使った環境変数の遅延評価は、子プロセスでは必要ですが孫プロセスでは不要です。マニアックですが、こんな感じです。

> cmd /C "set HOGE=1 && echo %HOGE% !HOGE! && cmd /c echo %HOGE% !HOGE!"
%HOGE% !HOGE!
1 !HOGE!

> cmd /V /C "set HOGE=1 && echo %HOGE% !HOGE! && cmd /c echo %HOGE% !HOGE!"
%HOGE% 1
1 1

したがって、sudo.exe を使って cmd /c "set TIMEOUT=10 && sudo ipconfig" 的なことをやれば一応は環境変数からタイムアウト値を取れる、と思えますが結局駄目でした。UAC 昇格を要求するコマンドを起動した場合、環境変数が引き継がれません。これは Linux の sudo のデフォルト動作と同じですが、sudo に -E オプションを付加すると環境変数を引き継ぐことができます。

$ echo $HOGE

$ HOGE=1 sudo ./test.sh

$ HOGE=1 sudo -E ./test.sh
1

上記の理由で、環境変数を使うのは諦めて引数を取ることにしました。空白などの扱いを自分で決めたかったので pCmdLine をパースするステート マシンを 1 から書きました。それが CCommandOptions クラスですが、無駄に長いです。たぶんもっとまともな実装方法があると思います。アルゴリズムは苦手・・。

とりあえずこれで要件を満たすコマンドができました。出力例は ↓ の通りです。ここまで書いて言うのもなんですが、UAC ポップアップの表示が遅いので、もっさりした動作にしかなりません。なんだかんだスピードを求めるなら二窓体制が無難かも。

> sudo /t 10 powershell "get-vm | ?{$_.State -eq ‘Running’} | select -ExpandProperty networkadapters | select vmname, macaddress, switchname, ipaddresses | fl *"
[sudo] START
Spawning a process (Timeout = 10 sec.)

VMName : VM1
MacAddress : 00155DFE7A01
SwitchName : External
IPAddresses : {10.124.252.117, fe80::8d2d:7dca:4498:82f9, 2001:4898:200:13:fc0e:945e:ffce:2bb5,
2001:4898:200:13:8d2d:7dca:4498:82f9}

[sudo] END
Press Enter to exit …

WorkQueue Model with POSIX Threads

少し前の記事で書きましたが、MNIST を MDS で処理する計算は、全て Python で書いたせいかパフォーマンスが悪く、N=10000 のデータにも関わらず N=200 程度で 6 分もかかってしまい、話になりませんでした。

MNIST with MDS in Python | すなのかたまり
https://msmania.wordpress.com/2015/12/13/mnist-with-mds-in-python/

しかし、ここまでやってようやく気づいてしまったのは、Field クラスは C++ で書いてしまったほうがよかったかもしれない、ということ。Sandy Bridge だから行列計算に AVX 命令を使えば高速化できそう。というか Python の SciPy は AVX 使ってくれないのかな。ノードにかかる運動ベクトルをラムダ式のリストにしてリスト内包表記で計算できるなんてエレガント・・という感じだったのに。

そこで、AVX 命令を使って演算するモジュールを C++ で書いて Boost.Python 経由で読み込むように書き換えてみました。(ばねの力を計算する部分で少しアルゴリズムも少し変えています。) 結果、期待していたよりもパフォーマンスが上がり、N=1000 でも 1 分弱、N=10000 の場合でも 1 時間程度で結果を得ることができました。

パラメーターをいろいろ変えて試しているので動きが統一されていませんが、結果はそれなりに統一されています。例えば、青色 (=1) のデータは、データ間の距離がかなり短いらしく収束が早いことがすぐに分かります。逆に、灰色 (= 8) や白色 (= 7) のデータは他の数字と混じっており、ユークリッド距離だけだと区別が難しそうです。緑 (= 4) と紺色 (= 9) は同じエリアを共有しがちですが、確かに数字の形を考えると、似ていると言えなくもありません。。

http://ubuntu-web.cloudapp.net/ems/cmodule.htm

image

結果の考察はさておいて、もう少し欲を出してみたくなりました。そこで試みたのは 2 点。

  1. ノードを動かす前に、各ノード間をばねで繋ぐ際のユークリッド距離の計算が遅い
  2. オイラー法の計算の並列化

1. は未だ Python でやっており、N=10000 の場合だと、C(10000, 2) = 49,995,000 回も 784 次元座標のユークリッド距離を計算していることになるので、馬鹿にならない時間がかかります。入力データは変わらないので、予め全部の距離を計算してファイルに書き出しておくことにしました。おそらく、ファイルを読むだけの方が距離を計算するのよりは早いはずです。

2. はそのままマルチスレッド化です。1 時間も 1 CPU だけが仕事をしているのは何かもったいないので、何とか並列化したいところ。アイディアとしては、扱っている 2 次元データを次元毎にスレッドを分けて計算したい、というものです。

結果から書くと、1 は成功、2 は失敗です。1. だけ実装して、N=10000 で 1 時間を切ることはできました。

計算の大部分を占めるのが、Field::Move で、最初にばねの力を足し合わせるためのループから Field::Spring::load を呼んでいます。次元毎に処理を分けるのは Move() 後半のループで、コード自体は簡単に書けましたが、パフォーマンスはほぼ同じか、少し悪くなりました。前半のばねの計算のところでは、ばね毎の計算を分けて各スレッドに割り振ってみましたが、こちらのパフォーマンスは最悪で、2 倍以上落ちました。

void Field::Spring::load() {
    std::valarray<double> diff(_field->_dim);
    int i, n = _field->_m.size();
    double norm = .0;
    for (i = 0 ; i < _field->_dim ; ++i) {
        diff[i] = _field->_position[_n2 + i * n] – _field->_position[_n1 + i * n];
        norm += diff[i] * diff[i];
    }
    norm = sqrt(norm);
    for (i = 0 ; i < _field->_dim ; ++i) {
        double f = _k * (1 – _l / norm) * diff[i];
        _field->_accel[_n1 + n * i] += f / _field->_m[_n1];
        _field->_accel[_n2 + n * i] += -f / _field->_m[_n2];
    }
}

void Field::Move(double dt) {
    int i, j, n = _m.size();
    _accel = .0;
    for (auto &f : _forces) {
        if (f != nullptr) {
            f->load(); <<<< この呼び出しを WorkItem にする
        }
    }
    for (i = 0 ; i < _dim ; ++i) {
        for (j = 0 ; j < n ; ++j) { <<<< このループを WorkItem にする
            int idx = j + i * n;
            _velocity[idx] += dt * _accel[idx];
            _velocity[idx] -= _velocity[idx] * _friction[j] / _m[j];
            _position[idx] += dt * _velocity[idx];
        }
    }
}

コードは dev-mt ブランチにまとめています。コミットの順番を間違えた上、マージのやり方も微妙でコミット履歴がぐちゃぐちゃ・・

msmania/ems at dev-mt · GitHub
https://github.com/msmania/ems/tree/dev-mt

Linux でマルチスレッドのプログラムをまともに書いたことがなかったので、最善か分かりませんが、Windows でよくある、WorkQueue/WorkItem モデル (正式名称が分からない) を POSIX Thread を使って一から書きました。もしかすると標準や Boost に既にいいのがありそうですが。

ヘッダーの workq.h

class WorkQueue {
public:
    class Job {
    public:
        virtual ~Job() {}
        virtual void Run() = 0;
    };

private:
    enum WorkItemType {
        wiRun,
        wiExit,
        wiSync
    };

    class Event {
    private:
        pthread_mutex_t _lock;
        pthread_cond_t _cond;
        int _waitcount;
        int _maxcount;

    public:
        Event(int maxcount);
        virtual ~Event();
        void Wait();
    };

    class WorkItem {
    private:
        WorkItemType _type;
        void *_context;

    public:
        WorkItem(WorkItemType type, void *context);
        virtual ~WorkItem();
        virtual void Run();
    };

    int _numthreads;
    std::vector<pthread_t> _threads;
    Event _sync;
    pthread_mutex_t _taskqlock;
    std::queue<WorkItem*> _taskq;

    static void *StartWorkerthread(void *p);
    void *Workerthread(void *p);

public:
    WorkQueue(int numthreads);
    virtual ~WorkQueue();
    int CreateThreads();
    void JoinAll();
    void AddTask(Job *job);
    void Sync();
    void Exit();
};

ソースの workq.cpp

#include <pthread.h>
#include <unistd.h>
#include <vector>
#include <queue>
#include "workq.h"

#ifdef _LOG
#include <stdio.h>
#define LOGINFO printf
#else
#pragma GCC diagnostic ignored "-Wunused-value"
#define LOGINFO
#endif

WorkQueue::Event::Event(int maxcount) : _waitcount(0), _maxcount(maxcount) {
    pthread_mutex_init(&_lock, nullptr);
    pthread_cond_init(&_cond, nullptr);
}

WorkQueue::Event::~Event() {
    pthread_cond_destroy(&_cond);
    pthread_mutex_destroy(&_lock);
}

// Test Command: for i in {1..1000}; do ./t; done
void WorkQueue::Event::Wait() {
    LOGINFO("[%lx] start:wait\n", pthread_self());
    pthread_mutex_lock(&_lock);
    if (__sync_bool_compare_and_swap(&_waitcount, _maxcount, 0)) {
        pthread_cond_broadcast(&_cond);
    }
    else {
        __sync_fetch_and_add(&_waitcount, 1);
        pthread_cond_wait(&_cond, &_lock);
    }
    pthread_mutex_unlock(&_lock);
}

WorkQueue::WorkItem::WorkItem(WorkItemType type, void *context)
    : _type(type), _context(context) {}

WorkQueue::WorkItem::~WorkItem() {}

void WorkQueue::WorkItem::Run() {
    switch (_type) {
    case wiExit:
        LOGINFO("[%lx] exiting\n", pthread_self());
        pthread_exit(nullptr);
        break;
    case wiSync:
        if (_context) {
            ((Event*)_context)->Wait();
        }
        break;
    case wiRun:
        ((Job*)_context)->Run();
        break;
    default:
        break;
    }
}

void *WorkQueue::StartWorkerthread(void *p) {
    void *ret = nullptr;
    if (p) {
        ret = ((WorkQueue*)p)->Workerthread(p);
    }
    return ret;
}

void *WorkQueue::Workerthread(void *p) {
    while (true) {
        WorkItem *task = nullptr;
        pthread_mutex_lock(&_taskqlock);
        if (!_taskq.empty()) {
            task = _taskq.front();
            _taskq.pop();
        }
        pthread_mutex_unlock(&_taskqlock);
        if (task != nullptr) {
            task->Run();
            delete task;
        }
        else {
            usleep(10000);
        }
    }
}

WorkQueue::WorkQueue(int numthreads) : _numthreads(numthreads), _sync(numthreads) {
    pthread_mutex_init(&_taskqlock, nullptr);
    _threads.reserve(numthreads);
}

WorkQueue::~WorkQueue() {
    if (_threads.size() > 0) {
        JoinAll();
    }
    pthread_mutex_destroy(&_taskqlock);
}

int WorkQueue::CreateThreads() {
    int ret = 0;
    pthread_attr_t attr;
    pthread_attr_init(&attr);
    pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_JOINABLE);
    for (int i = 0; i<_numthreads ; ++i) {
        pthread_t p = 0;
        ret = pthread_create(&p, &attr, StartWorkerthread, this);
        if (ret == 0) {
            _threads.push_back(p);
        }
        else {
            LOGINFO("pthread_create failed – %08x\n", ret);
            break;
        }
    }
    pthread_attr_destroy(&attr);
    return ret;
}

void WorkQueue::JoinAll() {
    for (auto &t : _threads) {
        pthread_join(t, nullptr);
    }
    _threads.clear();
}

void WorkQueue::AddTask(Job *job) {
    pthread_mutex_lock(&_taskqlock);
    _taskq.push(new WorkItem(wiRun, job));
    pthread_mutex_unlock(&_taskqlock);
}

void WorkQueue::Sync() {
    pthread_mutex_lock(&_taskqlock);
    for (int i = 0 ; i<_numthreads; ++i) {
        _taskq.push(new WorkItem(wiSync, &_sync));
    }
    pthread_mutex_unlock(&_taskqlock);
    _sync.Wait();
}

void WorkQueue::Exit() {
    pthread_mutex_lock(&_taskqlock);
    for (int i = 0 ; i<_numthreads; ++i) {
        _taskq.push(new WorkItem(wiExit, nullptr));
    }
    pthread_mutex_unlock(&_taskqlock);
}

WorkQueue クラスがキューを持っていて、各ワーカー スレッドが放り込まれた WorkItem を逐次処理します。それに加えてある種の同期処理を付け加えました。今回の例で言えば、ばねの力を計算する WorkItem を全部投げ終わった後、速度や位置の計算をするためには、全てのばねの計算が完了していないといけません。つまり、WorkItem が全て処理されたかどうかを WorkQueue 側で判断できる機構が必要になります。

同期処理は、pthread に加えて条件変数 (condition varialbe) を使って実現しています。これは Windows のカーネル オブジェクトの一つであるイベントに似ています。WorkQueue::Sync() を呼ぶと、条件変数のシグナル待ちを引き起こす WorkItem をワーカー スレッドの数だけ投げ込んで、待機状態になったスレッドの数がワーカー スレッドと同じになるまで、Sync() を呼び出しているスレッドもを待機させておく、という動作を行ないます。

話を戻して、ばねの力の計算、すなわち Field::Spring::load() の並列化が失敗した原因は明白で、個々のワークアイテムが細かすぎたことと、ばねの力を加速度のベクトルに代入するときに排他ロックを獲得する必要があるからでしょう。これのせいで、WorkItem を出し入れしているコストがだいぶ高くついてしまいます。もし double をアトミックに加算する命令があれば排他ロックしなくてもいいのですが・・・。アルゴリズムでカバーするとすれば、ばねにつながっているノードがスレッドごとに重複しないように WorkItem を分ける方法がありますが、これだと、全部で C(10000, 2) = 49,995,000ある計算を C(5000, 2) 12,497,500 分は 2 スレッドで処理して残りの 25,000,000 は 1 スレッドで処理する、という感じになって、大して得しなそうなので断念しました。他にもっとうまい分け方を思いついたら試してみます。

速度と位置の計算は、単純に次元毎にスレッドを分けられるため排他ロックの必要はありませんが、やはり WorkItem が細かいので並列化のコストのほうが高くなってしまったのだと考えられます。3 次元プロットだったら使えるのかもしれませんが、まだそこまで手を出す段階じゃない・・。

こんなので土曜日が無駄になってしまった。もったいない。

Boost.Python debugging

Boost.Python で std::valarray をエクスポートする際、__getitem__ に operator[] を渡すと、インデックスが境界を超えてもエラーにならないため、無限ループに陥る現象について書きました。その後の追加情報を紹介します。

1. 非メンバ関数をクラス メソッドとしてエクスポート

前回は、回避策として valarray を継承したクラスを作って operator::at を新たに定義しました。が、Python の wiki を見ていたところ、Boost.Python の class_ で定義するコンバーターのメンバー関数にはメンバー関数ポインターだけでなく、通常の関数も指定できることが分かりました。

boost.python/ExportingClasses – Python Wiki
https://wiki.python.org/moin/boost.python/ExportingClasses

これを使うと、新たにクラスを定義しなくても __getitem__ を正しく定義できます。

#include <boost/python.hpp>
#include <valarray>
#include <random>
#include <stdio.h>

std::default_random_engine generator;
std::uniform_real_distribution<double> distribution(0.0, 1.0);

typedef std::valarray<double> darray;

class Field {
private:
    darray _data;

public:
    Field(int n) : _data(n) {
        printf("Field::Field(): %p\n", this);
    }
    ~Field() {
        printf("Field::~Field() %p\n", this);
    }

    void Dump() const {
        printf("[");
        for (auto &d : _data) {
            printf("% 3.3f", d);
        }
        printf(" ]\n");
    }

    void Churn() {
        for (auto &d : _data) {
            d = distribution(generator);
        }
    }

    const darray &Positions() const {
        return _data;
    }
};

double GetAt(const darray &arr, size_t n) {
    if (n >= arr.size()) {
        std::__throw_out_of_range_fmt(__N("out_of_range"));
    }
    return arr[n];
}

BOOST_PYTHON_MODULE(ems) {
    using namespace boost::python;

    class_<Field>("Field", init<int>())
        .def("Positions", &Field::Positions,
             return_internal_reference<>())
        .def("Dump", &Field::Dump)
        .def("Churn", &Field::Churn)
        ;

    class_<darray>("darray")
        .def("__getitem__", GetAt)
        .def("__len__", &darray::size)
        ;
}

ここから、壮大に話が逸れていくのですが、前回こんなことを書きました。

もう少し見てみないと分かりませんが、ems.Field オブジェクトが iterator を使ってシーケンシャルにアクセスする種類になっているのが悪いのではないかと思います。何らかの方法で、ems.Field は iterator ではなくインデックスを使ってランダム アクセスすべきものに種別できればちゃんと動くのではないかと。そんな種類があるかどうか分かりませんが。後で調べよう。

今回も結論から書くとたぶんこれは無理です。Boost.Python をデバッグしつつ調べたので、その過程を書いておきます。

2. Boost.Python をソースからビルドして使う

まずデバッグ環境の構築です。Boost のコードは GitHub にあるので、クローンしてからビルドします。

git clone –recursive https://github.com/boostorg/boost.git modular-boost
git checkout refs/tags/boost-1.60.0
cd modular-boost/
./bootstrap.sh
./b2 -a –with-python debug-symbols=on
sudo ./b2 -a –prefix=/usr/local/boost/boost-1.60.0 –with-python debug-symbols=on install
sudo ln -s /usr/local/boost/boost-1.60.0 /usr/local/boost/current

コマンドを作るうえで参考にしたページは↓。Boost をビルドしている人は少ない気がする・・。

TryModBoost – Boost C++ Libraries
https://svn.boost.org/trac/boost/wiki/TryModBoost

Installing Boost.Python on your System
http://boostorg.github.io/python/doc/html/building/installing_boost_python_on_your_.html

Builtin features
http://www.boost.org/build/doc/html/bbv2/overview/builtins/features.html

ビルドには、make ではなく b2 (build boost?) を使います。最新のリポジトリをクローンしてそのままビルドしたところ、文法エラーでビルドが失敗したので、boost-1.60.0 のタグの状態でビルドしました。もう直っているかもしれません。

デバッグ情報を生成するため、debug-symbols=on というオプションをつけています。これは、コードの最適化はデフォルトの ON にしたまま、デバッグ情報を生成するという意味です。普通は variant=debug というオプションをつけて、最適化も off にしたほうがいいです。インライン展開された魔境に挑みたい人のみ、debug-symbols=on を使いましょう。

上記コマンドで、libboost_python が /usr/local/boost/current/lib にできるので、C++ の Makefile を以下のように変更します。Boost,Python は Python API を使うので、API の中をデバッグするため、libpython2.7 のデバッグ情報もあったほうが便利です。以下の Makefile は、ソースからビルドした Python 2.7 が /usr/local/python/current/ にインストールされている前提です。Boost.Python を使って共有ライブラリを作るので、libpython2.7 も PIC でコンパイルする必要があります。つまり、Python の configure で –enable-shared オプションをつけておいてください。

CC=g++
RM=rm -f

TARGET=ems.so
SRCS=$(wildcard *.cpp)
OBJS=$(SRCS:.cpp=.o)

override CFLAGS+=-Wall -fPIC -std=c++11 -O2 -g
LFLAGS=

INCLUDES=-I/usr/local/python/current/include/python2.7 -I/usr/local/boost/current/include
LIBDIRS=-L/usr/local/python/current/lib -L/usr/local/boost/current/lib
LIBS=-lpython2.7 -lboost_python

all: clean $(TARGET)

clean:
        $(RM) $(OBJS) $(TARGET)

$(TARGET): $(OBJS)
        $(CC) -shared $(LFLAGS) $(LIBDIRS) $^ -o $@ $(LIBS)

$(OBJS): $(SRCS)
        $(CC) $(INCLUDES) $(CFLAGS) -c $^

デバッガーを起動する前に、python を実行する前のライブラリの検索パスにも追加しておきます。gdb を起動するときはこんな感じにします。

export PYTHONPATH=/usr/local/lib/python2.7/dist-packages
export LD_LIBRARY_PATH=/usr/local/boost/current/lib:/usr/local/python/current/lib
gdb /usr/local/python/current/bin/python

ここから gdb によるデバッグを行いますが、結果として何か得られたわけではありません。考え方の参考になれば幸いです。

まず、Python API に PyObject_GetIter という関数があります。

Object Protocol — Python 2.7.11 documentation
https://docs.python.org/2/c-api/object.html

valarray のコンバーターである darray に対して Python から列挙を行なおうとすると、PyObject_GetIter が呼ばれます。

john@ubuntu1510:~/Documents/pyc$ export PYTHONPATH=/usr/local/lib/python2.7/dist-packages
john@ubuntu1510:~/Documents/pyc$ export LD_LIBRARY_PATH=/usr/local/boost/current/lib:/usr/local/python/current/lib
john@ubuntu1510:~/Documents/pyc$ gdb /usr/local/python/current/bin/python
GNU gdb (Ubuntu 7.10-1ubuntu2) 7.10
Copyright (C) 2015 Free Software Foundation, Inc.
(略)
Type "apropos word" to search for commands related to "word"…
Reading symbols from /usr/local/python/current/bin/python…done.
(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 22 2015, 22:30:16)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import ems
>>> f = ems.Field(4)
Field::Field(): 0x6d09d0
>>> x = f.Positions()
>>> x
<ems.darray object at 0x7ffff7ed5600>
>>>
Program received signal SIGINT, Interrupt.
0x00007ffff74e4723 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81
81      ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) b PyObject_GetIter
Breakpoint 1 at 0x7ffff7a261c0: file Objects/abstract.c, line 3085.
(gdb) i b
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   0x00007ffff7a261c0 in PyObject_GetIter at Objects/abstract.c:3085
(gdb) c
Continuing.

>>> [i for i in x]

Breakpoint 1, PyObject_GetIter (o=o@entry=0x7ffff7ed5600) at Objects/abstract.c:3085
3085    {
(gdb) bt 5
#0  PyObject_GetIter (o=o@entry=0x7ffff7ed5600) at Objects/abstract.c:3085
#1  0x00007ffff7ad7db0 in PyEval_EvalFrameEx (f=f@entry=0x7ffff7f7e050,
    throwflag=throwflag@entry=0) at Python/ceval.c:2790
#2  0x00007ffff7ae068c in PyEval_EvalCodeEx (co=co@entry=0x7ffff7ed6930,
    globals=globals@entry=0x7ffff7f6b168, locals=locals@entry=0x7ffff7f6b168, args=args@entry=0x0,
    argcount=argcount@entry=0, kws=kws@entry=0x0, kwcount=0, defs=0x0, defcount=0, closure=0x0)
    at Python/ceval.c:3582
#3  0x00007ffff7ae07a9 in PyEval_EvalCode (co=co@entry=0x7ffff7ed6930,
    globals=globals@entry=0x7ffff7f6b168, locals=locals@entry=0x7ffff7f6b168) at Python/ceval.c:669
#4  0x00007ffff7b05d81 in run_mod (arena=0x66f100, flags=0x7fffffffe370, locals=0x7ffff7f6b168,
    globals=0x7ffff7f6b168, filename=0x7fffffffe370 "", mod=0x6b9ce8) at Python/pythonrun.c:1370
(More stack frames follow…)

関数のコードはこうなっています。引数として与えられた Python オブジェクトに関連付けられた Iterator をオブジェクトとして返す関数です。

Objects/abstract.c
3083 PyObject *
3084 PyObject_GetIter(PyObject *o)
3085 {
3086     PyTypeObject *t = o->ob_type;
3087     getiterfunc f = NULL;
3088     if (PyType_HasFeature(t, Py_TPFLAGS_HAVE_ITER))
3089         f = t->tp_iter;
3090     if (f == NULL) {
3091         if (PySequence_Check(o))
3092             return PySeqIter_New(o);
3093         return type_error("’%.200s’ object is not iterable", o);
3094     }
3095     else {
3096         PyObject *res = (*f)(o);
3097         if (res != NULL && !PyIter_Check(res)) {
3098             PyErr_Format(PyExc_TypeError,
3099                          "iter() returned non-iterator "
3100                          "of type ‘%.100s’",
3101                          res->ob_type->tp_name);

関数の冒頭で、引数の PyTypeObject で Py_TPFLAGS_HAVE_ITER フラグを判定し、有効な場合は関連付けられた iterator である tp_iter を使うようになっています。これをパッと見たときに、valarray からコンバートした darray オブジェクトからこのフラグを削除してみようと考えました。まずは、現時点での TypeObject を見てます。

(gdb) frame
#0  PyObject_GetIter (o=o@entry=0x7ffff7ed5600) at Objects/abstract.c:3085
3085    {
(gdb) p *o->ob_type
$1 = {ob_refcnt = 5, ob_type = 0x7ffff5a7cc40 <boost::python::class_metatype_object>, ob_size = 0,
  tp_name = 0x7ffff7e94954 "darray", tp_basicsize = 48, tp_itemsize = 1,
  tp_dealloc = 0x7ffff7a8b390 <subtype_dealloc>, tp_print = 0x0, tp_getattr = 0x0,
  tp_setattr = 0x0, tp_compare = 0x0, tp_repr = 0x7ffff7a8f390 <object_repr>,
  tp_as_number = 0x6d3c88, tp_as_sequence = 0x6d3dd8, tp_as_mapping = 0x6d3dc0,
  tp_hash = 0x7ffff7a70be0 <_Py_HashPointer>, tp_call = 0x0, tp_str = 0x7ffff7a8acc0 <object_str>,
  tp_getattro = 0x7ffff7a72410 <PyObject_GenericGetAttr>,
  tp_setattro = 0x7ffff7a72670 <PyObject_GenericSetAttr>, tp_as_buffer = 0x6d3e28,
  tp_flags = 153595, tp_doc = 0x0, tp_traverse = 0x7ffff7a8b0a0 <subtype_traverse>,
  tp_clear = 0x7ffff7a8d290 <subtype_clear>, tp_richcompare = 0x0, tp_weaklistoffset = 32,
  tp_iter = 0x0, tp_iternext = 0x7ffff7a72100 <_PyObject_NextNotImplemented>, tp_methods = 0x0,
  tp_members = 0x6d3e68, tp_getset = 0x0,
  tp_base = 0x7ffff5a7cfa0 <boost::python::objects::class_type_object>, tp_dict = 0x7ffff7e98050,
  tp_descr_get = 0x0, tp_descr_set = 0x0, tp_dictoffset = 24,
  tp_init = 0x7ffff7a91f70 <slot_tp_init>, tp_alloc = 0x7ffff7a8ade0 <PyType_GenericAlloc>,
  tp_new = 0x7ffff5856890
     <boost::python::objects::instance_new(PyTypeObject*, PyObject*, PyObject*)>,
  tp_free = 0x7ffff7b1e2b0 <PyObject_GC_Del>, tp_is_gc = 0x0, tp_bases = 0x7ffff7e96410,
  tp_mro = 0x7ffff7e8e780, tp_cache = 0x0, tp_subclasses = 0x0, tp_weaklist = 0x7ffff7e77f70,
  tp_del = 0x0, tp_version_tag = 0}
(gdb) p/x 153595
$2 = 0x257fb

型の名前は "darray" となっており、Py_TPFLAGS_HAVE_ITER (= 0x80) は ON、tp_iter は NULL になっています。気づくまで時間がかかってしまったのですが、この TypeObject の内容と PyObject_GetIter のコードを見る限り、Py_TPFLAGS_HAVE_ITER の有無による影響はなく、いずれの場合でも f == NULL は true になります。そこで PySequence_Check の定義を見ます。

Objects/abstract.c
1843 int
1844 PySequence_Check(PyObject *s)
1845 {
1846     if (s == NULL)
1847         return 0;
1848     if (PyInstance_Check(s))
1849         return PyObject_HasAttrString(s, "__getitem__");
1850     if (PyDict_Check(s))
1851         return 0;
1852     return  s->ob_type->tp_as_sequence &&
1853         s->ob_type->tp_as_sequence->sq_item != NULL;
1854 }

darray オブジェクトは、3 つの if 文には引っかかりませんが、最後の条件で true になります。sq_item の値は slot_sq_item 関数になっています。slot_sq_item 関数は前回のデバッグ時に、iter_iternext から呼び出されており、これらが境界チェックをしていないのが無限ループの原因でした。

(gdb) p *$1.tp_as_sequence
$8 = {sq_length = 0x7ffff7a93f60 <slot_sq_length>, sq_concat = 0x0, sq_repeat = 0x0,
  sq_item = 0x7ffff7a91090 <slot_sq_item>, sq_slice = 0x0, sq_ass_item = 0x0, sq_ass_slice = 0x0,
  sq_contains = 0x0, sq_inplace_concat = 0x0, sq_inplace_repeat = 0x0}

そんなわけで PySequence_Check は true を返すので、PyObject_GetIter から PySeqIter_New が呼ばれて新しい iterator が作られます。その iterator が↓です。gdb に windbg で言うところの ub コマンドが無いのが辛い・・。

(gdb) x/5i 0x7ffff7ad7da1
   0x7ffff7ad7da1 <PyEval_EvalFrameEx+4225>:    mov    %rcx,%rbp
   0x7ffff7ad7da4 <PyEval_EvalFrameEx+4228>:    mov    -0x8(%rbx),%r13
   0x7ffff7ad7da8 <PyEval_EvalFrameEx+4232>:    mov    %r13,%rdi
   0x7ffff7ad7dab <PyEval_EvalFrameEx+4235>:    callq  0x7ffff7a0f550 <PyObject_GetIter@plt>
=> 0x7ffff7ad7db0 <PyEval_EvalFrameEx+4240>:    subq   $0x1,0x0(%r13)
(gdb) p *(seqiterobject*)$rax
$9 = {ob_refcnt = 1, ob_type = 0x7ffff7d9e9c0 <PySeqIter_Type>, it_index = 0,
  it_seq = 0x7ffff7ed5600}

つまり、__getitem__ だけを実装したオブジェクトはシーケンスとして扱われるが、Python はシーケンスもリストも iterator を使ってアクセスし、それは境界をいちいちチェックしない、という仕様になっています。つまりわりとどうしようもないです。冒頭で書いたように、クラス定義をしなくても通常関数をオブジェクト メソッドとして実装できるので、それが正しい解決策なのだと思います。

Boost のデバッグいつ出てくるんだ、という話ですが、Python オブジェクトから Py_TPFLAGS_HAVE_ITER フラグを消す方法を見つけるためにデバッグしました。

3. Boost.Python のコードをデバッグする

上述の o->ob_type が指すオブジェクトがいつ作られているのか、を追いかけます。Boost や Python のコードを見ても、Py_TPFLAGS_HAVE_ITER を個別に設定しているコードは無く、デフォルトの Py_TPFLAGS_DEFAULT で使われているだけです。darray の TypeObject が作られるヒントとしては、TypeObject の ob_type が ob_type = 0x7ffff5a7cc40 <boost::python::class_metatype_object> になっているのが使えます。

class_metatype_object は、Boost.Python のグローバル変数であり、これが使われる場所は一箇所しかありません。それが class_metatype() です。

src/object/class.cpp
315   BOOST_PYTHON_DECL type_handle class_metatype()
316   {
317       if (class_metatype_object.tp_dict == 0)
318       {
319           Py_TYPE(&class_metatype_object) = &PyType_Type;
320           class_metatype_object.tp_base = &PyType_Type;
321           if (PyType_Ready(&class_metatype_object))
322               return type_handle();
323       }
324       return type_handle(borrowed(&class_metatype_object));
325   }

幸い、この関数はインライン展開されないので、ここを起点にします。ポイントは、この関数はモジュールのインポート時に呼ばれることです。そこで、import 後の状態で関数の完全修飾名を調べてから、再度デバッグ ターゲットを実行します。

john@ubuntu1510:~/Documents/pyc$ gdb /usr/local/python/current/bin/python
GNU gdb (Ubuntu 7.10-1ubuntu2) 7.10
(略)
Reading symbols from /usr/local/python/current/bin/python…done.
(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 22 2015, 22:30:16)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import ems # まずは何もせずインポート
>>>
Program received signal SIGINT, Interrupt.
0x00007ffff74e4723 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81
81      ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) i func class_metatype # 完全修飾名を調べる
All functions matching regular expression "class_metatype":

File libs/python/src/object/class.cpp:
boost::python::type_handle boost::python::objects::class_metatype();

Non-debugging symbols:
0x00007ffff5845c40  boost::python::objects::class_metatype()@plt
(gdb) r # 再実行
The program being debugged has been started already.
Start it from the beginning? (y or n) y
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 22 2015, 22:30:16)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>>
Program received signal SIGINT, Interrupt.
0x00007ffff74e4723 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81
81      ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) b boost::python::objects::class_metatype # import 前にブレークポイント
Function "boost::python::objects::class_metatype" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (boost::python::objects::class_metatype) pending.
(gdb) c
Continuing.

>>> import ems

Breakpoint 1, 0x00007ffff5845c40 in boost::python::objects::class_metatype()@plt ()
   from /usr/local/boost/current/lib/libboost_python.so.1.60.0
(gdb) i b
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   <MULTIPLE>
        breakpoint already hit 1 time
1.1                         y     0x00007ffff5845c40 <boost::python::objects::class_metatype()@plt>
1.2                         y     0x00007ffff5856b00 in boost::python::objects::class_metatype()
                                                   at libs/python/src/object/class.cpp:317
(gdb) disable 1.1 # plt 上のブレークポイントは無効
(gdb) c
Continuing.

Breakpoint 1, boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
317           if (class_metatype_object.tp_dict == 0)
(gdb)

もう一点。この方法だと、モジュールがロードされたときにシンボル名をもとにアドレスをに検索するので、対象が共有ライブラリの場合、関数の先頭のアドレス以外に、plt 上のアドレスにもブレークポイントが設定されます。これは邪魔なので無効にしておきます。

PLT とは Procedure Linkage Table の略で、Windows でいうところのインポート テーブルと似たようなものです。

Technovelty – PLT and GOT – the key to code sharing and dynamic libraries
https://www.technovelty.org/linux/plt-and-got-the-key-to-code-sharing-and-dynamic-libraries.html

コールスタックを見ると、shared.cpp に実装された init_module_ems から、class_ クラスのコンストラクタ (#4) 経由で呼ばれています。テンプレートの入れ子で、シンボル名が複雑怪奇です。

(gdb) bt 10
#0  boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
#1  0x00007ffff5856bb8 in boost::python::objects::class_type ()
    at libs/python/src/object/class.cpp:473
#2  0x00007ffff5857d8d in boost::python::objects::(anonymous namespace)::new_class (
    doc=<optimized out>, types=0x7fffffffdd90, num_types=1, name=<optimized out>)
    at libs/python/src/object/class.cpp:561
#3  boost::python::objects::class_base::class_base (this=0x7fffffffdbf0,
    name=0x7ffff5a89bd5 "Field", num_types=1, types=0x7fffffffdd90, doc=0x0)
    at libs/python/src/object/class.cpp:591
#4  0x00007ffff5a874be in boost::python::class_<Field, boost::python::detail::not_specified, boost::python::detail::not_specified, boost::python::detail::not_specified>::class_<boost::python::init<int, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_, mpl_::void_> > (i=…,
    name=0x7ffff5a89bd5 "Field", this=0x7fffffffdbf0)
    at /usr/local/boost/current/include/boost/python/class.hpp:206
#5  init_module_ems () at shared.cpp:51
#6  0x00007ffff58639f3 in boost::function0<void>::operator() (this=0x7fffffffde50)
    at ./boost/function/function_template.hpp:771
#7  boost::python::handle_exception_impl (f=…) at libs/python/src/errors.cpp:25
#8  0x00007ffff5864736 in boost::python::handle_exception<void (*)()> (
    f=0x7ffff5a87440 <init_module_ems()>) at ./boost/python/errors.hpp:29
#9  boost::python::detail::(anonymous namespace)::init_module_in_scope (
    init_function=<optimized out>, m=0x7ffff7e937c0) at libs/python/src/module.cpp:24
(More stack frames follow…)

#3 の class_base のコンストラクタは以下のように定義されています。

src/object/class.cpp
589   class_base::class_base(
590       char const* name, std::size_t num_types, type_info const* const types, char const* doc)
591       : object(new_class(name, num_types, types, doc))
592   {
593       // Insert the new class object in the registry
594       converter::registration& converters = const_cast<converter::registration&>(
595           converter::registry::lookup(types[0]));
596
597       // Class object is leaked, for now
598       converters.m_class_object = (PyTypeObject*)incref(this->ptr());
599   }

class_metatype() は初期化リストのなかで使われています。ここでの object とは、class_base の基底クラスの一つです。object クラスを new_class 関数の戻り値で初期化すると、m_ptr というメンバー関数が初期化されます。引数の types を元に lookup してきたコンバーターの m_class_object に、その m_ptr を代入する、というのがこのコンストラクターの動作です。

ブレークポイントを設定した class_metatype() は、new_class() から 2 回呼ばれます。line:561 の class_type() 経由と、line:575 です。戻り値に直接関係あるのは後者です。

src/object/class.cpp
548     inline object
549     new_class(char const* name, std::size_t num_types, type_info const* const types, char const*     doc)
550     {
551       assert(num_types >= 1);
552
553       // Build a tuple of the base Python type objects. If no bases
554       // were declared, we’ll use our class_type() as the single base
555       // class.
556       ssize_t const num_bases = (std::max)(num_types – 1, static_cast<std::size_t>(1));
557       handle<> bases(PyTuple_New(num_bases));
558
559       for (ssize_t i = 1; i <= num_bases; ++i)
560       {
561           type_handle c = (i >= static_cast<ssize_t>(num_types)) ? class_type() : get_class(type    s[i]);
562           // PyTuple_SET_ITEM steals this reference
563           PyTuple_SET_ITEM(bases.get(), static_cast<ssize_t>(i – 1), upcast<PyObject>(c.release(    )));
564       }
565
566       // Call the class metatype to create a new class
567       dict d;
568
569       object m = module_prefix();
570       if (m) d["__module__"] = m;
571
572       if (doc != 0)
573           d["__doc__"] = doc;
574
575       object result = object(class_metatype())(name, bases, d);
576       assert(PyType_IsSubtype(Py_TYPE(result.ptr()), &PyType_Type));
577
578       if (scope().ptr() != Py_None)
579           scope().attr(name) = result;
580
581       // For pickle. Will lead to informative error messages if pickling
582       // is not enabled.
583       result.attr("__reduce__") = object(make_instance_reduce_function());
584
585       return result;
586     }
587   }

1 回目の呼び出しはスルーして、2 回目の呼び出しで止めます。

(gdb) b boost::python::objects::class_metatype
Function "boost::python::objects::class_metatype" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (boost::python::objects::class_metatype) pending.
(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 22 2015, 22:30:16)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import ems

Breakpoint 1, 0x00007ffff5845c40 in boost::python::objects::class_metatype()@plt ()
   from /usr/local/boost/current/lib/libboost_python.so.1.60.0
(gdb) i b
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   <MULTIPLE>
        breakpoint already hit 1 time
1.1                         y     0x00007ffff5845c40 <boost::python::objects::class_metatype()@plt>
1.2                         y     0x00007ffff5856b00 in boost::python::objects::class_metatype()
                                                   at libs/python/src/object/class.cpp:317
(gdb) disable 1.1
(gdb) c
Continuing.

Breakpoint 1, boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
317           if (class_metatype_object.tp_dict == 0)
(gdb) bt 4
#0  boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
#1  0x00007ffff5856bb8 in boost::python::objects::class_type ()
    at libs/python/src/object/class.cpp:473
#2  0x00007ffff5857d8d in boost::python::objects::(anonymous namespace)::new_class (
    doc=<optimized out>, types=0x7fffffffdd90, num_types=1, name=<optimized out>)
    at libs/python/src/object/class.cpp:561
#3  boost::python::objects::class_base::class_base (this=0x7fffffffdbf0,
    name=0x7ffff5a89bd5 "Field", num_types=1, types=0x7fffffffdd90, doc=0x0)
    at libs/python/src/object/class.cpp:591
(More stack frames follow…)
(gdb) c
Continuing.

Breakpoint 1, boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
317           if (class_metatype_object.tp_dict == 0)
(gdb) bt 3
#0  boost::python::objects::class_metatype () at libs/python/src/object/class.cpp:317
#1  0x00007ffff5857f92 in boost::python::objects::(anonymous namespace)::new_class (
    doc=<optimized out>, types=0x7fffffffdd90, num_types=1, name=<optimized out>)
    at libs/python/src/object/class.cpp:575
#2  boost::python::objects::class_base::class_base (this=0x7fffffffdbf0,
    name=0x7ffff5a89bd5 "Field", num_types=1, types=0x7fffffffdd90, doc=0x0)
    at libs/python/src/object/class.cpp:591
(More stack frames follow…)
(gdb)

line:575 の "object(class_metatype())(name, bases, d);" で、object が関数なのかコンストラクタなのか理解に苦しむところです。後半の (name, bases, d) は operator() 呼び出しだと推測は出来ます。この行は最適化が有効だと全部インライン展開されるので、とりあえず class_metatype() から戻ってきたところでアセンブリを見ます。

(gdb) fin
Run till exit from #0  boost::python::objects::class_metatype ()
    at libs/python/src/object/class.cpp:317
boost::python::objects::(anonymous namespace)::new_class (doc=<optimized out>,
    types=0x7fffffffdd90, num_types=1, name=<optimized out>)
    at libs/python/src/object/class.cpp:575
Value returned is $1 = {m_p = 0x7fffffffdaa0}
(gdb) x/20i $rip
=> 0x7ffff5857f92 <…+690>:   mov    0x60(%rsp),%rbx
   0x7ffff5857f97 <…+695>:   test   %rbx,%rbx
   0x7ffff5857f9a <…+698>:   je     0x7ffff5858582 <…+2210>
   0x7ffff5857fa0 <…+704>:   addq   $0x1,(%rbx)
   0x7ffff5857fa4 <…+708>:   test   %rbp,%rbp
   0x7ffff5857fa7 <…+711>:   mov    0x40(%rsp),%r14
   0x7ffff5857fac <…+716>:   mov    %rbp,%r13
   0x7ffff5857faf <…+719>:   je     0x7ffff5858576 <…+2198>
   0x7ffff5857fb5 <…+725>:   mov    0x18(%rsp),%rdi
   0x7ffff5857fba <…+730>:   callq  0x7ffff5844d40 <_ZN5boost6python9converter19do_return_to_pythonEPKc@plt>
   0x7ffff5857fbf <…+735>:   test   %rax,%rax
   0x7ffff5857fc2 <…+738>:   mov    %rax,%r12
   0x7ffff5857fc5 <…+741>:   je     0x7ffff58585bd <…+2269>
   0x7ffff5857fcb <…+747>:   lea    0x1705a(%rip),%rsi        # 0x7ffff586f02c
   0x7ffff5857fd2 <…+754>:   mov    %r14,%r8
   0x7ffff5857fd5 <…+757>:   mov    %r13,%rcx
   0x7ffff5857fd8 <…+760>:   mov    %r12,%rdx
   0x7ffff5857fdb <…+763>:   mov    %rbx,%rdi
   0x7ffff5857fde <…+766>:   xor    %eax,%eax
   0x7ffff5857fe0 <…+768>:   callq  0x7ffff5845a30 <PyEval_CallFunction@plt>
(gdb)

PyEval_CallFunction という Python API の呼び出しが怪しいのでここで止めます。

(gdb) b PyEval_CallFunction
Breakpoint 2 at 0x7ffff7b00fd0: file Python/modsupport.c, line 544.
(gdb) c
Continuing.

Breakpoint 2, PyEval_CallFunction (
    obj=obj@entry=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    format=format@entry=0x7ffff586f02c "(OOO)") at Python/modsupport.c:544
544     {
(gdb) bt 5
#0  PyEval_CallFunction (obj=obj@entry=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    format=format@entry=0x7ffff586f02c "(OOO)") at Python/modsupport.c:544

#1  0x00007ffff5857fe5 in boost::python::call<boost::python::api::object, char const*, boost::python::handle<_object>, boost::python::dict> (a2=…, a1=<synthetic pointer>, a0=<synthetic pointer>,
    callable=0x7ffff5a7cc40 <boost::python::class_metatype_object>) at ./boost/python/call.hpp:66
#2  boost::python::api::object_operators<boost::python::api::object>::operator()<char const*, boost::python::handle<_object>, boost::python::dict> (a2=…, a1=<synthetic pointer>,
    a0=<synthetic pointer>, this=<optimized out>) at ./boost/python/object_call.hpp:19
#3  boost::python::objects::(anonymous namespace)::new_class (doc=<optimized out>,
    types=0x7fffffffdd90, num_types=<optimized out>, name=<optimized out>)
    at libs/python/src/object/class.cpp:575
#4  boost::python::objects::class_base::class_base (this=0x7fffffffdbf0,
    name=0x7ffff5a89bd5 "Field", num_types=<optimized out>, types=0x7fffffffdd90, doc=0x0)
    at libs/python/src/object/class.cpp:591
(More stack frames follow…)
(gdb)

PyEval_CallFunction は、C/C++ から Python の関数を呼ぶための API です。第二引数の format が "(OOO)" になっているので、3 つのオブジェクトからなるタプルを引数として Python の関数を呼んでいます。何の関数を呼ぶのかは、第一引数を見れば分かります。

(gdb) p *obj->ob_type
$4 = {ob_refcnt = 41, ob_type = 0x7ffff7daaf60 <PyType_Type>, ob_size = 0,
  tp_name = 0x7ffff7b4008c "type", tp_basicsize = 872, tp_itemsize = 40,
  tp_dealloc = 0x7ffff7a8b1f0 <type_dealloc>, tp_print = 0x0, tp_getattr = 0x0, tp_setattr = 0x0,
  tp_compare = 0x0, tp_repr = 0x7ffff7a8f600 <type_repr>, tp_as_number = 0x0,
  tp_as_sequence = 0x0, tp_as_mapping = 0x0, tp_hash = 0x7ffff7a70be0 <_Py_HashPointer>,
  tp_call = 0x7ffff7a908a0 <type_call>, tp_str = 0x7ffff7a8acc0 <object_str>,
  tp_getattro = 0x7ffff7a9a2c0 <type_getattro>, tp_setattro = 0x7ffff7a91930 <type_setattro>,
  tp_as_buffer = 0x0, tp_flags = 2148423147,
  tp_doc = 0x7ffff7da8f80 <type_doc> "type(object) -> the object’s type\ntype(name, bases, dict) -> a new type", tp_traverse = 0x7ffff7a8c2c0 <type_traverse>, tp_clear = 0x7ffff7a90370 <type_clear>,
  tp_richcompare = 0x7ffff7a8bac0 <type_richcompare>, tp_weaklistoffset = 368, tp_iter = 0x0,
  tp_iternext = 0x0, tp_methods = 0x7ffff7da9200 <type_methods>,
  tp_members = 0x7ffff7da9500 <type_members>, tp_getset = 0x7ffff7da93e0 <type_getsets>,
  tp_base = 0x7ffff7daadc0 <PyBaseObject_Type>, tp_dict = 0x7ffff7f98280, tp_descr_get = 0x0,
  tp_descr_set = 0x0, tp_dictoffset = 264, tp_init = 0x7ffff7a8d3b0 <type_init>,
  tp_alloc = 0x7ffff7a8ade0 <PyType_GenericAlloc>, tp_new = 0x7ffff7a98200 <type_new>,
  tp_free = 0x7ffff7b1e2b0 <PyObject_GC_Del>, tp_is_gc = 0x7ffff7a8aca0 <type_is_gc>,
  tp_bases = 0x7ffff7f9b090, tp_mro = 0x7ffff7f9a878, tp_cache = 0x0,
  tp_subclasses = 0x7ffff7f4ce60, tp_weaklist = 0x7ffff7f9e050, tp_del = 0x0, tp_version_tag = 11}

名前と doc から、これは Python の組み込み関数 type() であることが分かります。どうやら Boost.Python は、Python の組み込み関数を使って型を作っているようです。テンプレートでこんなことができるとか Boost 凄すぎ・・。

Python のコードの中に、新しい型オブジェクトを作る関数があるはずなので、それを適当なキーワード (Py_TPFLAGS_HAVE_GC とか) を使って探すと、type_new というそれっぽい関数が Objects/typeobject.c に見つかるので、ここで止めます。

(gdb) i b
Num     Type           Disp Enb Address            What
1       breakpoint     keep y   <MULTIPLE>
        breakpoint already hit 3 times
1.1                         n     0x00007ffff5845c40 <boost::python::objects::class_metatype()@plt>
1.2                         y     0x00007ffff5856b00 in boost::python::objects::class_metatype()
                                                   at libs/python/src/object/class.cpp:317
2       breakpoint     keep y   0x00007ffff7b00fd0 in PyEval_CallFunction
                                                   at Python/modsupport.c:544
        breakpoint already hit 1 time
(gdb) disable
(gdb) b type_new
Breakpoint 3 at 0x7ffff7a98200: file Objects/typeobject.c, line 2068.
(gdb) c
Continuing.

Breakpoint 3, type_new (metatype=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    args=0x7ffff7e8e370, kwds=0x0) at Objects/typeobject.c:2068
2068    {
(gdb) bt 8
#0  type_new (metatype=0x7ffff5a7cc40 <boost::python::class_metatype_object>, args=0x7ffff7e8e370,
    kwds=0x0) at Objects/typeobject.c:2068
#1  0x00007ffff7a908c3 in type_call (type=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    args=0x7ffff7e8e370, kwds=0x0) at Objects/typeobject.c:729
#2  0x00007ffff7a244e3 in PyObject_Call (
    func=func@entry=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    arg=arg@entry=0x7ffff7e8e370, kw=<optimized out>) at Objects/abstract.c:2546
#3  0x00007ffff7ad6707 in PyEval_CallObjectWithKeywords (
    func=func@entry=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    arg=arg@entry=0x7ffff7e8e370, kw=kw@entry=0x0) at Python/ceval.c:4219
#4  0x00007ffff7b01087 in PyEval_CallFunction (
    obj=obj@entry=0x7ffff5a7cc40 <boost::python::class_metatype_object>,
    format=format@entry=0x7ffff586f02c "(OOO)") at Python/modsupport.c:557
#5  0x00007ffff5857fe5 in boost::python::call<boost::python::api::object, char const*, boost::python::handle<_object>, boost::python::dict> (a2=…, a1=<synthetic pointer>, a0=<synthetic pointer>,
    callable=0x7ffff5a7cc40 <boost::python::class_metatype_object>) at ./boost/python/call.hpp:66
#6  boost::python::api::object_operators<boost::python::api::object>::operator()<char const*, boost::python::handle<_object>, boost::python::dict> (a2=…, a1=<synthetic pointer>,
    a0=<synthetic pointer>, this=<optimized out>) at ./boost/python/object_call.hpp:19
#7  boost::python::objects::(anonymous namespace)::new_class (doc=<optimized out>,
    types=0x7fffffffdd90, num_types=<optimized out>, name=<optimized out>)
    at libs/python/src/object/class.cpp:575
(More stack frames follow…)

ここまで来れば、答えは見えました。この関数の中で PyTypeObject を作って返すのですが、tp_flags をセットするときに Py_TPFLAGS_DEFAULT を使っています。したがって、新しい型は必ず Py_TPFLAGS_HAVE_ITER フラグを持っています。というかわざわざデバッグしなくても、Python のドキュメントのどこかに書いてありそう。

2066 static PyObject *
2067 type_new(PyTypeObject *metatype, PyObject *args, PyObject *kwds)
2068 {
2069     PyObject *name, *bases, *dict;
2070     static char *kwlist[] = {"name", "bases", "dict", 0};

2326     /* Initialize tp_flags */
2327     type->tp_flags = Py_TPFLAGS_DEFAULT | Py_TPFLAGS_HEAPTYPE |
2328         Py_TPFLAGS_BASETYPE;

2329     if (base->tp_flags & Py_TPFLAGS_HAVE_GC)
2330         type->tp_flags |= Py_TPFLAGS_HAVE_GC;
2331     if (base->tp_flags & Py_TPFLAGS_HAVE_NEWBUFFER)
2332         type->tp_flags |= Py_TPFLAGS_HAVE_NEWBUFFER;

4. PyTypeObject::tp_flags を動的に変更する方法

Boost.Python や Python の実装を見ても、tp_flags を変更する API は用意されていないようです。しかし boost::python::objects::class_base::class_base の実装から分かるように、各型のひな形となるような TypeObject は、 boost::python::converter::registry::lookup で取ってきたコンバーターの m_class_object から取得できそうです。そこで、以下のようなコードを試してみます。

#include <boost/python.hpp>
#include <valarray>
#include <random>
#include <stdio.h>

std::default_random_engine generator;
std::uniform_real_distribution<double> distribution(0.0, 1.0);

void ChangeType();

typedef std::valarray<double> darray;

class Field {
private:
    darray _data;

public:
    Field(int n) : _data(n) {
        printf("Field::Field(): %p\n", this);
        ChangeType();
    }
    ~Field() {
        printf("Field::~Field() %p\n", this);
    }

    void Dump() const {
        printf("[");
        for (auto &d : _data) {
            printf("% 3.3f", d);
        }
        printf(" ]\n");
    }

    void Churn() {
        for (auto &d : _data) {
            d = distribution(generator);
        }
    }

    const darray &Positions() const {
        return _data;
    }
};

using namespace boost::python;

BOOST_PYTHON_MODULE(ems) {
    class_<Field>("Field", init<int>())
        .def("Positions", &Field::Positions,
             return_internal_reference<>())
        .def("Dump", &Field::Dump)
        .def("Churn", &Field::Churn)
        ;

    class_<darray>("darray")
        .def("__getitem__",
             (const double &(darray::*)(size_t) const)&darray::operator[],
             return_value_policy<copy_const_reference>())
        .def("__len__", &darray::size)
        ;
}

void ChangeType() {
    converter::registration const& converters =
        converter::registry::lookup(type_id<darray>());
    long l = converters.m_class_object->tp_flags;
    converters.m_class_object->tp_flags = l & ~Py_TPFLAGS_HAVE_ITER;
    printf("converters.m_class_object = %p\n", converters.m_class_object);
    printf("tp_flags: %08lx -> %08lx\n", l, converters.m_class_object->tp_flags);
}

ChangeType() という関数を作って、Field のコンストラクターから呼ぶコードを追加しました。これを Python から実行して、darray の tp_flags を確認します。

john@ubuntu1510:~/Documents/pyc$ gdb /usr/local/python/current/bin/python
GNU gdb (Ubuntu 7.10-1ubuntu2) 7.10
(略)
Reading symbols from /usr/local/python/current/bin/python…done.
(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 22 2015, 22:30:16)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import ems
>>> f = ems.Field(4)
Field::Field(): 0x6d09d0
converters.m_class_object = 0x6d3b00
tp_flags: 000257fb -> 0002577b

>>> x = f.Positions()
>>> x
<ems.darray object at 0x7ffff7ed5600>
>>>
Program received signal SIGINT, Interrupt.
0x00007ffff74e4723 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81
81      ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) p *(PyObject*)0x7ffff7ed5600
$1 = {ob_refcnt = 2, ob_type = 0x6d3b00}
(gdb) p *$1.ob_type
$2 = {ob_refcnt = 5, ob_type = 0x7ffff5a7cc40 <boost::python::class_metatype_object>, ob_size = 0,
  tp_name = 0x7ffff7e94954 "darray", tp_basicsize = 48, tp_itemsize = 1,
  tp_dealloc = 0x7ffff7a8b390 <subtype_dealloc>, tp_print = 0x0, tp_getattr = 0x0,
  tp_setattr = 0x0, tp_compare = 0x0, tp_repr = 0x7ffff7a8f390 <object_repr>,
  tp_as_number = 0x6d3c88, tp_as_sequence = 0x6d3dd8, tp_as_mapping = 0x6d3dc0,
  tp_hash = 0x7ffff7a70be0 <_Py_HashPointer>, tp_call = 0x0, tp_str = 0x7ffff7a8acc0 <object_str>,
  tp_getattro = 0x7ffff7a72410 <PyObject_GenericGetAttr>,
  tp_setattro = 0x7ffff7a72670 <PyObject_GenericSetAttr>, tp_as_buffer = 0x6d3e28,
  tp_flags = 153467, tp_doc = 0x0, tp_traverse = 0x7ffff7a8b0a0 <subtype_traverse>,
  tp_clear = 0x7ffff7a8d290 <subtype_clear>, tp_richcompare = 0x0, tp_weaklistoffset = 32,
  tp_iter = 0x0, tp_iternext = 0x7ffff7a72100 <_PyObject_NextNotImplemented>, tp_methods = 0x0,
  tp_members = 0x6d3e68, tp_getset = 0x0,
  tp_base = 0x7ffff5a7cfa0 <boost::python::objects::class_type_object>, tp_dict = 0x7ffff7e98050,
  tp_descr_get = 0x0, tp_descr_set = 0x0, tp_dictoffset = 24,
  tp_init = 0x7ffff7a91f70 <slot_tp_init>, tp_alloc = 0x7ffff7a8ade0 <PyType_GenericAlloc>,
  tp_new = 0x7ffff5856890
     <boost::python::objects::instance_new(PyTypeObject*, PyObject*, PyObject*)>,
  tp_free = 0x7ffff7b1e2b0 <PyObject_GC_Del>, tp_is_gc = 0x0, tp_bases = 0x7ffff7e96410,
  tp_mro = 0x7ffff7e8e780, tp_cache = 0x0, tp_subclasses = 0x0, tp_weaklist = 0x7ffff7e77f70,
  tp_del = 0x0, tp_version_tag = 0}
(gdb) p/x 153467
$3 = 0x2577b

思惑通り、tp_flags から Py_TPFLAGS_HAVE_ITER を消せました。今回は tp_flags を変えても全く意味がなかったのですが、これで TypeObject の内容は思いのままです。Boost.Python では、初期化時に int など基本型の TypeObject も列挙しているので、基本型の中身を変更する禁じ手も可能です。そんなことをしたらいろいろ壊れそうですが。

How to expose a valarray with Boost.Python

Python のパフォーマンスの不利を補うため、C++ で書いた共有ライブラリを Python のモジュールとして利用することができます。前回の速度比較の結果から、ベクトルの四則演算を std::valarray の形のまま実行すべく C++ のコードを書いたところ、思わぬ結果として Python の罠を見つけたので経緯を含めて紹介します。

1. Boost.Python を使う

まず、C++ で Python モジュールを書く方法ですが、伝統的な Python.h をインクルードして C で書く方法と、Boost.Python のテンプレートを使って C++ で書く方法の 2 通りがあります。Boost の方が圧倒的に楽です。以下のサイトの説明がとても分かりやすい。

c/c++をラップしてpythonで使えるように – Python | Welcome to underground
https://www.quark.kj.yamagata-u.ac.jp/~hiroki/python/?id=19

Boost.Python の機能をざっと紹介してみる – muddy brown thang
http://d.hatena.ne.jp/moriyoshi/20091214/1260779899

その他、ctypes モジュールを使って外部モジュールのエクスポート関数を呼び出す方法 (Windows で言うところの LoadLibrary と GetProcAddress を Python から呼べる) もありますが、これは関数が呼べるだけで、Python のモジュールやオブジェクトを作れるわけではないので、少し趣向が異なります。もし ctypes で間に合うなら一番楽な方法だと思います。

今実現したいのは、次のような動作を実装した C++ クラスを Python モジュールとして見せることです。

  1. std::valarray<double> を内部データとして保持
  2. 演算は valarray のまま実行する
  3. プロット描画のため、valarray を何らかの形で matplotlib.collections.PathCollection.set_offsets(offsets) に渡したい

3. についてですが、matplotlib のリファレンスを見ると、set_offsets の引数は "offsets can be a scalar or a sequence." という妙に曖昧な説明しかありません。

collections — Matplotlib 1.5.0 documentation
http://matplotlib.org/api/collections_api.html#matplotlib.collections.PathCollection

GitHub 上のコードを見ると、引数の offsets はすぐに np.asanyarray によって np.ndarray に変換されて 2 列の行列に変形させられるので、ndarray に変換可能なオブジェクトなら何でもよい、ということになります。

https://github.com/matplotlib/matplotlib/blob/master/lib/matplotlib/collections.py

C++ 側で列数が 2 の numpy.ndarray オブジェクトを作ることができれば速度的にはベストですが、面倒そうなのと、C++ のモジュールが Numpy に依存するのもあまり美しくないので、Python のリストを返すことができれば十分です。そこで、上記のサイトを参考にしつつ動作確認のため以下の C++ コードを書きました。

実行環境は前回と同じです。

  • OS: Ubuntu 15.10
  • gcc (Ubuntu 5.2.1-22ubuntu2) 5.2.1 20151010
  • Python 2.7.10

C++ ソースコード: shared.cpp

#include <boost/python.hpp>
#include <valarray>
#include <random>
#include <stdio.h>

std::default_random_engine generator;
std::uniform_real_distribution<double> distribution(0.0, 1.0);

typedef std::valarray<double> darray;

class Field {
private:
    darray _data;

public:
    Field(int n) : _data(n) {
        printf("Field::Field(): %p\n", this);
    }
    ~Field() {
        printf("Field::~Field() %p\n", this);
    }

    void Dump() const {
        printf("[");
        for (auto &d : _data) {
            printf("% 3.3f", d);
        }
        printf(" ]\n");
    }

    void Churn() {
        for (auto &d : _data) {
            d = distribution(generator);
        }
    }

    const darray &Positions() const {
        return _data;
    }
};

BOOST_PYTHON_MODULE(ems) {
    using namespace boost::python;

    class_<Field>("Field", init<int>())
        .def("Positions", &Field::Positions,
             return_value_policy<copy_const_reference>())
        .def("Dump", &Field::Dump)
        .def("Churn", &Field::Churn)
        ;

    class_<darray>("darray")
        .def("__getitem__",
             (const double &(darray::*)(size_t) const)&darray::operator[],
             return_value_policy<copy_const_reference>())
        .def("__len__", &darray::size)
        ;
}

メイク ファイル: Makefile

CC=g++
RM=rm -f

TARGET=ems.so
SRCS=$(wildcard *.cpp)
OBJS=$(SRCS:.cpp=.o)

override CFLAGS+=-Wall -fPIC -std=c++11 -O2 -g
LFLAGS=

INCLUDES=-I/usr/include/python2.7
LIBS=-lpython2.7 -lboost_python

all: clean $(TARGET)

clean:
        $(RM) $(OBJS) $(TARGET)

$(TARGET): $(OBJS)
        $(CC) -shared $(LFLAGS) $(LIBDIRS) $^ -o $@ $(LIBS)

$(OBJS): $(SRCS)
        $(CC) $(INCLUDES) $(CFLAGS) -c $^

Field クラスを Python オブジェクトとして扱えるようにします。このとき、valarray の const 参照を返すメンバ関数の Field::Positions を Python オブジェクトのメソッドとして実装するため、valarray のコンバーターを別途作って __getitem__ と __len__ メソッドを実装します。これは一種のダック タイピングで、Python 側ではシーケンスとして見えるようになります。

Field::Positions は Field::_data の参照を返すようにしておかないと、Positions を呼ぶたびに valarray をコピーして Python に渡すようになるので、速度が落ちます。しかし、実は上記のコードは間違っています。試しにこのまま Python から使ってみると以下の結果が得られます。

>>> import ems
>>> f = ems.Field(4)
Field::Field(): 0x2011a50
>>> x = f.Positions()
>>> f.Dump()
[ 0.000 0.000 0.000 0.000 ]
>>> x[0]
0.0

>>> f.Churn()
>>> f.Dump()
[ 0.132 0.459 0.219 0.679 ]
>>> x[0]
0.0

>>> quit()
Field::~Field() 0x2011a50
john@ubuntu1510:~/Documents/pyc$

f.Churn() で C++ 側の値を変更した後も、Python 側のシーケンスの値が 0 のままで変わっていません。x = f.Position() したときに、valarray がコピーされたようです。Positions を定義するときの return_value_policy で copy_const_reference ポリシーを使っているのがいけないのです。

    class_<Field>("Field", init<int>())
        .def("Positions", &Field::Positions,
             return_value_policy<copy_const_reference>())

以下のページに記載があるように、このポリシーは "returning a reference-to-const type such that the referenced value is copied into a new Python object." です。ポリシーの名前で勘違いしていましたが、これは、参照をコピーして Python に渡すのではなく、"参照された値" をコピーします。Positions の戻り値となる Python オブジェクトを作るときに、参照に対してコピー コンストラクタを呼んで、そのコピーをオブジェクトに保持させるのだと思います。これでは参照を使う意味がありません。

Boost.Python – <boost/python/copy_const_reference.hpp> – 1.54.0
http://www.boost.org/doc/libs/1_54_0/libs/python/doc/v2/copy_const_reference.html

ここで使うべきポリシーは、return_internal_reference です。説明によると "CallPolicies which allow pointers and references to objects held internally by a free or member function argument or from the target of a member function to be returned safely without making a copy of the referent" となっています。

Boost.Python – <boost/python/return_internal_reference.hpp> – 1.54.0
http://www.boost.org/doc/libs/1_54_0/libs/python/doc/v2/return_internal_reference.html

コードをこう変えます。

class_<Field>("Field", init<int>())
    .def("Positions", &Field::Positions,
         return_internal_reference<>())

これで、C++ オブジェクトへの参照を Python が保持できるようになりました。

>>> import ems
>>> f = ems.Field(4)
Field::Field(): 0xde4a50
>>> f.Dump()
[ 0.000 0.000 0.000 0.000 ]
>>> x = f.Positions()
>>> x[0]
0.0
>>> f.Churn()
>>> f.Dump()
[ 0.132 0.459 0.219 0.679 ]
>>> x[0]
0.13153778773876065

>>> x
<ems.darray object at 0x7fded8919130>
>>> y = f.Positions()
>>> y
<ems.darray object at 0x7fded89193d0>
>>> y[0]
0.13153778773876065
>>> quit()
Field::~Field() 0xde4a50

上記の例で、f.Positions() の戻り値である ems.darray オブジェクトの x と y を単純に表示させた値が異なっています。これも最初勘違いしていましたが、Positions() を呼ぶたびに、ems.darray という Python オブジェクトは常に新しく作られます。それぞれの ems.darray が同じ valarray への参照を内包する構造になっています。

2. Python のハングと原因

ここから本題です。先ほど作った ems.Field を matplotlib の set_offsets に渡すとハングすることが分かりました。上で既に触れたとおり、set_offsets は引数を ndarray に変換しているだけなので、以下のコードで簡単に再現できます。

>>> import ems
>>> import numpy as np
>>> np.__version__
‘1.10.1’
>>> f = ems.Field(4)
Field::Field(): 0x16f90b0
>>> x = f.Positinos()
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
AttributeError: ‘Field’ object has no attribute ‘Positinos’
>>> x = f.Positions()
>>> x[0]
0.0
>>> len(x)
4
>>> a = np.array(x) # ここでハング

__getitem__ と __len__ だけだとリストに見せかけるのは無理なのかと諦めかけていたのですが、偶然、Numpy 1.8 だと問題なく動くことが分かりました。

>>> import ems
>>> import numpy as np
>>> np.__version__
‘1.8.2’
>>> f = ems.Field(4)
Field::Field(): 0x233acf0
>>> x = f.Positions()
>>> a = np.array(x)
>>> x[0]
0.0
>>> a
array([ 0.,  0.,  0.,  0.])

Numpy 側のコードを比べると、1.8.x から 1.9.x にバージョンが上がった時に、PyArray_DTypeFromObjectHelper() のロジックが少し変更されています。520 行目あたりで青字の部分が追加されており、ハングは PySequence_Fast から制御が返ってこないことで発生しています。

https://github.com/numpy/numpy/blob/maintenance/1.8.x/numpy/core/src/multiarray/common.c
https://github.com/numpy/numpy/blob/maintenance/1.9.x/numpy/core/src/multiarray/common.c

/*
* fails if convertable to list but no len is defined which some libraries
* require to get object arrays
*/
size = PySequence_Size(obj);
if (size < 0) {
    goto fail;
}

/* Recursive case, first check the sequence contains only one type */
seq = PySequence_Fast(obj, "Could not convert object to sequence");
if (seq == NULL) {
    goto fail;
}

objects = PySequence_Fast_ITEMS(seq);
common_type = size > 0 ? Py_TYPE(objects[0]) : NULL;
for (i = 1; i < size; ++i) {
    if (Py_TYPE(objects[i]) != common_type) {
        common_type = NULL;
        break;
    }
}

結論から先に書くと、ems.darray の __getitem__ を実装するときに、valarray::operator[] を渡しているのが諸悪の根源でした。

    class_<darray>("darray")
        .def("__getitem__",
             (const double &(darray::*)(size_t) const)&darray::operator[],
             return_value_policy<copy_const_reference>())

ネット上でよく出てくるのは、valarray ではなく vector を Python に渡す方法ですが、この場合の __getitem__ は、operator[] ではなく vector::at を使うものばかりです。恥ずかしながら知らなかったのですが、vector::at と vector::operator[] には大きな違いがありました。vector::at は配列の長さを超えた場合に out_of_range 例外を投げてくれますが、operator[] は何もチェックせずに配列のインデックス アクセスを淡々とこなします。

vector::at – C++ Reference
http://www.cplusplus.com/reference/vector/vector/at/

The function automatically checks whether n is within the bounds of valid elements in the vector, throwing an out_of_range exception if it is not (i.e., if n is greater or equal than its size). This is in contrast with member operator[], that does not check against bounds.

Python 側に作られた ems.Field は iteratable なオブジェクトとして作られ、Python の iterator オブジェクト (seqiterobject 構造体) によって iterate されます。この動作は Objects/iterobject.c にある iter_iternext という関数で行われますが、iterate の終了条件は、戻り値が NULL を返すかどうかです。オブジェクトのサイズはチェックしません。

45 static PyObject *
46 iter_iternext(PyObject *iterator)
47 {
48     seqiterobject *it;
49     PyObject *seq;
50     PyObject *result;
51
52     assert(PySeqIter_Check(iterator));
53     it = (seqiterobject *)iterator;
54     seq = it->it_seq;
55     if (seq == NULL)
56         return NULL;
57     if (it->it_index == LONG_MAX) {
58         PyErr_SetString(PyExc_OverflowError,
59                         "iter index too large");
60         return NULL;
61     }
62
63     result = PySequence_GetItem(seq, it->it_index); // getitem を呼ぶ箇所
64     if (result != NULL) {
65         it->it_index++;
66         return result;
67     }
68     if (PyErr_ExceptionMatches(PyExc_IndexError) ||
69         PyErr_ExceptionMatches(PyExc_StopIteration))
70     {
71         PyErr_Clear();
72         Py_DECREF(seq);
73         it->it_seq = NULL;
74     }
75     return NULL;
76 }

Numpy 1.9.x 以上でハングが起こる原因は、Objects/listobject.c にある listextend で無限ループが発生するからです。iter_iternext がどんなインデックスに対しても値を返してくるので、このループが終わりません。

870     /* Run iterator to exhaustion. */
871     for (;;) {
872         PyObject *item = iternext(it);
873         if (item == NULL) {
874             if (PyErr_Occurred()) {
875                 if (PyErr_ExceptionMatches(PyExc_StopIteration))
876                     PyErr_Clear();
877                 else
878                     goto error;
879             }
880             break;
881         }
882         if (Py_SIZE(self) < self->allocated) {
883             /* steals ref */
884             PyList_SET_ITEM(self, Py_SIZE(self), item);
885             ++Py_SIZE(self);
886         }
887         else {
888             int status = app1(self, item);
889             Py_DECREF(item);  /* append creates a new ref */
890             if (status < 0)
891                 goto error;
892         }
893     }

他の人の役に立つか不明ですが、一応コールスタックなどの情報を含むデバッグ ログを載せておきます。

(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 21 2015, 12:40:02)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.

>>> import numpy as np
>>> import ems
>>> f = ems.Field(1)
Field::Field(): 0xaa0060
>>> x = f.Positions()
>>> f.Churn()
>>>

Program received signal SIGINT, Interrupt.
0x00007ffff71df723 in __select_nocancel () at ../sysdeps/unix/syscall-template.S:81
81      ../sysdeps/unix/syscall-template.S: No such file or directory.
(gdb) b slot_sq_item
Breakpoint 1 at 0x4816d0: file Objects/typeobject.c, line 4987.
(gdb) c
Continuing.

>>> a = np.array(x)

Breakpoint 1, slot_sq_item (self=0x7ffff1a92670, i=0) at Objects/typeobject.c:4987
4987    {
(gdb) p i
$1 = 0
(gdb) c
Continuing.
Breakpoint 1, slot_sq_item (self=0x7ffff1a92670, i=1) at Objects/typeobject.c:4987
4987    {
(gdb) p i
$2 = 1 <<<< この時点で既に out-of-range
(gdb) c
Continuing.
Breakpoint 1, slot_sq_item (self=0x7ffff1a92670, i=2) at Objects/typeobject.c:4987
4987    {
(gdb) p i
$3 = 2

(gdb) bt
#0  slot_sq_item (self=0x7ffff1a92670, i=2) at Objects/typeobject.c:4987
#1  0x0000000000444e5d in iter_iternext (iterator=0x7ffff7e96910) at Objects/iterobject.c:63
#2  0x0000000000448e9a in listextend (self=self@entry=0x7ffff1ab4cb0, b=b@entry=0x7ffff7e96910)
    at Objects/listobject.c:872
#3  0x000000000044aeb5 in _PyList_Extend (self=self@entry=0x7ffff1ab4cb0, b=b@entry=0x7ffff7e96910)
    at Objects/listobject.c:910
#4  0x000000000042243c in PySequence_List (v=0x7ffff7e96910) at Objects/abstract.c:2264
#5  PySequence_Fast (v=v@entry=0x7ffff1a92670, m=m@entry=0x7ffff5c299e8 "Could not convert object to sequence")
    at Objects/abstract.c:2293
#6  0x00007ffff5b5473c in PyArray_DTypeFromObjectHelper (obj=obj@entry=0x7ffff1a92670, maxdims=maxdims@entry=32,
    out_dtype=out_dtype@entry=0x7fffffffdea8, string_type=string_type@entry=0)
    at numpy/core/src/multiarray/common.c:531
#7  0x00007ffff5b549c3 in PyArray_DTypeFromObject (obj=obj@entry=0x7ffff1a92670, maxdims=maxdims@entry=32,
    out_dtype=out_dtype@entry=0x7fffffffdea8) at numpy/core/src/multiarray/common.c:184
#8  0x00007ffff5b5de81 in PyArray_GetArrayParamsFromObject (op=0x7ffff1a92670, requested_dtype=<optimized out>,
    writeable=<optimized out>, out_dtype=0x7fffffffdea8, out_ndim=0x7fffffffde9c, out_dims=0x7fffffffdeb0,
    out_arr=0x7fffffffdea0, context=0x0) at numpy/core/src/multiarray/ctors.c:1542
#9  0x00007ffff5b5e26d in PyArray_FromAny (op=op@entry=0x7ffff1a92670, newtype=0x0, min_depth=0, max_depth=0,
    flags=flags@entry=112, context=<optimized out>) at numpy/core/src/multiarray/ctors.c:1674
#10 0x00007ffff5b5e63f in PyArray_CheckFromAny (op=0x7ffff1a92670, descr=<optimized out>, min_depth=min_depth@entry=0,
    max_depth=max_depth@entry=0, requires=112, context=context@entry=0x0) at numpy/core/src/multiarray/ctors.c:1852
#11 0x00007ffff5bd850e in _array_fromobject (__NPY_UNUSED_TAGGEDignored=<optimized out>, args=<optimized out>, kws=0x0)
    at numpy/core/src/multiarray/multiarraymodule.c:1773
#12 0x00000000004b6f2a in call_function (oparg=<optimized out>, pp_stack=0x7fffffffe110) at Python/ceval.c:4350
#13 PyEval_EvalFrameEx (f=f@entry=0x7ffff7fc0c20, throwflag=throwflag@entry=0) at Python/ceval.c:2987
#14 0x00000000004b938c in PyEval_EvalCodeEx (co=co@entry=0x7ffff7ecfe30, globals=globals@entry=0x7ffff7f6c168,
    locals=locals@entry=0x7ffff7f6c168, args=args@entry=0x0, argcount=argcount@entry=0, kws=kws@entry=0x0, kwcount=0,
    defs=0x0, defcount=0, closure=0x0) at Python/ceval.c:3582
#15 0x00000000004b9499 in PyEval_EvalCode (co=co@entry=0x7ffff7ecfe30, globals=globals@entry=0x7ffff7f6c168,
    locals=locals@entry=0x7ffff7f6c168) at Python/ceval.c:669
#16 0x00000000004e2b4d in run_mod (arena=0x856e10, flags=<optimized out>, locals=0x7ffff7f6c168,
    globals=0x7ffff7f6c168, filename=0x546f03 "<stdin>", mod=0x8a1c48) at Python/pythonrun.c:1370
#17 PyRun_InteractiveOneFlags (fp=0x7ffff74a6980 <_IO_2_1_stdin_>, filename=0x546f03 "<stdin>", flags=<optimized out>)
    at Python/pythonrun.c:857
#18 0x00000000004e2dfe in PyRun_InteractiveLoopFlags (fp=fp@entry=0x7ffff74a6980 <_IO_2_1_stdin_>,
    filename=filename@entry=0x546f03 "<stdin>", flags=flags@entry=0x7fffffffe3a0) at Python/pythonrun.c:777
#19 0x00000000004e3366 in PyRun_AnyFileExFlags (fp=0x7ffff74a6980 <_IO_2_1_stdin_>, filename=<optimized out>,
    closeit=0, flags=0x7fffffffe3a0) at Python/pythonrun.c:746
#20 0x0000000000416160 in Py_Main (argc=<optimized out>, argv=<optimized out>) at Modules/main.c:640
#21 0x00007ffff7102a40 in __libc_start_main (main=0x415290 <main>, argc=1, argv=0x7fffffffe568, init=<optimized out>,
    fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffffffe558) at libc-start.c:289
#22 0x00000000004152c9 in _start ()

4. 回避策

valarray には at 関数がなく、境界チェックをしない operator[] があるのみです。したがって回避策として、valarray をラップする darray クラスを C++ 側で作って、at を追加実装しました。記憶が曖昧ですが、boost を使えば .NET のようにクラスを拡張できたような気がしますが、今回はこれで。

#include <boost/python.hpp>
#include <valarray>
#include <random>
#include <stdio.h>

std::default_random_engine generator;
std::uniform_real_distribution<double> distribution(0.0, 1.0);

class darray : public std::valarray<double> {
public:
    darray() : std::valarray<double>() {}
    darray(size_t n) : std::valarray<double>(n) {}

    const double& at(size_t n) const {
        if (n >= this->size()) {
            std::__throw_out_of_range_fmt(__N("out_of_range"));
        }
        return (*this)[n];
    }
};

class Field {
private:
    darray _data;

public:
    Field(int n) : _data(n) {
        printf("Field::Field(): %p\n", this);
    }
    ~Field() {
        printf("Field::~Field() %p\n", this);
    }

    void Dump() const {
        printf("[");
        for (auto &d : _data) {
            printf("% 3.3f", d);
        }
        printf(" ]\n");
    }

    void Churn() {
        for (auto &d : _data) {
            d = distribution(generator);
        }
    }

    const darray &Positions() const {
        return _data;
    }
};

BOOST_PYTHON_MODULE(ems) {
    using namespace boost::python;

    class_<Field>("Field", init<int>())
        .def("Positions", &Field::Positions,
             return_internal_reference<>())
        .def("Dump", &Field::Dump)
        .def("Churn", &Field::Churn)
        ;

    class_<darray>("darray")
        .def("__getitem__", &darray::at,
             return_value_policy<copy_const_reference>())
        .def("__len__", &darray::size)
        ;
}

Numpy 1.10.1 でも問題なく動作するようになりました。

>>> import ems
>>> import numpy as np
>>> np.__version__
‘1.10.1’
>>> f = ems.Field(4)
Field::Field(): 0x1029880
>>> x = f.Positions()
>>> f.Churn()
>>> f.Dump()
[ 0.132 0.459 0.219 0.679 ]
>>> np.array(x)
array([ 0.13153779,  0.45865013,  0.21895919,  0.67886472])
>>> quit()
Field::~Field() 0x1029880

この場合の動作ですが、darray::at で投げた例外が boost_python ライブラリの中の例外ハンドラーによって捕捉されるようです。たぶん #1 か #2 が例外ハンドラー。

#0  PyErr_SetString (exception=0x7a2ce0 <_PyExc_IndexError>, string=0x7ea428 "out_of_range") at Python/errors.c:68
#1  0x00007ffff56f3471 in boost::python::handle_exception_impl(boost::function0<void>) ()
   from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#2  0x00007ffff56e8719 in ?? () from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#3  0x0000000000422faa in PyObject_Call (func=func@entry=0x8bce90, arg=arg@entry=0x7ffff0b4f710, kw=kw@entry=0x0)
    at Objects/abstract.c:2546
#4  0x0000000000429dfc in instancemethod_call (func=0x8bce90, arg=0x7ffff0b4f710, kw=0x0) at Objects/classobject.c:2602
#5  0x0000000000422faa in PyObject_Call (func=func@entry=0x7ffff0b3ce60, arg=arg@entry=0x7ffff7e965d0, kw=kw@entry=0x0)
    at Objects/abstract.c:2546
#6  0x0000000000481766 in slot_sq_item (self=<optimized out>, i=<optimized out>) at Objects/typeobject.c:5012
#7  0x0000000000444e5d in iter_iternext (iterator=0x7ffff0b98e50) at Objects/iterobject.c:63
#8  0x0000000000448e9a in listextend (self=self@entry=0x7ffff0b4f5f0, b=b@entry=0x7ffff0b98e50)
    at Objects/listobject.c:872
#9  0x000000000044aeb5 in _PyList_Extend (self=self@entry=0x7ffff0b4f5f0, b=b@entry=0x7ffff0b98e50)
    at Objects/listobject.c:910
#10 0x000000000042243c in PySequence_List (v=0x7ffff0b98e50) at Objects/abstract.c:2264
#11 PySequence_Fast (v=v@entry=0x7ffff0b24670, m=m@entry=0x7ffff4aa09e8 "Could not convert object to sequence")
    at Objects/abstract.c:2293
#12 0x00007ffff49cb73c in PyArray_DTypeFromObjectHelper (obj=obj@entry=0x7ffff0b24670, maxdims=maxdims@entry=32,
    out_dtype=out_dtype@entry=0x7fffffffdea8, string_type=string_type@entry=0)
    at numpy/core/src/multiarray/common.c:531

このハングは、numpy.ndarray に限りません。例えばリスト内包表記で ems::darray を列挙しようとしても再現します。そのときのコールスタックはこのようになります。

#0  darray::at (this=0xb60d30, n=1) at shared.cpp:16
#1  0x00007ffff5e933bb in boost::python::detail::invoke<boost::python::to_python_value<double const&>, double const& (darray::*)(unsigned long) const, boost::python::arg_from_python<darray&>, boost::python::arg_from_python<unsigned long> >
    (rc=…, ac0=…, tc=<synthetic pointer>, f=
    @0x8bcc58: (const double &(darray::*)(const darray * const, unsigned long)) 0x7ffff5e92170 <darray::at(unsigned long) const>) at /usr/include/boost/python/detail/invoke.hpp:88
#2  boost::python::detail::caller_arity<2u>::impl<double const& (darray::*)(unsigned long) const, boost::python::return_value_policy<boost::python::copy_const_reference, boost::python::default_call_policies>, boost::mpl::vector3<double const&, darray&, unsigned long> >::operator() (args_=<optimized out>, this=0x8bcc58)
    at /usr/include/boost/python/detail/caller.hpp:223
#3  boost::python::objects::caller_py_function_impl<boost::python::detail::caller<double const& (darray::*)(unsigned long) const, boost::python::return_value_policy<boost::python::copy_const_reference, boost::python::default_call_policies>, boost::mpl::vector3<double const&, darray&, unsigned long> > >::operator() (this=0x8bcc50, args=<optimized out>,
    kw=<optimized out>) at /usr/include/boost/python/object/py_function.hpp:38
#4  0x00007ffff56eb33d in boost::python::objects::function::call(_object*, _object*) const ()
   from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#5  0x00007ffff56eb528 in ?? () from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#6  0x00007ffff56f3363 in boost::python::handle_exception_impl(boost::function0<void>) ()
   from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#7  0x00007ffff56e8719 in ?? () from /usr/lib/x86_64-linux-gnu/libboost_python-py27.so.1.58.0
#8  0x0000000000422faa in PyObject_Call (func=func@entry=0x8bce90, arg=arg@entry=0x7ffff0b4f758, kw=kw@entry=0x0)
    at Objects/abstract.c:2546
#9  0x0000000000429dfc in instancemethod_call (func=0x8bce90, arg=0x7ffff0b4f758, kw=0x0) at Objects/classobject.c:2602
#10 0x0000000000422faa in PyObject_Call (func=func@entry=0x7ffff0b3ce60, arg=arg@entry=0x7ffff7e964d0, kw=kw@entry=0x0)
    at Objects/abstract.c:2546
#11 0x0000000000481766 in slot_sq_item (self=<optimized out>, i=<optimized out>) at Objects/typeobject.c:5012
#12 0x0000000000444e5d in iter_iternext (iterator=0x7ffff0b98e50) at Objects/iterobject.c:63
#13 0x00000000004b2373 in PyEval_EvalFrameEx (f=f@entry=0x7ffff1b3faa0, throwflag=throwflag@entry=0)
    at Python/ceval.c:2806

フレーム#12 と #13 から分かるように、今度は PyEval_EvalFrameEx から iter_iternext が呼ばれています。仮にこのハングを Python 側で直すとして、iter_iternext の中でサイズをチェックする、というアプローチが考えられます。Numpy のコードから確認できますが、PySequence_Size は darray::__len__ を呼ぶので、サイズは正しく取得できます。が、コードを見る限り、Python の iterator オブジェクトはサイズをチェックしなくても iterator するだけで要素を列挙できるのが利点なので、iter_iternext はこのままのほうが自然です。

もう少し見てみないと分かりませんが、ems.Field オブジェクトが iterator を使ってシーケンシャルにアクセスする種類になっているのが悪いのではないかと思います。何らかの方法で、ems.Field は iterator ではなくインデックスを使ってランダム アクセスすべきものに種別できればちゃんと動くのではないかと。そんな種類があるかどうか分かりませんが。後で調べよう。

4. おまけ – Python のデバッグ環境

Python をデバッグするため、Python そのものをソースからビルドしたので、そのときのコマンドを紹介します。

$ wget https://www.python.org/ftp/python/2.7.11/Python-2.7.11.tgz
$ tar -xvf Python-2.7.11.tgz
$ cd Python-2.7.11/
$ ./configure –prefix=/usr/local/python/python-2.7.11 –enable-unicode=ucs4
$ make
$ sudo make install
$ sudo ln -s /usr/local/python/python-2.7.11 /usr/local/python/current

configure するときに ucs4 を指定しておかないと、numpy をインポートしたときに以下のエラーが出ます。

>>> import numpy as np
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/lib/python2.7/dist-packages/numpy/__init__.py", line 153, in <module>
    from . import add_newdocs
  File "/usr/lib/python2.7/dist-packages/numpy/add_newdocs.py", line 13, in <module>
    from numpy.lib import add_newdoc
  File "/usr/lib/python2.7/dist-packages/numpy/lib/__init__.py", line 8, in <module>
    from .type_check import *
  File "/usr/lib/python2.7/dist-packages/numpy/lib/type_check.py", line 11, in <module>
    import numpy.core.numeric as _nx
  File "/usr/lib/python2.7/dist-packages/numpy/core/__init__.py", line 6, in <module>
    from . import multiarray
ImportError: /usr/lib/python2.7/dist-packages/numpy/core/multiarray.so: undefined symbol: PyUnicodeUCS4_AsUnicodeEscapeString

このままだと、ビルドした Python のモジュール検索パスが空っぽなので、デバッグするときは環境変数を使って、元からあった Python の dist-packages を追加しておきました。たぶんもっとうまいやり方があるはず。

john@ubuntu1510:~/Documents/pyc$ export PYTHONPATH=/usr/local/lib/python2.7/dist-packages
john@ubuntu1510:~/Documents/pyc$ gdb /usr/local/python/current/bin/python
GNU gdb (Ubuntu 7.10-1ubuntu2) 7.10
Copyright (C) 2015 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"…
Reading symbols from /usr/local/python/current/bin/python…done.
(gdb) r
Starting program: /usr/local/python/python-2.7.11/bin/python
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Python 2.7.11 (default, Dec 21 2015, 12:40:02)
[GCC 5.2.1 20151010] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>>

Numpy は、以前 pip でインストールしたものにデバッグ情報が入っていたので、わざわざソースからビルドすることなくそのまま使いました。というか、Numpy のビルドは追加モジュールがいろいろ必要で面倒そうだったので諦めたともいいます。

Vectorized computation: R vs Python vs C++

前回のコードで、どうやら Python が遅いらしいことが分かったので、実際に C++ でモジュールを書き始める前に、どのぐらい遅いのかを調べてみることにしました。まずは軽く情報収集。

以下のページによると、Python は動的型付けなので、型チェックのせいで四則演算が遅くなるらしい。これは納得できる。さらに、NumPy は SIMD に対応していて、Cython を使うと速くなるとか。

Pythonを高速化するCythonを使ってみた – Kesin’s diary
http://kesin.hatenablog.com/entry/20120306/1331043675

その一方、R や Python の方が C より速くなる、というような不思議な結果を報告しているページもありました。この結論は原理的におかしいような気もしますが・・。

機械学習序曲(仮) > 数値計算の実行速度 – Python, C, Rの比較
http://hawaii.naist.jp/~kohei-h/my/python-numeric-comp.html

(2015/12/20 – 議論が雑だったので、データを取り直して全体的に修正。)

今回計測したいのは、2 次元ベクトルの四則演算 (オイラー法で、微小時間におけるベクトルの変化を計算するため)、及び、ばねの力を計算するときに使うノルムの計算です。というわけで、SSE や AVX といったベクトル演算用のユニット (= SIMD) をちゃんと使いたいところです。具体的には、こんな計算を計測することにしました。

V1 = V1 + d * V2

V1 と V2 は 2 次元ベクトルを横に P 個並べた行列、d はスカラーで、(0, 1) の範囲乱数を使います。この簡単な加算と乗算を N 回繰り返して速度を測ります。ノルムの演算は気が向いたら後で書き足します。

実行環境は以下の通り。

  • OS: Ubuntu 15.10
  • CPU: Intel(R) Core(TM) i5-2520M CPU @ 2.50GHz (Sandy Bridge)
  • gcc (Ubuntu 5.2.1-22ubuntu2) 5.2.1 20151010
  • Eigen 3.2.7
  • Python 2.7.10
  • R version 3.2.3 (2015-12-10) — "Wooden Christmas-Tree"

R と Python はそのまま、C++ では 6 つの処理系で比較します。C++ を使った場合の速度の違いで見ておきたいポイントは 2 つあり、一つは SIMD 演算で従来型の SSE を使うか Sandy Bridge から搭載された AVX 命令を使うかどうか、もう一つは、SSE/AVX 演算ユニットのスカラー演算を使うかベクトル演算を使うかという点です。前者は -mavx オプションで制御できます。後者は intrinsic を使って明示的に実装することもできますが、今回は gcc の自動ベクトル化機能を -ftree-vectorize オプションで有効にして利用します。ただし、最適化オプション -O3 を使うと、自動ベクトル化は勝手に行われます。よって、今回はベクトル化演算を行う前提で SSE と AVX でどれだけ違いが出るのかを見るのが趣旨です。というのも、SIMD は本来ベクトル演算向けのユニットなので、スカラー演算で使ってもあまり意味がないからです。

gcc のベクトル化に関しては ↓ が参考になります。

Auto-vectorization in GCC – GNU Project – Free Software Foundation (FSF)
https://gcc.gnu.org/projects/tree-ssa/vectorization.html

まとめるとこんな感じです。

Language Matrix datatype Gcc option SIMD
R num(,) N/A ?
Python numpy.ndarray N/A ?
C++ std::vector -O3 vectorized, SSE
C++ std:valarray -O3 vectorized, SSE
C++ Eigen::MatrixXd -O3 vectorized, SSE
C++ std::vector -O3 -ftree-vectorize -mavx vectorized, AVX
C++ std::valarray -O3 -ftree-vectorize -mavx vectorized, AVX
C++ Eigen::MatrixXd -O3 -ftree-vectorize -mavx vectorized, AVX

で、書いたコードがこれです。いろいろ詰め込んだせいで無駄にファイルが多い。

https://github.com/msmania/ems/tree/perftest

主要なファイルについてはこんな感じ。

  • perftest.R – R の計算ルーチン
  • perftest.py – Python の計算ルーチン
  • perftest.cpp – C++ の計算ルーチン
  • main.cpp – 実行可能ファイル runc 用の main()
  • shared.cpp – Python モジュール化のためのコード
  • common.h / common.cpp – shared.cpp と main.cpp とで共有するコード
  • draw.R – 結果を折れ線グラフで描く R のコード

コードを make すると、Python モジュールとしてインポートできる perftest.so と、スタンドアロンの実行可能ファイルである runc ができます。いずれのファイルにも、AVX を使った場合の関数と、使っていない場合の関数がそれぞれ avx、noavx という名前空間内に作られます。

Makefile の中で、perftest.cpp を別のレシピでコンパイルするようにしました。

override CFLAGS+=-Wall -fPIC -std=c++11 -O3 -g -Wno-deprecated-declarations
VFLAGS=-ftree-vectorize -ftree-vectorizer-verbose=6 -mavx -D_AVX
perftest.o: perftest.cpp
    $(CC) $(INCLUDES) $(CFLAGS) -c $^
perftest_avx.o: perftest.cpp
    $(CC) $(INCLUDES) $(CFLAGS) $(VFLAGS) -c $^ -o $@

-Wno-deprecated-declarations オプションは、Eigen のヘッダーをインクルードしたときに警告が出るので入れています。

では実測タイム。まずは Python から実行。引数の意味は、2 次元ベクトルを 10,000 個並べた行列を 1,000,000 回計算する、という意味です。

john@ubuntu1510:~/Documents/ems$ python perftest.py 10000 1000000
*** Python: numpy.ndarray ***
time = 26.096 (s)
*** R ***
[1] "*** matrix(n, 2) ***"
[1] time = 69.94 (s)
*** C++: no-vectorize no-avx ***
std::vector   time = 11.398 (s)
std::valarray time = 11.371 (s)
Eigen::Matrix time = 10.547 (s)
*** C++: vectorize avx ***
std::vector   time = 10.208 (s)
std::valarray time = 10.221 (s)
Eigen::Matrix time = 10.549 (s)

R 遅すぎ・・・。コンパイルされないからだろうか。Python も C++ と比べると 2 倍以上遅い。C++ については、avx と no-avx を比べると 10% ぐらい avx の方が速そう。もう少し試行回数を増やすため R と Python には退場してもらって、C++ だけ実行します。そんなときに runc を使います。

john@ubuntu1510:~/Documents/ems$ ./runc 10000 1000000 20 > result-O3-1000k
john@ubuntu1510:~/Documents/ems$ R

> source(‘draw.R’)
> drawResult(‘result-O3-1000k’)

runc の stdout への出力結果は R でそのまま読み込めるようにしているので、これをグラフ化します。レジェンドを入れていないので分かりにくいですが、青 = std::vector, 赤 = std::valarray, 紫 = Eigen、また、明るい色が AVX 有、暗い色が AVX 無になっています。

result-O3-1000k

明らかに、AVX 無の vector と valarray は他より遅いです。AVX を使うと約 10% 速度が向上しています。逆に、Eigen は変化なしといってよさそうです。上位 4 つはほとんど差がありませんが、Eigen よりは AVX を使った vector/valarray の方が有利に見えます。

正直、AVX による速度向上が 10% 程度というのは期待外れでした。理想的には、レジスター サイズが xmm 系の 128bit から ymm 系の 256bit になることによって、速度は 2 倍ぐらいになって欲しいのです。本当に AVX が使われているかどうかを確認するため、生成されたアセンブリを見てみます。gdb を使って逆アセンブル結果をファイルに出力します。

john@ubuntu1510:~/Documents/ems$ gdb runc
(gdb) set height 0
(gdb) set logging file perftest.log
(gdb) i func Test
All functions matching regular expression "Test":

File perftest.cpp:
void avx::TestEigen(int, int);
void avx::TestValArray(int, int);
void avx::TestVector(int, int);
void noavx::TestEigen(int, int);
void noavx::TestValArray(int, int);
void noavx::TestVector(int, int);
(gdb) disas avx::TestEigen
(gdb) disas avx::TestValArray
(gdb) disas avx::TestVector
(gdb) disas noavx::TestEigen
(gdb) disas noavx::TestValArray
(gdb) disas noavx::TestVector
(gdb) set logging  off
Done logging to perftest.log.
(gdb) quit

例えばavx::TestVectorをざっと見ると、以下の部分がベクトル演算をしているところです。pd というサフィックスが Packed Double を意味しています。

0x000000000040236b <+1035>:    vmovddup %xmm0,%xmm9
0x000000000040236f <+1039>:    xor    %ecx,%ecx
0x0000000000402371 <+1041>:    xor    %r15d,%r15d
0x0000000000402374 <+1044>:    vinsertf128 $0x1,%xmm9,%ymm9,%ymm9
0x000000000040237a <+1050>:    vmovupd (%r10,%rcx,1),%xmm1
0x0000000000402380 <+1056>:    add    $0x1,%r15d
0x0000000000402384 <+1060>:    vinsertf128 $0x1,0x10(%r10,%rcx,1),%ymm1,%ymm1
0x000000000040238c <+1068>:    vmulpd %ymm9,%ymm1,%ymm1
0x0000000000402391 <+1073>:    vaddpd (%r8,%rcx,1),%ymm1,%ymm1
0x0000000000402397 <+1079>:    vmovapd %ymm1,(%r8,%rcx,1)
0x000000000040239d <+1085>:    add    $0x20,%rcx
0x00000000004023a1 <+1089>:    cmp    %r11d,%r15d
0x00000000004023a4 <+1092>:    jb  0x40237a <avx::TestVector(int, int)+1050>

上記のコードの前半の vmovddup と vinsertf128 で、xmm0 に入っている 128bit の値 (double  2 つ分) を 2 つにコピーして ymm9 にセットします。おそらくこれは乱数の d です。次に、(%r10,%rcx,1) = r10 + (rcx * 1) のアドレスから 32 バイト (16 バイトずつvmovupd とvinsertf128 を使って) コピーして ymm1 にセットします。これは V2 でしょう。ここで AVX 命令を使って、V2 に d をかけて (%r8,%rcx,1) に加算しています。これが V1 になりそうです。このベクトル演算で、4 つの double を同時に処理していることになります。

avx::TestValArray にも同じ処理が見つかります。avx::TestEigen にも packed double を使っているコードは見つかりますが、ymm レジスタを使っていませんでした。これが、AVX の有無で Eigen の速度が変わらない理由として有力です。

0x0000000000402dcf <+511>:    vmovddup %xmm1,%xmm1
0x0000000000402dd3 <+515>:    xor    %eax,%eax
0x0000000000402dd5 <+517>:    nopl   (%rax)
0x0000000000402dd8 <+520>:    vmulpd (%r12,%rax,8),%xmm1,%xmm0
0x0000000000402dde <+526>:    vaddpd (%rbx,%rax,8),%xmm0,%xmm0
0x0000000000402de3 <+531>:    vmovaps %xmm0,(%rbx,%rax,8)
0x0000000000402de8 <+536>:    add    $0x2,%rax
0x0000000000402dec <+540>:    cmp    %rax,%rbp
0x0000000000402def <+543>:    jg     0x402dd8 <avx::TestEigen(int, int)+520>

AVX 命令の利点の一つとして、従来の SSE 命令のオペランドの数が 2 つだったのに対し、AVX では 3 または 4 オペランドを使用できるようになっています。したがって、計算によっては mov の数を減らすことができるのですが、今回の例ではあまりそれは活きないのかもしれません。

ちなみに -O3 を -O2 に変更した場合、つまり SSE のスカラー演算と AVX のベクトル演算を比較すると、以下のように速度差がより顕著になります。この場合の Eigen のグラフを見るだけでも分かりますが、Eigen は最適化オプションが -O2 であってもベクトル化演算のコードを生成しています。

result-O2

手元に Sandy Bridge 以前の CPU があったので、ベクトル化の有無で速度の違いを比べてみました。コンパイル時に gcc によるベクトル化に失敗したので、コンパイル オプションによる違いはなく、明らかに速度が Eigen > valarray > vector の順になっています。

CPU: AMD Athlon(tm) 64 X2 Dual Core Processor 3800+
result-AMD

というわけで結果からの考察。

  1. 特に工夫をしない場合、R と Python は遅い。
  2. SIMD を意識せずに書いた単純な C++ のループでも、ベクトル化 + AVX によって明白に速度向上が見込める。 というわけで何らかの方法 (既存のライブラリ、intrinsic、gcc のオプション) で必ずベクトル化はしておくべき。
  3. 明白な理由がない限り、 vector を使って自分でループを書くよりは、valarray の四則演算を使っておいた方が利点が多い。ベクトル化 + AVX を使った場合に両者の速度差はほとんどない上、valarray の方がコードが見やすい。 ただし、複雑な演算の時に、vector を使った方がループを工夫できる可能性はあるかも。
  4. Eigen は gcc の自動ベクトル化に頼らず自力でベクトル演算を使える。ただし (現バージョンの 3.2.7 では) AVX を有効にしても ymm レジスタを使わない。Sandy Bridge 以前の CPU では Eigen を使えば間違いない。Sandy Bridge 以降だと、valarray で間に合う演算であれば valarray を使う方がよい。

ただし上記は、SIMD を特に意識せずに C++ を書いた場合なので、intrinsic などを使えばもっと効率よくベクトル化の恩恵を受けられるかもしれません。もちろん、計算アルゴリズムやベクトルのサイズなどが大きく関係してくるので、一概にどれがベストと言い難いのですが、少なくとも、配列要素のアラインメントも特に指定しない単純なループでさえ、自動ベクトル化と AVX はそれなりに効果があるということが分かりました。この速度比較は、それだけで別のテーマになりますが今回はここまでにして、オイラー法は valarray でやってみようかな・・。

Skylake の Xeon モデルには 512bit レジスターを使う AVX3 ユニットが搭載されているらしい。これは使ってみたい。

MS-DOS 6.22 on Hyper-V

CPU の仕組みについて書かれた本の中でも、「はじめて読む 486」 はかなり有名な名著と言えるはずです。

はじめて読む486―32ビットコンピュータをやさしく語る
http://www.amazon.co.jp/%E3%81%AF%E3%81%98%E3%82%81%E3%81%A6%E8%AA%AD%E3%82%80486%E2%80%9532%E3%83%93%E3%83%83%E3%83%88%E3%82%B3%E3%83%B3%E3%83%94%E3%83%A5%E3%83%BC%E3%82%BF%E3%82%92%E3%82%84%E3%81%95%E3%81%97%E3%81%8F%E8%AA%9E%E3%82%8B-%E8%92%B2%E5%9C%B0-%E8%BC%9D%E5%B0%9A/dp/4756102131

途中で挫折していたので、最初からちゃんと読んでいたところ、やっぱり実機でサンプル コードを試したくなります。ちょっと前にブート コードの勉強をしていたときは、仮想ディスク (VHD) のマスター ブート レコード (MBR) をエディタで書き換えて、 Hyper-V の仮想マシンをその VHD から起動して動かすというけっこう面倒な方法を取っていました。

もっと楽に 16 ビット リアルモードで遊べる環境を作っておこう、ということで、MS-DOS を Hyper-V 仮想マシンにインストールしてみました。何も MS-DOS まで遡らなくても、Windows 9x や ME の DOS モードを使えばいいのですが、まあそこは好奇心ということで。どうでもいい昔話をすると、初めてプログラミングというものに触れたのが中一のときに学校にあった PC-9801 の N88-BASIC で、その後すぐに Windows 95 (年から考えると 98 だったかも) が導入されて Visual Basic/Visual C++ で遊び始めたので、Windows 以前の MS-DOS は全然触ったことがありません。そういえば当時の起動フロッピー ディスクはまだ手元にあるかも・・。

閑話休題、MS-DOS ですが、インストーラーは MSDN サブスクリプションに MS-DOS 6.0 と 6.22 が含まれていたのでそれを使います。MSDN を持っていない人は、"MS-DOS 6.22 download" とかのキーワードでググると、見つかるはずなので自己責任でどうぞ。

手順は以下の通り。6.22 はアップグレード用で、新規インストールはできないので、6.0 を入れてから 6.22 にアップグレードします。

  1. 適当な Windows マシンで MS-DOS 起動ディスクを作る
  2. MSDN からインストールしたファイルを仮想フロッピー、もしくは VHD にコピー
  3. 起動ディスクから DOS を起動
  4. MS-DOS 6.0 をフロッピーにインストール
  5. MS-DOS 6.0 を起動
  6. MS-DOS 6.22 を VHD にインストール

MSDN でダウンロードできるインストーラー en_msdos60.exe や en_msdos622.exe は自己解凍書庫で、解凍すると MS-DOS アプリの setup.exe が出てきます。これを使うためにはそもそも DOS を起動しないといけません。ということで、まずは DOS の起動ディスクを作らないといけません。

まずは空の仮想フロッピー ファイル (.vfd) を作ります。普通は PowerShell の New-Vfd コマンドレットを使うところですが、このコマンドレットは規定サイズの空ファイルを作っているだけなので、fsutil でも代用できます。サイズの 1474560 = 1440 * 1024 は、2HD フロッピーのバイト数です。

D:\MSWORK\dos> fsutil file createnew floppy.vfd 1474560
File D:\MSWORK\dos\floppy.vfd is created

これを仮想マシンにマウントし、エクスプローラーからフォーマットの画面を起動すると、なんと Windows 8.1 でも "Create an MS-DOS startup disk" のチェックボックスが使えます。よく廃止されないものです。ちなみに FORMAT コマンドにはそれに該当するようなオプションは見当たりません。GUI でしかできないんでしょうかね。

01

次に仮想マシンを作ります。RAM は 32MB、HDD は 1GB にしておきます。仮想 BIOS の設定で、Floppy を一番上に移動させます。こんな感じです。

image

先ほど作った起動ディスクをマウントして起動すると、無事 DOS が起動します。バージョンは Windows Millenium [Version 4.90.3000] だそうです。すぐには使わないので、仮想マシンはシャットダウンします。shutdown コマンドなんておものは存在せず、いきなり Turn off で問題ありません。

image

さて次に、DOS インストーラーの準備ですが、MS-DOS 6.0、6.22 共にインストール ファイルの合計サイズが 1.44MB を超えるので、VFD ではなく VHD で作ります。MS-DOS 6.22 の方は、親切にも複数のディスク イメージ ファイル (.img) をそれぞれフロッピーに書き込むためのスクリプトが用意されていますが、ディスクの入れ替えが面倒なだけなので使いません。

New-VHD コマンドレットなどで VHD を作って、MBR ディスクとして初期化し、FAT でフォーマットします。NTFS だと読めないので注意です。インストーラーのファイルは、おそらくドライブのルート ディレクトリ直下に入れておかないと動かないはずなので、それぞれのインストール用 VHD を作らないといけません。

作った VHD を仮想マシンにマウントし、再度起動ディスクから DOS を起動します。構成はこんな感じ。

image

1GB の VHDX はまだフォーマットされていないので認識されず、C: がインストーラーのドライブになります。したがって、C:\SETUP と実行します。

image

なぜか認識できないパーティションがあるとか言われます。よく分からないのでそのまま続行します。

image

MS-DOS 6.0 のインストーラーにはハード ディスクをフォーマットする機能が含まれず、空のハードディスクが見つからなかったため、フロッピーにインストールすることになります。仮にフォーマット済みの VHD をマウントして VHD にインストールしようとしても、有効な DOS が見つかりませんでした、というエラーが出てインストールできないので、最初の MS-DOS はフロッピーにインストールする必要があります。とりあえずこの画面ではそのまま Enter キーを押します。

image

この画面も Enter で続行します。

image

フロッピーを入れろと言われるので、ここで新たに VFD ファイルを作ってマウントしてから Enter キーを押します。

image

フロッピーの種類を聞かれるので、1.44MB を選びます。

image

無事終わりました。Enter キーを押してインストーラーを終了します。

image

元の DOS 画面でエラーが出ますが、おそらく起動ディスクを抜いてしまったためなので、気にせず仮想マシンを再起動します。

image

無事、MS-DOS 6.00 が起動しました。

image

次に MS-DOS 6.22 のインストールに移ります。手順はほとんど同じです。今度はハードディスクにインストールしたいので、インストール先の VHD を予め FAT でフォーマットしておきます。

今度は C: が空ディスク、D: がインストーラーなので D:\SETUP と実行します。

image

また未フォーマットのパーティションが検出されます。そんなのどこにあるんだ・・・気にせず続行します。

image

今度は最小構成ではなく、通常の構成でハードディスクにインストールしてくれそうです。ここも Enter を押します。

image

アンインストール ディスクというものを作る必要があるようです。今でいうリカバリ ディスクでしょうか。ここではそのまま Enter を押します。いちいちラベルを貼る猶予を与えてくれる親切設計。

image

インストール設定の確認です。C:\DOS にインストールされるようです。これぞ C:\WINDOWS の前身!

image

オプションのソフトウェアについて聞かれます。この当時のアンチ ウィルスって一体。Undelete ってのも謎。ごみ箱的な機能・・?とりあえず全部インストールしておきます。

image

いよいよ開始です。

image

フロッピーを入れ替える時間です。

image

サイズは 1.44MB です。

image

まさかのインストール エラー。ISK って何のことか分からず、わりと為す術がない。最初からのステップを 2 回繰り返しましたが、このエラーは変わらず。同じファイルを別の Windows 8.1 上の Hyper-V で試したら特にエラーは出ないので、Windows Server 2012 の Hyper-V との相性が悪いとかだったりして。詳細は不明です。

image

一応インストールは終わりました。フロッピーを抜いて Enter を押します。

image

Enter を押して再起動します。

image

起動には問題ないようです。HIMEM ってやつが結構遅い。

image

次に、どこからともなく入手してきた QuickC with Quick Assembler 2.51 をインストールします。ディスクが 10 枚もあって面倒くさい・・。

image

インストール後、何やら重要そうなことが書かれている画面が出てくるのでキャプチャーしておく。

image

インストールが終わったら、先ほどキャプチャーした画面の記述にしたがって環境変数の設定。現在の C:\AUTOEXEC.BAT はこんな感じ。

@ECHO OFF
PROMPT $p$g
PATH C:\DOS
SET TEMP=C:\DOS

これを、C:\QC25\BIN\NEW-VARS.BAT を参考にして、以下のように変更。MOUSE コマンドを実行してマウス ドライバーを有効にすると、高確率で OS がハングするので、マウスは諦めます。

@ECHO OFF
PROMPT $p$g
SET PATH=C:\QC25\BIN;C:\QC25\TUTORIAL;C:\DOS

SET LIB=C:\QC25\LIB
SET INCLUDE=C:\QC25\INCLUDE

SET TEMP=C:\DOS

あと config.sys。懐かしすぎる。C:\QC25\BIN\NEW-CONF.SYS には FILES=20, BUFFERS=10 と書かれていましたが、FILES は既に 30 になっていたので、BUFFERS を多めの 20 にしておくことに。

DEVICE=C:\DOS\SETVER.EXE
DEVICE=C:\DOS\HIMEM.SYS
DOS=HIGH
FILES=30
SHELL=C:\DOS\COMMAND.COM C:\DOS\  /p
BUFFERS=20

再起動して、早速 QuickC を起動。

image

これが 20 年前の IDE 。。というか画面ちっさ。Hyper-V のせいだけど。

image

ただ普通に Hello World を書いても面白くないので、以下のような 3 つのファイルを書いて NMAKE でビルド。

まずは C のソース。これは普通です。

//
// 00.C
//

#include <stdio.h>

extern int GetVer();

void main(int argc, char **argv)
{
    printf("Hello, MS-DOS %d!", GetVer());
    exit(0);
}

次にアセンブリ言語。サンプルからコピペしただけです。int 21 でバージョンが返ってくるみたいです。

;
; UTILS.ASM
;

    .MODEL    small, c
    .CODE

;* GetVer – Gets DOS version.
;*
;* Shows:   DOS Function – 30h (Get MS-DOS Version Number)
;*
;* Params:  None
;*
;* Return:  Short integer of form (M*100)+m, where M is major
;*        version number and m is minor version, or 0 if
;*        DOS version earlier than 2.0

GetVer    PROC

    mov    ah, 30h       ; DOS Function 30h
    int    21h           ; Get MS-DOS Version Number
    cmp    al, 0         ; DOS version 2.0 or later?
    jne    @F            ; Yes?    Continue
    sub    ax, ax        ; No?  Set AX = 0
    jmp    SHORT exit    ;   and exit
@@:    sub    ch, ch     ; Zero CH and move minor
    mov    cl, ah        ;   version number into CX
    mov    bl, 100
    mul    bl            ; Multiply major by 10
    add    ax, cx        ; Add minor to major*10
exit:    ret             ; Return result in AX

GetVer    ENDP

    END

最後が MAKEFILE。サンプルのファイルを元にいろいろと修正しましたが、リンカの設定のところが意味不明・・。

PROJ    =TEST
CC      =qcl
AS      =qcl
CFLAGS=/Od /Gi$(PROJ).mdt /DNDEBUG /Zi /Zr
AFLAGS=/Zi /Cx /P1
LFLAGS  =/NOI /INCR /CO

.asm.obj: ; $(AS) $(AFLAGS) -c $*.asm

all:    $(PROJ).EXE

utils.obj:        utils.asm

00.obj: 00.c

$(PROJ).EXE:    utils.obj 00.obj
    echo >NUL @<<$(PROJ).crf
utils.obj +
00.obj
$(PROJ).EXE
NUL.MAP

<<
    ilink -a -e "qlink $(LFLAGS) @$(PROJ).crf" $(PROJ)

ファイルを作ったら NMAKE するだけです。

image

おお、MS-DOS のバージョンが出た!これでリアルモードと仲良くできそう。

image

しかしファイルの編集がやりにくすぎる・・・SSH みたいなリモート接続はできないのだろうか。そもそも Hyper-V の仮想 NIC に対応している TCP/IP のドライバーなんてなさそう。