[Rescan (parallel) , 0.0291598 secs]14.395: [weak refs processing, 0.0000232 secs]14.395: [class unloading, 0.0117661 secs]14.407: [scrub symbol table, 0.0015323 secs]14.409: [scrub string table, 0.0003221 secs][1 CMS-remark: 976591K(1756416K)] 1159184K(2063104K), 0.0462010 secs] [Times: user=0.14 sys=0.00, real=0.05 secs]14.412: [CMS-concurrent-sweep-start]14.633: [CMS-concurrent-sweep: 0.221/0.221 secs] [Times: user=0.37 sys=0.00, real=0.22 secs]14.633: [CMS-concurrent-reset-start]14.636: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

從以上能夠看出，在運(yùn)行了12次新生代GC后的確出現(xiàn)了一些“不太尋常”的事情。但并不是執(zhí)行了兩次Full GC，這個(gè)“不尋常”的事情其實(shí)只是在年老代中執(zhí)行了一次包含了數(shù)個(gè)階段的GC而已：

• 初始標(biāo)記階段，從0.0041705 秒或者說(shuō)4ms的時(shí)候開(kāi)始。這一階段是一次“stop-the-world”事件，所有的應(yīng)用線程都被暫停以便進(jìn)行初始標(biāo)記。
• 并發(fā)地執(zhí)行標(biāo)記和預(yù)清理(Preclean)的階段。這是和應(yīng)用線程一起并發(fā)執(zhí)行的。
• 最終標(biāo)記階段，從0.0462010秒或者說(shuō)46毫秒的時(shí)候開(kāi)始。這一階段也同樣是“stop-the-world”的。
• 并發(fā)地進(jìn)行清除操作。正如名字所說(shuō)的，這一階段也無(wú)需中斷應(yīng)用線程，可以并發(fā)地執(zhí)行。

因此我們從實(shí)際的GC日志中所看到的是這樣——其實(shí)沒(méi)有什么兩次所謂的Full GC,只有一次清理年老代空間的Major GC而已。

如果你再看下jstat輸出的結(jié)果，就不難得出結(jié)論了。它確切地指出了兩次stop-the-world事件，總耗時(shí)50ms，這段時(shí)間內(nèi)所有活躍線程都會(huì)出現(xiàn)延遲響應(yīng)。不過(guò)如果你想據(jù)此來(lái)優(yōu)化吞吐量的話，很可能會(huì)徒勞無(wú)功——jstat只列出了兩次stop-the-world的初始標(biāo)記及最終標(biāo)記的部分，而并發(fā)執(zhí)行的那部分工作卻被它給隱藏掉了。

 12/12   首頁(yè) 上一頁(yè) 10 11 12