Как измерить время инструкции в консоли scala?

Я использую Scala для измерения производительности regex engine java. Регулярное выражение ниже выполняется примерно за 3 секунды, но пока я не могу измерить его с помощью System.currentTimeMillis. (последнее выражение возвращает 0)

scala> val b = System.currentTimeMillis; val v = new Regex("(x+)+y").findAllIn("x"*25); b-System.currentTimeMillis
b: Long = 1330787275629
v: scala.util.matching.Regex.MatchIterator = empty iterator
res18: Long = 0

Вы теперь, почему последнее возвращаемое значение равно 0, а не количество ms, которое Scala тратит на выполнение регулярного выражения?

Ответ 1

Необъяснимая продолжительность происходит от вызова REPL toString на итераторе, возвращенного из findAllIn. Это, в свою очередь, вызывает Regex.MatchIterator#hasNext, который запускает поиск.

scala> def time[A](a: => A) = {
     |   val now = System.nanoTime
     |   val result = a
     |   val micros = (System.nanoTime - now) / 1000
     |   println("%d microseconds".format(micros))
     |   result
     | }
time: [A](a: => A)A

scala> :power
** Power User mode enabled - BEEP WHIR GYVE **
** :phase has been set to 'typer'.          **
** scala.tools.nsc._ has been imported      **
** global._, definitions._ also imported    **
** Try  :help, :vals, power.<tab>           **

scala> :wrap time
Set wrapper to 'time'

scala> new Regex("(x+)+y").findAllIn("x"*25).toString
3000737 microseconds
res19: String = empty iterator

scala> {new Regex("(x+)+y").findAllIn("x"*25); 0}
582 microseconds
res20: Int = 0

Ответ 2

def time[A](f: => A) = {
  val s = System.nanoTime
  val ret = f
  println("time: "+(System.nanoTime-s)/1e6+"ms")
  ret
}

Используйте его с помощью:

scala> time { 10*2 }
time: 0.054212ms
res1: Int = 20

Ответ 3

Это очень интересно! Я добавил println("start") и "end" вокруг строки, которая создает регулярное выражение и запускает код - это печатает

start 
end

затем приостанавливается примерно на три секунды перед печатью остальной части вывода.

Итак, похоже, что создается регулярное выражение, но не запускается до тех пор, пока не вызывается toString, чтобы вывести его на консоль. Чтобы заставить тест работать, добавьте ручной вызов toString перед вычислением затраченного времени.

scala> val b = System.currentTimeMillis; val v = new scala.util.matching.Regex("(x+)+y").findAllIn("x"*25); v.toString; System.currentTimeMillis-b
b: Long = 1330789547209
v: scala.util.matching.Regex.MatchIterator = empty iterator
res14: Long = 4881

Также это должно быть System.currentTimeMillis-b, а не наоборот...

Ответ 4

Это не прямой ответ на ваш вопрос, но вы можете рассмотреть возможность использования зрелой библиотеки для сравнения, например Criterium.

Есть много подводных камней, связанных с бенчмаркингом в целом и с JVM в частности (это является хорошим обсуждением). Это не тривиально, если вы откажетесь от своего собственного решения.

Ответ 5

Небольшое улучшение может включать несколько прогонов. Однако правильная библиотека бенчмаркинга важна, если вы обеспокоены более чем относительными различиями в скорости.

def time[A](a: => A, n:Int) = {
    var times = List[Long]()
        for (_ <- 1 to n) {
        val now = System.nanoTime
        val res = a
        times :::= List(System.nanoTime - now)
    }
    val result = times.sum / n
    println("%d microseconds".format(result / 1000))
    result
}

Ответ 6

Рассмотрим также этот подход для возврата фактического выхода прикладного метода, а также прошедшего времени, как в кортеже (Scala 2.10+),

implicit class RichElapsed[A](f: => A) {

  def elapsed(): (A, Double) = {
    val start = System.nanoTime()
    val res = f
    val end = System.nanoTime()

    (res, (end-start)/1e3)
  }

}

Для любой заданной функции def f(n: Int) = (1 to n) product,

scala> val (res, time) = f(3).elapsed
res: Int = 6
time: Double = 46.4378