負荷テストを行う際に知っておきたいこと

初心者編

まべ☆てっく vol.2

株式会社マーベラス 森 正一 <morim@marv.jp>

1. ストレージのシンプロビジョニングについて

2. ロードバランサの負荷について

3. jmeterのチューニングについて

今日お話しすること

ストレージの シンプロビジョニング

ストレージは最初にまるっと確保しちゃいましょう

結論から言うと

クラウド環境でなければ、あまり関係ない話かも

でも、知っておけばいずれ役立つ (と思いたい)

ちなみに

・物理ストレージを仮想化し、論理ストレージとして管理する手法

・例えばユーザーが100GBのストレージを作成しても、

実際に物理ストレージが100GB確保されるわけではない

- ユーザーからは100GBのストレージとして普通に認識される

・実際に確保された物理ストレージの残容量が少なくなると拡張される

ストレージのシンプロビジョニングとは

・ストレージ作成時に、全ての領域が確保されないということは

- 拡張時にオーバヘッドが生ずる

・ベンチマークによると、極端に遅くはならないようだ

・かなり大きいファイル(数GB～数十GB)をコピーすると、

拡張が繰り返されることがあるようだ

- 拡張された領域に初めて書き込みする際に0埋めされる

(らしい)

シンプロビジョニングの問題

・パブリックのクラウド環境だと、拡張時に遅延が生じたりするかも

- 最悪、ヘルスチェックに失敗して、フェイルオーバーしたり

- 仮想マシンごとにI/Oのパフォーマンスが異なる

→最初から全ての領域を確保しておいた方が無難

シンプロビジョニングの問題

負荷テストの際は、余計な問題は潰しておきましょう

何れにせよ

ex.

dd if=/dev/zero of=warm.`date '+%Y%m%dT%H%M%S'` bs=1M count=10000

bs(1Mbytes)*(count)10,000回 = 10Gbytesのファイルが作成される

まるっと確保する

オプション 内容

if 入力ファイル

of 出力ファイル

bs 1回のread/writeの単位(bytes)

count 要するに回数

・100GBの契約をしているユーザーが100人

→100G*100人=10TBの物理ストレージが必要…

とはならないのでコスト削減になる

・クラウドの場合、ストレージのシンプロビジョニングを採用しているところが多い (らしい)

クラウド業者側には都合が良い仕組み

ルータ(ロードバランサ)の負荷

・クラウドの場合、最初から用意されている

- 各アカウントがVLANで分かれているような構成

・クラウド業者によって仮想ルータだったり物理ルータだったり

ルータ(ロードバランサ)

・VLAN内に仮想ルータ用のマシンが存在

・冗長構成になっている

・中でkeepalivedが動いていたり

仮想ルータの場合

・仮想ルータの負荷が問題になる場合がある

- CPU負荷とか帯域とか

- 過負荷によるフェイルオーバーで通信断が発生したり

- 直接見えないところなので分かりづらい

仮想ルータの問題

・pv4,500～5,000/sec、1リクエスト辺りの処理時間が

60～80msec程度の負荷

- 仮想ルータのCPU過負荷によるフェイルオーバー

- 負荷を受ける側ではなく、負荷をかける側の

アカウントで発生 (両方クラウド環境)

- 小さいパケットを大量に送るとCPU負荷が

上がりやすかったりする

仮想ルータの問題::実例

・負荷をかける側のアカウントを分散

- 2アカウントに分散。1アカウント辺り10～15台。

- 1台辺りjmeterで100スレッド程度

・仮想ルータをスペックアップ

・アプリケーション(PHP)のpersistent接続をoff

仮想ルータの問題::対処

・自動でスケールするような仮想ルータでも、急に負荷が上がった場合は間に合わない場合も

- 商用サービスの場合「間に合わなかった」では済まない

- 事前にスペックを上げておく

仮想ルータの問題::事前の対応

・場合によっては複数のアカウントを使う、専用線を引いてnatでLVSを立てたり…等の対応も必要

