社内se × プログラマ × ビッグデータ

プログラミングなどITに興味があります。

pyspark TypeError: namedtuple() missing 3 required keyword-only arguments

$ /usr/local/spark/bin/spark-submit --master local[1] textStream.py
Traceback (most recent call last):
  File "/home/mh/workspace/spark/pyspark-practice/textStream.py", line 1, in <module>
    from pyspark import SparkContext
-------
pyspark TypeError: namedtuple() missing 3 required keyword-only arguments

タイトルのエラーメッセージ、最初の import の部分で躓いていました。

from pyspark import SparkContext

調べてみると、spark 2.1.0 以下のバージョンについては、python 3.6 をサポートしていないらしい。
現在使っている python のバージョンは、3.6.3 で spark のバージョンは 1.6

$ python
Python 3.6.3 |Anaconda, Inc.| (default, Oct 13 2017, 12:02:49) 

とりあえず、既に python 2.7.6 もインストール済みだったので python 側のバージョンを下げてみることに。
.bashrc に以下を適用することで、デフォルトのバージョンが変更が変更される。

# default python
alias python='/usr/bin/python2.7'
$ python
Python 2.7.6 (default, Mar 22 2014, 22:59:56) 

よしこれで大丈夫!再実行!!したが、同じエラー。。。
pyspark で使用する python のバージョンは PYSPARK_PYTHON で定義してあげる必要がありました。

export PYSPARK_PYTHON=/usr/bin/python2.7
$ /usr/local/spark/bin/spark-submit --master local[1] textStream.py

これでエラーは表示されなくなりました。

VirtualBox 仮想ディスクのサイズを変更

VirtualBox で使用している仮想ディスクの使用率が99パーセント近くになってしまったので、ホストOSからのディスクサイズの割り当てを増やすことを決断。
Vagrantを使用しているため、仮想ディスクは VMDK 形式になっています。
ただこの形式は、サイズ変更がサポートされていないため、一旦 VDI 形式に変換してあげる必要がありました。

おおまかな手順

1. VMDK 形式から VDI 形式へ変換
2. ディスク割り当て量を増やす(リサイズ)
3. VDI 形式から VMDK 形式へ変換
4. パーティション変更

1. VMDK 形式から VDI 形式へ変換

既存の仮想ディスクの一覧

$ VBoxManage list hdds
UUID:           8cbbe27d-8feb-4444-88ce-e5df4fe5ac71
Parent UUID:    base
State:          created
Type:           normal (base)
Location:       C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\box-disk1.vmdk
Storage format: VMDK
Capacity:       30720 MBytes
Encryption:     disabled

既存でおよそ30GB割り当てられています。

VDI 形式へ変換(別ファイルで生成)

$ VBoxManage clonehd "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\box-disk1.vmdk" "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi" --format vdi

既存のファイル(VMDK)はそのままで、新しいファイル(VDI)が生成されることになります。
そのため、ディスクの空き容量に注意が必要です!
この処理には1時間以上かかりました。

$ c:\Program Files\Oracle\VirtualBox>VBoxManage clonehd "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\box-disk1.vmdk" "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi" --format vdi
0%...10%...20%...30%...40%...50%...60%...70%...80%...90%...100%
Clone medium created in format 'vdi'. UUID: 1a09f8cf-6eb8-40af-a233-f797810a31f3
$ VBoxManage showhdinfo "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi"
UUID:           1a09f8cf-6eb8-40af-a233-f797810a31f3
Parent UUID:    base
State:          created
Type:           normal (base)
Location:       C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi
Storage format: vdi
Format variant: dynamic default
Capacity:       30720 MBytes
Size on disk:   30249 MBytes
Encryption:     disabled

出来上がりました。

2. ディスク割り当て量を増やす(リサイズ)
$ VBoxManage modifyhd "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi" --resize 61440

約60GBに増やしています。
この処理は一瞬で完了しました。

