ファイルから一行ずつ読み込む方法のベンチマーク
Rubyでファイルから一行ずつ読み込んで何か処理をするときにはIO#each_lineやIO#getsをよく使う。そこでふと「一行ずつ読み込むのを他のメソッドでやったらどうなるか」が気になったので簡単なコードで試してみた。
使用したベンチマークはこれで、読み込むファイルのサイズは約220MB、Rubyのバージョンは2.6.5という条件で以下の結果となった。
user system total real
#read [all] 0.015987 0.077855 0.093842 ( 0.094016)
#gets 0.371307 0.044368 0.415675 ( 0.417150)
#each_line 0.329978 0.043069 0.373047 ( 0.373835)
#sysread [128] 6.016064 3.680863 9.696927 ( 9.710723)
#sysread [512] 1.902203 0.963871 2.866074 ( 2.870271)
#sysread [1024] 1.176114 0.498456 1.674570 ( 1.676942)
#sysread [4096] 0.608257 0.148385 0.756642 ( 0.757932)
#sysread [8192] 0.510168 0.088529 0.598697 ( 0.600006)
#read [128] 2.122405 0.051417 2.173822 ( 2.177007)
#read [512] 0.898166 0.048396 0.946562 ( 0.947740)
#read [1024] 0.692436 0.046495 0.738931 ( 0.740503)
#read [4096] 0.507455 0.042812 0.550267 ( 0.551098)
#read [8192] 0.470628 0.041879 0.512507 ( 0.513222)
#readpartial [128] 2.105541 0.052476 2.158017 ( 2.162032)
#readpartial [512] 0.901669 0.052096 0.953765 ( 0.955619)
#readpartial [1024] 0.676670 0.045136 0.721806 ( 0.722763)
#readpartial [4096] 0.511316 0.043307 0.554623 ( 0.555656)
#readpartial [8192] 0.475274 0.042989 0.518263 ( 0.519282)
StringScanner [128] 1.231599 0.075308 1.306907 ( 1.308811)
StringScanner [512] 0.751719 0.099575 0.851294 ( 0.852907)
StringScanner [1024] 0.634276 0.088091 0.722367 ( 0.723404)
StringScanner [4096] 0.569987 0.090044 0.660031 ( 0.661539)
StringScanner [8192] 0.553297 0.088739 0.642036 ( 0.643493)
このうち#read [all]は一行ずつ読み込むのではなくて、ファイルをいっきに読み込んでいるだけのもので、参考のために加えた。
#getsはwhile line = io.gets; ... endで、#each_lineはio.each_line { ... }で、それぞれ一行ずつの処理をしている。
#read [...]と#readpartial [...]は一定サイズごとにファイルから読み込み、String#each_lineで一行ずつ切りしている。ただし中途半端に読み込むことがあるので、改行文字を確認して途中のものを次にまわす処理を加えている。
StringScanner [...]は#readpartial [...]と同様の処理をしているが、一行ずつの切り出しにStringScannerを使っている。
やる前から分かっていたような気が、やってみてからしたのだが、やはり#getsや#each_lineが速い。ただし#each_lineのほうが#getsより速かったのは少し意外だった。
次に、この結果をもとにしてもう少し現実的な例をと考え、Railsのログから一行ずつ切り出して、日時やPID、ログの本文を処理するといった、よくありそうなコードを作成して比較してみた。実際のコードはこれで、結果は以下の通りとなった。
user system total real
#read [all] 6.526680 0.044861 6.571541 ( 6.577277)
#gets 5.738924 0.063472 5.802396 ( 5.808797)
#each_line 5.741025 0.053634 5.794659 ( 5.800046)
#readpartial [4096] 6.613471 0.055632 6.669103 ( 6.677320)
#readpartial [8192] 6.469769 0.055768 6.525537 ( 6.532796)
#readpartial [16384] 6.474019 0.054888 6.528907 ( 6.535206)
#readpartial [65536] 6.481601 0.055922 6.537523 ( 6.544236)
#readpartial [262144] 6.467564 0.055558 6.523122 ( 6.529386)
StringScanner [4096] 5.587214 0.103010 5.690224 ( 5.695447)
StringScanner [8192] 5.545400 0.099410 5.644810 ( 5.650417)
StringScanner [16384] 5.561968 0.099630 5.661598 ( 5.667500)
StringScanner [65536] 5.563528 0.100213 5.663741 ( 5.669328)
StringScanner [262144] 5.562420 0.099453 5.661873 ( 5.667616)
日時文字列の取り出などはすべて正規表現で行っている。見ての通り、StringScannerが健闘している。
なお、#readpartial [...]は内部でString#scanを使っている。内部でString#each_lineを使うともう少し違ってくるかもしれないが、その場合でも#each_lineを越えることはないはずなので、StringScannerの健闘という結果には変わりなさそうだ。
正規表現を使わずに処理すればかなり違った結果になるかもしれない。
同じベンチマークをRuby 2.5.3でとってみたところ、以下の結果となった。
user system total real
#read 7.184698 0.082951 7.267649 ( 7.274646)
#gets 5.763538 0.063250 5.826788 ( 5.833132)
#each_line 5.774047 0.053289 5.827336 ( 5.833412)
#readpartial [4096] 7.268451 0.059829 7.328280 ( 7.334584)
#readpartial [8192] 7.107022 0.058614 7.165636 ( 7.175746)
#readpartial [16384] 7.070806 0.057129 7.127935 ( 7.136860)
#readpartial [65536] 7.095140 0.058572 7.153712 ( 7.162590)
#readpartial [262144] 7.070790 0.056670 7.127460 ( 7.135610)
StringScanner [4096] 5.652786 0.078822 5.731608 ( 5.738183)
StringScanner [8192] 5.629550 0.099086 5.728636 ( 5.734746)
StringScanner [16384] 5.624071 0.101662 5.725733 ( 5.731590)
StringScanner [65536] 5.642039 0.101069 5.743108 ( 5.749317)
StringScanner [262144] 5.650001 0.101210 5.751211 ( 5.756517)
Ruby 2.6.5と2.5.3で#readや#readpartial [...]について10%程度の違いが出ている。String#scanか、または長めの文字列に対する正規表現のマッチの速度に改善があったのかもしれない。