3

21KB (圧縮サイズ) の JSON をクライアントに返す Web サービス呼び出しを行う 100 クライアントの負荷がかかっている Java アプリケーションで、フル GC を含む頻繁な GC を観察しています。圧縮されていない JSON は約 200 KB になります。GC が頻繁に行われるため、2.6 秒という大きな遅延が発生しています。ここでは、負荷テストに使用される JVM オプション

-Xloggc:/mnt/apache-tomcat-7.0.29/logs/gc.log -XX:+UseConcMarkSweepGC -XX:+UseCompressedOops -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintTenuringDistribution -XX:+PrintTenuringDistribution -XX:+UseParNewGC -Xms5048M  -XX:MaxTenuringThreshold=2 -XX:SoftRefLRUPolicyMSPerMB=73 -Djava.net.preferIPv4Stack=true -server -XX:NewRatio=4 -XX:SurvivorRatio=8

4vCPU と 15 MB RAM の AWS xLarge インスタンスを使用しています。

プロセスによって生成された GCl ログは次のとおりです。

 249.988: [GC 249.988: [ParNew
2163 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2164 - age   1:   83821968 bytes,   83821968 total
2165 - age   2:   20181408 bytes,  104003376 total
2166 : 896337K->103360K(930432K), 0.0409860 secs] 4453729K->3663260K(5065792K), 0.0412220 secs] [Times: user=0.16 sys=0.00, real=0.04 secs]

2167 250.051: [GC 250.051: [ParNew
2168 Desired survivor size 52920320 bytes, new threshold 2 (max 2)
2169 - age   1:   24997144 bytes,   24997144 total

2170 : 185613K->82956K(930432K), 0.0620620 secs] 3745513K->3744426K(5065792K), 0.0622810 secs] [Times: user=0.22 sys=0.00, real=0.06 secs]

2171 250.408: [GC 250.409: [ParNew
2172 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2173 - age   1:   86010184 bytes,   86010184 total
2174 - age   2:   19119656 bytes,  105129840 total


2183 : 930432K->103360K(930432K), 0.0904080 secs] 4767408K->4080180K(5065792K), 0.0906520 secs] [Times: user=0.33 sys=0.01, real=0.09 secs]
2184 251.229: [GC 251.229: [ParNew: 215470K->215470K(930432K), 0.0000370 secs] 4192291K->4192291K(5065792K), 0.0001620 secs] [Times: user=0.00 sys=0.00, real     =0.00 secs]

2185 GC locker: Trying a full collection because scavenge failed
2186 251.229: [Full GC 251.229: [CMS251.495: [CMS-concurrent-mark: 6.443/8.877 secs] [Times: user=30.14 sys=3.55, real=8.87 secs]
2187  (concurrent mode failure): 3976820K->354739K(4135360K), 0.9792960 secs] 4192291K->354739K(5065792K), [CMS Perm : 42722K->42722K(71212K)], 0.9794580 sec     s] [Times: user=0.96 sys=0.02, real=0.98 secs]
2188 252.439: [GC 252.440: [ParNew
2189 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2190 - age   1:  105807496 bytes,  105807496 total
2191 : 837144K->103360K(930432K), 0.0562310 secs] 1191884K->474282K(5065792K), 0.0564520 secs] [Times: user=0.22 sys=0.00, real=0.05 secs]
2192 252.676: [GC 252.676: [ParNew
2193 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2194 - age   1:   95836672 bytes,   95836672 total
2195 : 924377K->103360K(930432K), 0.0772210 secs] 1295299K->575312K(5065792K), 0.0774650 secs] [Times: user=0.28 sys=0.01, real=0.08 secs]
2196 253.001: [GC 253.001: [ParNew
2197 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2198 - age   1:   99903544 bytes,   99903544 total

2199 : 930432K->103360K(930432K), 0.0712130 secs] 1405673K->680963K(5065792K), 0.0714420 secs] [Times: user=0.25 sys=0.01, real=0.07 secs]

