隠れたJVMオンライン悲劇の分析、調査、解決を記録する

  [[276426]]

1. 背景

この記事では、特別な JVM 最適化のケースについて説明します。この最適化のケース自体は、初心者のエンジニアが JVM の最適化について中途半端な理解しか持たず、どこかで非常に特殊な JVM パラメータを見つけてそれを誤って設定したために、オンライン システムで Full GC の問題が頻繁に発生したためです。

しかし、その後の最適化ケースの多くは、実際にはあらゆる種類の奇妙なシナリオです。これらの奇妙なシナリオにより、JVM 最適化におけるより豊富な実践的な経験を徐々に蓄積できるからです。

理解するシナリオが多ければ多いほど、将来 JVM パフォーマンスの問題に対処する際の負担が軽減されます。

2. 問題の生成

このシナリオは、おおよそ次のように起こります。ある日、チームの新人エンジニアが、おそらく気まぐれで、インターネットで特定のJVMパラメータを見て、武術の秘密を学んだと思い込み、その日にシステムを起動したときに、JVMパラメータを勝手に設定しました。

このパラメータとは何ですか?

心配しないでください。以下のケース分析に従ってください。今知っておくべきことは、彼が奇妙なパラメータを設定し、その後事故が起こったということだけです。

一般的に、中規模企業や大規模企業は、Zabbix、OpenFalcon などの監視システムや、自社開発の監視システムに接続しているからです。監視システムは一般的によくできており、システムを直接監視システムに接続できます。すると、各マシンの CPU、ディスク、メモリ、ネットワークの負荷を確認できます。

JVM のメモリ使用量の変動を示す折れ線グラフと、JVM GC の頻度を示す折れ線グラフも表示できます。自分で経営指標を報告すれば、モニタリングシステムでも確認できるようになります。

さらに、オンラインで実行されているマシンやシステムには、通常、いくつかのアラームが設定されます。たとえば、システムの JVM で 10 分以内に 3 回を超える Full GC が発生した場合にアラームが送信されるように設定できます。アラームは、テキスト メッセージ、電子メール、または DingTalk などの IM ツールに送信できます。

このような監視システムは、このコラムの範囲外です。ご自身で情報を調べることをお勧めします。実際、jstat などの説明したコマンドライン ツールに基づいて、Linux 上でいくつかのコマンドを使用することで、jstat に JVM を自動的に監視させ、監視結果をマシン上のファイルに出力させることができます。

翌日、そのファイルを調べて、そのマシンの JVM の GC 統計も確認できます。

したがって、視覚化ツールがなくても、最も単純なコマンドライン ツールで同様の効果を実現できます。

そのため、その日エンジニアが JVM パラメータを設定した後、オンライン チームは頻繁に JVM Full GC アラームを受信しました。皆は非常に驚き、そのシステムを調査し始めました。

3. GCログを確認する

システム起動時に GC ログを出力する方法についてはすでに説明しましたので、アラームが見つかったら、オンライン マシンに直接ログインすると、対応する GC ログが表示されます。

この時点で、GC ログに多数の Full GC レコードが表示されます。

では、Full GC の原因は何でしょうか?

ログには、次のログのような「Metadata GC Threshold」という単語が表示されました。

【フルGC(メタデータGCしきい値)xxxxx, xxxxx】

このことから、頻繁なフル GC は実際には JDK 1.8 以降のメタデータ領域によって発生していることがわかります。これは、前述の永続世代に似ています。

このメタデータ領域は通常、JVM にロードされたクラスを格納するために使用されます。

ですから、この時点では非常に奇妙です。メタデータ領域が頻繁にいっぱいになり、Full GC がトリガーされるのはなぜですか?そして、ご存知のとおり、フル GC により、CMS は古い世代をリサイクルし、メタデータ領域自体もリサイクルします。

次の図を見てみましょう。

4. メタスペースのメモリ使用量を確認する

次に、もちろん、Metaspace 領域のメモリ使用量を確認したいと思います。簡単に言えば、jstat を通じて観察することができます。監視システムがある場合は、以下のようなメタスペース メモリ領域の使用量の変動曲線グラフが表示されます。

メタスペース領域のメモリが変動状態になっているようです。常に最初に増加します。ピークに達すると、メタスペース領域がいっぱいになり、Full GC が自然にトリガーされます。 Full GC によりメタスペース領域でガベージコレクションが実行されるため、メタスペース領域のメモリ使用量は非常に少なくなります。

5. 包括的な分析アプローチ

これを見て、誰もが何かしらの感情を抱くはずだと私は思います。システムの動作中、新しいクラスが絶えず生成され、メタスペース領域にロードされ、その後メタスペース領域が絶えずいっぱいになり、その後、メタスペース領域内の一部のクラスをリサイクルするためにフル GC がトリガーされることは明らかです。

