Java™ 7でのガーベジコレクションの選択

Java 7のガーベジコレクションの入り口

Java 7のガーベジコレクションの仕様や実装を調べるなら、次の2つが入り口となるでしょう。

• Java Garbage Collection Basics (日本語訳なし)
• Getting Started with the G1 Garbage Collector (拙者の日本語訳)

Java 7でガーベジコレクションを選択する方法(6種類)

Java 7ではエルゴノミクス機能により、自動的にガーベジコレクション(GC)を決定します。
エルゴノミクス機能による決定を無効にして自分でGCを選択したい場合、次の6種類のオプションの指定方法があります。

• -XX:+UseSerialGC
• -XX:+UseParallelGC
• -XX:+UseParallelGC -XX:+UseParallelOldGC
• -XX:+UseConcMarkSweepGC
• -XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode
• -XX:+UseG1GC

-XX:+UseSerialGC

New世代領域、Old世代領域ともに、GCを単一スレッドで実行。

-XX:+UseParallelGC

New世代領域では、GCを複数スレッドで実行。

Old世代領域が不足したら、Full GCを単一スレッドで実行。

-XX:+UseParallelGC -XX:+UseParallelOldGC

New世代領域では、GCを複数スレッドで実行。

Old世代領域が不足したら、Full GCを複数スレッドで実行。

-XX:+UseConcMarkSweepGC

New世代領域は-XX:+UseParallelGCと同様の処理。

Old世代領域でCMS GCを実行。

CMS GCは、アプリケーションスレッドと並列してGCを実行することにより、Stop the worldを減らすのが狙い。

CMS GCはコンパクションを行わないので、CMS GCでもメモリが不足する場合は、フォールバックとしてFull GCを実行。

-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode

-XX:+UseConcMarkSweepGCをインクリメンタル・モードで実行。

インクリメンタルモードの詳細は未調査だが、Old世代領域のGCを少しずつ実行するイメージ）

Oracleのドキュメントでは「i-cms」で説明されています。

-XX:+UseG1GC

Java 7新機能のG1 GCを実行。

Javaヒープを細かく細分化し、New世代領域やOld世代領域などを割り当てる方式。

詳細は、上の「Getting Started with the G1 Garbage Collector」を参照。

なお、Full GCはMark Sweep and Compaction方式です。
また「-Xincgc」は上の5つめの「-XX:+UseConcMarkSweepGC -XX:+CMSIncrementalMode」と同じになります。
なおCMS GCは「Concurrent Mark Sweep [Garbage] Collectorの略称で、CMS GCの説明は「Java SE 6 HotSpot™ Virtual Machine Garbage Collection Tuning」にあります。

Java 7でのSystem.gc()の実行について

十分プログラムを追えていませんが、

1. \jdk\src\share\classes\java\lang\Runtime.java
2. \jdk\src\share\native\java\lang\Runtime.c
3. hotspot\src\share\vm\prims\jvm.cpp
4. hotspot\src\share\vm\memory\universe.cpp

と追っていくと、

• GenCollectedHeap::collect(GCCause::Cause cause)と
• G1CollectedHeap::collect(GCCause::Cause cause)

に辿り着きます。
条件によっては、FullGCを実行するように見えます。「条件によっては」と書いたのですが、基本的にFull GCになると期待しています。
「Java™ Platform, Standard Edition 7 API Specification」のRuntime.gc()のところに

Runs the garbage collector. Calling this method suggests that the Java virtual machine expend effort toward recycling unused objects in order to make the memory they currently occupy available for quick reuse. When control returns from the method call, the virtual machine has made its best effort to recycle all discarded objects.

ガベージコレクタを実行します。このメソッドを呼び出すと、Java 仮想マシンは使用していないオブジェクトをリサイクルし、使用中のメモリーをすばやく再利用可能な状態にします。メソッド呼び出しから制御が戻された時点で、仮想マシンは破棄されたオブジェクトをすべて再利用するよう最善を尽くしたことになります。

とあります。Full GCを実行することが明記されていないし、コンパクションを行うかも判りませんが、「-verbose:gc」でログを取るなどしてウラを取ってみたいと考えています。

文字列操作の速度を測ってみた(やっつけ3)

文字列操作の速度を測ってみた(やっつけ2)について、もう少し突っ込んで調べました。

