用的println和System.currentTimeMillis的

Question

我運行下面的代碼奇怪的行爲：

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 

這是爲什麼？

Answer 1

很難相信，你可以測量任何有意義的東西以這種方式，所以這是一個有點像臆斷多少天使可以在別針的頭上跳舞。

有用於檢查選擇你的代碼編譯爲：

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使用java.lang.StringBuilder，而在第一種情況下表達式使用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; 

Answer 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 
took 0 ms 
took 0 ms

Answer 3

這裏有兩個建議： 1）而不是使用System.currentTimeMillis，使用System.nanoTime獲得更精確。 2）多次調用方法後找到平均值（10x，100x，..）。

原因似乎是您的第一個塊在println中調用System.currentTimeMillis，而第二個塊在之前計算值。

這是我的結果調用該方法幾次在第二塊的風格（花費計算外println），並使用ns。

了140納秒 了119納秒 了150納秒 了132納秒 了129納秒