$ VBoxManage showhdinfo "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi"
UUID:           1a09f8cf-6eb8-40af-a233-f797810a31f3
Parent UUID:    base
State:          created
Type:           normal (base)
Location:       C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi
Storage format: vdi
Format variant: dynamic default
Capacity:       61440 MBytes
Size on disk:   30249 MBytes
Encryption:     disabled

Capacity が増えていますね。

3. VDI 形式から VMDK 形式へ変換
$ VBoxManage clonehd "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\clone-disk1.vdi" "C:\Users\xx\VirtualBox VMs\Ubuntu14.04-2-box\box-disk2.vmdk" --format vmdk
0%...10%...20%...30%...40%...50%...60%...70%...80%...90%...100%
Clone medium created in format 'vmdk'. UUID: f52bff5a-4e35-4148-bfa4-2f3781ffe989

実際に計っていませんが、この処理も時間がかかりました。
これも厳密には変換ではなく、新しい VMDK ファイルが生成されることになります。
よって、元のファイルと合わせると3つの仮想ディスクファイルが保持されることになります。
box-disk1.vmdk (元の VMDK ファイル) 30GB
clone-disk1.vdi (変換用の vdi ファイル) 30GB
box-disk2.vmdk (変換後の新しい VMDK ファイル) 30GB

そのため、ディスクの空き容量に注意が必要です!!
変換後の新しい VMDK ファイル は 60GB になるのでは? と思っていたのですが、30 GB ほどでした。
恐らく実データが入るようになってから、喰われるのではないかと思います。

box-disk1.vmdk と clone-disk1.vdi は作業完了後に削除して良いと思います。

4. パーティション変更

ディスクの割り当て量は増えてバンザイ!だと思ったのですが、df コマンドで確認しても領域は増えていません。。
まだ増やした領域はパーティションとして未割り当て領域になっているため、割り当てる必要がありました。
fdisk よりも、専用のツール GParted とか使った方が簡単で良いかもしれません。

Java ソート条件を動的に指定してみたい

Java8 で書いてます。

静的に指定

// Item("name", "price", "reviewAve", "reviewNum")
Item itemA = new Item("itemA", 1000, 3.3f, 100);
Item itemB = new Item("itemB", 2000, 4.5f, 20);
Item itemC = new Item("itemC", 3000, 4.5f, 10);
		
List<Item> items = Arrays.asList(itemA, itemB, itemC);
		
// static sort condition		
System.out.println("sort by price desc");
items.sort(Comparator.comparing(Item::getPrice).reversed());  // <- こんな感じで指定
items.forEach(item -> System.out.println(item.getName()));

こんな感じで指定すれば、"price" の降順でソートされます。

sort by price desc
itemC
itemB
itemA

もし自分たちが欲しい結果がいつも "price" の降順なのであれば、これで十分かもしれません。
ただ、もし"price" の昇順で結果が欲しい時があれば、このプログラムでは期待する結果を返してくれません。

動的に指定してみたい

設定ファイルやプログラムの引数などから、ソート条件を与えてあげて、それに基づいてソートして欲しい。
ここでは、以下の手順での実現を考えてみます。
1. 想定されるソートの条件を Map に格納(key に条件、value にComparator)おく
2. プログラムの引数でソート条件を与える
3. 与えられたソート条件を基に、Map から Comparator を取得する
4. 取得した Comparator を基に、ソートする

ソート条件を保持するクラスを定義する

public final class SortCondition {
    private final String field;
    private final Direction direction;
	    
    public SortCondition(String field, Direction direction) {
    	this.field = field;
    	this.direction = direction;
    }
	    
    @Override
    public boolean equals(Object obj) {
        if (obj instanceof SortCondition) {
            SortCondition condition = (SortCondition) obj;
            return this.field.equals(condition.field) && this.direction.equals(condition.direction);
        } else {
            return false;
        }
    }