- 対応に数営業日かかるので、早めの見極めが大事

・明確なしきい値を用意しておく等

- サービスオープン後だと大変なことに…

仮想ルータの問題::事前の対応

jmeterのチューニング

数秒に渡ってwebサーバへのアクセスが途絶える

発生した事象

Time pv/sec

20:23:18 1189

20:23:19 0

20:23:20 0

20:23:21 0

20:23:22 0

20:23:23 1715

Time pv/sec

20:24:44 1029

20:24:45 0

20:24:46 0

20:24:47 0

20:24:48 0

20:24:49 1202

Time pv/sec

20:24:50 954

20:24:51 0

20:24:52 0

20:24:53 0

20:24:54 0

20:24:55 765

・jmeterでフルガベージコレクションが発生していた

・ログを取った結果

発生した事象

2015年 12月 17日 木曜日 20:23:19 JST

[Full GC (Ergonomics) 1453552K->1318639K(2040320K), 4.6455914 secs]

～ 2015年 12月 17日 木曜日 20:24:44 JST

[Full GC (Ergonomics) 1453399K->1355673K(2040320K), 4.8516675 secs]

～ 2015年 12月 17日 木曜日 20:24:51 JST

[Full GC (Ergonomics) 1449802K->1202556K(2011136K), 4.7977979 secs]

javaのメモリ管理ってどうなってるの

何とかしなければ…

ガベージコレクションのログ出力オプション

jmeterチューニング前準備::ログ出力

Option 説明

-verbose:gc 詳細情報。stdoutに出力

-Xloggc:filename ファイル出力

-XX:+PrintGCDetails Young/Old Generation領域詳細情報を出力

-XX:+PrintGCDateStamps 日付表示

java7のメモリ管理

- 新規に確保したオブジェクトは基本的にEdenに格納される

- ある程度時間が経過するとSurvivor Spaceに移動される

・更に、From/Toを相互に移動する

・メモリのフラグメンテーションを少なくするための仕組み

- ある程度時間が経過すると、Old Generationに移動される

jmeterチューニング前準備::ヒープの仕組み

・上記に加えてPermanent Generationが存在する

- Java8ではMetaspaceに変更されている

- クラスやメソッド等のメタデータ

(java7ではstatic変数等も)が格納される

・Old Generation/Permanent Generation(Metaspace)が不足するとFull GCが行われる。

jmeterチューニング前準備::ヒープの仕組み

Option 説明

-Xmsn ヒープの初期サイズ(bytes)。Young Generation + Old Generation

-Xmxn ヒープの最大サイズ(bytes)。Young Generation + Old Generation

-XX:MaxTenuringThreshold Young GenerationからOld Generationに移動するまでのしきい値(最大値)。GC時にFrom/Toを行き来する回数

jmeterチューニング前準備::ヒープ設定オプション

jmeterチューニング前準備::ヒープの仕組み

パスは環境依存

ex. /usr/local/apache-jmeter-2.13/bin/jmeter

Option 説明

-XX:PermSize=n Permanent領域の初期値(java8ではMetaspaceに変更されている)

-XX:MaxPermSize=n Permanent 領域の最大値(java8ではMetaspaceに変更されている)

-XX:NewRatio Young GenerationとOld Generationの割合

-XX:SurvivorRatio EdenとSurvivor Spacesの割合

実際は他にもいろいろとオプションがあります。

jmeterチューニング前準備::Metadetaについて

Option 説明

MinMetaspaceExpansion Metaspace拡張時の最小値(bytes)

MaxMetaspaceExpansion Metaspace拡張時の最大値(bytes)

MinMetaspaceFreeRatio Metaspaceの容量調整の基準となる%(最小値)

MaxMetaspaceFreeRatio Metaspaceの容量調整の基準となる%(最大値)

MetaspaceSize Metaspace領域に起因するFull GCの基準値(byte)

