##はじめに
「NonStopServer」(NSS)というHPE社のサーバの保守開発をしている@kmttmkです。
先日NSSに関する研修「Performance Analysis and Tuning」を受講してきました。
NSS上のパフォーマンスデータの収集・解析・改善方法等に関する研修です。
学んだことを実践してみたので、備忘録がてらまとめてみます。
最終日に超ニッチなテーマで、すみません！
ちょちょっと開発機ツールのファイル設計を手直ししてみたら結構性能改善できたって話なので、
● システムのインフラな部分にはあまり普段絡みがない
● 代々受け継がれた開発機のツールの仕様に実はめっちゃ文句ある
って感じの方には多少は興味を持ってもらえるかと思います。
##NonStopServer？
簡単にご紹介まで。
1974年以来HPE社(当時はTandem Computers)にて販売されている無停止コンピュータのシリーズです。
（正式名称は「HPE Integrity NonStop」ですが、大抵NonStopサーバって呼んでます。)
特徴としては以下のような感じです。
とりあえず24時間365日止まらないシステムを構築できます。
・CPUやプロセス、またDISK装置等のハードウェアからハードウェアとのI/Oアダプタに到るまで、
全てが2重以上に冗長化されている。
・フェイルファストにより各コンポーネントの故障の兆候を検知したら即システムから切り離し。
かつ各コンポーネントはオンラインに影響なく修繕可能。
##実践編
今回のテーマです。研修で得た知識を使ってみます。
###テーマと前提
NSS開発環境上で稼働する、とある検証用PGの性能改善にトライします。
この検証用PGとはインプットとなるファイルをCSV形式に整形してくれるものです。
NSSにはCPUやDISKのパフォーマンスデータを収集してくれるサブシステムとして「MEASURE」というものがあります。
下記のようにパフォーマンスデータを項目別に整理して出力してくれます。
しかし、一方でEXCEL等で解析用に整理しようとすると整形されているが故にかなり厄介。
------------ Processor -----------------------------------------------------
Cpu-Busy-Time 5.12 sec Dispatches 338,323 #
Ready-Time 17.03 sec Comp-Traps 1 #
Launch-Wait-Time Launches
Vsems Ipu-Switches 1 #
Ipu-Num 1 # Ipu-Num-Prev 0 #
Initial-Priority-Start Initial-Priority-End 190 #
Current-Priority-Start Current-Priority-End 190 #
そこで、これらのデータを以下のように「,（カンマ）」区切りでCSV化してくれる検証用のPGがあるのですが、このPGの処理がとにかく遅いのです。
,,,Cpu-Busy-Time,5.12,Dispatches,338.323,Ready-Time,17.03,Comp-Traps,1,,,,
,,,Cpu-Busy-Time,3.88,Dispatches,6.245,Ready-Time,1.10,Comp-Traps,1,,,,,,,
そこでこのPGの処理速度改善にトライします。
開発環境
OS：NB65000c J06.17.01(6Cpu/2Core)
PG：COBOL85
###改善前の性能
まず改善前の処理性能を確認します。
上記の通りパフォーマンスデータの収集には「MEASURE」を使用します。
（性能改善の対象と測定手段がともにMEASUREで分かりにくくすみません、、、）
「整形PG」と「CSVファイル」に関するパフォーマンスデータを確認してみます。
== 整形PGのデータ（抜粋）
Local System \NODE1 From 17 Dec 2019, 7:37:29 For 32.5 Minutes
------------ Processor -----------------------------------------------------
Cpu-Busy-Time 5.12 sec Dispatches 338,323 #
Ready-Time 17.03 sec Comp-Traps 1 #
Launch-Wait-Time Launches
Vsems Ipu-Switches 1 #
Ipu-Num 1 # Ipu-Num-Prev 0 #
Initial-Priority-Start Initial-Priority-End 190 #
Current-Priority-Start Current-Priority-End 190 #
== CSVファイルのデータ（抜粋）
------------ Requests ------------------------------------------------------
Lockwait-Time Requests 135,070 #
Max-Lockwait-Time Requests-Blocked
Lock-Timeouts Lock-Bounces
------------ Logical I/O ---------------------------------------------------
Cache-Hits 402,047 # Cache-Write-Hits 68,035 #
Block-Splits 67,564 # Cache-Write-Cleans 474,712 #
Driver-Input-Calls 402,047 # Driver-Output-Calls 542,747 #
DBIO-Input-Calls DBIO-Output-Calls
整形PGのデータからはCPUの使用時間(Cpu-Busy-Time)などが、CSVファイルのデータからは読み取り時のキャッシュヒット数(Cache-Hits)などが分かります。
そして処理速度は整形PGのデータの一番最初の行の通り、「32.5分」かかっていることが分かります。
※今回の実践ではCSVファイルはキー順ファイルで135000件書き込まれる。
各項目の詳細はマニュアルの通りなので、参照頂ければと思います。
###改善① DISK I/O回数を減らす
「ライトスルー・ライトバック方式」ってやつです。
CPUメモリへのI/Oに比べ、物理DISK I/Oの方が断然処理時間が長いです。
そのためCSVファイルに書き出す時、1レコードごと物理DISKへI/Oする方式はなるべく避けたいです。
ところがNSS上でファイルを作成すると、I/O時のデフォルト設定は「ライトスルー方式」(毎回物理DISKへI/O)とのこと。(例外があるため注意1)
「ライトバック方式」にするためにはNSS上のファイル属性「BUFFERED」を対象ファイルへ付与すれば良いとのことなので、早速CSVファイルに設定します。
TACL> == 変更前のCSVファイルの設定
TACL> FUP INFO $DATA01.MEASURE.OUTFILE, DETAIL
$DATA01.MEASURE.OUTFILE 17 Dec 2019, 8:20
ENSCRIBE
TYPE K
FORMAT 2
EXT ( 150000 PAGES, 150000 PAGES )
REC 1676
BLOCK 4096
KEYLEN 11
KEYOFF 0
MAXEXTENTS 40
OWNER 10,1
SECURITY (RWEP): GOGO
DATA MODIF: 17 Dec 2019, 8:10
CREATION DATE: 17 Dec 2019, 7:34
LAST OPEN: 17 Dec 2019, 7:37
FILE LABEL: 352 (8.6% USED)
EOF: 278822912 (2.3% USED)
EXTENTS ALLOCATED: 1
INDEX LEVELS: 3
TACL>
TACL>
TACL> == BUFFEREDを付与する
TACL> FUP $DATA01.MEASURE.OUTFILE, BUFFERED
TACL>
TACL>
TACL> == 変更後のCSVファイルの設定
TACL> FUP INFO $DATA01.MEASURE.OUTFILE,DETAIL
$DATA01.MEASURE.OUTFILE 17 Dec 2019, 8:20
ENSCRIBE
TYPE K
FORMAT 2
EXT ( 150000 PAGES, 150000 PAGES )
REC 1676
BLOCK 4096
KEYLEN 11
KEYOFF 0
MAXEXTENTS 40
BUFFERED
OWNER 10,1
SECURITY (RWEP): GOGO
DATA MODIF: 17 Dec 2019, 8:10
CREATION DATE: 17 Dec 2019, 7:34
LAST OPEN: 17 Dec 2019, 7:37
FILE LABEL: 352 (8.6% USED)
EOF: 278822912 (2.3% USED)
EXTENTS ALLOCATED: 1
INDEX LEVELS: 3
TACL>
変更後のファイル属性に「BUFFERED」が追加されたことが確認できます。
これでDISK I/O回数は減らせたはず。
早速またMEASUREで整形PGの処理性能を確認してみます。
###改善①後の性能
== 整形PGのデータ（抜粋）
Local System \NODE1 From 17 Dec 2019, 8:22:16 For 26.9 Minutes
------------ Processor -----------------------------------------------------
Cpu-Busy-Time 4.98 sec Dispatches 433,433 #
Ready-Time 15.42 sec Comp-Traps 1 #
Launch-Wait-Time Launches
Vsems Ipu-Switches
Ipu-Num 1 #
Initial-Priority-Start Initial-Priority-End 190 #
Current-Priority-Start Current-Priority-End 190 #
== CSVファイルのデータ（抜粋）
------------ Requests ------------------------------------------------------
Lockwait-Time Requests 135,069 #
Max-Lockwait-Time Requests-Blocked
Lock-Timeouts Lock-Bounces
------------ Logical I/O ---------------------------------------------------
Cache-Hits 402,047 # Cache-Write-Hits 133,710 #
Block-Splits 67,564 # Cache-Write-Cleans 409,037 #
Driver-Input-Calls 402,047 # Driver-Output-Calls 542,749 #
DBIO-Input-Calls DBIO-Output-Calls
------------ SQL -----------------------------------------------------------
処理時間が32.5分から26.9分に改善されました。
CSVファイルのデータの「Cache-Write-Hits(WRITE時のキャッシュヒット数)」も改善前の「68,035回」から「133,710回」に増加し、物理I/Oが減っていることが確認できます。
ただし、キャッシュに長く置く分データロストの可能性も高まるので扱いには注意が必要とのこと。
検証用ならまだしも、本番用ログファイル等では基本NGな構成っぽいです。。
###改善② ファイルを分割する
続いて「パーティションファイル」という構成を使用し、CSVファイルを作ってみます。
これは論理的(整形PGから見ると)には1ファイルですが、実際は複数の物理DISKから構成されるというファイルです。
性能的にも機能的にも様々なメリットがあるそうです。
● ファイルサイズがディスク容量に左右されない
● 異なるディスクにあるレコードに並行して同時アクセスできる
● 増やしたディスク分だけ使えるキャッシュが増える
● 他諸々、、、
物は試しで早速パーティションファイルを作ってみます。
TACL> FUP
- SET TYPE K
- SET FORMAT 2
- SET EXT ( 2 PAGES, 2 PAGES )
- SET REC 1676
- SET BLOCK 4096
- SET KEYLEN 9
- SET KEYOFF 2
- SET PART ( 1, $DATA02, 150000 PAGES, 150000 PAGES, "00" )
- SET PART ( 2, $DATA03, 150000 PAGES, 150000 PAGES, "10" )
- SET PART ( 3, $DATA04, 150000 PAGES, 150000 PAGES, "20" )
- SET PART ( 4, $DATA05, 150000 PAGES, 150000 PAGES, "30" )
- SET PART ( 5, $DATA06, 150000 PAGES, 150000 PAGES, "40" )
- SET PART ( 6, $DATA07, 150000 PAGES, 150000 PAGES, "50" )
- SET PART ( 7, $DATA08, 150000 PAGES, 150000 PAGES, "60" )
- SET PART ( 8, $DATA09, 150000 PAGES, 150000 PAGES, "70" )
- SET PART ( 9, $DATA10, 150000 PAGES, 150000 PAGES, "80" )
- SET PART ( 10, $DATA11, 150000 PAGES, 150000 PAGES, "90" )
- SET MAXEXTENTS 40
- SET BUFFERED
- CREATE $DATA01.MEASURE.OUTFILE2
- EXIT
TACL>
\$DATA02〜$DATA11までの合計10DISKにまたがるファイルを作成しました。
CSVファイルをこのファイルに変更し、さっそく効果を試してみます。
###改善②後の性能
== 整形PGのデータ（抜粋）
Local System \NODE1 From 17 Dec 2019, 8:53:01 For 17.2 Minutes
------------ Processor -----------------------------------------------------
Cpu-Busy-Time 4.96 sec Dispatches 203,842 #
Ready-Time 14.07 sec Comp-Traps 1 #
Launch-Wait-Time Launches
Vsems Ipu-Switches 2 #
Ipu-Num 0 # Ipu-Num-Prev 1 #
Initial-Priority-Start Initial-Priority-End 190 #
Current-Priority-Start Current-Priority-End 190 #
== CSVファイルのデータ（抜粋）
------------ Requests ------------------------------------------------------
Lockwait-Time Requests 135,109 #
Max-Lockwait-Time Requests-Blocked
Lock-Timeouts Lock-Bounces
------------ Logical I/O ---------------------------------------------------
Cache-Hits 335,225 # Cache-Write-Hits 132,596 #
Block-Splits 67,555 # Cache-Write-Cleans 403,915 #
Driver-Input-Calls 335,225 # Driver-Output-Calls 536,516 #
DBIO-Input-Calls DBIO-Output-Calls
------------ SQL -----------------------------------------------------------
処理時間が26.9分からさらに17.2分に改善されました。
最初と比較するとほぼ半減です。
「Driver-Input-Calls(ディスクの読み込み命令)」が目立って減っているので、ディスクを分割したことによりインデックスの高さが浅くなったことが功を奏したのかと思われます。2
ただこれも使用ディスクが増える分、当然ディスク故障等のリスク範囲も拡大します。
NSSであればディスクも多重化されていますから気にする程でもないかもしれませんが、、
不要なパーティション分割は避けたほうが良いかもしれません。
##まとめ
色々やってみた感想としてはあっさりしてますが、下記な感じです。
1. 最近流行りの「効率化」・「生産性向上」。
歴史あるシステムでもまだまだきっかけはあるんだなと。視点を変えることが重要でした。
2. メリ"デメ"をしっかり意識。
今回で言えば早くなる分ロストのリスク増。
ベンダと会話していると良い部分しか出てこないですから、デメの意識はより重要そうです。
今回はただひたすらに実践に終始しました。
そのため各データの推移分析も不十分ですし、取得対象データにも不足があります。
（NSSにはPEEK/DSAP/SCF等他にもキャッシュ統計等抽出できるツールはあるので。）
データの解析、改善ポイントの発見は引き続き取り組み、そのうちまたまとめるかもです。