    @Override
    public int hashCode() {
        return Objects.hash(field, direction);
    }
}

昇順か降順か

protected enum Direction {
	ASC,
	DESC
}

想定されるソート条件を Map に格納(定義)

Map<SortCondition, Comparator<Item>> comparatorMap = new HashMap<>();
comparatorMap.put(new SortCondition("price", Direction.ASC), Comparator.comparing(Item::getPrice));
comparatorMap.put(new SortCondition("price", Direction.DESC), Comparator.comparing(Item::getPrice).reversed());
comparatorMap.put(new SortCondition("reviewAve", Direction.ASC), Comparator.comparing(Item::getReviewAve));
comparatorMap.put(new SortCondition("reviewAve", Direction.DESC), Comparator.comparing(Item::getReviewAve).reversed());
comparatorMap.put(new SortCondition("reviewNum", Direction.ASC), Comparator.comparing(Item::getReviewNum));
comparatorMap.put(new SortCondition("reviewNum", Direction.DESC), Comparator.comparing(Item::getReviewNum).reversed());

ソート条件を引数から取得

private List<SortCondition> getSortCondition(String[] args) {
  List<SortCondition> sortConditions = new ArrayList<>();
  for (int i = 0; i < args.length; i++) {
  	String[] condition = args[i].split(":", 0);
       	sortConditions.add(new SortCondition(condition[0], Direction.valueOf(condition[1])));
  }
  return sortConditions;
}

ソート条件から Comparator を構築

private Comparator<Item> comparatorBuilder(List<SortCondition> conditions) {
  Comparator<Item> dynamicComparator = this.comparatorMap.get(conditions.get(0));
  for (int i = 1; i < conditions.size(); i++) {
	dynamicComparator = dynamicComparator.thenComparing(this.comparatorMap.get(conditions.get(i)));
  }
  return dynamicComparator;
}

ソートする

private void sort(List<Item> items) {
  String[] args = {"reviewAve:DESC", "reviewNum:DESC"};
  List<SortCondition> sortConditions = getSortCondition(args);

  Comparator<Item> dynamicComparator = comparatorBuilder(sortConditions);
	
  System.out.println("sort by dynamic condition");
  items.sort(dynamicComparator);
  items.forEach(item -> System.out.println(item.getName()));
}

今回の例では、第1ソート条件を"reviewAve:DESC", 第2ソート条件を"reviewNum:DESC" としました。

sort by dynamic condition
itemB
itemC
itemA

所感

一応、やりたかったことは実現できましたが、欠点はやはり想定されるソート条件を予め Map に格納(定義)しているところで、結局定義しているソート条件以外は指定できない。
それを引数に基づいて呼び出しているに過ぎないところです。
リフレクションとか使えば、もっと柔軟に Comparator を生成することができるのかもしれないですが。

Java 自作クラスを Map のキーにする

Map のキーは、int 型 や String 型で済ませることが多い。
自作クラスを Map のキーにする機会はたぶん今までなかった。
今回たまたま、それをする機会があったのだけど、get する時に果たして Map に格納されているものと等しいキーとして認識してくれるのだろうか?

作成したクラス

オブジェクトのソート条件を保持するクラス。
ソート対象フィールド名と、昇順・降順の何れかを保持する。

public final class SortCondition {
	    private final String field;
	    private final Direction direction;
	    
	    public SortCondition(String field, Direction direction) {
	    	this.field = field;
	    	this.direction = direction;
	    }
}
Map の生成

こんな感じで Map を生成する。

Map<SortCondition, Comparator<Item>> comparatorMap = new HashMap<>();
comparatorMap.put(new SortCondition("reviewAve", Direction.ASC), Comparator.comparing(Item::getReviewAve));
Map から get してみる
SortCondition condition1 = new SortCondition("reviewAve", Direction.ASC);
Comparator<Item> comparator = this.comparatorMap.get(condition1);
System.out.println(comparator);  // <- null

