這篇文章不能算是把問(wèn)題徹底解決了，僅僅只是一種分析和猜測，后續的一些行動(dòng)可能會(huì )證明一些猜想，也可能什么都解決不了。如果有和我相同情況的同學(xué)，也知道是什么問(wèn)題造成的，請不吝賜教。
問(wèn)題如下：
上周周末，沒(méi)有和同事們出去Outing，在家管孩子，去生產(chǎn)環(huán)境觀(guān)察了一下集群機器的當前運行狀態(tài)，發(fā)現應用在這些多核機器上壓力極端不均勻。
Top一下大致?tīng)顟B(tài)如下：
峰值的時(shí)候，單CPU的使用率都到了80%，這種情況對于多核服務(wù)器來(lái)說(shuō)是很不正常的使用。對于Java的開(kāi)發(fā)者來(lái)說(shuō)，多線(xiàn)程編程是無(wú)法控制線(xiàn)程如何在CPU上分配的，因為Java本身不實(shí)現線(xiàn)程機制，說(shuō)是跨平臺的語(yǔ)言，但是性能及特性會(huì )根據操作系統的實(shí)現有很大的差異，因此Java調優(yōu)有時(shí)候需要對系統配置甚至內核作調優(yōu)。分析：
首先在測試環(huán)境下作了多次同樣的壓力測試，嘗試了與線(xiàn)上一樣的操作系統版本，相似的配置，但測試結果卻是負載分配很均勻。
http://www.flickr.com/photos/33194437@N03/3703485402/ (沒(méi)辦法，上傳圖片較麻煩，引用圖片，只好給鏈接了)
此時(shí)重新啟動(dòng)了一臺問(wèn)題機器，發(fā)現負載降下來(lái)了，同時(shí)也很均衡，也就是說(shuō)在當前的壓力下不應該有這樣高的cpu消耗，同時(shí)也排除了硬件或者操作系統的一些配置問(wèn)題。
在CPU滿(mǎn)負荷的情況下，很多時(shí)候會(huì )認為應該是循環(huán)造成的，對于單個(gè)CPU的消耗更是。通過(guò)Top H查看具體到底哪一個(gè)線(xiàn)程會(huì )長(cháng)時(shí)間消耗CPU。
http://www.flickr.com/photos/33194437@N03/3702676803/ (沒(méi)辦法，上傳圖片較麻煩，引用圖片，只好給鏈接了)
可以看到PID為13659的線(xiàn)程是“罪魁禍首”，但13659究竟在干什么，是應用的線(xiàn)程還是系統的線(xiàn)程，是否是陷入了死循環(huán)，不得而知。接著(zhù)就按照Java的土辦法，Kill -3 pid，然后看看輸出日志。
根據線(xiàn)程號來(lái)查找dump出來(lái)的日志中nid，發(fā)現這個(gè)線(xiàn)程是VM Thread，也就是虛擬機線(xiàn)程。（這里作一下轉換，將13659轉換成為16進(jìn)制就是0×355b）
http://www.flickr.com/photos/33194437@N03/3703479942/(沒(méi)辦法，上傳圖片較麻煩，引用圖片，只好給鏈接了)
用pstack看了一下這個(gè)線(xiàn)程的工作，結果如下：
Thread 2074 (Thread 1846541216 (LWP 13659)):
#0 0×0659fa65 in ObjectSynchronizer::deflate_idle_monitors ()
#1 0×065606e5 in SafepointSynchronize::begin ()
#2 0×06613e83 in VMThread::loop ()
#3 0×06613a6f in VMThread::run ()
#4 0×06506709 in java_start ()
#5 0×00aae3cc in start_thread () from /lib/tls/libpthread.so.0
#6 0×00a1896e in clone () from /lib/tls/libc.so.6
搜索了一下ObjectSynchronizer::deflate_idle_monitors，發(fā)現了sun的bug庫中有bug關(guān)于jdk1.6中由于這個(gè)方法導致運行期問(wèn)題的說(shuō)法：http://bugs.sun.com/bugdatabase/view_bug.do;jsessionid=803cb2d95886bffffffff9a626d3b9b28573?bug_id=6781744
然后就直接去openjdk官方網(wǎng)站去查找這個(gè)類(lèi)的代碼，大致了解一下他的作用，具體的代碼鏈接如下：http://xref.jsecurity.net/openjdk-6/langtools/db/d8b/synchronizer_8cpp-source.html
主要工作應該是對資源對象的回收，在加上pstack的結果，應該大致知道是對線(xiàn)程資源的管理。但具體代碼就沒(méi)有進(jìn)一步分析了。
接著(zhù)就分析一下自己的應用：
壓力測試（高強度、長(cháng)時(shí)間）都做過(guò)，沒(méi)有發(fā)現什么異常。
本身應用是否會(huì )存在的缺陷導致問(wèn)題呢。有人說(shuō)VM Thread兼顧著(zhù)GC的工作，因此內存泄露，對象長(cháng)期積壓過(guò)多也可能影響，但其實(shí)在dump的結果可以看到，GC有單獨的工作線(xiàn)程，同時(shí)我也觀(guān)察到GC這些線(xiàn)程的工作時(shí)間長(cháng)度，因此由于GC繁忙導致CPU上去，基本上來(lái)說(shuō)可以排除。
其次在SIP項目中使用了JDK的線(xiàn)程池(ExecutorService)和LinkedBlockingQueue。后者以前的文章里面提到在1.5版本里使用poll方法會(huì )有內存泄露，到1.6雖然沒(méi)有內存泄露，但是臨時(shí)鎖對象增長(cháng)的很快，會(huì )導致GC的頻度增加。
行動(dòng)：
上面零零散散的一些分析，最終讓我決定有如下的行動(dòng)：
1. 升級某一臺服務(wù)器的JDK，當前是1.6.0_10-b33，打算升級到1.6的14版本。比較觀(guān)察多臺機器的表現，看是否升級了JDK可以解決問(wèn)題。
2. 去除LinkedBlockingQueue作為消息隊列，直接由生產(chǎn)者將生產(chǎn)結果按照算法分配給消費者線(xiàn)程，避免競爭，鎖的消耗，同時(shí)也防止LinkedBlockingQueue帶來(lái)的資源消耗。
3. 測試環(huán)境繼續作長(cháng)時(shí)間的壓力測試，同時(shí)可以結合Jprofile之類(lèi)的工具來(lái)分析長(cháng)時(shí)間后可能出現的問(wèn)題。
后話(huà)：
這年頭真的啥都要學(xué)一點(diǎn)，求人不如求己。
SA,DBA,測試都需要能夠去學(xué)習一些，起碼在初期排查問(wèn)題上自己能夠做點(diǎn)啥，要不然別人也忙，自己又無(wú)從下手。就好比這次壓力測試好不容易排上隊，但是還是滿(mǎn)足不了及時(shí)上線(xiàn)的需求，因此自己去LoadRunner壓，好歹給出一個(gè)零時(shí)的報告先大家看著(zhù)。應用的異常有時(shí)候是應用本身設計問(wèn)題，也可能是開(kāi)發(fā)語(yǔ)言的問(wèn)題，也可能是操作系統的問(wèn)題，因此要去定位這種比較復雜的問(wèn)題，真的需要有耐心去好好的學(xué)習各種知識，現在看來(lái)知識還是匱乏啊，要不然就可以分析出openjdk中可能存在的問(wèn)題。
聯(lián)系客服
