2013-05-28 36 views
8

試圖調試運行不當的Java VM。有問題的進程是在Centos 5上運行Sun VM 1.6u24的大型虛擬機(100GB堆),它正在執行例行的後端工作 - 即數據庫訪問,文件I/O等等。JVM定期掛起

在軟件版本升級過程重新啓動後,我們注意到其吞吐量顯着下降。大多數時候,頂級報告稱Java進程正在充分利用2個內核。在此期間,虛擬機完全沒有責任:沒有寫入日誌,它不響應外部工具,如jstack或kill -3。一旦虛擬機恢復,過程將按照正常進行,直到下一次掛起。

strace顯示在這些掛起期間,只有2個線程進行系統調用。這些是VM線程「VM線程」(21776)和「VM週期任務線程」(21786)。據推測,這2個線程正在使用CPU時間。應用程序線程偶爾醒來並完成他們的工作。剩下的時間,他們似乎在等待不同的futexes。順便說一下,正常階段的第一行總是一個SIGSEGV。

[pid 21776] sched_yield()    = 0 
[pid 21776] sched_yield()    = 0 
[pid 21776] sched_yield(<unfinished ...> 
[pid 21786] <... futex resumed>)  = -1 ETIMEDOUT (Connection timed out) 
[pid 21776] <... sched_yield resumed>) = 0 
[pid 21786] futex(0x2aabac71ef28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> 
[pid 21776] sched_yield(<unfinished ...> 
[pid 21786] <... futex resumed>)  = 0 
[pid 21786] clock_gettime(CLOCK_MONOTONIC, {517080, 280918033}) = 0 
[pid 21786] clock_gettime(CLOCK_REALTIME, {1369750039, 794028000}) = 0 
[pid 21786] futex(0x2aabb81b94c4, FUTEX_WAIT_PRIVATE, 1, {0, 49923000} <unfinished ...> 
[pid 21776] <... sched_yield resumed>) = 0 
[pid 21776] sched_yield()    = 0 
[pid 21776] sched_yield()    = 0 
[pid 21955] --- SIGSEGV (Segmentation fault) @ 0 (0) --- 
[pid 21955] rt_sigreturn(0x2b1cde2f54ad <unfinished ...> 

該問題表現在2個不同的服務器中。回滾我們的代碼版本僅適用於2臺服務器中的一臺。系統日誌中沒有報告錯誤消息,受影響機器上的另一個Java進程表現正常。

與gstack獲得這下面的輸出和顯示2個典型的等待應用程序線程:

Thread 552 (Thread 0x4935f940 (LWP 21906)): 
#0 0x00000030b040ae00 in [email protected]@GLIBC_2.3.2() from /lib64/libpthread.so.0 
#1 0x00002b1cdd8548d6 in os::PlatformEvent::park(long)() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#2 0x00002b1cdd92b230 in ObjectMonitor::wait(long, bool, Thread*)() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#3 0x00002b1cdd928853 in ObjectSynchronizer::wait(Handle, long, Thread*)() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#4 0x00002b1cdd69b716 in JVM_MonitorWait() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#5 0x00002b1cde193cc8 in ??() 
#6 0x00002b1ce2552d90 in ??() 
#7 0x00002b1cdd84fc23 in os::javaTimeMillis()() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#8 0x00002b1cde188a82 in ??() 
#9 0x0000000000000000 in ??() 
Thread 551 (Thread 0x49460940 (LWP 21907)): 
#0 0x00000030b040ab99 in [email protected]@GLIBC_2.3.2() from /lib64/libpthread.so.0 
#1 0x00002b1cdd854d6f in Parker::park(bool, long)() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#2 0x00002b1cdd98a1c8 in Unsafe_Park() from /usr/lib/jvm/java/jre/lib/amd64/server/libjvm.so 
#3 0x00002b1cde193cc8 in ??() 
#4 0x000000004945f798 in ??() 
#5 0x00002b1cde188a82 in ??() 
#6 0x0000000000000000 in ??() 

我們看問題與NTPD,包括閏秒的bug,但建議的解決方法沒有幫助,也沒有使用外部NTPD服務器。重新啓動機器本身也沒有幫助。我們啓用了GC日誌記錄功能,並沒有將其視爲GC問題,因爲沒有指示它的消息。尋找任何可以幫助解決這個問題的建議,非常感謝任何幫助。

+1

難道是「GC暫停」?你檢查過使用的GC算法嗎? http://www.oracle.com/technetwork/java/gc-tuning-5-138395.html#0.0.0.%20The%20Concurrent%20Low%20Pause%20Collector%7Coutline – kosa

+0

我同意@Nambari - 我已經當它們處於負載狀態時,在大型JVM中看到很長的停頓。如果GC過程無法在合理的時間內完成,則可能會發生內存不足錯誤。你的JVM真的需要那麼大嗎? –

+0

堆越大,GC進程需要解析的對象越多 –

回答

3

這裏有一對夫婦的事情,我想看看:

  • 當JVM是反應遲鈍,用iostatvmstat,看看系統是否抖動。當您過度分配內存時可能會發生這種情況;即您的整個系統使用的虛擬內存明顯多於物理內存。

  • 打開JVM的GC日誌記錄,並查看JVM無響應和GC運行之間是否存在關聯。