見た目上は、同じキーを生成しているつもりでも、インスタンスが異なるので、値は取得できず comparator は null。

Map に入っているものと一致するキーにするためには?

SortCondition 内で hashCode() と equals() を正しくオーバーライドする必要があります。
SortCondiiton クラスに以下を追記します。

    @Override
    public boolean equals(Object obj) {
        if (obj instanceof SortCondition) {
            SortCondition condition = (SortCondition) obj;
            return this.field.equals(condition.field) && this.direction.equals(condition.direction);
        } else {
            return false;
        }
    }

    @Override
    public int hashCode() {
        return Objects.hash(field, direction);
    }

equals() の結果が true で、hashCode() の結果が両オブジェクトで等しくなるので、この状態であれば一致するキーがあった時、Mapから対応する値が取得されるようになります。

SortCondition condition1 = new SortCondition("reviewAve", Direction.ASC);
Comparator<Item> comparator = this.comparatorMap.get(condition1);
System.out.println(comparator);  // <- 指定したキーで、値(null ではない) が取得できた
所感

必要になるケースは少ないと思いますが、やや複雑な条件における Key に基づく Value を管理したい場合、自作クラスをキーとして扱うことがあるかもしれません。
equals() についてはイメージがつきやすいですが、hashCode() についてもケアしないといけません。
オーバーライドしないと、Object の hashCode がそのまま使われるので、Mapに入っているキーと実際に使おうとしているキーのインスタンスが異なることから、返却されるハッシュ値も異なります。

GCログを取得し、GCViewer で見てみる

0. GCViewer のインストール

// git clone でダウンロード
$ git clone https://github.com/chewiebug/GCViewer.git

// git clone した pom.xml と同じディレクトリで
$ mvn clean install

// target ディレクトリ内にある jar を実行
$ java -jar gcviewer-1.36-SNAPSHOT.jar

起動すると、GCViewer がGUIで起動するので、あとはGCログファイルをドラッグ&ドロップしてあげるだけで、グラフが描画されます。

jstat コマンドで GC の様子を見てみる - 社内se × プログラマ × ビッグデータ
ここで使ったプログラムを VM 引数を変えつつ GC の様子を見てみます。

ケース1. -verbose:gc を指定してみる

VM引数に以下を指定します。

-verbose:gc
-Xloggc:/tmp/gc.log

取得されたログ

Java HotSpot(TM) 64-Bit Server VM (25.144-b01) for linux-amd64 JRE (1.8.0_144-b01), built on Jul 21 2017 21:57:33 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 4048172k(1575784k free), swap 4187132k(4187132k free)
CommandLine flags: -XX:InitialHeapSize=64770752 -XX:MaxHeapSize=1036332032 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
0.456: [GC (Allocation Failure)  15872K->9601K(60928K), 0.0264499 secs]
0.491: [GC (Allocation Failure)  25473K->20215K(76800K), 0.0352044 secs]
0.540: [GC (Allocation Failure)  51959K->44870K(76800K), 0.0568122 secs]
0.597: [Full GC (Ergonomics)  44870K->39980K(123904K), 0.4672640 secs]
1.076: [GC (Allocation Failure)  71724K->71757K(140288K), 0.0869480 secs]
1.163: [Full GC (Ergonomics)  71757K->61041K(185344K), 0.5344934 secs]
1.718: [GC (Allocation Failure)  109169K->109222K(200704K), 0.1078145 secs]
GCViewerで見たグラフ

f:id:blueskyarea:20180615005233p:plain

このオプション(-verbose:gc)では、Young 領域や、Tenured 領域が取得されないため、それぞれの領域内での動作が確認できません。

ケース2. -XX:+PrintGCDetails を指定してみる

VM引数に以下を指定します。GCログ取得オプションを変更しています。

-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-Xloggc:/tmp/gc2.log

取得されたログ