このプロセスが繰り返され、メタスペース領域が繰り返し埋め尽くされ、次の図に示すように、フル GC が繰り返し発生します。

6. 継続的にロードされているクラスは何ですか?

すると、少し困惑しますが、JVM の Metaspace 領域には常にどのようなクラスがロードされているのでしょうか?

このとき、JVM 起動パラメータに次の 2 つのパラメータを追加する必要があります。

 「-XX:TraceClassLoading -XX:TraceClassUnloading」

名前が示すように、これら 2 つのパラメーターはクラスのロードとクラスのアンロードを追跡します。ログを通じて、JVM でロードおよびアンロードされたクラスが出力されます。

これら 2 つのパラメータを追加すると、Tomcat の catalina.out ログ ファイルに次のような内容のログが出力されることがわかります。

【__JVM_Defined_Classからsun.reflect.GeneratedSerializationConstructorAccessorをロードしました】

JVM が動作中に、いわゆる「GeneratedSerializationConstructorAccessor」クラスをメタスペース領域に大量にロードし続けることは明らかです。

下の図に示すように

これは、JVM が動作中にこれらの奇妙なクラスをロードし続け、Metaspace 領域を埋め続けるため、Full GC が継続的に実行されるためだと考えています。

これはすべての学生が習得しなければならない非常に実用的なスキルです。頻繁なフル GC は、古い世代によってトリガーされるだけでなく、メタスペース領域にクラスが多すぎるためにトリガーされることもあります。

これまで、私たちはゆっくりと真実に近づいてきました。

7. 奇妙なクラスが頻繁にロードされるのはなぜですか?

同様の問題に遭遇したときは、Google または Baidu を探す必要があります。もちろん、Google を使用することをお勧めします。継続的にロードされているクラスを確認できます。それはどんな授業ですか？それらは自分で書いたクラスですか?それとも、JDK に組み込まれているクラスですか?

たとえば、上記のクラスに関する情報を調べると、Java でリフレクションを使用するときにそのクラスがロードされる可能性が高いことが簡単にわかります。いわゆるリフレクションコードは次のようになります。

メソッド method = XXX.class.getDeclaredMethod(xx,xx);
メソッドを呼び出します(ターゲット、パラメータ);

念のためお知らせしますが、リフレクションは Java の最も基本的な概念の 1 つです。分からない場合はご自身で調べてください。

簡単に言うと、XXX.class を通じてクラスを取得し、geteDeclaredMethod を通じてそのクラスのメソッドを取得します。

このメソッドは Method オブジェクトであり、Method.invoke を通じてそのクラスのオブジェクトのメソッドを呼び出すことができます。大体そういう意味です。

この種のリフレクション コードを実行すると、JVM は、リフレクションと呼び出しを一定回数実行した後に、いくつかのクラスを動的に生成します。これは、前に見たような不可解なクラスです。

次にリフレクションを実行するときは、これらのクラスのメソッドを直接呼び出します。これは JVM の低レベルの最適化メカニズムです。

これを見て、少し混乱した人もいるのではないでしょうか?

実際のところ、それは問題ではありません。この部分は JVM の最適化にはまったく影響しません。

覚えておかなければならない結論は 1 つだけです。コード内で上記のようなリフレクションを多く使用すると、JVM はいくつかのクラスを動的に生成し、それらを Metaspace 領域に配置します。

したがって、上記の奇妙なクラスは、次の図に示すように、リフレクション コードの継続的な実行によって生成されます。

8. JVM によって作成される奇妙なクラスの背後にある謎は何ですか?

そこで、私たちが非常に興味を持っているのは、なぜ JVM がそれらの奇妙なクラスを作成し続けて Metaspace に配置するのか、ということです。

実際、これはある点からの分析が必要です。なぜなら、上で述べた JVM 自体によって作成された奇妙なクラスでは、その Class オブジェクトが SoftReference、つまりソフト参照だからです。

クラスが何であるか聞いたことがないとは言わないでください。簡単に言えば、各クラスは実際にはオブジェクト自体、つまり Class オブジェクトであり、Class オブジェクトはクラスを表します。同時に、この Class オブジェクトによって表されるクラスは、多くのインスタンス オブジェクトを派生できます。

たとえば、Class Student はクラスであり、それ自体は Class 型のオブジェクトによって表されます。

しかし、Student student = new Student() を実行すると、Student クラスのオブジェクトがインスタンス化され、それが Student 型のインスタンス オブジェクトになります。

したがって、ここで説明する Class オブジェクトは、起動プロセス中に JVM によって動的に生成されるクラスの Class オブジェクトであり、それらはすべて SoftReference ソフト参照です。

いわゆるソフト参照は、別の記事で最初に述べたように、通常の状況ではリサイクルされませんが、メモリが不足している場合は、これらのオブジェクトがリサイクルされます。

