JVM・ガベージコレクションに関してまとめてみた

先日、業務でフルGCが発生しアプリケーションが止まってしまうことがありました。
そもそもフルGCとは何か、わからなかったのでそこから調べて、またGCってどれくらいの頻度で発生するのか気になったので、調べて実際にちょこっと触ってみたことを書いています。


## GCとは

簡単にいうと、JVM上に確保されたヒープ領域で、不要になったオブジェクトに紐づいているメモリを開放すること。

たとえば、以下のようなコードがあった場合には、Compnayのオブジェクトが100000個も作成されます。
ほっておくとメモリを圧迫してしまいます。
実際にはこんなコード書かないと思いますが、このように少しのあらゆるコードの箇所で、数多くのオブジェクトが作られメモリに乗っています。

```scala:test.scala

case class Company(name: String)

for(i 0 <- 100000 ) {
  val company = Company(s"企業-${i}")
}

```

## JVMのヒープ領域の詳細


young・oldに大別されます。
youngはさらに、eden survivorという二つの空間に分けられます。

オブジェクトは以下のようなライフサイクルになります。

```bash:オブジェクトライフサイクル

object生成 -> eden -> パンパンになる -> GC（マイナーガベージコレクション） -> 開放 or survivor/oldに昇格 -> パンパンになる -> GC（マイナーガベージコレクション） -> 開放 or oldに昇格 ->　oldパンパン -> GC(フルガベージコレクション)
```

注意点としては、どんなGCのアルゴリズムでも、マイナーGCが走るたびにアプリケーションのスレッドは全て停止されます。
なので、young領域が小さければ小さいほど頻繁にマイナーGCが走ります。(基本的には、頻繁に小さいGCが起きる方が良いらしい。)


フルGCに関しては、GCアルゴリズムによって挙動がだいぶ違ってきます。アプリケーションスレッドを停止するものもあれば、並列でフルGCを走らせるものもあります。

フルGCがやることとしては、old領域から不要なオブジェクトを見つけて、メモリを開放し、ヒープをコンパクト化する（デフラグメンテーションする）なので、長い時間がかかります。
GCのチューニングをする際は、アプリケーションによるがこのフルGCを回避する方法を見つけることが肝になってきます。


## GCアルゴリズム

GCのアルゴリズムは以下の四つが存在します。
それぞれ特徴があるので、特徴をちょろっと書いていきます。

#### シリアル型ガベージコレクター
- ヒープの処理を行うスレッドは一つ
- マイナーGCとフルGCの両方で、実行時にアプリケーションスレッドを停止する必要がある

#### スループット型ガベージコレクタ
- young領域の処理に複数のスレッドを利用するので、マイナーGCは上記のシリアル型よりも非常に高速
- old領域の処理にも複数のスレッドを利用することができる
- マイナーGCとフルGCの両方で、実行時にアプリケーションスレッドを停止する必要がある

#### CMSガベージコレクタ（コンカレント型）
- マイナーGCに関しては、上記の二つの処理と同じ
- フルGCの場合には、アプリケーションスレッドを停止しないように、一つか複数のスレッドをバックグラウンドでold領域のメモリ解放に当てている
- バックグラウンドで動かすことになるので、CPU利用率は上がる
- 処理時にコンパクト化を行わないので、ヒープのフラグメンテーション化が発生する。
- 断片化が進行し、割り当てるメモリが存在しなくなったら、他のGCアルゴリズムと同じようにアプリケーションスレッドを停止し、単一のスレッドを使って、old領域のコンパクト化やクリーンアップを行う。


#### G1ガベージコレクタ（コンカレント型）
- young領域、old領域で、複数のリージョンに分割されている
- マイナーGCに関しては。他のアルゴリズム同様
- フルGCに関しては、コンカレント型なのでバックグラウンドで実行されるので、アプリケーションスレッドを停止する必要がない
- old領域も複数のリージョンに分割されているので、使われているメモリを別のリージョンに移動するという形でコンパクト化を行っている


## 試してみる

ここまでで、GCの基礎をインプットしたので、実際にどんな感じでGCが発生しているのかを試してみました。

sbt(1.3.8) console上で、プログラムを書いてJVMのメトリクスを取得していきます。

#### sbtのJVMのチューニング
sbtを実行する配下に、`.jvmoptions`ファイルを配置しておくと、そのファイルの中身をJVMのパラメータとして読み込まれます。


```shell:.jvmopts
-Xms1024M
-Xmx1024M
-Xss1024M
-XX:MaxMetaspaceSize=1024M
-XX:+UseSerialGC
```

>
-Xms ・・・初期ヒープサイズ
-Xmx ・・・最大ヒープサイズ
-Xss ・・・スレッドスタックサイズ
-XX:MaxMetaspaceSize ・・・パーマネント領域のサイズ
-XX:+UseSerialGC ・・・GCアルゴリズムの指定（サンプルでは、シリアル型ガベージコレクタを指定しています）


では、実際に`.jvmopts`に各項目の設定を行なって、プログラムを実行します。

jvmのオプションは、上記の設定を同じ数値にします。

```shell:sbtプロセス

~/jvm-test $ sbt

```

jpsコマンドで、動いているjavaプロセスを確認できるので、上記で動かしたsbtのプロセスが存在することを確認する。
sbt-launch.jarが実行しているsbtのプロセスです。