MaxMetaspaceSize Metaspace領域のサイズ最大値(byte)

jmeterの設定はデフォルトのままシナリオを廻してみる

まずはログを出力

ex. -Xloggc:/tmp/gc.log -XX:+PrintGCDetails

jmeterチューニング::その1

300.625: [GC (Allocation Failure) [PSYoungGen: 167052K->4811K(168448K)] 228720K->68993K(518144K), 0.0072286 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 301.320: [GC (Allocation Failure) [PSYoungGen: 167115K->4860K(168448K)] 231297K->71642K(518144K), 0.0062726 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 301.432: [GC (Metadata GC Threshold) [PSYoungGen: 30915K->1997K(168448K)] 97697K->71411K(518144K), 0.0042318 secs] [Times: user=0.01 sys=0.00, real=0.00 s 301.436: [Full GC (Metadata GC Threshold) [PSYoungGen: 1997K->0K(168448K)] [ParOldGen: 69414K->38678K(349696K)] 71411K->38678K(518144K), [Metaspace: 82360K->21400K(1110016K)], 0.0548297 secs] [Times: user=0.11 sys=0.00, real=0.06 secs] 302.169: [GC (Allocation Failure) [PSYoungGen: 162304K->5229K(167424K)] 200982K->43908K(517120K), 0.0042335 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 302.889: [GC (Allocation Failure) [PSYoungGen: 166509K->4420K(167936K)] 205188K->45720K(517632K), 0.0061693 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 303.635: [GC (Allocation Failure) [PSYoungGen: 165700K->4201K(168448K)] 207000K->48056K(518144K), 0.0062849 secs] [Times: user=0.02 sys=0.00, real=0.01 sec 304.391: [GC (Allocation Failure) [PSYoungGen: 166505K->4644K(168448K)] 210360K->51043K(518144K), 0.0077471 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 305.127: [GC (Allocation Failure) [PSYoungGen: 166948K->4623K(168448K)] 213347K->53656K(518144K), 0.0063692 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 305.804: [GC (Allocation Failure) [PSYoungGen: 166927K->4882K(168448K)] 215960K->56501K(518144K), 0.0064685 secs] [Times: user=0.02 sys=0.00, real=0.01 sec 306.553: [GC (Allocation Failure) [PSYoungGen: 167186K->4742K(168448K)] 218805K->58971K(518144K), 0.0065102 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 307.250: [GC (Allocation Failure) [PSYoungGen: 167046K->4540K(168448K)] 221275K->61398K(518144K), 0.0064846 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 307.992: [GC (Allocation Failure) [PSYoungGen: 166844K->4882K(168448K)] 223702K->64292K(518144K), 0.0064639 secs] [Times: user=0.03 sys=0.00, real=0.00 sec

毎秒以上の間隔で勢いよくGCが発生している

GCに要している時間を確認してみる jstatコマンドを使用 ex. jstat -gccause -h5 -t 9789 1000

jmeterチューニング::その2

Timestamp S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC 300.7 0.00 78.31 17.36 18.35 75.99 87.98 459 3.317 37 2.172 5.490 Allocation Failure No GC 301.7 0.00 0.00 37.52 11.06 33.63 65.81 461 3.328 38 2.227 5.555 Metadata GC Threshold No GC 302.7 85.12 0.00 77.12 11.06 41.39 67.71 462 3.332 38 2.227 5.559 Allocation Failure No GC 303.7 68.38 0.00 13.62 12.54 57.14 71.74 464 3.345 38 2.227 5.572 Allocation Failure No GC 304.7 0.00 75.60 44.51 13.27 64.90 73.76 465 3.352 38 2.227 5.579 Allocation Failure No GC 305.7 75.25 0.00 89.48 14.02 73.10 75.83 466 3.359 38 2.227 5.586 Allocation Failure No GC 306.7 77.20 0.00 33.95 15.51 78.12 79.97 468 3.371 38 2.227 5.599 Allocation Failure No GC 307.7 0.00 73.90 60.39 16.26 77.40 81.93 469 3.378 38 2.227 5.605 Allocation Failure No GC 308.7 79.47 0.00 82.88 16.99 76.98 84.00 470 3.384 38 2.227 5.612 Allocation Failure No GC 309.7 83.74 0.00 25.91 18.48 75.98 88.03 472 3.397 38 2.227 5.624 Allocation Failure No GC

項目 説明

S0, S1 Survivor Spaceの使用率(%)

E Edenの使用率(%)

O Old Generationの使用率(%)

M Metaspaceの使用率(%)

YGC Young GenerationのGC回数

項目 説明

YGCT YGCに要した時間(sec)

FGC Full GC回数

FGCT Full GCに要した時間(sec)

GCT GC総時間(YGCT + FGCT)

・ヒープサイズを増やしてみる

ex. -Xms4096m -Xmx4096m

- ヒープの初期サイズ/最大サイズともに4G

jmeterチューニング::その3

300.470: [GC (Allocation Failure) [PSYoungGen: 1304064K->32019K(1336320K)] 1342797K->70752K(4132864K), 0.0317416 secs] [Times: user=0.11 sys=0.00,

real=0.03 s 303.093: [GC (Metadata GC Threshold) [PSYoungGen: 606193K->14041K(1350656K)] 644926K->66275K(4147200K), 0.0363289 secs] [Times: user=0.12 sys=0.00, real

303.130: [Full GC (Metadata GC Threshold) [PSYoungGen: 14041K->0K(1350656K)] [ParOldGen: 52234K->38488K(2796544K)] 66275K->38488K(4147200K),

[Metaspace: 79290K->21255K(1103872K)], 0.0476072 secs] [Times: user=0.09 sys=0.00, real=0.05 secs] 308.982: [GC (Allocation Failure) [PSYoungGen: 1303040K->31014K(1350144K)] 1341528K->69510K(4146688K), 0.0266850 secs] [Times: user=0.12 sys=0.00, real=0.02 311.482: [GC (Metadata GC Threshold) [PSYoungGen: 614958K->14282K(1351168K)] 653454K->65675K(4147712K), 0.0303426 secs] [Times: user=0.11 sys=0.00, real=0. 311.512: [Full GC (Metadata GC Threshold) [PSYoungGen: 14282K->0K(1351168K)] [ParOldGen: 51392K->38656K(2796544K)] 65675K->38656K(4147712K), [Metaspace: 79286K->21249K(1107968K)], 0.0497781 secs] [Times: user=0.09 sys=0.00, real=0.05 secs]

頻度はだいぶ減った

YGCおよびYGCTは明らかに減った。それにより総GC時間も短くなった。Full GCが若干増えているが…

ログからOld GenerationよりYoung Generationが問題になっていることが窺える

jmeterチューニング::その3

Timestamp S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC 300.1 0.00 0.00 91.30 1.39 37.08 65.67 76 2.115 40 2.302 4.417 Metadata GC Threshold No GC 301.1 0.00 99.27 10.59 1.39 77.45 81.90 77 2.147 40 2.302 4.449 Allocation Failure No GC 302.1 0.00 99.27 27.69 1.39 77.45 81.90 77 2.147 40 2.302 4.449 Allocation Failure No GC 303.1 0.00 99.27 43.43 1.39 77.45 81.90 77 2.147 40 2.302 4.449 Allocation Failure No GC 304.1 0.00 0.00 16.75 1.38 37.08 65.66 78 2.183 41 2.349 4.533 Metadata GC Threshold No GC 305.1 0.00 0.00 33.10 1.38 37.08 65.66 78 2.183 41 2.349 4.533 Metadata GC Threshold No GC 306.1 0.00 0.00 50.44 1.38 37.08 65.66 78 2.183 41 2.349 4.533 Metadata GC Threshold No GC 307.1 0.00 0.00 67.35 1.38 37.08 65.66 78 2.183 41 2.349 4.533 Metadata GC Threshold No GC 308.1 0.00 0.00 84.67 1.38 37.08 65.66 78 2.183 41 2.349 4.533 Metadata GC Threshold No GC 309.1 0.00 65.84 2.75 1.38 77.45 81.85 79 2.210 41 2.349 4.559 Allocation Failure No GC

更に頻度が減った

jmeterチューニング::その4

280.679: [Full GC (Metadata GC Threshold) [PSYoungGen: 40522K->0K(2050560K)] [ParOldGen: 51260K->50886K(2097152K)] 91783K->50886K(4147712K), [Metaspace: 79234K->21477K(1105920K)], 0.0613836 secs] [Times: user=0.15 sys=0.00, real=0.06 secs] 288.897: [GC (Metadata GC Threshold) [PSYoungGen: 1860458K->40765K(2051072K)] 1911345K->91651K(4148224K), 0.0472159 secs] [Times: user=0.14 sys=0.01, real= 288.944: [Full GC (Metadata GC Threshold) [PSYoungGen: 40765K->0K(2051072K)] [ParOldGen: 50886K->51279K(2097152K)] 91651K->51279K(4148224K), [Metaspace: 79277K->21381K(1105920K)], 0.0632846 secs] [Times: user=0.12 sys=0.00, real=0.07 secs] 297.318: [GC (Metadata GC Threshold) [PSYoungGen: 1872530K->40540K(2051072K)] 1923809K->91827K(4148224K), 0.0376583 secs] [Times: user=0.11 sys=0.00, real 297.355: [Full GC (Metadata GC Threshold) [PSYoungGen: 40540K->0K(2051072K)] [ParOldGen: 51287K->51313K(2097152K)] 91827K->51313K(4148224K), [Metaspace: 79305K->21404K(1105920K)], 0.0536986 secs] [Times: user=0.11 sys=0.00, real=0.06 secs] 305.855: [GC (Metadata GC Threshold) [PSYoungGen: 1873542K->40245K(2051072K)] 1924856K->91559K(4148224K), 0.0400885 secs] [Times: user=0.18 sys=0.00, re 305.895: [Full GC (Metadata GC Threshold) [PSYoungGen: 40245K->0K(2051072K)] [ParOldGen: 51313K->50980K(2097152K)] 91559K->50980K(4148224K), [Metaspace: 79236K->21339K(1105920K)], 0.0509746 secs] [Times: user=0.12 sys=0.00, real=0.05 secs]

Young Generation領域を調整してみる

ex. -XX:NewRatio=1 -XX:SurvivorRatio=8

- Young Generation:Old Generation = 1:1

- Eden:Survivor Space = 8:1

YGCは更に減った。総GC時間も短くなった。

jmeterチューニング::その4

Timestamp S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC 300.1 0.00 0.00 30.94 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 301.1 0.00 0.00 41.52 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 302.1 0.00 0.00 52.49 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 303.1 0.00 0.00 63.66 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 304.1 0.00 0.00 75.24 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 305.1 0.00 0.00 85.61 2.45 36.12 65.78 41 1.370 41 2.311 3.681 Metadata GC Threshold No GC 306.1 0.00 0.00 3.33 2.43 36.01 65.67 42 1.410 42 2.362 3.772 Metadata GC Threshold No GC 307.1 0.00 0.00 14.09 2.43 36.01 65.67 42 1.410 42 2.362 3.772 Metadata GC Threshold No GC 308.1 0.00 0.00 25.84 2.43 36.01 65.67 42 1.410 42 2.362 3.772 Metadata GC Threshold No GC 309.1 0.00 0.00 36.42 2.43 36.01 65.67 42 1.410 42 2.362 3.772 Metadata GC Threshold No GC

Metadata領域を調整してみる ex. -XX:MetaspaceSize=3072m -XX:MaxMetaspaceSize=4096m - MetaspaceSize…Metaspace領域に起因する Full GCの基準値(bytes) - MaxMetaspaceSize…Metaspace領域のサイズ最大値

jmeterチューニング::その5

256.643: [GC (Allocation Failure) [PSYoungGen: 2042812K->40697K(2050048K)] 2122592K->123926K(4147200K), 0.0223751 secs] [Times: user=0.08 sys=0.01, real=0.0 266.073: [GC (Allocation Failure) [PSYoungGen: 2043641K->42246K(2050048K)] 2126870K->128055K(4147200K), 0.0213952 secs] [Times: user=0.07 sys=0.00, real=0. 275.462: [GC (Allocation Failure) [PSYoungGen: 2045190K->42083K(2051072K)] 2130999K->130455K(4148224K), 0.0227541 secs] [Times: user=0.07 sys=0.01, real=0.02 284.956: [GC (Allocation Failure) [PSYoungGen: 2046563K->41545K(2050560K)] 2134935K->133136K(4147712K), 0.0217961 secs] [Times: user=0.08 sys=0.01, real=0.02 294.342: [GC (Allocation Failure) [PSYoungGen: 2046025K->41711K(2051584K)] 2137616K->135994K(4148736K), 0.0232748 secs] [Times: user=0.08 sys=0.01, real=0.02 303.911: [GC (Allocation Failure) [PSYoungGen: 2047215K->41708K(2051072K)] 2141498K->138524K(4148224K), 0.0235565 secs] [Times: user=0.04 sys=0.00, real=0.03

若干頻度が減った程度だが…

FGCが激減(1回だけ) 総GC時間も短くなった

jmeterチューニング::その5

Timestamp S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC 300.5 90.52 0.00 64.03 4.50 60.36 83.05 34 1.411 1 0.036 1.447 Allocation Failure No GC 301.5 90.52 0.00 74.92 4.50 60.36 83.05 34 1.411 1 0.036 1.447 Allocation Failure No GC 302.5 90.52 0.00 85.05 4.50 60.36 83.05 34 1.411 1 0.036 1.447 Allocation Failure No GC 303.6 90.52 0.00 96.15 4.50 60.36 83.05 34 1.411 1 0.036 1.447 Allocation Failure No GC 304.6 0.00 91.53 7.94 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC 305.6 0.00 91.53 17.61 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC 306.6 0.00 91.53 27.51 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC 307.6 0.00 91.53 39.25 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC 308.6 0.00 91.53 49.96 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC 309.6 0.00 91.53 60.89 4.62 60.25 83.01 35 1.434 1 0.036 1.470 Allocation Failure No GC

・最初にFull GCが1発かかる (System.gc())

・-XX:MetaspaceSize=3072mにしてもMetaspaceのサイズ自体が変わってないのが確認できる

jmeterチューニング::補足

0.631: [GC (System.gc()) [PSYoungGen: 203448K->9720K(1887744K)] 203448K->9736K(3984896K), 0.0070194 secs] [Times: user=0.02 sys=0.01, real=0.01 secs] 0.638: [Full GC (System.gc()) [PSYoungGen: 9720K->0K(1887744K)] [ParOldGen: 16K->9402K(2097152K)] 9736K->9402K(3984896K), [Metaspace: 9492K->9492K(1058816K)], 0.0309553 secs] [Times: user=0.08 sys=0.00, real=0.03 secs]

jcmdで確認するとMetaspaceのサイズが変わってる

みたい (動的に変化)

- ex. jcmd 8749 PerfCounter.print | grep meta

jmeterチューニング::補足

sun.gc.metaspace.capacity=2364276736 sun.gc.metaspace.maxCapacity=3403677696 sun.gc.metaspace.minCapacity=0 sun.gc.metaspace.used=1416081480

・Full-GCを無くすというよりは、スループットを一定にする方が大事

・ヒープを大きくすれば頻度を下げられるが、GC(Full GC)が発生したときの停止時間も長くなる

・今回のチューニングは一例に過ぎない。ケースバイケース

おわり