年前一篇blog提過(guò)，寫了一個(gè)stm-profiler用于統(tǒng)計(jì)clojure STM的運(yùn)行狀況，放在了github上：
https://github.com/killme2008/stm-profiler
STM的事務(wù)在遇到寫沖突（多個(gè)事務(wù)寫同一個(gè)ref的時(shí)候）就會(huì)回滾事務(wù)并重試，通過(guò)stm-profiler你可以查看事務(wù)的重試次數(shù)，重試原因，以及每個(gè)reference的使用情況。使用很簡(jiǎn)單，在lein的project.clj引用stm-profiler:
[stm-profiler "1.0.2-SNAPSHOT"]
注意，目前stm profiler僅支持clojure 1.3。
我們寫一個(gè)簡(jiǎn)單例子：
(use 'stm)
(def a (ref 1))
(def b (ref 2))
(dotimes [_ 100] (future (dosync (alter a + 1) (alter b - 1))))
(Thread/sleep 1000)
(prn @a)
(prn @b)
(Thread/sleep 1000)
(prn "stm statistics" (stm-stats))
(prn "reference a statistics" (ref-stats a))
(prn "reference b statistics" (ref-stats b))
定義了兩個(gè)ref：a和b，然后用future啟動(dòng)100個(gè)線程并發(fā)地發(fā)起同一個(gè)事務(wù)操作，對(duì)a加一，對(duì)b減一。最后打印a和b的值，使用stm-stats函數(shù)獲取stm的統(tǒng)計(jì)信息并打印，使用ref-stats獲取a和b兩個(gè)reference的統(tǒng)計(jì)信息并打印。
運(yùn)行這個(gè)例子，在啟動(dòng)的時(shí)候會(huì)有些警告信息，忽略即可（主要是因?yàn)閟tm profiler重新定義了一些跟STM相關(guān)的函數(shù)和宏，如dosync等，但是僅僅是添加了統(tǒng)計(jì)功能，并沒(méi)有修改他們?cè)镜墓δ埽?br />
在我機(jī)器上的一次輸出：
101
-98
"stm statistics" {"(alter a + 1)(alter b - 1)" {:not-running 11, :average-retry 5, :total-cost 1233, :get-fault 44, :barge-fail 224, :change-committed 227, :total-times 100, :average-cost 12}}
"reference a statistics" {"(alter a + 1)(alter b - 1)" {:alter 609, :get-fault 44, :barge-fail 224, :change-committed 227}}
"reference b statistics" {"(alter a + 1)(alter b - 1)" {:alter 114, :not-running 11}}
a和b的結(jié)果都沒(méi)問(wèn)題。重點(diǎn)看打印的統(tǒng)計(jì)信息，(stm-stats)的輸出結(jié)果是：
{"(alter a + 1)(alter b - 1)" {:not-running 11, :average-retry 5, :total-cost 1233, :get-fault 44, :barge-fail 224, :change-committed 227, :total-times 100, :average-cost 12}}
這個(gè)結(jié)果是一個(gè)map,key是事務(wù)的form，而value就是該form的統(tǒng)計(jì)信息，也是一個(gè)map，具體各項(xiàng)的含義如下：
total-cost
|
所有事務(wù)的總耗時(shí)
|
100個(gè)事務(wù)耗時(shí)1233毫秒
|
total-times
|
事務(wù)運(yùn)行次數(shù)
|
100次
|
average-cost
|
平均每個(gè)事務(wù)耗時(shí)
|
平均一個(gè)事務(wù)耗時(shí)12毫秒
|
average-retry
|
平均每個(gè)事務(wù)的重試次數(shù) |
平均每個(gè)事務(wù)重試了5次才成功 |
| not-running |
當(dāng)前事務(wù)不處于running狀態(tài)，可能是被其他事務(wù)打斷（barge)，需要重試 |
因?yàn)閚ot-running的原因重試了11次 |
get-fault
|
讀取ref值的時(shí)候沒(méi)有找到read point之前的值，被認(rèn)為是一次讀錯(cuò)誤，需要重試
|
因?yàn)樽xref錯(cuò)誤重試了44次
|
| barge-fail |
打斷其他事務(wù)失敗次數(shù)，需要重試 |
嘗試打斷其他事務(wù)失敗而重試了224次 |
| change-committed |
在本事務(wù)read point之后有ref值獲得提交，則需要重試
|
因?yàn)閞ef值被其他事務(wù)提交而重試了227次 |
從輸出結(jié)果來(lái)看，這么簡(jiǎn)單的一個(gè)事務(wù)操作，每次事務(wù)要成功平均都需要經(jīng)過(guò)5次的重試，最大的原因是因?yàn)閞ef的值在事務(wù)中被其他事務(wù)更改了，或者嘗試打斷其他正在運(yùn)行的事務(wù)失敗而重試。關(guān)于clojure STM的具體原理推薦看這篇文章《
Software transactional memory》。STM不是完美的，事務(wù)重試和保存每個(gè)reference的歷史版本的代價(jià)都不低。
再看
(ref-stats a)的輸出：
{"(alter a + 1)(alter b - 1)" {:alter 609, :get-fault 44, :barge-fail 224, :change-committed 227}}
可以看到a在所有事務(wù)中的統(tǒng)計(jì)信息，返回的結(jié)果同樣是個(gè)map，key是使用了a的事務(wù)，value是具體的統(tǒng)計(jì)信息。各項(xiàng)的含義類似上表，不過(guò)這里精確到了具體的reference。其中alter項(xiàng)是指對(duì)a調(diào)用alter函數(shù)了609次。ref-stats會(huì)輸出所有在事務(wù)中調(diào)用了a的函數(shù)的調(diào)用次數(shù)。
通過(guò)stm profiler你可以分析具體每個(gè)事務(wù)的執(zhí)行狀況，甚至每個(gè)reference的運(yùn)行狀況，查找熱點(diǎn)事務(wù)和熱點(diǎn)reference等。stm-profiler還不完善，目前還不支持1.2（1.4測(cè)試是可以的）。希望有興趣的朋友加入進(jìn)來(lái)一起完善。
轉(zhuǎn)載請(qǐng)注明出處：
http://www.aygfsteel.com/killme2008/archive/2012/02/09/369694.html