今度は、Java VMオプションを「-server -XX:+PrintCompilation」にして、Java 1.4.2、5.0、6、7のそれぞれで実行してみました。すると、Java 5.0と6との間で出力内容に大きな変化が見られました。

Java SE 5.0の場合

  1       java.io.Win32FileSystem::normalize (143 bytes)
  2  !    java.net.URLEncoder::encode (378 bytes)
  3       java.lang.Character::isLetter (158 bytes)
  4       sun.nio.cs.UTF_8$Encoder::encodeArrayLoop (490 bytes)
  5       java.nio.Buffer:: (68 bytes)
  6  !    java.nio.charset.CharsetEncoder::encode (285 bytes)
  7*      java.lang.System::arraycopy (0 bytes)
  8       java.nio.Buffer::position (43 bytes)
  9       java.nio.Buffer::limit (62 bytes)
 10  !    java.lang.StringCoding::encode (127 bytes)
 11       sun.nio.cs.UTF_8$Encoder::encodeLoop (28 bytes)
 12  !    java.io.CharArrayWriter::toCharArray (37 bytes)
 13       java.lang.AbstractStringBuilder::expandCapacity (51 bytes)
 14 s     java.lang.StringBuffer::toString (17 bytes)
 15       java.lang.AbstractStringBuilder:: (12 bytes)
 16       java.nio.charset.Charset::forName (20 bytes)
 17       java.io.CharArrayWriter:: (7 bytes)
  1%      b.A::measure @ 14 (47 bytes)
 18       b.A::measure (47 bytes)       //この行以降が2回目のmeasureメソッド呼出し後
  2%      b.A::measure @ 14 (47 bytes)

Java SE 6の場合

    195   1       java.lang.String::charAt (33 bytes)
    196   2       java.lang.AbstractStringBuilder::append (40 bytes)
    229   3 s     java.lang.StringBuffer::append (8 bytes)
    231   4       java.lang.CharacterDataLatin1::getProperties (11 bytes)
    232   5  !    java.net.URLEncoder::encode (375 bytes)
    234   6       java.lang.Character::forDigit (42 bytes)
    234   7       java.lang.Character::isLetter (5 bytes)
    235   8       java.lang.Character::isLetter (158 bytes)
    236   9       java.lang.CharacterDataLatin1::isLetter (20 bytes)
    237  10       java.lang.CharacterDataLatin1::getType (10 bytes)
    237  11       java.util.BitSet::wordIndex (5 bytes)
    237  12       java.util.BitSet::checkInvariants (111 bytes)
    238  13       java.util.BitSet::get (69 bytes)
    245  14       java.lang.Object:: (1 bytes)
    250  15       sun.nio.cs.UTF_8$Encoder::encodeArrayLoop (490 bytes)
    261  16       java.lang.Math::min (11 bytes)
    267  17       java.nio.Buffer::position (43 bytes)
    267  18       java.nio.charset.CoderResult::isUnderflow (13 bytes)
