ページの先頭行へ戻る
Interstage Application Server V12.0.0 チューニングガイド
FUJITSU Software

9.4.3 暖機運転

Javaアプリケーション実行において、動的コンパイルから受ける影響の確認方法、およびその対応方法である暖機運転について説明します。

チューニング方法

9.3 動的コンパイル”で説明したように、Javaアプリケーションの実行は、Java VM起動直後はインタプリタ実行だけで行われ、次第にインタプリタ実行と動的コンパイル結果による機械命令実行との混合動作になります。また動的コンパイルにより翻訳された機械命令の内容も、Javaアプリケーションの実行が進むにつれて、次第にJavaアプリケーションの実行状況に合った翻訳結果に最適化されます。つまりJavaアプリケーションの実行には、以下の動的コンパイルによるオーバーヘッドや最適化状態の推移があるため、Javaアプリケーションとして安定した実行性能になるまで、プロセス起動時からある程度の時間を必要とする場合があります。

なお、Javaアプリケーションとして安定した実行性能になるまでに掛かる時間は、各アプリケーションによって異なります。

動的コンパイル発生状況の調査

Javaアプリケーション実行時における動的コンパイルから受ける影響の有無は、Javaアプリケーションによる業務が開始された際に、動的コンパイルの発生頻度が高いかどうかを判断することで行います。

具体的には、“9.3.3 動的コンパイル発生状況のログ出力機能”を用いてコンパイラスレッドのCPU使用状況や動的コンパイル結果情報を出力し、その結果から以下の傾向が見て取れ、かつJavaアプリケーションとして安定した実行性能になるまでに掛かる時間との関連性が見て取れるかどうかを元に判断します。

注意

Javaアプリケーション起動時や、業務を開始してJavaアプリケーションへの入力が始まる時に、動的コンパイル処理が発生する頻度が高くなる傾向は、Javaアプリケーション実行時の一般的な傾向です。そのため、動的コンパイル発生状況の調査の結果として、「コンパイラスレッドのCPU時間の割合が高い」や「動的コンパイルの発生頻度が高い」などの傾向が見て取れる場合であっても、インタプリタ実行と機械命令による実行がバランス良く行われており、対応が不要な場合が多々あります。

動的コンパイル発生状況の調査は、Javaアプリケーションとして安定した実行性能になるまでに掛かる時間が実運用上の問題となった場合に行ってください。

注意

Javaアプリケーション起動直後の性能に影響を与える処理は、動的コンパイル処理だけではありません。Javaアプリケーション自体の初期化処理や関連するアプリケーションの起動待ちなど、Javaアプリケーションの起動直後でだけ動作する動的コンパイル以外の要因についても考慮する必要があります。

注意

ServletやEJBなどのJavaアプリケーションがInterstage Application Server配下で動作する場合、「Javaアプリケーションの起動(開始)」には以下の2つの意味があります。

  1. Interstage Application Serverの起動(Java EE 6 環境のIJServerクラスタ起動)

  2. 業務アプリケーションの運用開始

動的コンパイル処理が行われる頻度が高まるのは(a)の直後と(b)の直後の両方ですが、業務としての影響を確認することが目的であるため、動的コンパイル発生状況の調査対象は(b)の状況になります。

なお、動的コンパイル結果情報(-XX:+FJPrintCompilationオプション指定時の出力結果)から、(b)の始まりを調べるには、システムログなどから(a)の完了時刻を調べ、その時刻以降に発生した動的コンパイルを対象に調査を行います。

注意

JavaアプリケーションがJSPで作成されている場合、アプリケーションを配備する際にJSPのプリコンパイル(javacコマンドによりJavaソースをクラスファイルへ変換する処理)が実施されていないと、Javaアプリケーション起動時にjavacコマンド実行によるオーバヘッドが発生する場合があります。

JSPのプリコンパイル運用ができる場合は、JSPのプリコンパイルを実施することで、Javaアプリケーションとして安定した実行性能になるまでに掛かる時間が小さくなるかどうかを確認してださい。

暖機運転

Javaアプリケーションを起動した後、業務としての運用を開始する時点で安定した実行性能を得る状態にするためには、暖機運転という運用を行います。
暖機運転とは、Javaアプリケーションを起動した後、実際の業務を開始する前に、業務と同様のダミーデータを用いて疑似実行させることで、事前に主なJavaメソッドを動作させ、クラスファイルのロードやJavaメソッドの動的コンパイルを完了させておくことを言います。

暖機運転により、動的コンパイルなどのオーバーヘッドを減らすことができ、また機械命令への翻訳・最適化処理もその時点で行われるようになるため、業務としての運用開始時点から安定した実行性能を得ることができるようになります。

なお暖機運転をどの程度の期間行ったら良いのかについては、Javaアプリケーションの実行性能が運用要件を満たすところまで安定しているかのかどうかが、判断の基準になります。ただし、Javaアプリケーションを起動してから業務開始までの時間は無限にあるわけではないので、“9.3.3 動的コンパイル発生状況のログ出力機能”の動的コンパイル結果情報の出力結果を参考に、暖気運用に掛ける時間をある程度のところで区切る判断をする必要があります。