Java HotSpot(TM) 64-Bit Server VM (25.144-b01) for linux-amd64 JRE (1.8.0_144-b01), built on Jul 21 2017 21:57:33 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 4048172k(1446236k free), swap 4187132k(4187132k free)
CommandLine flags: -XX:InitialHeapSize=64770752 -XX:MaxHeapSize=1036332032 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
2018-06-15T00:12:34.369+0900: 0.629: [GC (Allocation Failure) [PSYoungGen: 15872K->2531K(18432K)] 15872K->9585K(60928K), 0.0262355 secs] [Times: user=0.04 sys=0.00, real=0.03 secs] 
2018-06-15T00:12:34.404+0900: 0.665: [GC (Allocation Failure) [PSYoungGen: 18403K->2560K(34304K)] 25457K->22305K(76800K), 0.0415842 secs] [Times: user=0.06 sys=0.01, real=0.04 secs] 
2018-06-15T00:12:34.461+0900: 0.722: [GC (Allocation Failure) [PSYoungGen: 34304K->2560K(34304K)] 54049K->46964K(79360K), 0.0729155 secs] [Times: user=0.09 sys=0.01, real=0.08 secs] 
2018-06-15T00:12:34.534+0900: 0.795: [Full GC (Ergonomics) [PSYoungGen: 2560K->0K(34304K)] [ParOldGen: 44404K->39959K(91648K)] 46964K->39959K(125952K), [Metaspace: 3991K->3991K(1056768K)], 0.7964764 secs] [Times: user=0.67 sys=0.18, real=0.79 secs] 
2018-06-15T00:12:35.351+0900: 1.611: [GC (Allocation Failure) [PSYoungGen: 31744K->2560K(49664K)] 71703K->71735K(141312K), 0.1097980 secs] [Times: user=0.09 sys=0.02, real=0.11 secs] 
2018-06-15T00:12:35.461+0900: 1.721: [Full GC (Ergonomics) [PSYoungGen: 2560K->0K(49664K)] [ParOldGen: 69175K->61019K(137728K)] 71735K->61019K(187392K), [Metaspace: 3991K->3991K(1056768K)], 0.5710107 secs] [Times: user=0.63 sys=0.20, real=0.58 secs] 
2018-06-15T00:12:36.055+0900: 2.315: [GC (Allocation Failure) [PSYoungGen: 47104K->2560K(66048K)] 108123K->108176K(203776K), 0.1056789 secs] [Times: user=0.20 sys=0.01, real=0.10 secs] 
GCViewerで見たグラフ

f:id:blueskyarea:20180615005802p:plain

このオプションでは、より詳しい情報が取得できています。
黄色がYoung 領域で、ピンクがTenured 領域になっています。
サイズが頻繁に変わっていて、不安定な形状になっています。

ケース3. ヒープサイズを増やしてみる

VM引数に以下を指定します。

-Xms2048m
-Xmx2048m
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-Xloggc:/tmp/gc3.log

取得されたログ

