問題の簡単な説明
実稼働環境でシステムコンポーネントの1つ(Tomcatで実行されている唯一のもの)をトマトの新しいバージョンに移行した後、ログでGCが0.5秒間起動するのを見ると、サポートが突然パニックになりました。
一般に、私たちのプロジェクト(投資銀行のFX取引プラットフォーム)では、50ミリ秒(ms)を超えるGCの起動は、とりわけ、GCログ、および100 msを超えるGCのサポート監視に懸念を生じさせます。 したがって、ログに1.45秒が表示されると、単にパニックになりました。 その日は「第二の防衛線」にいたことが幸運だったので、何が問題なのか理解し始めました。
調査進捗
手始めに、ログに登りました。 そして私は見た:
[Full GC (System) 25.575: [CMS: 20700K->22393K(655360K) <...>
ここでのキーは、これがシステムであることを示しています-つまり
System.gc()
呼び出すと、完全なガベージコレクションがアクティブになります。 これは私たちのコードでは使用されていないと言うのは不必要だと思います。
叙情的な余談
完全に正直に言うと、これは真実ではありません
呼び出しを非常に良い目的に使用しています。 実際には、起動プロセス中に、システムは膨大な量の「静的データ」-ユーザー、通貨などに関する情報を事前にキャッシュし、このプロセスは大量のゴミを生成します。 したがって、すべての準備が完了した後、システムが起動したことを報告する直前に、
を呼び出して、不要なメモリの断片化を同時に取り除きます。 さらに、取引時間の終わりのニューヨーク時間午後5時に毎晩同じことを行い、システム全体が5分間オフラインになり(メンテナンスモード)、日中に蓄積されたゴミを削除し、メモリを最適化します。 20〜40ミリ秒かかるParNewアセンブリでさえ許容できない遅延を作成することがあるため、勤務時間中は旧世代のコレクションを回避しようとします。
System.gc()
呼び出しを非常に良い目的に使用しています。 実際には、起動プロセス中に、システムは膨大な量の「静的データ」-ユーザー、通貨などに関する情報を事前にキャッシュし、このプロセスは大量のゴミを生成します。 したがって、すべての準備が完了した後、システムが起動したことを報告する直前に、
System.gc()
を呼び出して、不要なメモリの断片化を同時に取り除きます。 さらに、取引時間の終わりのニューヨーク時間午後5時に毎晩同じことを行い、システム全体が5分間オフラインになり(メンテナンスモード)、日中に蓄積されたゴミを削除し、メモリを最適化します。 20〜40ミリ秒かかるParNewアセンブリでさえ許容できない遅延を作成することがあるため、勤務時間中は旧世代のコレクションを回避しようとします。
古いメモリによると、最初のことはDGCによってチェックされました(反モンゴル語のリンク、簡単に-RMIアプリケーションで使用されたときにアクティブ化されるガベージコレクター)。 かつて、JMXにRMIを使用するという単純な理由で、多くのシステムで1時間ごとに完全なアセンブリを引き起こしたのは彼でした。 そのため、何年も前のある晴れた日、すべてのシステムで、JVM起動パラメーターに次を追加しました。
-Dsun.rmi.dgc.server.gcInterval=0x7FFFFFFFFFFFFFFE -Dsun.rmi.dgc.client.gcInterval=0x7FFFFFFFFFFFFFFE
これらの設定のソース: [1] 、 [2] 。 変更する必要があるのは、DGCに
0x7FFFFFFFFFFFFFFE
ミリ秒に1回(約292471208年に1回)実行できることを伝えることだけです。
トマトの起動スクリプトを確認したところ、小さなエラーがあり、
0x7FFFFFFFFFFFFFFF
代わりに
0x7FFFFFFFFFFFFFFF
使用されていることが
0x7FFFFFFFFFFFFFFF
。 この値を
sun.misc.GC
すると、
IllegalArgumentException
(
sun.misc.GC
クラスのコード)がスローされます。
if (this.latency == 9223372036854775807L) { throw new IllegalStateException("Request already cancelled"); }
もっと深くする必要があります!
しかし、この誤解を正すと、トマトを再起動した後、同じ1時間ごとの
Full GC (System)
再び表示されたとき、私は非常に驚きました! 私は心に負担をかけなければなりませんでした。
System.gc()
呼び出しの責任者を見つけるために、私はすぐに
java.lang.Runtime
クラスの実装を書き、標準クラスをコピーしてその
gc()
メソッド(
System.gc()
呼び出されたときに呼び出されます)を変更しました。
元の方法:
public native void gc();
変更された方法:
public void gc() { Thread.dumpStack(); }
ご覧のとおり、ここで行うことはすべて、sttraceを
stdout
出力することで、誰が私たちを同じように呼び出したかを見つけることです。
Thread.dumpStack()
メソッドは、例外をスローしてスタックトレースをスローするだけです。
/** * Prints a stack trace of the current thread to the standard error stream. * This method is used only for debugging. * * @see Throwable#printStackTrace() */ public static void dumpStack() { new Exception("Stack trace").printStackTrace(); }
Javaマシンの
java.lang.Runtime
クラスを
-Xbootclasspath/p:/tmp/runtime
に置き換えて実行します...そして、何が見えますか?
java.lang.Exception: Stack trace at java.lang.Thread.dumpStack(Thread.java:1249) at java.lang.Runtime.gc(Runtime.java:689) at java.lang.System.gc(System.java:926) at sun.misc.GC$Daemon.run(GC.java:92)
同じDGC! しかし、どのように? DGCの起動間隔を事実上無限に設定していますか? ここでは、Googleのすべてのスキルに負担をかける必要がありました。 そして、私は検索し、そのように-何も見つけることができませんでした。 DGCの設定を誰かが上書きしていないかどうかを確認しました。GCが起動するまでに、すべてのシステムプロパティが設定した値と同じであることがわかりました。 サプライズ...
...より深く!
この時点で、私の疑念はTomcatに落ちました。 したがって、Googleリクエストの単語の幸せな組み合わせは、ここで印刷することを非常に恥ずかしかったことを私に言う唯一のリンクを私に与えてくれました(私の同僚は、可能な限り調査で私に示唆を求めて助けてくれました) 「Googleを試してみましたか?」などの質問)彼らは私を非常に不満に見ました...それから彼らはリンクに書かれたものを見て、私の呪いを繰り返しました。
そのため、ここにリンクがあり 、それがtomcat bugzilla:tyntsにつながります。 要するに、これらの独創的なApacheの連中は、
sun.rmi.GC
クラスでDGCを正しく呼び出す間隔の値を上書きし、
-Dsun.rmi.dgc.*
を設定したという事実にもかかわらず
-Dsun.rmi.dgc.*
プロパティは、すべて同じです。効果はありません! tomcat 6.0.35を使用しており、このバグは次のバージョン6.0.36で修正されたためです。
以下に、Tomcatクラス
JreMemoryLeakPreventionListener
コードを示します。これは実際にこの動作を担当します。
/* * Several components end up calling: * sun.misc.GC.requestLatency(long) * * Those libraries / components known to trigger memory leaks * due to eventual calls to requestLatency(long) are: * - javax.management.remote.rmi.RMIConnectorServer.start() */ if (gcDaemonProtection) { try { Class<?> clazz = Class.forName("sun.misc.GC"); Method method = clazz.getDeclaredMethod("requestLatency", new Class[] {long.class}); method.invoke(null, Long.valueOf(3600000)); } catch (...) { ... } }
そこで、SOで、回避策を見つけました:
セット/>
それはまさに私がやったことです。 上記のコードからわかるように、
gcDaemonProtection
フラグは、奇妙な動作の原因となるこのコードブロックを単に無効にします。 そして-ああ、奇跡! -助けた! 毎時ゴミ収集は忘却に消え、サポートは幸せです、私はお茶を飲みに行きました。
結論
そして、一般的に結論はわずかです:
- 最も重要なこと-Googleへのリクエストを正しく作成することを学んでください! 数十種類の組み合わせを試してみましたが、最終的には完全に平凡な
tomcat hourly full GC
リクエストに出会い、探していたリンクを取得しました。 - 非常に有名なソフトウェアであっても、サードパーティにバグがないことを暗示してはいけません。 そして、これがバグに遭遇するのは初めてではありません。 前回はHotspot CMSのバグだったため、ガベージコレクションの時間を本当に無駄にしました。 新しいJVMにアップグレードすることにしました。
- そして、もちろん、特にコンテナやライブラリの開発者であり、リフレクションを使用してシステムクラスに
手を汚す場合、リフレクションは悪です。
ご清聴ありがとうございました。誰かが私の経験を役立ててくれることを願っています。