正しいGroovyベンチマーク

GroovyのようなJVM上に乗っている言語のベンチマークは難しく、安易に行うと誤った結果を出すことになります。例えばStringBuilderとStringBufferの比較するため次のようなプログラムを書いたとします。StringBufferは同期の為にStringBuilderよりも遅いことがよく知られています:

def n = 100 * 1000
def at, bt

bt = System.nanoTime()
n.times {
    def sb = new StringBuilder()    
    sb.append('foo')
    sb.append('bar')
    sb.append('baz')
}
at = System.nanoTime()
println((at - bt) / n) 

bt = System.nanoTime()
n.times {
    def sb = new StringBuffer()    
    sb.append('foo')
    sb.append('bar')
    sb.append('baz')
}
at = System.nanoTime()
println((at - bt) / n) 

しかし期待とは異なりStringBufferがStringBuilderよりも2倍以上も速い結果になりました(Groovy 1.8.6、JVM 1.7.0_04-ea Server VM)。最適化により同期のコストがなくなったとしても同等以下のはずであり、この計測は完全に失敗しています:

StringBuilder   1947.3 (2.76)
StringBuffer     703.1 (1)

StringBuilder同士で比較すれば失敗はより明らかとなります:

StringBuilder #1   2030.68 (4.85)
StringBuilder #2    418.47 (1)

何が問題だったのかは実行時間の推移を見るとわかります。1回目の計測中に最適化が行われ、2回目は最適化がある程度完了した状態から開始されています。そのため1回目は2回目より不利となります。また、2回目の計測中に飛び出ている数値があります。これはガベージコレクションによるものですが、この時に回収されるゴミは1回目の計測中に出たものを含みます。この点では逆に2回目が1回目より不利となります。つまり正しいベンチマークとは同じスタートラインに立たせることであり、そのためには計測前に最適化を完了させメモリを掃除しゴミ箱を空にしておく必要があります。

これらの問題を自身で解決するのもよいですが、幸運なことにGroovyにはベンチマークフレームワーク、GBenchがあります。GBench 0.3.0はあなたに代わってこれらの面倒な課題を解決し正しい結果を出す機能を持っています。GBenchを使って書き直したのが次のコードです。measureCpuTimeをfalseにしCPU時間の計測を無効にすると実行時間のみの簡潔なレポートを受け取れます:

import gbench.*

new BenchmarkBuilder().run(measureCpuTime:false) {
    'StringBuilder' {
        def sb = new StringBuilder()        
        sb.append('foo')
        sb.append('bar')
        sb.append('baz')
        sb.toString()
    }
    'StringBuffer' {
        def sb = new StringBuffer()        
        sb.append('foo')
        sb.append('bar')
        sb.append('baz')
        sb.toString()
    }
}.prettyPrint()

このコードの実行結果は次のようになりました。差がそれ程ないのは私の環境がServer VMであり、ロック周りが最適化される為です。ロックの最適化ついてはJeroen Borgersの記事、Java 6のスレッド最適化は実際に動作しているのか？が参考になります:

StringBuilder   244 (1)
StringBuffer    265 (1.08)

最適化を無効にした(-XX:-DoEscapeAnalysis -XX:-EliminateLocks -XX:-UseBiasedLocking)結果は以下のとおりでした:

StringBuilder   242 (1)
StringBuffer    310 (1.28)