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

Question

Я использую Scala для измерения производительности движка регулярных выражений 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, а не количество мс, которое тратит scala на выполнение регулярного выражения?

Answer 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

Answer 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

Answer 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, а не наоборот ...

Answer 4

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

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

Answer 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
}

Answer 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