| Interstage Application Server トラブルシューティング集 |
|
目次
索引
|
| 付録B Javaツール機能 | > B.3 Qualyzer |
ここでは、サンプルプログラム“slow.java”を使用して、Qualyzerの操作手順と解析方法の例を示します。なお、ここで使用している画面や結果、数値データはWindows 2000上で採取したものです。したがって、コマンドオプションの一部や、画面および結果が、利用者のハードウェアおよびOSにより異なることがありますので、あらかじめご了承ください。
サンプルプログラム“slow.java”は、次に示すように、Stringに文字列“Qualyzer”を5000回連結する処理を行うプログラムです。
----------------------------------------------------------------------
class slow{
void main(String[] arg){
String s1 ="";
String s2 = "Qualyzer";
:
for(int i=0; i<5000; i++){
s1 += s2;
}
}
}
----------------------------------------------------------------------
“slow.class”を実行します。
---------------------------------------------------------------------- C:\temp>java slow 10045 ms length = 40000 ----------------------------------------------------------------------
出力結果の1行目の“10045 ms”はStringに文字列“Qualyzer”を5000回連結させるために要した時間です。なお、この値はシステム環境により変動しますのでご注意ください。
Qualyzerを使って各種情報を採取します。
Qualyzerでメモリ/GC情報を収集し、結果を表示します。
---------------------------------------------------------------------- C:\temp>java -Xms64m -Xrunfts:heap=1 slow (*1) 5818 ms length = 40000 C:\temp>java -jar fts.jar heap data=qua.2072 (*2) ----------------------------------------------------------------------
ここでは、以下の情報収集オプションを指定しています。(*1)
また、以下の情報表示オプションを指定しています。(*2)
“slow.class”が出力する実行時間は、Qualyzerの解析時間が含まれるため、情報収集オプションを指定しなかった場合より多くなっています。
heapオプションによりQualyzerのGUIが起動し、[ヒープ使用状況]ウィンドウが現れます。
グラフを見るとGCにより定期的にメモリ回収が行われ、その度に消費メモリ(赤のグラフ)はほぼ一定量まで減少しています。また利用可能メモリ(緑のグラフ)も特に増加はありません。“slow.class”にメモリの問題はないことがわかります。
Qualyzerでサンプリング情報を収集し、結果を表示します。
---------------------------------------------------------------------- C:\temp>java -Xms64m -Xrunfts:sample=10 slow (*1) Not found corresponding thread. 5968 ms length = 40000 C:\temp>java -jar fts.jar sample data=qua.884 (*2) ----------------------------------------------------------------------
ここでは、以下の情報収集オプションを指定しています。(*1)
また、以下の情報表示オプションを指定しています。(*2)
sampleオプションによりQualyzerのGUIが起動し、[メソッド毎サンプリング]ウィンドウが現れます。
上記では、“java.lang.StringBuffer#expandCapacity(int)”のコストが高いことがわかります。このメソッドの行をダブルクリックすると、サンプリングに関するこのメソッドのプロパティが表示されます。
行番号は、このメソッドの実行部が、ソースファイル“StringBuffer.java”の190行から201行にあることを示しています。
QualyzerでCPU情報を収集し、結果を表示します。
---------------------------------------------------------------------- C:\temp>java -Xms64m -Xrunfts:cpu=1 slow (*1) 16189 ms length = 40000 C:\temp>java -jar fts.jar cpu data=qua.2120 (*2) ----------------------------------------------------------------------
ここでは、以下の情報収集オプションを指定しています。(*1)
また、以下の情報表示オプションを指定しています。(*2)
cpuオプションによりQualyzerのGUIが起動し、[メソッド毎CPU消費状況]ウィンドウが現れます。
cpuオプションで最初に表示される[呼出し回数]順のデータでは、以下が多く呼び出されていることがわかります。
java.lang.System#arraycopy(java.lang.Object,int,java.lang.Object,int,int)
しかし、[並び替え条件:]コンボボックスで[メソッド実行時間(ms)]を選択すると、下図のように、以下が上記を上回ってCPU時間を消費していることがわかります。
java.lang.StringBuffer#expandCapacity(int)
Qualyzerでメソッドトレース情報を収集し、結果を表示します。
---------------------------------------------------------------------- C:\temp>java -Xms64m -Xrunfts:trace=5 slow (*1) 16159 ms length = 40000 C:\temp>java -jar fts.jar trace data=qua.1420 (*2) ----------------------------------------------------------------------
ここでは、以下の情報収集オプションを指定しています。(*1)
また、以下の情報表示オプションを指定しています。(*2)
traceオプションによりQualyzerのGUIが起動し、[メソッドトレース]ウィンドウが現れます。
上位3メソッドについて*ボタンをクリックして展開してみます。
上位3メソッドは別々に現れていますが、以下は同じトレース上に現れています。そして、それは現在解析中の“slow.class”のmainから呼ばれていることがわかります。
“slow#main(java.lang.String[])”上でStringBufferを呼び出している個所はないよう見えますが、以下のString結合演算は内部で“java.lang.StringBuffer”が使用されています。
s1 += s2;
そしてメソッド実行時間で最もコストがかかるメソッドは、String結合演算と同等の文字列追加メソッドである“java.lang.StringBufferクラス”のappendメソッドから呼び出されており、appendメソッドは“slow.java”で指定した結合演算回数の2倍以上である10007回呼び出されています。また、コンストラクタStringBuffer()は結合の回数以上である5003回呼び出されています。(結合回数にならないのは結果出力部分でもString結合演算をしているためです。)
Java2 SDKドキュメントのAPI仕様を見てもわかるとおり、コンストラクタStringBuffer()は、初期容量が16文字の文字列バッファを構築します。繰り返されるString結合演算で毎回バッファを構築することは無駄です。
“slow.java”を改良した“fast.java”では、“slow.java”の12行目の以下の部分を書きかえています。
s1 += s2;
上記の代わりに、次に示すように“java.lang.StringBufferクラス”のappendメソッドを直接使用するように改良しています。
----------------------------------------------------------------------
String s1 ="";
String s2 = "Qualyzer";
:
StringBuffer buffer = new StringBuffer( 2048 );
for (int i=0; i<5000; i++) {
buffer.append( s2 );
}
s1 = buffer.toString();
----------------------------------------------------------------------
コンストラクタStringBufferであらかじめ大きめに文字列バッファを確保し、バッファ上で文字列結合を行い、最後にStringに格納する方法をとっています。
実際に動作させて見ると、以下のように、ほとんど時間がかからなくなります。
---------------------------------------------------------------------- C:\temp>java fast 0 ms length = 40000 ----------------------------------------------------------------------
----------------------------------------------------------------------
/*
All Rights Reserved. Copyright Fujitsu Limited, 2002.
*/
class slow {
public static void main ( String args[] ) {
String s1 ="";
String s2 = "Qualyzer";
long time=System.currentTimeMillis();
for (int i=0; i<5000; i++) {
s1 += s2;
}
time=System.currentTimeMillis()-time;
System.out.println( " " + time + " ms");
System.out.println( " length = " + s1.length());
}
}
----------------------------------------------------------------------
----------------------------------------------------------------------
/*
All Rights Reserved. Copyright Fujitsu Limited, 2002.
*/
class fast {
public static void main ( String args[] ) {
String s1 ="";
String s2 = "Qualyzer";
long time=System.currentTimeMillis();
StringBuffer buffer = new StringBuffer( 2048 );
for (int i=0; i<5000; i++) {
buffer.append( s2 );
}
s1 = buffer.toString();
time=System.currentTimeMillis()-time;
System.out.println( " " + time + " ms");
System.out.println( " length = " + s1.length());
}
}
----------------------------------------------------------------------
|
目次
索引
|