```shell:確認プロセス
~/jvm-test$ jps
77057 sbt-launch.jar
56693
77100 Jps
3406 Main

```

上記のプロセスでのGCメトリクスを表示します。
jstatコマンドでの-gcオプションを使うと、該当プロセスでのGCメトリクスを取得できます。
10はメトリクスを取得する間隔です。デフォルトの単位は、msになっています。

```shell-session
~/jvm-test$ jstat -gc 77057 10
```

実際にプログラムを書いて、gcメトリクスを取得していきます。
まず、プログラムを動かす前のGCメトリクスを確認します。

```shell
➜  jvm_test jstat -gc 77057
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
34944.0 34944.0  0.0    0.0   279616.0 232912.0  699072.0   52034.1   59028.0 54605.4 7612.0 7243.9      0    0.000   3      0.157    0.157
```

それぞれの詳しいことは、[ドキュメント](https://docs.oracle.com/javase/jp/6/technotes/tools/share/jstat.html#output_options)に書いています。
今回の分析をしていく中で、重要な物を書いていきます。

> 
S0C・・・Survivor領域0の現在の容量(KB)
S1C・・・Survivor領域1の現在の容量(KB)
S0U・・・Survivor領域0の利用率(KB)
S1U・・・Survivor領域1の利用率(KB)
EC・・・Eden領域の現在の容量（KB）
EU・・・Eden領域の現在の容量（KB）
YGC・・・若い世代のGCイベント数
FGC・・・古い世代のGCイベント数


sbtプロセスを実行した段階では、まだオブジェクトは何も作成していないので、S0U・S1U・YGCは0になっています。
立ち上げた時点で、FGCの値は既に3になっているのですが、なぜかわかりません。。。

またEUの値も0ではなく、プロセスを立ち上げた時点でEden領域のメモリは使われるのでしょうか。

以下のプログラムを動かしていきます。
1Mのオブジェクトをループで作成していきます。

```scala:test.scala
for(i <- 0 to 1000) {
  val builder = new StringBuilder(1000000)
}
```

1秒間隔でメトリクスを取得しています。

```shell-session
~/jvm-test$ jstat -gc 77057 1000
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
34944.0 34944.0  0.0    0.0   279616.0   0.0     699072.0   52811.1   99532.0 86381.2 13556.0 12524.2     72    0.183   4      0.330    0.513
34944.0 34944.0  0.0    0.0   279616.0   0.0     699072.0   52811.1   99532.0 86381.2 13556.0 12524.2    111    0.246   4      0.330    0.575
34944.0 34944.0  0.0    0.0   279616.0 17278.5   699072.0   52811.1   99532.0 86381.2 13556.0 12524.2    151    0.308   4      0.330    0.637
34944.0 34944.0  0.0    0.0   279616.0   0.0     699072.0   52811.1   99532.0 86381.2 13556.0 12524.2    190    0.371   4      0.330    0.701

```

EUとYGCの値が増えていることが確認できます。
上記のプログラムで作成したbuilerオブジェクトがまず、Eden領域に入り、その時点で走ったマイナーGCによって、Survivor領域には昇格せずに開放されているからです。



次に、フルGCの確認をします。
フルGCを起こしやすいように、ヒープのサイズを以下のように小さく設定しておきます。

```shell-session:.jvmopts
-Xms100M
-Xmx100M
-Xss100M
-XX:MaxMetaspaceSize=1024M
```

今回実行するプログラムです。

```scala:test.scala
val builder1 = new StringBuilder(5000000)
```

初めからEden領域の容量を超えるオブジェクトを作成します。
この場合、Eden領域には入らないので、いきなりold領域にオブジェクトが移動することになります。さらに、old領域の空き容量を超えているので、
フルGCを行なってからold領域に割り当てられます。


```shell-session
~/jvm-test$ jstat -gc 87198
S0C    S1C    S0U    S1U      EC       EU        OC         OU       MC     MU    CCSC   CCSU   YGC     YGCT    FGC    FGCT     GCT
11264.0 11264.0  0.0   3961.1 11264.0  10713.2   68608.0    40401.1   95764.0 83780.1 13116.0 12384.1     43    0.114   3      0.166    0.279
10752.0 11264.0 10716.2  0.0   11264.0   274.5    68608.0    41973.0   98580.0 85517.2 13372.0 12405.6     48    0.131   4      0.268    0.399
```

一行目と二行目で、FGCの値が違うのが確認できます。

ここで疑問なのが、YGCの値が43->48・S0Uの値も変化していることです。
つまりマイナーGCが実行され、もともとEdenにあったオブジェクトがSurvivor0領域に移動しています。
Eden領域以上のオブジェクトを割り当てようとすると、まずマイナーGCが走ってそれでもEden領域に入らなければ、old領域に割り当てられるというロジックなのかなと推測しています。


## まとめ

いろんな記事・ドキュメントを読んで、書いているロジック通りにはGCが動いていないように見えるところもありましたが、なんとなくGCに関して理解できました。

次回は、GCアルゴリズムでどのようにGC処理が違うのか、試したいと思います。


## 参考
- https://qiita.com/e_tyubo/items/48398391a8ef0f24c1be
- https://gihyo.jp/dev/serial/01/jvm-arc/0008
- https://docs.oracle.com/javase/jp/8/docs/technotes/guides/troubleshoot/memleaks002.html
- https://blog.wackwack.net/entry/2016/10/30/171752