2

下面是我在 jrocket 中的应用程序 JAVA_OPTS 参数。

> -DRMIEngine -Xms10G -Xmx10G -Xns:1g -Xgc:pausetime -XpauseTarget:201 -XXgcTrigger=20 
> -Xgc:gencon -XXkeepAreaRatio:50 -XXcompactRatio:10 -Xverbose:memory -Xverbose:gcreport -Xverbose:compaction -Xverbose:gcpause -xverboselog:${HOME}/bin/GCLOG/verbose-jrockit-server.log 
> -Xverbosetimestamp -Delite.serverinstace=PRIMARY_4 -Djava.rmi.server.hostname=10.25.59.31
> -Djava.rmi.activation.port=3232 -Dcom.sun.management.jmxremote 
> -Dcom.sun.management.jmxremote.port=8874 -Dcom.sun.management.jmxremote.authenticate=false 
> -Dcom.sun.management.jmxremote.ssl=false -Doracle.net.disableOob=true

在这里,我附上了应用程序的 GC 日志。我们已经分析了当在堆上进行压缩时。那时应用程序暂停了将近 52 秒。由于超时,此压缩中止。因此,如果有人可以帮助我找出为什么这个压缩被中止并且应用程序得到这么多暂停时间的原因。

以下是 52 秒暂停的日志片段。

> [compact][Wed Mar 15 13:36:50 2017][05297] [OC#1175] Compaction
> reason: Normal.
> 
> [compact][Wed Mar 15 13:36:50 2017][05297] [OC#1175] Compacting 409 of
> 4096 parts at index 3687. Compaction type is external. Exceptional:
> No.
> 
> [compact][Wed Mar 15 13:36:50 2017][05297] [OC#1175] Compaction area
> start: 0x340180000, end: 0x380000000. Timeout: 80.400 ms.
> 
> [compact][Wed Mar 15 13:36:50 2017][05297] [OC#1175] Compactset limit
> (per thread): 22611163 (dynamic), using matrixes.
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Average compact
> time ratio (move phase/total time): 1.000000.
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Compaction time,
> total: 28.157 ms (target 80.400 ms).
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Compaction moved
> 9331 objects and left 34 objects. Total moved size 908576B.
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Compaction added
> 1072117928B of free memory in 18 parts.
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Found 20148
> references.
> 
> [compact][Wed Mar 15 13:37:50 2017][05297] [OC#1175] Updated 10591
> references.
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [---] 62415.309
> ms (1771992.078000-1772054.493000)  OC
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [con]     0.002
> ms (1771992.078000-1771992.078000)  OC:PreGC
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [pau]   325.399
> ms (1771992.078000-1771992.403000)  OC:Initial
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [con]  5201.610
> ms (1771992.403000-1771997.605000)  OC:ConcurrentMark
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [pau]   336.194
> ms (1771997.605000-1771997.942000)  OC:Main
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [con]   258.891
> ms (1771997.942000-1771998.201000)  OC:ConcurrentSweep1
> 

[gcpause][2017 年 3 月 15 日星期三 13:37:53][05297] [OC#1175] [pau] 52942.776

> ms (1771998.201000-1772051.144000)  OC:SweepSwitch
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [con]   247.626
> ms (1772051.144000-1772051.392000)  OC:ConcurrentSweep2
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [pau]     2.055
> ms (1772051.392000-1772051.395000)  OC:Cleanup
> 
> [gcpause][Wed Mar 15 13:37:53 2017][05297] [OC#1175] [con]  3098.431
> ms (1772051.395000-1772054.493000)  OC:PostGC
> 
> [memory ][Wed Mar 15 13:37:53 2017][05297] [OC#1175]
> 1771992.078-1772054.493: OC 8574661KB->3276276KB (10485760KB), 62.415 s, sum of pauses 53606.424 ms, longest pause 52942.776 ms.

以下是您可以在日志中搜索压缩中止的字符串。

[压缩][2017 年 3 月 15 日星期三 18:44:23][05297] [OC#1189] 压缩在 0x240780050 处中止,没有用于外部压缩的可用堆

[compact][Wed Mar 15 19:03:58 2017][05297] [OC#1190] 压缩在 0x1014eb4e8 中止,压缩已达到时间限制

GC 日志

4

0 回答 0