では、GC 中に SoftReference オブジェクトをリサイクルする必要があるかどうかを判断するためにどのような式が使用されるのでしょうか?

それは次の式です。

クロック - タイムスタンプ <= 空き領域 * SoftRefLRUPolicyMSPerMB。

この式は、「clock - timestamp」がソフト参照オブジェクトがアクセスされていない時間を表し、freespace が JVM 内の空きメモリ領域を表し、SoftRefLRUPolicyMSPerMB が空きメモリ領域の各 MB で SoftReference オブジェクトが存続できる時間を表すことを意味します。

たとえば、JVM が現在多くの奇妙なクラスを作成し、これらのクラスの Class オブジェクト自体がすべて SoftReference によってソフト参照されているとします。

現在、JVM には 3000 MB のメモリ領域があり、SoftRefLRUPolicyMSPerMB のデフォルト値は 1000 ミリ秒です。つまり、奇妙な SoftReference ソフト参照を持つ Class オブジェクトは、3000 * 1000 = 3000 秒、つまり約 50 分間存続できます。

もちろん、上記は単なる例です。ご存知のとおり、一般的に言えば、GC が発生すると、JVM 内には常にいくらかの空きメモリが存在するため、基本的に、OOM メモリ オーバーフローが発生しない限り、ソフト参照はリサイクルされません。

したがって、論理的に言えば、リフレクション コードが実行されると、JVM はいくつかの奇妙なクラスを動的に作成する必要があることは誰もが知っています。それらのクラス オブジェクトはソフト参照されており、通常の状況ではリサイクルされませんが、急速に増加することもありません。

9. JVM によって作成される奇妙なクラスの数が増え続けるのはなぜですか?

では、なぜ JVM によって作成される奇妙なクラスが増え続けるのでしょうか?

理由は非常に単純で、この記事の冒頭で初心者エンジニアが JVM 起動パラメータ SoftRefLRUPolicyMSPerMB をどこかから見つけ出し、このパラメータを直接 0 に設定してしまったためです。

彼が考えたのは、このパラメータを 0 に設定すると、ソフト参照オブジェクトは保持されることなくできるだけ早く解放され、可能な限り多くのメモリ領域を解放できるというものでした。これにより、メモリの使用効率は向上するのではないでしょうか?

それは本当に愚かで世間知らずだ。

実際、このパラメータを 0 に設定すると、式 clock - timestamp <= freespace * SoftRefLRUPolicyMSPerMB の右半分は 0 になります。つまり、JVM によって生成される奇妙な Class オブジェクトなどのすべてのソフト参照オブジェクトは、作成されるとすぐに Young GC によってリサイクルされる可能性があります。

下の図の通りです。

たとえば、JVM は 100 個の奇妙なクラスを作成しましたが、ソフト参照パラメータを盲目的に設定したため、GC は突然数十個のクラスを再利用します。

その後、リフレクション コードの実行中に、JVM はこのような奇妙なクラスを作成し続けます。 JVM のメカニズムでは、このような奇妙なクラスがますます増えることになります。

次の GC で奇妙なクラスがリサイクルされる可能性もありますが、JVM はそのようなクラスを生成し続けるため、最終的には Metaspace 領域がいっぱいになります。メタスペース領域がいっぱいになると、Full GC がトリガーされ、多くのクラスがリサイクルされ、次の図に示すように、上記のサイクルが繰り返されます。

実際、多くの人が疑問を抱いています。誤ったパラメータ設定によりソフト参照クラスがすぐにリサイクルされた後も、JVM がなぜ新しいクラスを作成し続けるのでしょうか?

実際のところ、ここで詳細に立ち入る必要はありません。基盤となる JDK ソース コード実装は多数あり、非常に複雑です。これらを本当にわかりやすく説明したい場合、JDK の基盤となるソース コードの詳細を説明する記事が複数必要になります。

必要なのは、この結論を覚えて、この原則を理解することだけです。

10. この問題を解決するにはどうすればいいでしょうか?

基盤となる JDK の実装の詳細の一部を分析していませんが、大まかなアイデアは整理されており、問題と原因についても全員が明確に理解しています。

解決策は簡単です。リフレクションコードがたくさんあるシナリオでは、

 -XX:ソフト参照LRUPolicyMSPerMB=0

このパラメータはより大きな値に設定できます。初心者には 0 に設定させないでください。1000、2000、3000、または 5000 ミリ秒に設定できます。

この値を増やすと、リフレクション プロセス中に JVM によって自動的に作成されるソフト参照を持つ一部のクラスの Class オブジェクトが、不用意にリサイクルされなくなります。このパラメータを最適化した後、システムが安定して動作していることがわかりました。

基本的に、Metaspace 領域のメモリ使用量は安定しており、大きく変動することはありません。