- PR -

lg4j のローテーション時にアプリが固まる

«前のページへ 1|2
投稿者投稿内容
山本 裕介
ぬし
会議室デビュー日: 2003/05/22
投稿数: 2415
お住まい・勤務地: 恵比寿
投稿日時: 2005-02-23 14:25
再現環境で固まりかけている段階でスレッドダンプを何度か取得してみてはいかがでしょうか？
スタックに出現する箇所の頻度で何に時間がかかっているか確認することができます。
ねま
会議室デビュー日: 2004/11/10
投稿数: 18
投稿日時: 2005-02-24 20:23
Full thread dump Java HotSpot(TM) Client VM (1.4.2_04-b05 mixed mode):

"Thread-4" prio=5 tid=0x00a5c808 nid=0xe80 waiting for monitor entry [5fdf000..5fdfd8c]
at org.apache.log4j.Category.callAppenders(Category.java:185)
- waiting to lock <0x104fe670> (a org.apache.log4j.spi.RootCategory)
at org.apache.log4j.Category.forcedLog(Category.java:372)
at org.apache.log4j.Category.info(Category.java:674)
at jp.co.xxxxx.cmn.Log.info(Unknown Source)
at jp.co.xxxxx.logic.WatchLogic.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)

"main" prio=5 tid=0x000349b0 nid=0xdc0 runnable [7f000..7fc40]
at java.io.WinNTFileSystem.rename(Native Method)
at java.io.File.renameTo(Unknown Source)
at org.apache.log4j.RollingFileAppender.rollOver(RollingFileAppender.java:128)
at org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:228)
at org.apache.log4j.WriterAppender.append(WriterAppender.java:150)
at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:221)

- locked <0x10513108> (a org.apache.log4j.RollingFileAppender)
at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:57)
at org.apache.log4j.Category.callAppenders(Category.java:187)
- locked <0x104fe670> (a org.apache.log4j.spi.RootCategory)
at org.apache.log4j.Category.forcedLog(Category.java:372)
at org.apache.log4j.Category.debug(Category.java:241)
at jp.co.xxxxx.cmn.Log.debug(Unknown Source)
at jp.co.xxxxx.bean.TrafficChartBean.setInSwsec(Unknown Source)
at jp.co.xxxxx.logic.TrafficChartLogic.setChartBean(Unknown Source)
at jp.co.xxxxx.logic.TrafficChartLogic.getTrafficData(Unknown Source)
at jp.co.xxxxx.logic.TrafficChartLogic.access$200(Unknown Source)
at jp.co.xxxxx.logic.TrafficChartLogic$1.run(Unknown Source)
at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:106)
- locked <0x10480128> (a org.eclipse.swt.widgets.RunnableLock)
at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:2749)
at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:2434)
at org.eclipse.jface.window.Window.runEventLoop(Window.java:668)
at org.eclipse.jface.window.Window.open(Window.java:648)
at jp.co.xxxxx.gui.Main.main(Unknown Source)

"VM Thread" prio=5 tid=0x00a336d0 nid=0xb0 runnable

"VM Periodic Task Thread" prio=10 tid=0x00a364e8 nid=0xc60 waiting on condition

"Suspend Checker Thread" prio=10 tid=0x00a545a8 nid=0xe1c runnable
ねま
会議室デビュー日: 2004/11/10
投稿数: 18
投稿日時: 2005-02-24 20:26
お言葉に甘えてスレッドダンプを貼り付けてみました。全部は長すぎるので log4j の部分のみ
抜粋しました。

アプリが固まるとき、タスクマネージャで見てみると、
java.exe と exploer.exe がそれぞれ 40数％ずつ使っていました。

スレッドダンプの読み方がよくわからないので、解析はこれからです。
山本 裕介
ぬし
会議室デビュー日: 2003/05/22
投稿数: 2415
お住まい・勤務地: 恵比寿
投稿日時: 2005-02-25 02:11
debug() の延長線上で rename メソッドが呼ばれていますね。
固まっているときに何回かスレッドダンプをとって同じあたりの処理が繰り返し現れるようでしたら、やはりリネーム（周辺の処理）に時間がかかっていることになります。
解析が面倒でしたら侍なんかをつかうといくらか楽です。
・侍
http://yusuke.homeip.net/samurai/
«前のページへ 1|2

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