以下は、 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.
以下は、圧縮が中止されたことをログで検索できる文字列です。
[compact][Wed Mar 15 18:44:23 2017][05297] [OC#1189] 圧縮は 0x240780050 で中止されました。外部圧縮用の空きヒープがありません
[compact][Wed Mar 15 19:03:58 2017][05297] [OC#1190] 圧縮は 0x1014eb4e8 で中止され、圧縮は制限時間に達しました