OutOfMemoryError: Java heap spaceの対策について

Question

Aapche+Tomcat+PostgreSQLの構成でシステムを運用しておりますが、
レスポンスに時間がかかる検索処理等をを行うと「OutOfMemoryError: Java heap space」が発生します。
その後すぐにサービスは復活するのですが、上記のような検索処理のアクセスが続くとシステムの応答が遅くなり、最終的にはサービスダウンする状況です。

現在、暫定対策として、2週間に1回Aapche、Tomcatの再起動を行いつつ運用しており、今後、発生原因を切り分けつつ、抜本的対策を検討する必要がありますが、JAVAの知識が不足しているため、難航している状況です。

システムログを閲覧することは可能なので、今後抜本的な対策として、どのような視点でログを見るかなどご教示頂けると助かります。

Answer 1

一時的にheapのサイズ増やしてもあまり解決にはならないと思います。
既に検索処理で起きているとわかっているのであれば一回の検索処理で取得するレコード件数を減らすなどの視点で見てみてはどうでしょうか?

Comments

[sho88]

euledge様

早速ありがとうございます。
検索処理で起きているというのは、あくまで推測の話となります。

抜本的な対策を検討するには、何が起きているのかをログから確認することが必須であると思うのですが、
実際にログを見ても何が起きているのかが判らない状態です。
宜しければ、ログを見る際のポイントなどをご教示いただけると幸いです。
どうぞ宜しくお願いいたします．

[euledge]

このページにかなり詳しくまとめられています。

Qiita - OutOfMemoryError の調べ方
https://qiita.com/opengl-8080/items/64152ee9965441f7667b

[sho88]

情報をありがとうございました。
javaのヒープ領域の使用量を調べたいと考えていますが、jstatコマンド以外のコマンドをご教示いただけないでしょうか。(出来ればCUIがいいです。）
(rootユーザで）jstatで実行しようとしましたが、プロセスIDを取得してくれませんでした。回避策はあるようですが、サーバ環境の設定は変えずに取得したいと考えています。

どうぞよろしくお願いいたします。

以下実行環境です。
-----------------------------------------------------------------
java version "1.8.0_45"
-----------------------------------------------------------------

[euledge]

プロセスIDは、 jcmd -l で確認できるのではないでしょうか?
プロセスIDがわかれば、jstat とか jcmdでいろいろ情報取れるかと思います。

[sho88]

情報をありがとうございます。

以下のように、jcmdで取得したPIDに対して、jstatしてみましたが
ダメみたいです。

--------------------------------
#jcmd -l
27660 sun.tools.jcmd.JCmd -l

#jstat -gc 27660
27660 not found
--------------------------------

[euledge]

27660ってjcmd -lのプロセスですよね
jstatのコマンド打つときには終わってますから見つかりませんよ。

何のプロセスに対して調べようと思っているのでしょうか?

[sho88]

説明が不十分ですみません。

#jcmd -l とコマンドを打っても、27660のプロセスしか表示されないようです。

[euledge]

コマンド実行しているPC上で、Apache+Tomcat+Postgresのシステムが動いているんですよね?

[sho88]

おっしゃる通りです。そのPCでApache+Tomcat+Postgresが動いています。
そこで、root権限でコマンドを打っています。

[euledge]

プロセスの実行ユーザーでないとだめらしいです。
ですので sudo tomcat jcmd -l でしょうか?
念のため ps ax でプロセスの実行ユーザー確認してからやるとよいかも

[sho88]

ありがとうございます。
tomcatユーザのみでしか利用できないのですね。

ご教示頂いた方法で実行してみましたが、パスワードを聞かれてダメでした。
sudo設定をしていないためだと思われます。
sudo設定をして、実行したいのですが、お客様の管理サーバなので勝手には変更できない状況です。
もはや、万事休すという状態ですかね。(笑)

[euledge]

rootで入れるのであれば su - tomcat はできませんか?

[sho88]

何度もすみません。
本当にありがとうございます。

以下、実行しましたが以下のエラーになるようです。
# su - tomcat
This account is currently not available.
以下、tomcatのログインが/sbin/nologinになっているためだと思われます。

tomcat:x:***:***::/home/tomcat:/sbin/nologin

[euledge]

あと、別観点で PostgreSQLのSlow logとるとか出来ればSQL関係の問題点はわかるかも
http://hakomori.net/postgresql-slow-log/

[euledge]

su -s /bin/bash tomcat ではどうでしょう？ 若干グレーっぽいですが、
無理やりシェル変えちゃう感じです。

[退会済みユーザー]

su tomcat -c /path/to/jcmd -l
su tomcat -c /path/to/jstat -gc procno

とかでいけるんじゃね

[sho88]

euledge様、asahina1979様

ありがとうございます。
おかげさまでようやく以下、jstatの値が取得でき、OOME対策のスタートラインに立つことが出来ました。
もう少しだけお付き合い頂けないでしょうか。

jstat -gc (PID) 1000 30
S0C S1C 　 S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
116224.0 116224.0 0.0 3156.4 116736.0 11516.7 699392.0 222605.7 61184.0 54774.2 6400.0 5733.5 1189 36.314 172 124.721 161.035

------------------------------
SOC+S1C+EC+OC+MC = 確保済み領域
SOU+S1U+EU+OU = 使用中の領域
------------------------------
上記の情報を参考に、OOMEの検討を進める予定ですが、正直、OOMEの原因と推測される検索実行時にjstatの数値を監視してみたものの、どのように検討をすすめていいかわからない状況です。
大変申し訳ないのですが、検討を進めるうえでのポイントをご教示頂けないでしょうか。
(この数値の状況を見て、JVMの設定変更とか、サーバ物理メモリの増強等の対策、提案を考えています。)

以下に、OOMEが発生する事象とJVM設定値の情報を記載しています。

------------------------------------------------------------------------------------------------
事象：検索処理などをすると、その後何度かGC overhead limit exceededが発生し、その後サービスダウンする。
対処：定期的にapache,tomcatのサービス再起動を実施。
　　　(※ただし、再起動直後でも重い検索処理を実行するとすぐに、GC overhead limit exceededが発生する)

JVM設定値 : -Xmx1024m -Xms1024m -XX:MetaspaceSize=512m -XX:MaxMetaspaceSize=512m
サーバ物理メモリ：32GB
------------------------------------------------------------------------------------------------

何度もすみませんが、どうぞよろしくお願いいたします。

[euledge]

OutOfMemoryError発生時にヒープダンプを取得して、そのヒープダンプをローカルPCに持ってきて発生時に何が多くメモリを使用しているかを解析する感じでしょうか?

[ヒープダンプをEclipse Memory Analyzerで解析しよう！ ]
http://tech.furyu.jp/blog/?p=3554

[sho88]

ありがとうございます。
ダンプを取らないといけないのですね。
因みに、jstatの結果を数秒間隔で監視しながら、原因を探るのは難しいという認識でしょうか。
ご教示頂けるとありがたいです。

[euledge]

ダンプを取らないと分からない事はないと思います。監視しながらその時のcatalina.outから実行している処理見つけるのでも良いと思います。

[sho88]

ご教示いただきありがとうございます。
初歩的な質問となりすみませんが、そもそもOOMEがヒープ領域、ネイティブ領域(Metaspacer領域)どちらで発生しているなどはすぐにわかるのでしょうか。(それを把握するために、ヒープダンプとか、スレッドダンプとかが必要になってくるのでしょうか。）