---   n   java.lang.System::arraycopy (static)
    287  19       java.nio.Buffer::limit (62 bytes)
    287  20       java.nio.Buffer:: (68 bytes)
    306  21       java.lang.String::equals (88 bytes)
    326  22       java.nio.Buffer::hasRemaining (17 bytes)
    326  23       java.nio.ByteBuffer:: (45 bytes)
    326  24  !    java.nio.Bits::byteOrder (119 bytes)
    326  25       java.nio.CharBuffer::hasArray (20 bytes)
    327  26       java.nio.ByteBuffer::hasArray (20 bytes)
    327  27       java.nio.charset.CoderResult::isOverflow (14 bytes)
    327  28       java.nio.CharBuffer:: (22 bytes)
    327  29  !    java.nio.ByteBuffer::wrap (20 bytes)
    328  30       java.nio.HeapByteBuffer:: (14 bytes)
    329  31  !    java.nio.CharBuffer::wrap (20 bytes)
    329  32       java.nio.HeapCharBuffer:: (14 bytes)
    330  33       java.lang.StringCoding::access$000 (6 bytes)
    330  34       java.lang.StringCoding::scale (7 bytes)
    331  35       java.nio.charset.Charset::atBugLevel (53 bytes)
    331  36       java.nio.ByteBuffer::wrap (8 bytes)
    332  37       java.nio.charset.CharsetEncoder:: (16 bytes)
    332  38       java.nio.charset.CharsetEncoder:: (113 bytes)
    334  39       java.nio.charset.CharsetEncoder::replaceWith (81 bytes)
    334  40       java.nio.charset.CharsetEncoder::onMalformedInput (26 bytes)
    335  41       java.nio.charset.CharsetEncoder::onUnmappableCharacter (26 bytes)
    335  42       java.util.Arrays::copyOf (19 bytes)
    335  43       java.lang.StringCoding$StringEncoder:: (7 bytes)
    336  44       java.lang.StringCoding$StringEncoder:: (35 bytes)
    338  45  !    java.lang.StringCoding$StringEncoder::encode (130 bytes)
    339  46       java.nio.charset.CharsetEncoder::maxBytesPerChar (5 bytes)
    339  47       java.nio.charset.CharsetEncoder::reset (11 bytes)
    339  48  !    java.nio.charset.CharsetEncoder::encode (285 bytes)
    345  49       java.nio.charset.CharsetEncoder::flush (49 bytes)
    345  50       java.nio.charset.CharsetEncoder::implFlush (4 bytes)
    345  51       java.lang.StringCoding::access$300 (7 bytes)
    347  52       java.lang.StringCoding::safeTrim (30 bytes)
    349  53       sun.nio.cs.UTF_8::newEncoder (10 bytes)
    350  54       sun.nio.cs.UTF_8$Encoder:: (6 bytes)
    351  55       sun.nio.cs.UTF_8$Encoder:: (10 bytes)
    352  56       sun.nio.cs.UTF_8$Encoder::isLegalReplacement (26 bytes)
    352  57       sun.nio.cs.UTF_8$Encoder::encodeLoop (28 bytes)
    462  58       java.util.Arrays::copyOfRange (63 bytes)
    463  59       java.nio.charset.Charset::lookup (44 bytes)
    465  60       java.nio.charset.Charset::forName (20 bytes)
    520   1%      b.A::measure @ 14 (47 bytes)
   7009   1%     made not entrant  b.A::measure @ -2 (47 bytes)
   7010  48  !   made not entrant  java.nio.charset.CharsetEncoder::encode (285 bytes)
   7010  61       b.A::measure (47 bytes)       //この行以降が2回目のmeasureメソッド呼出し後
   7014   2%      b.A::measure @ 14 (47 bytes)

java.nioパッケージのAPIに対するJITコンパイルが増えています。
このことから次のような推測が導かれます。

1. （Java VM自体の性能改善よりもむしろ）java.nioパッケージを使うように改善したことによる性能差 or / and
2. java.nioパッケージ自体の改善による性能差

これ以上の調査は辛いので、今回はここまで。

文字列操作の速度を測ってみた(やっつけ2)

Java1.4.2～Java7.0で文字列操作の速度を測ってみた(やっつけ)を見て気になったので、こちらでも少し測定してみました。

元の記事のものに少しだけ手を加えたプログラムを用意しました。

package b;

import java.net.URLDecoder;

public class A {
 private static final String URL = "http://www.google.co.jp/?q=URLEncoder%E3%81%AF%E3%81%A9%E3%82%8C%E3%81%8F%E3%82%89%E3%81%84%E9%81%85%E3%81%84%E3%81%AE%E3%81%8B%E3%80%81commons-codec%E3%81%A8%E6%AF%94%E8%BC%83%E3%81%97%E3%81%A6%E3%81%BF%E3%81%BE%E3%81%99";
 private static final int TIMES = 1000000;

 public static void main(String[] args) throws Throwable {
  measure();
  measure();
 }

 public static void measure() throws Throwable {
  final String input = URLDecoder.decode(URL, "UTF-8");

  final long startTime = System.currentTimeMillis();
  for (int i=0; i<TIMES; i++) {
   java.net.URLEncoder.encode(input, "UTF8");

  }
  final long endTime = System.currentTimeMillis();

  System.out.println(endTime - startTime);
 }
}

次のようなバッチファイルで測定しました。

SET MYOPTS=-Xint -client
D:\jdk4\bin\java -cp bin %MYOPTS% b.A
D:\jdk5\bin\java -cp bin %MYOPTS% b.A
D:\jdk6\bin\java -cp bin %MYOPTS% b.A
D:\jdk7\bin\java -cp bin %MYOPTS% b.A

SET MYOPTS=-Xint -server
D:\jdk4\bin\java -cp bin %MYOPTS% b.A
D:\jdk5\bin\java -cp bin %MYOPTS% b.A
D:\jdk6\bin\java -cp bin %MYOPTS% b.A
D:\jdk7\bin\java -cp bin %MYOPTS% b.A

