- PR -

FullGCが頻発しCPU100%

1|2|3 次のページへ»
投稿者投稿内容
さと丸
会議室デビュー日: 2006/01/24
投稿数: 19
投稿日時: 2006-01-24 19:31
WEBシステム構築を行ったところ、アクセスが集中する15:30-17:00の間でサーバが
CPU100％になり、その後ユーザからのシステムへのアクセスが不能になります。

※CPU100%を確認するためTOP･PSコマンド等で確認してもCPUを掴んでいるプロセスは
発見できず

そのため、毎日WEB・APサーバの再起動にて状況を
なんとかしのいでいます。
（CPUはTOMCATのプロセスを切ると開放されます。）

また、GCの設定ができていないと認識し、設定を行ったのですが、
以下にも示すように、15:00まではうまく動いているGCが
FullGCを乱発させ（一秒間に2回など永遠に）、やがてサーバがCPU100％になって
しまいます。

現在GCは以下の設定で動かしています。
export CATALINA_OPTS="-server -Xmx256M -Xms256M -XX:NewSize=128M
-XX:MaxNewSize=128M -XX:SurvivorRatio=2 -Xloggc:/home/share/gc_ac.log"

FullGCがこのような動作するという事象がNET上探せなかったのもので
教えていただきたいと思います。
簡単なことかもしれませんが、よろしくお願いいたします。


★環境：
OS Fedora Core 3(32bit)
DB MySQL4.0.13
Java jdk 1.5.0
Web Apache 2.0.52
WebAP Tomcat 5.5.4
jakarta-tomcat-connectors-jk2-src-current
jakarta-structs-1.1
その他 jakarta-log4j-1.2.8
mysql-connector-java-3.0.8-stable
CPU Pentium4 2.80GHz
メモリ 1256M

★GCログ
31403.088: [GC 87161K->23950K(229376K), 0.0152160 secs]
31587.858: [GC 89486K->25189K(229376K), 0.0177720 secs]
31885.422: [GC 90720K->27297K(229376K), 0.0256670 secs]
32202.980: [GC 92833K->28908K(229376K), 0.0296310 secs]
32383.421: [GC 94444K->30720K(229376K), 0.0368400 secs]
32644.006: [GC 96256K->32399K(229376K), 0.0405570 secs]
32852.018: [GC 97935K->33527K(229376K), 0.0425860 secs]
33229.271: [GC 99063K->35937K(229376K), 0.0525010 secs]
33343.808: [Full GC 62858K->23994K(229376K), 0.5220820 secs]
33626.070: [GC 89530K->26122K(229376K), 0.0146250 secs]
33914.616: [GC 91658K->28040K(229376K), 0.0206330 secs]
34049.749: [GC 93547K->29620K(229376K), 0.0283350 secs]
34154.396: [GC 95156K->30963K(229376K), 0.0342670 secs]
34278.328: [GC 96499K->31885K(229376K), 0.0322320 secs]
34557.721: [GC 97421K->34051K(229376K), 0.0427140 secs]
34753.425: [GC 99587K->34565K(229376K), 0.0406540 secs]
34929.401: [GC 100101K->36077K(229376K), 0.0477600 secs]
35004.317: [Full GC 58456K->27072K(229376K), 0.5735400 secs]
35292.678: [GC 92608K->29186K(229376K), 0.0165650 secs]
35470.029: [GC 94722K->30546K(229376K), 0.0187230 secs]
35710.544: [GC 96082K->32310K(229376K), 0.0257770 secs]
35947.509: [GC 97846K->33667K(229376K), 0.0294300 secs]
36114.289: [GC 99203K->35092K(229376K), 0.0322990 secs]
36197.479: [GC 100628K->36678K(229376K), 0.0445980 secs]
36423.640: [GC 102214K->37586K(229376K), 0.0408630 secs]
36530.981: [Full GC 72136K->22398K(229376K), 0.7143570 secs]
36912.102: [GC 87934K->25283K(229376K), 0.0191790 secs]
37183.630: [GC 90819K->26981K(229376K), 0.0220280 secs]
37503.020: [GC 92517K->29178K(229376K), 0.0298010 secs]
37955.416: [GC 94714K->31800K(229376K), 0.0359020 secs]
37994.026: [Full GC 44941K->23858K(229376K), 0.5635840 secs]
37994.670: [Full GC 23858K->23858K(229376K), 0.6371330 secs]
37995.334: [Full GC 24321K->23915K(229376K), 0.4776510 secs]
37995.822: [Full GC 24381K->22164K(229376K), 0.6458460 secs]
38119.559: [Full GC 62553K->23217K(229376K), 0.5110510 secs]
38120.072: [Full GC 23217K->23217K(229376K), 0.5480870 secs]
38122.109: [Full GC 23631K->23308K(229376K), 0.4920180 secs]
38122.681: [Full GC 23308K->22258K(229376K), 0.5319660 secs]
38159.288: [Full GC 37677K->22882K(229376K), 0.4941680 secs]
38159.784: [Full GC 22882K->22882K(229376K), 0.5407490 secs]
38160.332: [Full GC 22962K->22883K(229376K), 0.4761570 secs]
38160.888: [Full GC 22883K->22161K(229376K), 0.5251770 secs]
38170.127: [Full GC 28827K->22445K(229376K), 0.4944970 secs]
38170.624: [Full GC 22448K->22445K(229376K), 0.5416030 secs]
38171.177: [Full GC 22677K->22518K(229376K), 0.4962860 secs]
38171.752: [Full GC 22518K->22326K(229376K), 0.5108140 secs]
38172.298: [Full GC 23159K->22438K(229376K), 0.4802610 secs]
38172.781: [Full GC 22559K->22438K(229376K), 0.5430430 secs]

