974
魔獸
Clojure世界:如何做性能測試
我們經常需要在程序中測量某段代碼的性能,或者某個函數的性能,在Java中,我們可能簡單地循環調用某個方法多少次,然後利用System.currentTimeMillis()方法測量下時間。在Ruby中,一般都是用Benchmark module做測試,提供了更詳細的報告信息。同樣,在Clojure裏你可以做這些事情,你仍然可以使用System.currentTimeMillis()來測量運行時間,例如:
user=> (defn sum1 [& args] (reduce + 0 args))
#'user/sum1
user=> (defn sum2 [& args]
(loop [rt 0
args args]
(if args
(recur (+ rt (first args)) (next args))
rt)))
#'user/sum2
user=> (defn bench [sum n]
(let [start (System/currentTimeMillis)
nums (range 0 (+ n 1))]
(dotimes [_ n] (apply sum nums))
(println (- (System/currentTimeMillis) start))))
user=> (bench sum1 10000)
1818
nil
user=> (bench sum2 10000)
4220
nil
#'user/sum1
user=> (defn sum2 [& args]
(loop [rt 0
args args]
(if args
(recur (+ rt (first args)) (next args))
rt)))
#'user/sum2
user=> (defn bench [sum n]
(let [start (System/currentTimeMillis)
nums (range 0 (+ n 1))]
(dotimes [_ n] (apply sum nums))
(println (- (System/currentTimeMillis) start))))
user=> (bench sum1 10000)
1818
nil
user=> (bench sum2 10000)
4220
nil
定義兩個求和函數sum1和sum2,一個是利用reduce,一個是自己寫loop,然後寫了個bench函數循環一定次數執行sum函數並給出執行時間,利用System.currentTimeMillis()方法。顯然sum1比sum2快了一倍多。為什麼更快?這不是我們的話題,有興趣可以自己看reduce函數的實現。
除了用System.currentTimeMillis()這樣的java方式測量運行時間外,clojure還提供了time宏來包裝這一切:
user=> (doc time)
-------------------------
clojure.core/time
([expr])
Macro
Evaluates expr and prints the time it took. Returns the value of
expr.
nil
-------------------------
clojure.core/time
([expr])
Macro
Evaluates expr and prints the time it took. Returns the value of
expr.
nil
time宏用的不是currentTimeMillis方法,而是JDK5引入的nanoTime方法更精確。重寫bench函數:
user=> (defn bench [sum n]
(time (dotimes [_ n] (apply sum (range 0 (+ n 1))))))
#'user/bench
user=> (bench sum1 10000)
"Elapsed time: 5425.074 msecs"
nil
user=> (bench sum2 10000)
"Elapsed time: 7893.412 msecs"
nil
盡管精度不一致,仍然可以看出來sum1比sum2快。(time (dotimes [_ n] (apply sum (range 0 (+ n 1))))))
#'user/bench
user=> (bench sum1 10000)
"Elapsed time: 5425.074 msecs"
nil
user=> (bench sum2 10000)
"Elapsed time: 7893.412 msecs"
nil
這樣的測試仍然是比較粗糙的,真正的性能測試需要考慮到JVM JIT、warm up以及gc帶來的影響,例如我們可能需要預先執行函數多少次來讓JVM“預熱”這些代碼。慶幸的是clojure世界裏有一個開源庫Criterium幫你自動搞定這一切,它的項目主頁也在github上:https://github.com/hugoduncan/criterium
首先在你的項目裏添加criterium依賴:
:dependencies [[org.clojure/clojure "1.3.0"]
[criterium "0.2.0"]])
[criterium "0.2.0"]])
接下來引用criterium.core這個ns,因為criterium主要宏也叫bench,因此我們原來的bench函數不能用了,換個名字叫bench-sum:
user=> (use 'criterium.core)
nil
user=> (defn bench-sum [sum n]
(with-progress-reporting (bench (apply sum (range 0 (+ 1 n))) :verbose)))
#'user/bench-sum
nil
user=> (defn bench-sum [sum n]
(with-progress-reporting (bench (apply sum (range 0 (+ 1 n))) :verbose)))
#'user/bench-sum
調用criterium的bench宏執行測試,使用with-progress-reporting宏包裝測試代碼並匯報測試進展,測試進展會打印在標準輸出上。請注意,我這裏並沒有利用dotimes做循環測試,因為criterium會自己計算應該運行的循環次數,我們並不需要明確指定,測試下結果:
user=> (bench-sum sum1 10000)
Cleaning JVM allocations
Warming up for JIT optimisations
Estimating execution count
Running with sample-count 60 exec-count 1417
Checking GC
Cleaning JVM allocations
Finding outliers
Bootstrapping
Checking outlier significance
x86_64 Mac OS X 10.7.3 4 cpu(s)
Java HotSpot(TM) 64-Bit Server VM 20.4-b02-402
Runtime arguments: -Dclojure.compile.path=/Users/apple/programming/avos/logdashboard/test/classes -Dtest.version=1.0.0-SNAPSHOT -Dclojure.debug=false
Evaluation count : 85020
Execution time mean : 722.730169 us 95.0% CI: (722.552670 us, 722.957586 us)
Execution time std-deviation : 1.042966 ms 95.0% CI: (1.034972 ms, 1.054015 ms)
Execution time lower ci : 692.122089 us 95.0% CI: (692.122089 us, 692.260198 us)
Execution time upper ci : 768.239944 us 95.0% CI: (768.239944 us, 768.305222 us)
Found 2 outliers in 60 samples (3.3333 %)
low-severe 2 (3.3333 %)
Variance from outliers : 25.4066 % Variance is moderately inflated by outliers
nil
user=> (bench-sum sum2 10000)
Cleaning JVM allocations
Warming up for JIT optimisations
Estimating execution count
Running with sample-count 60 exec-count 917
Checking GC
Cleaning JVM allocations
Finding outliers
Bootstrapping
Checking outlier significance
x86_64 Mac OS X 10.7.3 4 cpu(s)
Java HotSpot(TM) 64-Bit Server VM 20.4-b02-402
Runtime arguments: -Dclojure.compile.path=/Users/apple/programming/avos/logdashboard/test/classes -Dtest.version=1.0.0-SNAPSHOT -Dclojure.debug=false
Evaluation count : 55020
Execution time mean : 1.070884 ms 95.0% CI: (1.070587 ms, 1.071136 ms)
Execution time std-deviation : 1.057659 ms 95.0% CI: (1.050688 ms, 1.062877 ms)
Execution time lower ci : 1.024195 ms 95.0% CI: (1.024164 ms, 1.024195 ms)
Execution time upper ci : 1.145664 ms 95.0% CI: (1.145664 ms, 1.145741 ms)
Found 1 outliers in 60 samples (1.6667 %)
low-severe 1 (1.6667 %)
Variance from outliers : 19.0208 % Variance is moderately inflated by outliers
nil
Cleaning JVM allocations

Warming up for JIT optimisations

Estimating execution count

Running with sample-count 60 exec-count 1417
Checking GC

Cleaning JVM allocations

Finding outliers

Bootstrapping

Checking outlier significance
x86_64 Mac OS X 10.7.3 4 cpu(s)
Java HotSpot(TM) 64-Bit Server VM 20.4-b02-402
Runtime arguments: -Dclojure.compile.path=/Users/apple/programming/avos/logdashboard/test/classes -Dtest.version=1.0.0-SNAPSHOT -Dclojure.debug=false
Evaluation count : 85020
Execution time mean : 722.730169 us 95.0% CI: (722.552670 us, 722.957586 us)
Execution time std-deviation : 1.042966 ms 95.0% CI: (1.034972 ms, 1.054015 ms)
Execution time lower ci : 692.122089 us 95.0% CI: (692.122089 us, 692.260198 us)
Execution time upper ci : 768.239944 us 95.0% CI: (768.239944 us, 768.305222 us)
Found 2 outliers in 60 samples (3.3333 %)
low-severe 2 (3.3333 %)
Variance from outliers : 25.4066 % Variance is moderately inflated by outliers
nil
user=> (bench-sum sum2 10000)
Cleaning JVM allocations

Warming up for JIT optimisations

Estimating execution count

Running with sample-count 60 exec-count 917
Checking GC

Cleaning JVM allocations

Finding outliers

Bootstrapping

Checking outlier significance
x86_64 Mac OS X 10.7.3 4 cpu(s)
Java HotSpot(TM) 64-Bit Server VM 20.4-b02-402
Runtime arguments: -Dclojure.compile.path=/Users/apple/programming/avos/logdashboard/test/classes -Dtest.version=1.0.0-SNAPSHOT -Dclojure.debug=false
Evaluation count : 55020
Execution time mean : 1.070884 ms 95.0% CI: (1.070587 ms, 1.071136 ms)
Execution time std-deviation : 1.057659 ms 95.0% CI: (1.050688 ms, 1.062877 ms)
Execution time lower ci : 1.024195 ms 95.0% CI: (1.024164 ms, 1.024195 ms)
Execution time upper ci : 1.145664 ms 95.0% CI: (1.145664 ms, 1.145741 ms)
Found 1 outliers in 60 samples (1.6667 %)
low-severe 1 (1.6667 %)
Variance from outliers : 19.0208 % Variance is moderately inflated by outliers
nil
這個報告是不是相當專業?不是搞統計還不一定讀的懂。大概解讀下,sample-count是取樣次數,默認是60次,exec-count是測試的執行次數(不包括前期warm up和JIT在內),CI是可信區間,這裏取95%,Execution time mean是平均執行時間,而lower和upper是測試過程中執行時間的最小和最大值。而outliers是這一組測試中的異常值,比如執行sum1測試發現了2組異常結果。從結果來看,sum1的平均執行時間是722微秒,而sum2的平均執行時間是1.07毫秒,因此還是sum1更快一些。
總結下,如果隻是在開發過程中做一些小塊代碼的簡單測試,可以直接利用內置的time宏,如果你希望做一次比較標準的性能測試,那麼就應該利用criterium這個優秀的開源庫。
文章轉自莊周夢蝶 ,原文發布時間2012-03-22
最後更新:2017-05-18 20:36:28
上一篇:
Clojure世界:靜態代碼分析
下一篇:
《Netty 實戰》Netty In Action中文版 第2章——你的第一款Netty應用程序(三)
hibernate的多條件查詢——Criteria Query的應用
全球4萬多“技術宅”來了 雲棲大會要讓杭州熱一把
Feature extraction - sklearn文本特征提取
ASP.NET Core的配置(3): 將配置綁定為對象[上篇]
IT人的英語歌單:沒有Bug的日子充滿了Sunshine
餓了麼Redis Cluster集群化演進
[usaco] 4.1.4 PROB Cryptcowgraphy
IBM WebSphere Application Server V6.1 Fix Pack 27於2009.09.21發布
這些年,聯想未能實現的4個戰略轉型
Hibernate三種狀態的區分