SET MYOPTS=-client
D:\jdk4\bin\java -cp bin %MYOPTS% b.A
D:\jdk5\bin\java -cp bin %MYOPTS% b.A
D:\jdk6\bin\java -cp bin %MYOPTS% b.A
D:\jdk7\bin\java -cp bin %MYOPTS% b.A

SET MYOPTS=-server
D:\jdk4\bin\java -cp bin %MYOPTS% b.A
D:\jdk5\bin\java -cp bin %MYOPTS% b.A
D:\jdk6\bin\java -cp bin %MYOPTS% b.A
D:\jdk7\bin\java -cp bin %MYOPTS% b.A

測定結果を次に示します(2回目の測定値のみ)。

Java SE	JITなし		JITあり
	Hotspot ClientVM	Hotspot ServerVM	Hotspot ClientVM	Hotspot ServerVM
1.4.2	106967	114095	15716	12396
5.0	134080	140290	15898	11667
6	134502	129110	6987	4280
7	125772	112755	6013	3483

Java SE 5.0とJava SE 6のJIT (Just In Time)コンパイラの性能差が目立ちます。
また反復処理が多い場合は、Java Hotspot ServerVMの方が良さそうですね。

Java排他処理のボトルネックの発見方法

“Javaメソッドトレース”を自作すれば、処理時間が長いメソッドを絞り込むことができることを紹介しました。
今回は排他処理によるボトルネックを解析する方法を紹介します。

複数スレッドで同時に処理を行うとデータが壊れてしまうような場合に排他制御を行います。Javaでは排他制御をsynchronized節を用いて簡単に実現することができるため、マルチスレッドプログラミングが比較的簡単にできるわけですね。

しかし外注先で、64個のコア(CPU)を搭載したマシンを使って、64個のスレッドをフルに動かして大量処理を行うJavaアプリケーションの性能測定を行った結果、思うように性能が上がらず、CPUの使用率も60%程度に留まることが判り、問題視された経験があります。

“-verbose:gc”オプションを付けてもFullGCが走った形跡がなく、何が原因で性能低下が発生したのかを誰も実証することができませんでした。Javaメソッドトレースではメソッドの実行時間を測定することができても、CPU使用率の低下を実証することはできません。外注先はとうとう原因を究明することができず、私にヘルプを求めてきました。

私も少し苦しみましたが、“JDK 5.0 Documentation”と睨めっこしていたら、java.lang.managementにThreadMXBeanとThreadInfoがあり、スレッドの状態、スレッドのブロック時間、ロックのモニタ、そして、スタックトレースなどを取得することができそうではありませんか！早速、プロファイリングを行うツールを自作しました。

性能測定の対象となるJavaアプリケーションを“-Dcom.sun.management.jmxremote”などのオプションを付けてJMXエージェントを有効にさせれば、別マシンからプロファイリングを行うことができます。自作プロファイリングツールでは、ThreadMXBean.getAllThreadIds()で全スレッドのIDを取得し、ThreadMXBean.getThreadInfo(long)でThreadInfoオブジェクトを取得し、ログ出力を行うといった処理を、長時間、何回も繰り返して行いました。ThreadInfo#getThreadState()がThread.State.BLOCKEDを返す場合は、スタックトレースも採取しました。つまりBLOCKED状態となった箇所の統計を取ることにより、排他制御が発生しやすい箇所が判るわけです。

次に、排他制御が発生しやすい処理をスキップする（処理しない）ようにJavaアプリケーションを仮修正して、再度、性能測定を行ったところ、なんとCPU使用率が約60%→約95%に向上し、もちろん処理性能も著しく向上しました。

Java SE 5.0で追加されたJMX機能およびjava.lang.managementパッケージにあるMXBeanを使ってプロファイリングを行うのは、非常に有効な手段です。MXBeanを使ってアプリケーションのメモリ消費量を監視するツールも自作しましたが、これまた有効でした。ちなみにJDK 6以降では“-Dcom.sun.management.jmxremote”オプションを付けなくてもtools.jarにあるAPIを使って、プロファイリングツールから特定のJava VMにアタッチしてJMX通信を行うことができます。

またテスト用MBeanを自作して、外部ツールからそのMBeanと通信してJavaアプリケーションのテストを行うことも容易にできるようになります。アイデア次第ではJavaアプリケーションの可能性が広がりそうです。ぜひJMX、MBeanおよび、MXBeanに関心を持っていただきたいと思います。