_________________
かつのり
ぬし
会議室デビュー日: 2004/03/18
投稿数: 2015
お住まい・勤務地: 札幌
投稿日時: 2006-01-24 19:50
参考になるでしょうか。

http://www.atmarkit.co.jp/fjava/rensai3/devedge03/devedge03_1.html
さと丸
会議室デビュー日: 2006/01/24
投稿数: 19
投稿日時: 2006-01-24 20:16
かつのりさん
早急な返答大変ありがとうございます。

一応ここのURLを参考に設定値を
考えたんですが、
やはりGCのオーバーフローがおこっているという
解釈が正しいのですよね。。。。

もう一度このページを読み返してみたいと思います。
_________________
takashi
会議室デビュー日: 2003/01/27
投稿数: 7
投稿日時: 2006-01-24 22:45
Permanent領域の設定もしてみてはいかがでしょうか。
こちらが参考になると思います。
http://www.atmarkit.co.jp/fjava/rensai3/devedge06/devedge06_2.html
K
大ベテラン
会議室デビュー日: 2004/04/07
投稿数: 174
投稿日時: 2006-01-25 01:45
一番手っ取り早いのはヒープの割り当て自体（Xmxの値）をもっと増やすことでしょう。
あとは該当プログラムをプロファイラーを使って見てみるとよいかもしれません。


[ メッセージ編集済み 編集者: moge 編集日時 2006-01-25 01:58 ]
さと丸
会議室デビュー日: 2006/01/24
投稿数: 19
投稿日時: 2006-01-25 09:04
色々なアドバイス本当にありがとうございます。
ためになります。

export CATALINA_OPTS="-server -Xmx512M -Xms256M -Xss256K -Xloggc:/home/share/gc_ac.log"

↑以前この設定で運用した際も
同じ状況（FullGCの乱発）になってしまい

ヒープ領域の最大値上げるだけではだめかとおもい
現在の設定にしております。

Permanent領域に関しては存在は分かっておりましたが、
まったく調査はしておりません
これから調査してみたいと思います。

アドバイス
よろしくお願いいたいます。
_________________
K
大ベテラン
会議室デビュー日: 2004/04/07
投稿数: 174
投稿日時: 2006-01-25 14:19
ヒープサイズを上げてもだめだったのですね。
であるとすればやはりソースコードを精査してメモリへの負荷を下げる対策を行なったほうがよいと思います。

原因さえ掴めればちょっとした修正（たとえばループの中でオブジェクトをnewしているのを止めてループの外側に出すとか）で改善される可能性も高いと思います。
山本 裕介
ぬし
会議室デビュー日: 2003/05/22
投稿数: 2415
お住まい・勤務地: 恵比寿
投稿日時: 2006-01-25 14:31
ヒープサイズにかなり余裕がある状態でFull GC が発生していますね。
Full GC が発生しているということは Old 領域か Permanent 領域が一杯になっているのだと思います。
JDK1.5.0であればPermanent領域はそう気軽に一杯になることはありませんので Old 領域を疑った方がよいかもしれません。
Old 領域を多めに設定するのはいかがでしょう？

あとは JVM を変えてみるとか？
JRockit を使うと JRokcit Runtime Analyzer というツールで動作中のシステムに負荷をかけずにプロファイリングすることができます。

http://www.beasys.co.jp/e-docs/wljrockit/docs50/
・JRockit Runtime Analyzer ユーザーズ ガイド
http://www.beasys.co.jp/e-docs/wljrockit/docs50/usingJRA/index.html
http://commerce.bea.com/products/weblogicjrockit/accept_terms50.jsp
1|2|3 次のページへ»

スキルアップ／キャリアアップ（JOB@IT）