require高速化：基準となるベンチマーク
先日の記事でrequireの高速化をしたいと書いてから、ずいぶん時間が空いてしまいました。遅々とした進み具合で申し訳ないのですが、まずは高速化の基準となるベンチマークを取ってみました。基準点がなければ、具体的にどのくらい高速化したかわからないためです。
ベンチマークを行った環境
まずベンチマークを行った環境なのですが、「Windowsで遅い」と言われる問題の検証ですので、比較対象としてMacでも同じベンチマークを行うことにしました。マシンはいわゆるLate 2008 MacBook、スペックは以下の通りです。
| CPU | 2.4GHz Intel Core 2 Duo |
| メモリ | 4GB 1067MHz DDR3 |
| ハードディスク | TOSHIBA MK3253GSX 320GB 5400RPM 8MB Buffer |
また、WindowsのシステムはBootCampで起動したWindowsXP Home SP3、ファイルシステムはNTFSです。MacはSnow Leopard、ファイルシステムは HFS+です。全く同じマシンで動作させていますので、システムの違いだけが出てくるはずです。
rubyのバージョンについては、基本的にはリリース済みの最新バージョンである1.8.7p249と1.9.1p378を用いています。Windowsではコンパイルの仕方がいろいろあるのですが、最もよく使われているmswin32(VC6でコンパイルされたもの)を用いています。ただしMacでは、MacPortsでインストールした1.8.7p249がうまく動作しなかったため、Snow Leopardに標準でインストールされている1.8.7p173を使用しました。
注意すべき点として、WindowsもMacも、「ディスクキャッシュ」という仕組みがあります。これは一度ハードディスクから読み込んだファイルをメモリ上にキャッシュしておき、もう一度読み込んだときにはハードディスクからではなくメモリから読み出すものです。ディスクキャッシュがあるため、rubyのスクリプトの起動は、１回目よりも２回目以降の方が断然早くなります。普通rubyで開発を行うときは、requireされるスクリプトのファイルはほぼディスクキャッシュに載った状態になっていると思われますので、今回はベンチマークを何度か実行し、ディスクキャッシュが有効になった状態で計測を行いました。
各ライブラリはどのくらいの数のファイルをrequireしているのか？
まず手始めに、時間を計るのではなくて、requireを行ったときにrubyのライブラリがどのくらいの数のファイルにアクセスするのかを調べました。これを調べておくことで、後からファイルアクセスに関して調査を行う際の基準になります。
これは、rubyのバージョンが同じならWindowsでもMacでも違いはないはずですので、Windowsでのみ調査しています。
調査に使用したスクリプトは以下のようなものです。requireがfalseを返した場合は、そのファイルを既にロードしているということなので数えていません。
alias :require_original :require $require_success_files = [] def require(feature) ret = require_original(feature) if ret $require_success_files << feature end ret end require 'rexml/document' # この行を調べたいライブラリに変更 p $require_success_files.size
ただし、rubygemsでインストールしたライブラリの場合は、rubygemsがrequireを書き換えますので、一番最初に先にrequire 'rubygems'を行っておく必要があります。
結果は以下のようになりました。(gem)と書かれているのは、rubygemsでインストールしたライブラリです。
| ライブラリ名 | 1.8.7で読み込んだファイル数 | 1.9.1で読み込んだファイル数 |
|---|---|---|
| rexml/document | 35 | 35 |
| rubygems | 35 | 0 |
| sqlite3-ruby(gem) | 11 | 12 |
| oauth(gem) | 60 | 59 |
| twitter(gem) | 125 | 135 |
1.8.7と1.9.1では、rubygems以外はそれほど違いは出ていません。1.9.1でrubygemsが0になったのは、システムで組み込みになったためです。twitter gemの起動が重いというのは前から感じていたのですが、実際に100以上のファイルへのアクセスをしていたというのは驚きました。
各ライブラリをrequireするのにどのくらい時間がかかるか？
それでは次に、本題であるrequireの時間を計ってみます。
| モジュール名 | Windows 1.8.7 | Mac 1.8.7 | Windows 1.9.1 | Mac 1.9.1 |
|---|---|---|---|---|
| rexml/document | 0.140625 | 0.029783 | 0.281250 | 0.058118 |
| rubygems | 0.171875 | 0.092663 | 0.000000 | 0.000113 |
| sqlite3-ruby(gem) | 0.031250 | 0.034831 | 0.187500 | 0.031970 |
| oauth(gem) | 0.187500 | 0.060517 | 0.406250 | 0.088203 |
| twitter(gem) | 0.546875 | 0.158961 | 0.921875 | 0.244374 |
1.8.7同士で比べると、ライブラリによってばらつきがあるのですが、確かにWindowsでは、Macの4倍以上の時間がかかることがあるようです。1.9.1では全体的に1.8.7より時間がかかるのですが、これはVMの中間言語へのコンパイルなど、プログラムを実行する際の処理が複雑になったためで、全体的な速度向上とのトレードオフです。
ただ、さらによく見ると、1.8.7と1.9.1を比較したときに、Windowsの方がより遅くなる傾向があることがわかります。Macの場合は1〜2倍というところですが、Windowsの場合は6倍以上遅くなっているものもあります。これがなぜなのかも調べる必要がありそうです。
requireの個別のプロセスを計測する
requireがWindowsで遅いのはわかったのですが、requireはいろいろなプロセスを含んでいますので、Windowsでなぜ遅いのか調べるには、その個別のプロセスについて計測を行う必要があります。
requireのプロセスは、大まかに言って以下のとおりです。
- $LOAD_PATHに入っているパスのリストの中に、指定されたライブラリ名に.rbか.soを付けたファイルがないか調べる
- ファイルを見つけたらそれを読み込む
- 読み込んだプログラムを解析し、ロードする
遅い原因はこの中にあるはずです。さらに問題を分割すると、以下のような可能性があります。
- ファイルが存在するかどうかのチェックが遅い。これはファイルを探す処理のスピードに効いてくる。
- ファイルをオープンし、読み込むのが遅い。ディスクキャッシュが効いているはずだが、うまく効かないことがあるかもしれない。
- プログラムの解析・ロードが重い。ただ、これはOSとほぼ関係がない、純粋なプログラム処理なので、これが遅いというのは、普通にプログラムの実行が遅いということになる。コンパイラの違いの可能性もある。
この推測を元に、requireに関するベンチマークプログラムを作成しました。プログラムはgithubで公開しています。
http://github.com/ashel/ruby-require-benchmark
使い方は、git cloneした後に
% ruby create_testdata.rb % ruby run_benchmarks.rb
とします。今のところ11個のベンチマークがあり、それぞれbenchmark_*というファイルに記述されています。run_benchmarks.rbはそれらをまとめて実行するためのランチャです。なお、run_benchmarks.rbに引数を渡すと、その引数のコマンドでベンチマークを起動します。例えばrubyの1.9系をruby1.9というコマンド名で実行したい場合は、
% ruby1.9 create_testdata.rb % ruby1.9 run_benchmarks.rb ruby1.9
とすればOKです。
今回作成したベンチマークは以下の通りです。
- require_empty
- 空のファイル(実際にはmagic commentのみ含まれます)を100個requireします。空のファイル1つをrequireするのにかかる時間を求めます。
- require_class
- require_emptyと似ていますが、空のファイルではなく、よくあるクラスの定義１つ（数十程度のメソッド、定数を含むクラス）を含んだファイル100個をrequireします。equire_emptyと比較すると、ファイルの読み込みやプログラムのロードにかかる時間を推測できます。
- require_class_onefile
- require_classでrequireしたのと同じ構成のクラス100個が全て含まれるファイル1つをrequireします。require_classと比較することにより、多くのファイルを扱うのがどのくらい処理負荷になるのかを推測できます。
- read_empty
- require_emptyと似ていますが、requireするのではなく単に文字列としてreadします。requireのうちの「ファイルから読み込む」部分のみのコストを計測するためのベンチマークです。
- read_class
- require_classと似ていますが、requireするのではなく単に文字列としてreadします。
- read_class_onefile
- require_class_onefileと似ていますが、requireするのではなく単に文字列としてreadします。
- read_class_onefile_binmode
- read_class_onefileとほぼ同じですが、文字列で読み込む際にバイナリモードで読み込みます。Macでは違いはありませんが、Windowsでは文字列としての処理をするか否かで違いが出ます。
- read_class_onefile_windows31j
- read_class_onefileとほぼ同じですが、文字列で読み込む際のエンコーディングにWindows-31Jを指定します。これはruby1.9のみのテストです。Macでの文字列のエンコーディング処理をWindowsと揃えるために作りました。
- file_exist
- ファイルが存在するかどうかを調べるメソッド(File.exist?)の速度を調べるためのベンチマークです。100個の別々のファイルに対するFile.exist?を20セット繰り返します。
- compile_class_onefile
- これはruby1.9のみのテストです。require_class_onefileで使ったのと同じファイルを使用して、RubyVM::InstructionSequence.compileでのコンパイルのみを計測します。これはほぼOSの機能とは関係ないプログラム処理なので、これに違いが出るということは、コンパイラの違い等の理由から「単純にプログラムの実行速度が遅い」ということになります。
- file_exist_load_path
- $LOAD_PATH(requireする際に検索すべきパスが入ったグローバル変数)からファイルを検索するところまでを100回行うベンチマークです。$LOAD_PATHは環境によって異なりますので、プラットフォーム毎の比較は行えません。参考として行いました。
各プラットフォームでの結果は以下のようになりました。
| テスト内容 | Win 1.8.7 | Mac 1.8.7 | Win 1.9.1 | Mac 1.9.1 |
|---|---|---|---|---|
| require_empty | 0.156250 | 0.015123 | 0.234375 | 0.041115 |
| require_class | 0.218750 | 0.049868 | 0.406250 | 0.095429 |
| require_class_onefile | 0.062500 | 0.033033 | 0.171875 | 0.054280 |
| read_empty | 0.015625 | 0.002333 | 0.015625 | 0.003199 |
| read_class | 0.015625 | 0.002755 | 0.109375 | 0.003580 |
| read_class_onefile | 0.000000 | 0.000480 | 0.093750 | 0.000375 |
| read_class_onefile_binmode | 0.000000 | 0.000468 | 0.000000 | 0.000364 |
| read_class_onefile_windows31j | 0.093750 | 0.001068 | ||
| file_exist | 0.093750 | 0.012620 | 0.062500 | 0.014248 |
| compile_class_onefile | 0.062500 | 0.045660 | ||
| file_exist_load_path | 0.031250 | 0.005939 | 0.078125 | 0.019137 |
各プラットフォームの違いで目に付くのは、まず1.8.7で比較すると、WindowsとMacでは、空のファイル一つをrequireするためにかかる時間に10倍の差があるということです。一方、require_class_onefileのような、ファイルアクセスがほぼ関係しない処理ではそこまでの差はありません。（それでも2倍近く差が付いていますが…。）require_classのように実際のrequireに近い処理では、これらが混ざった結果、WindowsはMacの4倍時間がかかるという結果に至っています。これは、上で行った実際のライブラリをrequireしたときの差とほとんど同程度です。
それではなぜ、require_emptyでそこまでの差が出てしまうのでしょうか？read_emptyの結果を見ると、WindowsとMacでは差があるのですが、かかる時間が相対的に少ないことがわかります。よって、ファイル1個の読み出しにそれほど時間がかかるわけではありません。file_existやfile_exist_load_pathの結果を見ると、むしろ時間がかかっているのは、requireすべきファイルを探す処理であることがわかります。
さらに1.9.1に目を移すと、不自然な点が見つかります。Windowsの1.8.7では、read_emptyとread_classにほとんど差がないのですが、1.9.1では明らかにread_classが遅いです。さらに、read_class_onefileでも同じくらいの時間がかかってしまいます。つまりWindowsの1.9.1では、ファイルの内容に比例して時間がかかる現象が起こっていることになります。Macではこのような違いはありません。
このような現象が起こるのは一体なぜなのでしょうか？理由は、read_class_onefile_binmodeを見るとすぐに分かります。バイナリモードでは、Windowsの1.8.7と1.9.1は違いがないのです。バイナリモードとテキストモードの違いは、文字列のエンコード関係の処理を行うか否かですので、これにより、Windowsではファイル読み込み時のエンコード処理に時間がかかることがわかります。
なお、この処理コストは、Windowsでファイルを読み込むときに標準で行われる、Windows-31Jへのエンコードが原因ではないかと思い、read_class_onefile_windows31jでMacでファイルをWindows-31Jとして読み込むベンチマークを行ってみたのですが、特に遅くありませんでした。Windowsでは、はやり何か特殊な事情があるようです。
なお、compile_class_onefileを見ると、単なるプログラム処理でもMacの方が1.37倍速いことがわかります。VC6はかなり昔のコンパイラですので、最新のgccと比較するとやはり歩が悪いようです。
まとめ
以上の計測から以下のようなことがわかります。