Javaメソッドトレース

“ソフトウェアの二大ボトルネック ”で2種類のボトルネックがあることを述べました。

Javaアプリケーションについて前者のボトルネックを見つける1つの手法として、“メソッドトレース”があります。具体的には、メソッドの入口と出口に次のようなログ出力のコードを埋め込み、ログからメソッドの実行時間を知るという手法です。(ちなみに精密な性能測定を行う場合は、System.currentTimeMillis()よりもSystem.nanoTime()がお勧め)

System.out.println("a: start: "+System.nanoTime());

小さなアプリケーションならメソッドが少なく、上記コードをゴリゴリ手書きすればよいです。しかし巨大なアプリケーションになると手書きする箇所が膨大になり、現実的ではありません。

そのようなときには、Spring FrameworkなどにあるAOP(Aspect Oriented Programming)機能が役に立ちそうです。AOPを使ってバイトコードにログ出力のコードを埋め込ませ、メソッドトレースを実現するというものです。
 
しかし私はSpring Frameworkをまだ試したことがありません。が、次を使用してメソッドトレースを実現しました。

1. Java SE 5.0で追加されたjava.lang.instrumentパッケージ
2. Javassist

java.lang.instrumentパッケージは、平たく言うと次を提供してくれています。

• アプリケーションのmainメソッドを呼ぶ前に、エージェントのpremainメソッドを呼ぶ仕組み
• アプリケーションの実行に必要なクラスをJava VMが定義する前にクラスファイルを変換する機会

ClassFileTransformerの実装クラスを作って、premainメソッドを持つエージェントでInstrumentation#addTransformer()を使ってClassFileTransformerの実装クラスを登録するだけでよいのです。ところがクラスファイルを変換するAPIはJava SEには含まれていないのです。

そこで必要となるのが、バイトコードを変換するAPIであるjavassistです。バイトコードを変換するAPIとして、他にBCELもありますが、私はjavassistを選択しました。ClassFileTransformerの実装クラスからjavaassistを使ってバイトコードを変換し、ログを出力するコードを埋め込ませるだけです。具体的な作り方は記載しませんが、意外と簡単そうでしょう？

私はこうしてメソッドトレース機能を作り、さらに別途、メソッドトレース機能が出力するログを解析するプログラムも作って、処理時間が長いメソッドを特定できるようになり、巨大なJavaアプリケーションのボトルネック箇所をいくつか見つけることができました。

市販のプロファイラツールは高価だし、自分の思うようなデータを出力してくれない可能性もありますから、メソッドトレース機能を2、3日間で自作したのですが、このメソッドトレース機能は意外と応用範囲が広かったのです。ボトルネック箇所の特定だけでなく、メソッドの呼び出しシーケンス分析や、メソッド実行網羅率の採取などにも活用することができ、非常に便利なツールになっています。

ソフトウェアの二大ボトルネック

ソフトウェアのボトルネックを調べる目的で、性能測定を行うことがありますが、ボトルネックには、大きく2種類があると考えています。

• 不適切な処理ロジックによるボトルネック
• 排他処理によるボトルネック

前者は、一般的に言われているような、狭い意味でのデータ構造やアルゴリズムの問題や、単純に不適切な順次処理をコーディングをした場合のボトルネックです。このケースでは、ボトルネック箇所が判明されば、比較的、修正が簡単です。

後者は、マルチスレッドで動作するソフトウェアにおいて、ハードウェアまたはソフトウェアによる排他処理の影響で、処理待ちが発生し、CPUパワーを十分に活用できないケースです。“アムダールの法則の紹介”に記載したアムダールの法則を使って、排他率（並列処理ができない部分の割合）を求めればよいかと思います。算出した排他率を見てソフトウェアの修正が必要かどうかを判断します。

どちらのボトルネックにしても、ボトルネック箇所を正確に見極めるのが難しい場合が多いですね。経験豊かな開発者なら経験に裏付けられたカンでボトルネック箇所をある程度絞れますが、どの箇所でどのくらいの性能劣化が起きているのかを知りたいこともあります。

Javaアプリケーションでボトルネック箇所を特定する市販製品が結構出回っていますが、Java SE 5.0以降なら市販製品を使わずにボトルネック箇所を特定するツールを比較的簡単に自作できます。後日、簡単にご紹介したいと思います。