注意

通常、Javaアプリケーションの実行には、実行結果の表示、データの更新などの結果を伴います。暖機運転による実行結果が、Javaアプリケーションの運用自体に影響を与えないように注意する必要があります。

例えば、暖機運転用のダミーデータをそのままデータベースに登録してしまい、運用時に誤ったデータを返却するなどの問題が発生しないように注意してください。

注意

Javaアプリケーション自体の初期化処理や関連するアプリケーションの起動待ちなど、動的コンパイル以外の要因でJavaアプリケーションとして安定した実行性能になるまでに時間が掛かっている場合は、暖機運転では対処することができません。

動的コンパイル結果情報(-XX:+FJPrintCompilationオプション指定時)の出力例

0.133: 1 sun.misc.ASCIICaseInsensitiveComparator::compare (143 bytes)
0.137: 2 java.lang.String::charAt (33 bytes)
0.142: 3 java.lang.String::hashCode (64 bytes)
0.204: 4 java.lang.String::equals (88 bytes)
0.210: 5 java.lang.String::indexOf (151 bytes)
0.215: 6 java.lang.AbstractStringBuilder::append (40 bytes)
0.226: 7 java.lang.String::replace (142 bytes)
(中略)
0.444: 30 java.util.jar.Attributes::read (410 bytes)
0.470: 31 java.lang.String::<init> (111 bytes)
0.486: [CompilerThread0: cpu=140.63ms elapsed=367.55ms 1]
0.486: 32 java.util.jar.Attributes$Name::isValid (32 bytes)
0.487: 33 java.util.jar.Attributes$Name::isAlpha (30 bytes)
0.487: 34 sun.nio.cs.ext.MS932$Decoder::decodeSingle (19 bytes)
(中略) Application Server起動時は、頻繁に動的コンパイルが発生
15.449: 796 net.jxta.impl.document.LiteXMLElement::addAttribute (450 bytes)
15.538: 797 java.io.ObjectOutputStream::writeHandle (21 bytes)
15.574: 798 java.util.Hashtable$Enumerator::hasNext (5 bytes)
15.600: 799 com.sun.enterprise.config.ConfigBean::addXPathToChild (27 bytes)
15.606: [CompilerThread0: cpu=250.00ms elapsed=781.02ms 24]
15.630: 800 java.util.regex.Matcher::<init> (84 bytes)
23.535: 801 java.util.Arrays::copyOf (47 bytes)
25.542: 802 java.util.Arrays::copyOf (13 bytes)
25.545: 803 net.jxta.document.MimeMediaType::findNextSeperator (39 bytes)
43.567: 804 net.jxta.impl.document.LiteXMLElement::getTagRanges (1697 bytes)
この時点でInterstage Application Serverとしての起動が完了し、動的コンパイルの発生がいったん減少
(Interstage Application Serverの起動(JavaEE 6 環境のIJServerクラスタ起動)の完了時間は、Interstage Application Serverのログ(サーバ情報のログ) から調べることができます。)
44.212: 805 org.apache.tomcat.util.buf.Ascii::toLower (14 bytes)
44.223: 806 org.apache.tomcat.util.buf.ByteChunk::equalsIgnoreCase (76 bytes)
44.224: 807 sun.nio.cs.ISO_8859_1$Decoder::decodeArrayLoop (263 bytes)
44.240: 18% java.util.Properties$LineReader::readLine @ 21 (452 bytes)
44.258: 808 org.apache.coyote.http11.InternalInputBuffer::parseHeader (585 bytes)
44.265: 809 java.util.Properties$LineReader::readLine (452 bytes)
44.290: 810 java.lang.ThreadLocal$ThreadLocalMap::nextIndex (15 bytes)
44.332: 811 java.util.Hashtable$Enumerator::next (27 bytes)
44.387: 812 java.net.URI::quote (208 bytes)
44.412: 19% sun.nio.cs.ext.DoubleByteEncoder::encodeArrayLoop @ 55 (608 bytes)
(中略) 業務が開始し、再び頻繁に動的コンパイルが発生
158.121: 1128 sun.util.calendar.ZoneInfo::getOffsetsByWall (8 bytes)
160.374: 1129 javax.management.NotificationBroadcasterSupport::sendNotification (118 bytes)
160.698: 1130 java.util.TimeZone$DisplayNames::access$000 (4 bytes)
161.405: 1131 com.sun.jmx.remote.internal.ArrayNotificationBuffer::addNotification (144 bytes)
163.572: 1132 sun.nio.cs.ext.DoubleByteDecoder::decodeLoop (28 bytes)
164.460: 1133 sun.util.calendar.CalendarDate::isDaylightTime (22 bytes)
170.743: 1134 java.util.AbstractCollection::toArray (116 bytes)
業務開始からしばらく経過した時点で、動的コンパイルの発生が減少