以前、マイクロベンチマークツールであるJMHを試してみたというエントリを書きました。
JMH
http://openjdk.java.net/projects/code-tools/jmh/
マイクロベンチマークツール、JMHを試す
http://d.hatena.ne.jp/Kazuhira/20140102/1388662362
で、その後Scalaで書こうとして、APTがあるのでJavaのブリッジコードが必要だというエントリを書きました。
Scala＋sbtと、JMHを合わせて使う
http://d.hatena.ne.jp/Kazuhira/20140102/1388671010
これに対して、最近@xuwei_kさんからsbtのJMHプラグインができたとツッコミをいただいたので、試してみることにしました。
sbt-jmh
プラグインの名前は、「sbt-jmh」です。
sbt-jmh
https://github.com/ktoso/sbt-jmh
実体は以下の1本のようですが、最終的に実行時（run時）にJavaのコードを生成、コンパイル、実行みたいな動作をします。
https://github.com/ktoso/sbt-jmh/blob/master/src/main/scala/pl/project13/scala/sbt/SbtJmh.scala
とりあえず、使っていってみましょう。あまり深く考えずに、以下のエントリで書いた内容をScalaに移植することを目標にします。
マイクロベンチマークツール、JMHを試す
http://d.hatena.ne.jp/Kazuhira/20140102/1388662362
準備
sbt-jmhはsbtのプラグインとなっているので、まずはplugins.sbtを作成します。
project/plugins.sbt
addSbtPlugin("pl.project13.scala" % "sbt-jmh" % "0.1.4")
あとは、build.sbtを作成。
build.sbt
import JmhKeys._ name := "jhm-scala-example" version := "0.0.1-SNAPSHOT" scalaVersion := "2.11.1" organization := "org.littlewings" incOptions := incOptions.value.withNameHashing(true) val jmhVersion = "0.9.2" libraryDependencies += "org.openjdk.jmh" % "jmh-core" % jmhVersion jmhSettings version in Jmh := jmhVersion outputTarget in Jmh := target.value / s"scala-${scalaBinaryVersion.value}"
若干、カスタム入ってますがとりあえず
import JmhKeys._
として
jmhSettings
があればいいらしいのですが、そもそもソースコードのコンパイル自体にJMHが必要なのと、sbt-jmhが使うJMHのバージョンを変えるために以下のような設定を入れています。
val jmhVersion = "0.9.2" libraryDependencies += "org.openjdk.jmh" % "jmh-core" % jmhVersion jmhSettings version in Jmh := jmhVersion
「version in Jmh」に値を設定しなかった場合、sbt-jmhプラグインのバージョンが0.1.4だった場合、JMH 0.9が使用されます。今回は、0.9.2を使用するようにしました。
また、以下の設定は今回の設定だと入れても入れなくても一緒です。
outputTarget in Jmh := target.value / s"scala-${scalaBinaryVersion.value}"
ベンチマーク対象のコードを作成する
では、以前のエントリからJavaコードをScalaコードに移植して、ベンチマーク対象のコードを書きます。
意味はまったく変わらないので、何をしているかの説明は以下のエントリを参照してください。
マイクロベンチマークツール、JMHを試す
http://d.hatena.ne.jp/Kazuhira/20140102/1388662362
src/main/scala/org/littlewings/jmh/example/HelloJmhScala.scala
package org.littlewings.jmh.example import java.util.concurrent.TimeUnit import org.openjdk.jmh.annotations.Benchmark class HelloJmhScala { @Benchmark def simpleBench(): Unit = TimeUnit.MILLISECONDS.sleep(500L) }
src/main/scala/org/littlewings/jmh/example/LoopScala.scala
package org.littlewings.jmh.example import java.util.concurrent.TimeUnit import org.openjdk.jmh.annotations.Benchmark import org.openjdk.jmh.annotations.OperationsPerInvocation class LoopScala { def method(limit: Int): Unit = { (0 until limit).foreach(_ => TimeUnit.MILLISECONDS.sleep(10)) } @Benchmark @OperationsPerInvocation(1) def invoke1(): Unit = method(1) @Benchmark @OperationsPerInvocation(100) def invoke100(): Unit = method(100) }
src/main/scala/org/littlewings/jmh/example/TestStateScala.scala
package org.littlewings.jmh.example import org.openjdk.jmh.annotations.{Benchmark, Level, Setup, Scope, State, TearDown} @State(Scope.Thread) class TestStateScala { private var counter: Long = 0 @Setup //@Setup(Level.Iteration) def setup(): Unit = { println("========== setup ==========") counter = 0 } @Benchmark def methodA(): Unit = counter += 1 @Benchmark def methodB(): Unit = counter += 1 @TearDown //@TearDown(Level.Iteration) def tearDown(): Unit = { println("========== teardown ==========") println("counter = " + counter) } }
取り立てて移植にはそれほど困りませんでしたが、前に使ったJMHのバージョンが0.2で、今回は0.9.2ですがベンチマークを表すアノテーションが変わっていて、そこは読み替えました（@GenerateMicroBenchmark → @Benchmark）。
実行
ベンチマークは、sbtのrunコマンドと引数を使って実行します。特にassemblyプラグインを使ってJARを生成する必要などはないようです。
また、run時にはforkがかかります。
ヘルプの表示。
> run -h 〜省略〜[error] Usage: java -jar ... [regexp*] [options] [error] [opt] means optional argument. [error] <opt> means required argument. [error] "+" means comma-separated list of values. [error] "time" arguments accept time suffixes, like "100ms". [error] [error] [arguments] Benchmarks to run (regexp+). [error] -bm <mode> Benchmark mode. Available modes are: [Throughput/thrpt, [error] AverageTime/avgt, SampleTime/sample, SingleShotTime/ss, [error] All/all] 〜省略〜
ベンチマークの一覧。
> run -l 〜省略〜 [info] Running org.openjdk.jmh.Main -l [info] Benchmarks: [info] org.littlewings.jmh.example.HelloJmhScala.simpleBench [info] org.littlewings.jmh.example.LoopScala.invoke1 [info] org.littlewings.jmh.example.LoopScala.invoke100 [info] org.littlewings.jmh.example.TestStateScala.methodA [info] org.littlewings.jmh.example.TestStateScala.methodB
それでは、HelloWorld的なものを動かしてみましょう。
> run org.littlewings.jmh.example.HelloJmhScala.+ -wi 3 -i 3 -f 1 -r 1s -bm thrpt -tu s
結果。
[info] Running org.openjdk.jmh.Main org.littlewings.jmh.example.HelloJmhScala.+ -wi 3 -i 3 -f 1 -r 1s -bm thrpt -tu s [info] # VM invoker: /usr/lib/jvm/java-8-oracle/jre/bin/java [info] # VM options: <none> [info] # Warmup: 3 iterations, 1 s each [info] # Measurement: 3 iterations, 1 s each [info] # Threads: 1 thread, will synchronize iterations [info] # Benchmark mode: Throughput, ops/time [info] # Benchmark: org.littlewings.jmh.example.HelloJmhScala.simpleBench [info] [info] # Run progress: 0.00% complete, ETA 00:00:06 [info] # Fork: 1 of 1 [info] # Warmup Iteration 1: 1.998 ops/s [info] # Warmup Iteration 2: 1.995 ops/s [info] # Warmup Iteration 3: 1.996 ops/s [info] Iteration 1: 1.996 ops/s [info] Iteration 2: 1.997 ops/s [info] Iteration 3: 1.998 ops/s [info] [info] [info] Result: 1.997 ±(99.9%) 0.022 ops/s [Average] [info] Statistics: (min, avg, max) = (1.996, 1.997, 1.998), stdev = 0.001 [info] Confidence interval (99.9%): [1.975, 2.019] [info] [info] [info] # Run complete. Total time: 00:00:09 [info] [info] Benchmark Mode Samples Score Score error Units [info] o.l.j.e.HelloJmhScala.simpleBench thrpt 3 1.997 0.022 ops/s
ちょっと以前のバージョンと、表示が変わりましたね。引数の意味などは、以前のエントリを参照してください。
繰り返しのベンチマークを実行。
> run org.littlewings.jmh.example.LoopScala.+ -wi 3 -i 3 -f 1 -r 1s -bm all -tu s
結果。
[info] # Run complete. Total time: 00:01:06 [info] [info] Benchmark Mode Samples Score Score error Units [info] o.l.j.e.LoopScala.invoke1 thrpt 3 88.939 29.343 ops/s [info] o.l.j.e.LoopScala.invoke100 thrpt 3 89.491 51.835 ops/s [info] o.l.j.e.LoopScala.invoke1 avgt 3 0.011 0.003 s/op [info] o.l.j.e.LoopScala.invoke100 avgt 3 0.011 0.003 s/op [info] o.l.j.e.LoopScala.invoke1 sample 284 0.011 0.000 s/op [info] o.l.j.e.LoopScala.invoke100 sample 3 0.011 0.004 s/op [info] o.l.j.e.LoopScala.invoke1 ss 3 0.012 0.021 s [info] o.l.j.e.LoopScala.invoke100 ss 3 1.123 0.877 s
状態を持たせたベンチマーク。
> run org.littlewings.jmh.example.TestStateScala.+ -wi 3 -i 3 -f 1 -r 1s -bm thrpt -tu s
結果。
[info] Result: 382742653.005 ±(99.9%) 426391567.957 ops/s [Average] [info] Statistics: (min, avg, max) = (355927973.628, 382742653.005, 398791634.469), stdev = 23371960.634 [info] Confidence interval (99.9%): [-43648914.951, 809134220.962] [info] [info] [info] # Run complete. Total time: 00:00:16 [info] [info] Benchmark Mode Samples Score Score error Units [info] o.l.j.e.TestStateScala.methodA thrpt 3 374397237.327 597683389.117 ops/s [info] o.l.j.e.TestStateScala.methodB thrpt 3 382742653.005 426391567.957 ops/s
結果、どれもそんなに変わらないから大丈夫かな…。
とりあえず、使えそうですね。
ちょっと気になったこと
JMH自体を使っていればそれほどハマりどころはないような気はするものの、ちょっと気になったのが実行時の挙動。
runコマンドで実行すると、必ず以下のようなログが出力されます。
> run org.littlewings.jmh.example.TestStateScala.+ -wi 3 -i 3 -f 1 -r 1s -bm thrpt -tu s [info] Compiling 3 Scala sources to /xxxxx/jmh-scala-example/target/scala-2.11/classes... [info] Generating JMH benchmark Java source files... Processing 4 classes from /xxxxx/jmh-scala-example/target/scala-2.11/classes with "reflection" generator Writing out Java source to /xxxxx/jmh-scala-example/target/scala-2.11/generated-sources/jmh and resources to /xxxxx/jmh-scala-example/target/scala-2.11/classes [info] Compiling generated JMH benchmarks... [info] Compiling 3 Scala sources and 5 Java sources to /xxxxx/jmh-scala-example/target/scala-2.11/classes...
で、ここからベンチマーク実行開始。
[info] Running org.openjdk.jmh.Main org.littlewings.jmh.example.TestStateScala.+ -wi 3 -i 3 -f 1 -r 1s -bm thrpt -tu s
前回のコンパイル有無に関わらず、毎回Javaのコード生成が走ります。ヘルプを見るのにも、コード生成が走ります。ベンチマークの一覧を見るのにも、やっぱり走ります。というか、本体のコードもコンパイルされているような…。
まあ仕方がないのかなーという気もしますけどね…。