Java HotSpot(TM) 64-Bit Server VM (25.144-b01) for linux-amd64 JRE (1.8.0_144-b01), built on Jul 21 2017 21:57:33 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 4048172k(2316068k free), swap 4187132k(4178876k free)
CommandLine flags: -XX:InitialHeapSize=2147483648 -XX:MaxHeapSize=2147483648 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC 
2018-06-15T00:28:39.876+0900: 1.727: [GC (Allocation Failure) [PSYoungGen: 524800K->87011K(611840K)] 524800K->177939K(2010112K), 0.4045245 secs] [Times: user=0.72 sys=0.07, real=0.40 secs] 
2018-06-15T00:28:40.551+0900: 2.403: [GC (Allocation Failure) [PSYoungGen: 611811K->87011K(611840K)] 702739K->720339K(2010112K), 1.4527595 secs] [Times: user=2.70 sys=0.15, real=1.45 secs] 
2018-06-15T00:28:42.598+0900: 4.450: [GC (Allocation Failure) [PSYoungGen: 611811K->11747K(611840K)] 1245139K->645075K(2010112K), 0.0300888 secs] [Times: user=0.06 sys=0.00, real=0.03 secs] 
2018-06-15T00:28:43.006+0900: 4.858: [GC (Allocation Failure) [PSYoungGen: 536547K->87011K(611840K)] 1169875K->1171891K(2010112K), 1.6728124 secs] [Times: user=2.67 sys=0.59, real=1.67 secs] 
2018-06-15T00:28:44.679+0900: 6.531: [Full GC (Ergonomics) [PSYoungGen: 87011K->0K(611840K)] [ParOldGen: 1084880K->471985K(1398272K)] 1171891K->471985K(2010112K), [Metaspace: 3996K->3996K(1056768K)], 5.8750924 secs] [Times: user=8.38 sys=1.97, real=5.88 secs] 
2018-06-15T00:28:50.897+0900: 12.749: [GC (Allocation Failure) [PSYoungGen: 524800K->87012K(611840K)] 996785K->792974K(2010112K), 0.8543719 secs] [Times: user=1.66 sys=0.01, real=0.86 secs] 
2018-06-15T00:28:52.082+0900: 13.933: [GC (Allocation Failure) [PSYoungGen: 611812K->87008K(320000K)] 1317774K->1054921K(1718272K), 0.7219949 secs] [Times: user=1.40 sys=0.01, real=0.73 secs] 
GCViewerで見たグラフ

f:id:blueskyarea:20180615010121p:plain

GCの発生頻度は相変わらず多いものの、ヒープサイズを増やしたため、グラフの形状が安定しているように見えます。
jstat コマンドで数字だけ追っているより、このように見える化されているとやはり分かり易いです。

ヒープサイズを変えつつ jstat コマンドで GC の様子を見てみる

jstat コマンドで GC の様子を見てみる - 社内se × プログラマ × ビッグデータ
ここで使ったプログラムをヒープサイズを変えつつ GC の様子を見てみます。

$ jstat -gcutil -h10 [pid] 1000

ケース1:

-Xms1024m
-Xmx1024m
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
 58.73  89.92  73.82  36.11  81.91  86.90     14    5.780     8   20.965   26.745
  0.00  99.97 100.00  70.45  81.91  86.90     15    6.497     9   20.965   27.462
  0.00  99.97 100.00  70.45  81.91  86.90     15    6.497     9   20.965   27.462
  0.00  99.97 100.00  70.45  81.91  86.90     15    6.497     9   20.965   27.462
  0.00  99.97 100.00  70.45  81.91  86.90     15    6.497     9   20.965   27.462
 55.64   0.00 100.00  66.27  81.91  86.90     16    6.497     9   25.006   31.503
100.00   0.00   0.00  66.35  81.91  86.90     16    6.871    10   25.006   31.877
100.00   0.00   0.00  66.35  81.91  86.90     16    6.871    10   25.006   31.877
100.00   0.00   0.00  66.35  81.91  86.90     16    6.871    10   25.006   31.877
  0.00  95.54   0.00  82.96  81.91  86.90     17    7.212    11   28.388   35.600
  0.00  95.54   0.00  82.96  81.91  86.90     17    7.212    11   28.388   35.600
  0.00  95.54   0.00  82.96  81.91  86.90     17    7.212    11   28.388   35.600
  0.00  95.54   0.00  82.96  81.91  86.90     17    7.212    11   28.388   35.600
  0.00   0.00  17.96  98.82  81.91  86.90     17    7.212    11   32.430   39.642
  0.00   0.00 100.00  98.82  81.91  86.90     17    7.212    12   32.430   39.642
  0.00   0.00 100.00  98.82  81.91  86.90     17    7.212    12   32.430   39.642
  0.00   0.00 100.00  98.82  81.91  86.90     17    7.212    12   32.430   39.642
 66.69  64.55  72.52   7.78  81.93  86.90     19    7.351    13   35.987   43.338

