1

我运行以下代码:

object Main {
  def main(args: Array[String]) = {
    {
      val start = System.currentTimeMillis
      println("took " + (System.currentTimeMillis - start) + " ms")
    }
    {
      val start = System.currentTimeMillis
      val took = System.currentTimeMillis - start
      println(s"took $took ms")
    }
  }
}

它给出了:

took 246 ms
took 0 ms

但是如果我交换两个块,那么我得到

took 0 ms
took 0 ms

为什么会这样?

4

3 回答 3

3

很难相信你可以用这种方式测量任何有意义的东西,所以这有点像猜测有多少天使可以在针头上跳舞。

有一些选项可以检查你的代码编译成什么:

apm@mara:~/tmp$ skalac -Xprint:typer angeldance.scala
[[syntax trees at end of                     typer]] // angeldance.scala
package angeldance {
  object Main extends scala.AnyRef {
    def <init>(): angeldance.Main.type = {
      Main.super.<init>();
      ()
    };
    def main(args: Array[String]): Unit = {
      {
        val start: Long = java.this.lang.System.currentTimeMillis();
        scala.this.Predef.println("took ".+(java.this.lang.System.currentTimeMillis().-(start)).+(" ms"))
      };
      {
        val start: Long = java.this.lang.System.currentTimeMillis();
        val took: Long = java.this.lang.System.currentTimeMillis().-(start);
        scala.this.Predef.println(scala.StringContext.apply("took ", " ms").s(took))
      }
    }
  }
}

在第二种情况下,StringContext.s是 using java.lang.StringBuilder,而在第一种情况下的表达式是 using scala/collection/mutable/StringBuilder。这可能会导致类加载成本。你必须对它很好奇才能尝试-XX:+PrintClassLoading。调用它作为scala -J-XX:+PrintClassLoading.

scala> val i = 5L
i: Long = 5

scala> "hello, " + i
res0: String = hello, 5

scala> :javap -
  Size 1007 bytes
  MD5 checksum bbccca3ecafe9287f07df81ea123676e
  Compiled from "<console>"
[snip]
         8: aload_0       
         9: new           #23                 // class scala/collection/mutable/StringBuilder
        12: dup           
        13: invokespecial #24                 // Method scala/collection/mutable/StringBuilder."<init>":()V
        16: ldc           #26                 // String hello, 
        18: invokevirtual #30                 // Method scala/collection/mutable/StringBuilder.append:(Ljava/lang/Object;)Lscala/collection/mutable/StringBuilder;
        21: getstatic     #35                 // Field .MODULE$:L;
        24: invokevirtual #39                 // Method .i:()J
        27: invokestatic  #45                 // Method scala/runtime/BoxesRunTime.boxToLong:(J)Ljava/lang/Long;
        30: invokevirtual #30                 // Method scala/collection/mutable/StringBuilder.append:(Ljava/lang/Object;)Lscala/collection/mutable/StringBuilder;
        33: invokevirtual #48                 // Method scala/collection/mutable/StringBuilder.toString:()Ljava/lang/String;
于 2013-08-17T03:49:57.580 回答
2

我猜这与 JVM 的预热有关(运行中的优化?),因为当我尝试降低代码时,它给了我零次(我添加了一个println调用)。

object Main {
  def main(args: Array[String]) {
    println("x")
    val a = ()=> {
      val start = System.currentTimeMillis
      println("took " + (System.currentTimeMillis - start) + " ms")
    }
    val b = ()=> {
      val start = System.currentTimeMillis
      val took = System.currentTimeMillis - start
      println(s"took $took ms")
    }
    a()
    b()
  }
}
X
花了 0 毫秒
花了 0 毫秒
于 2013-08-16T16:43:55.663 回答
1

这里有两个建议:1)不要使用System.currentTimeMillis,使用System.nanoTime来获得更高的精度。2)多次调用该方法后求平均值(10x,100x,..)。

原因似乎是您System.currentTimeMillis在 println 中的第一个块调用,而第二个块在之前计算值。

这是我以第二个块的样式多次调用该方法的结果(在 println 之外计算),并使用 ns.

耗时 140 ns 耗时 119 ns 耗时 150 ns 耗时 132 ns 耗时 129 ns

于 2013-08-16T18:36:10.287 回答