2200 253.324: [GC 253.324: [ParNew
2201 Desired survivor size 52920320 bytes, new threshold 1 (max 2)
2202 - age   1:  105814880 bytes,  105814880 total

2203 : 930432K->103360K(930432K), 0.0736730 secs] 1513770K->807662K(5065792K), 0.0739490 secs] [Times: user=0.27 sys=0.00, real=0.08 secs]
2204 253.666: [GC 253.667: [ParNew
4

2 に答える 2

3

ドライブバイがなぜそうするのかについてコメントするのを少なくとも一時停止することなく、なぜドライブバイが単にこの質問をしているのだろうか... それは私を悩ませます。

このメッセージに焦点を当てる：

GC locker: Trying a full collection because scavenge failed

このスレッドを見つけました：

https://blogs.oracle.com/poonam/entry/understanding_cms_gc_logs

この情報で:

CMS は、-XX:+CMSIncrementalMode で有効化されたインクリメンタル モード (i-cms) で実行することもできます。

CMS を (i-cms) モードで実行していますか? これは私の専門知識ではないことは認めますが、私には役立つようです。助けに立ち寄っただけです。

ここでは、この問題と考えられる解決策についてさらに説明します。

https://forums.oracle.com/thread/1543499

また、大きな問題である「concurrent mode failure」というメッセージに焦点を当てます: Java の同時モードの失敗と過剰な gc を減らす方法

于 2013-08-15T11:30:45.757 に答える
2

メモリ設定を要約しましょう。

上記の 15 MB はタイプミスだと思います。マシンの RAM が 19.7 GB 未満であると仮定すると、オプション "-Xms5048M" は最小および最大ヒープ サイズを効果的に 5048 MB に設定します (デフォルトの最大値はマシン RAM の 25% であるため、19.7 GB を超える場合は最大値が大きくなります)。 GB RAM)。

オプション -XX:NewRatio=4 および -XX:SurvivorRatio=8 と共に使用すると、次のメモリ レイアウトが得られます。

  • 合計ヒープ サイズ: 5048 MB。新しい比率によると、これは
    • 80%、つまり 4038.4 MB の Tenured (旧世代) スペース
    • 20%、つまり 1009.6 MB の若い世代のスペース。選択された生存率に応じて、以下で構成されます
      • 80%、つまり 807.68 MB の Eden スペースと
      • 10%、つまり 101.96 MB S0 (サバイバー) スペース
      • 10%、つまり 101.96 MB の S1 (サバイバー) スペース

ここで、JVM がそれから何を作成するかを確認しましょう。

ログから、サバイバー スペースが非常に小さいことがわかります。たとえば、2174 行では、age 1 と 2 のエントリの合計が 182 MB であり、S0/S1 のサイズをはるかに超えています。max age が低い (1 世代または 2 世代) ことも、survivor 領域が制限されすぎていることを示しています。JVM は、survivor 領域の使用率を目標値 (デフォルトでは 50%) に調整しようとするため、max age を減らします。

行 2183 のレポート行は、136.5 MB が若いスペースから Tenured スペースに昇格したことを示しています (GC 後の若い世代の差分は 930432 KB - 103360 KB = 827072 KB、合計ヒープ差分は 4767408 KB - 4080180 KB = 687228 KB、したがって 139844 KB が昇格されました) ）。

同じ行 2183 で、古い世代の使用量が 4080180 KB - 103360 KB = 3976820 KB = 3883.6 MB であることがわかります。これにより、154.8 MB だけが旧世代の最大サイズに残ります。

私は GC アルゴリズムのトリガーの詳細には興味がありません (そして、私が学んだことから、それらは JVM のバージョン間で変化します)。

  • 最後のプロモーションのサイズ (136.5 MB) と
  • 次の昇格のために残っている古い世代のスペースの量 (154.8 MB)

...完全な GC が緊急に必要であることは明らかです。

解決策として、若い世代のサイズを大きくしてみます

  • これにより、非常にタイトな S0/S1 セットアップが緩和されます。
  • より多くのオブジェクトが若くして死亡する可能性があるため、
  • 在職中のスペースへの昇格率が低下し、
  • CMS コンカレント モードには、「フル GC」緊急ブレーキをトリガーする必要がある前に完了するのに十分な時間があります。

もちろん、SurvivorRatio 値をさらに調整する場合と同様に、合計ヒープ サイズを増やすことも役立ちます。ただし、特に後者はアプリケーションに大きく依存するため、アプリケーションと GC アルゴリズムの両方を深く理解していなければ触れません。

于 2016-02-15T14:57:02.733 に答える