所要時間
BigList 748ms
BigMap 17187ms
Young世代のGCイベントの数 5回
フルGCイベントの数 5回

ケース2:

-Xms1536m
-Xmx1536m
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00   0.00  95.72  65.91  82.30  86.90      5    4.612     4   16.251   20.863
 99.95   0.00 100.00  27.44  82.31  86.90      6    4.612     4   17.433   22.045
 46.32  99.98 100.00  47.65  82.31  86.90      8    5.648     4   17.433   23.082
 99.98   0.00   0.00  61.26  82.31  86.90      8    6.249     5   17.433   23.682
 99.98   0.00   0.00  61.26  82.31  86.90      8    6.249     5   17.433   23.682
 99.98   0.00   0.00  61.26  82.31  86.90      8    6.249     5   17.433   23.682
 99.98   0.00   0.00  61.26  82.31  86.90      8    6.249     5   17.433   23.682
 99.98   0.00   0.00  61.26  82.31  86.90      8    6.249     5   17.433   23.682
  0.00   0.00  87.26  54.26  82.31  86.90      8    6.249     5   22.820   29.068
 97.34  70.05 100.00  54.26  82.31  86.90     10    6.657     5   22.820   29.476
  0.00  77.38   0.00  69.74  82.33  86.90     11    7.703     6   22.820   30.523
  0.00  77.38   0.00  69.74  82.33  86.90     11    7.703     6   22.820   30.523
  0.00  77.38   0.00  69.74  82.33  86.90     11    7.703     6   22.820   30.523

所要時間
BigList 1423ms
BigMap 7962ms
Young世代のGCイベントの数 6回
フルGCイベントの数 2回

ケース3:

-Xms2048m
-Xmx2048m
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  1.77  99.99 100.00  41.90  81.86  86.90     10    5.673     2    7.283   12.955
 18.63  89.52  73.99  60.19  81.86  86.90     12    6.424     2    7.283   13.707
 72.69   0.00   0.00  72.78  81.86  86.90     12    7.221     3    7.283   14.504
 72.69   0.00   0.00  72.78  81.86  86.90     12    7.221     3    7.283   14.504
 72.69   0.00   0.00  72.78  81.86  86.90     12    7.221     3    7.283   14.504
 72.69   0.00   0.00  72.78  81.86  86.90     12    7.221     3    7.283   14.504
  0.00   0.00  42.00  30.51  81.86  86.90     12    7.221     3   11.547   18.768
 30.67  99.99  99.38  45.93  81.86  86.90     14    7.601     3   11.547   19.148
 65.85  70.90 100.00  54.20  81.86  86.90     16    8.423     3   11.547   19.970

所要時間
BigList 782ms
BigMap 6704ms
Young世代のGCイベントの数 6回
フルGCイベントの数 1回

所感

ヒープサイズを変更した場合、
List の生成とデータの取得に関しては、所要時間はほぼ同じ(変化が見られない)だった。
Young世代のGCイベント回数においても同じだった。

Map の生成とデータの取得に関しては、ヒープサイズが大きいほど所要時間に改善(短くなった)が見られた。
フルGCのイベント回数においても改善(より少ない回数)が見られた。

jstat コマンドで GC の様子を見てみる

何も特別なことはしていません。最近あまり使うことがなかったので。

サンプル用プログラム

一応、何らかのJavaプロセスを起動する必要があったので、単に1000万要素のList と Map を延々と作り続けるプログラムを用意。

public class GcTest {

  private static int numberOfData = 10000000;
  private static StopWatch stopWatch = new StopWatch();
  private static Integer counter = 1;

  public static void main(String[] args) {
	while (true) {
		System.out.println("----- attempt:" + counter + " -----");
		GcTest.createBigList();
		GcTest.createBigMap();
		counter++;
	}
  }

