Timing a computation

I regularly use a simply function such as the following to time a given computation block. It prints a message and returns the average wall-time in milliseconds. This works great, except that if I launch a sequence of 1000s of such computations and forget to tell my macbook to NOT go to sleep, when I come in the next day, the sequence as paused, and I can resume simply by pressing a key, but then one of the computations has taken a really long time.

Are there better functions I can use which will measure the computation time filtering out the time the laptop was asleep? I.e., if I count the CPU time, or something better.

  // returns the average amount of time of evaluating block
  // after evaluating block repetitions number of times.
  def time[R](repetitions: Int, name: String, block: => R): Double = {
    val t0 = System.nanoTime()
    (1 to repetitions).foreach { _ => block }
    val t1 = System.nanoTime()
    val elapsed = {
      (t1 - t0) / (repetitions * 1.0e6)
    }
    println(s"$name: Elapsed time: $elapsed ms")
    elapsed
  }

If you really want to be reliably precise, use a profiler. Or, figure out how to tell the JVM to produce profiling information and how to access it.

If you’re OK with something simple, crude and unreliable, you could put, on a separate thread, an endless loop that increases a counter about every ten milliseconds, and then use the state of that counter as your clock.

But really, profiling is very tricky, because there is garbage collection and there is the Java Memory Model.

You can try MXBeans from JMX, e.g.

AFAIR they are not guaranteed to be available everywhere or have the full functionality on all platforms.

I’m not sure whether a profiler would do what I want. What I’m doing is running a function with successively larger inputs and plotting the performance as a function of the “input size”. such as the following. I don’t really need incredible accuracy, because there’s lots of inherent noise in the computation as you can see from the plot

bdd-ratio

Example with ThreadMXBean https://scastie.scala-lang.org/ySk8pNu0T32sR8paz1CvZA

val mxBean = java.lang.management.ManagementFactory.getPlatformMXBean(classOf[java.lang.management.ThreadMXBean])

// returns the average amount of time of evaluating block
// after evaluating block repetitions number of times.
def time[R](repetitions: Int, name: String, block: => R): Double = {
  val t0 = mxBean.getCurrentThreadCpuTime()
  (1 to repetitions).foreach { _ => block }
  val t1 = mxBean.getCurrentThreadCpuTime()
  val elapsed = {
    (t1 - t0) / (repetitions * 1.0e6)
  }
  println(s"$name: Elapsed time: $elapsed ms")
  elapsed
}

time(5, "aaa", {
  Thread.sleep(123)
})
time(5, "bbb", {
  val endTime = System.currentTimeMillis() + 100
  while (System.currentTimeMillis() < endTime) {}
})

Prints:

aaa: Elapsed time: 0.2801784 ms
bbb: Elapsed time: 98.7493052 ms

That’s great. I need to test that to see what happens when he mac goes to sleep, whether getCurrentThreadCpuTime considers the laptop being asleep as zero amount of time.