  private static void createBigList() {
	System.out.println("BigList");
	stopWatch.start();
	List<Integer> bigList = new ArrayList<>();
		
	// save
	IntStream.rangeClosed(0, numberOfData).forEach(i -> bigList.add(i));
		
	// load
	IntStream.rangeClosed(0, numberOfData).forEach(i -> bigList.get(i));
		
	System.out.println(stopWatch.getTime());
	stopWatch.reset();
  }
	
  private static void createBigMap() {
	System.out.println("BigMap");
	stopWatch.start();
		
	Map<Integer, Integer> bigMap = new HashMap<>();
	// save
	IntStream.rangeClosed(0, numberOfData).forEach(i -> bigMap.put(i, i));
		
	// load
	IntStream.rangeClosed(0, numberOfData).forEach(i -> bigMap.get(i));
		
	System.out.println(stopWatch.getTime());
	stopWatch.reset();
  }
}
jstat コマンド

Java プログラム開始後、プロセスIDを取得し、以下のコマンドを実行。

$ jstat -gcutil -h10 [プロセスID] 1000

gcutil : ガベージ・コレクション統計データのサマリー
h10 : 10行ごとにヘッダー表示
1000 : 1000ミリ秒ごとに更新

出力結果
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
  0.00  73.27   0.00 100.00  81.69  86.79     13    2.434     6    3.997    6.432
  0.00  73.18 100.00  69.69  81.69  86.79     14    2.434     6    7.437    9.871
 77.36   0.00   0.00  85.64  81.69  86.79     14    3.095     7    7.437   10.532
 77.36   0.00   0.00  85.64  81.69  86.79     14    3.095     7    7.437   10.532
 77.36   0.00   0.00  85.64  81.69  86.79     14    3.095     7    7.437   10.532
  0.00  22.87 100.00  73.65  81.69  86.79     15    3.095     7   10.685   13.781
 71.76   0.00   0.00  90.36  81.86  86.90     16    4.060     8   10.685   14.746
 71.76   0.00   0.00  90.36  81.86  86.90     16    4.060     8   10.685   14.746
 71.76   0.00   0.00  90.36  81.86  86.90     16    4.060     8   10.685   14.746
 71.76   0.00   0.00  90.36  81.86  86.90     16    4.060     8   10.685   14.746
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
 71.76   0.00   0.00  90.36  81.86  86.90     16    4.060     8   10.685   14.746
 14.00   0.00 100.00  99.93  81.86  86.90     16    4.060     9   15.546   19.606
 14.00   0.00 100.00  99.93  81.86  86.90     16    4.060     9   15.546   19.606
 14.00   0.00 100.00  99.93  81.86  86.90     16    4.060     9   15.546   19.606
 14.00   0.00  92.92  99.93  81.86  86.90     16    4.060    10   18.503   22.563
 99.12  78.71 100.00  17.41  81.86  86.90     18    4.193    10   19.029   23.222
 99.97   0.00   0.00  69.26  81.86  86.90     20    5.178    11   19.029   24.207
 99.97   0.00   0.00  69.26  81.86  86.90     20    5.178    11   19.029   24.207
  0.00  36.70 100.00  31.31  81.86  86.90     21    5.178    11   21.052   26.230
  0.00  99.97   5.99  64.73  81.86  86.90     23    6.104    11   21.052   27.156

これで1周分(List作成とMap作成をそれぞれ1回ずつ)くらい。
想像していたよりも、GCの回数(フルGC)を含めて多い。
それぞれのオブジェクト(List, Map)を生成するのに要した時間は以下のとおり。
BigList 2510ms
BigMap 16847ms

BigMap 生成に 17秒近く要している。
ただ、フルGCだけでトータル21秒近く要していることから、Map生成処理そのものよりも、フルGCが原因で待たされていた可能性がある。
あとで、ヒープサイズを増やして試してみる。