第７章 モニタリング

第７章 モニタリング
本書に含まれている情報は、正式なIBMのテストを受けていません。また、明記にしろ、暗黙的にしろ、なんらの保証もなしに配布されるものです。
この情報の使用またはこれらの技術の実施は、いずれも、使用先の責任において行われるべきものであり、それらを評価し、実際に使用する環境に統合する
使用先の判断に依存しています。それぞれの項目は、ある特定の状態において正確であることがIBMによって調べられていますが、他のところで同じまたは同
様の結果が得られる保証はありません。これらの技術を自身の環境に適用することを試みる使用先は、自己の責任において行う必要があります。
© Copyright IBM Japan Co., Ltd. 2011
内容
• トラブルを未然に防ぐための第一歩
• DB2の出力するログ
• 診断ログ
• 管理通知ログ
• DB2が提供するモニタリングツール
• Optim Performance Manager (OPM)
• db2top
• Snapshot Monitor
• db2pd
• モニター表関数
• イベント・モニター
• その他
• 定常監視
• 問題判別実践編
• OPMを利用したデータベースの問題判別
2
© 2011 IBM Corporation
トラブルを未然に防ぐための第一歩
• まず第一歩として
• 日々の運用の中でDB2の活動状況を記録する、監視する
• 問題を見つけたら原因を推測する
• 必要であればさらに詳細な情報を得るためのモニタリングの実施
• 解決プランを立てる
• 構成パラメーターの変更
• アプリケーションの処理の変更
• データベースの物理設計の変更
など
• テスト環境などでの確認
• 理論的に出した結論がふさ
わしいかどうかの判断
• スケジュールを考える
• 現行値でいつまで使い続けられる
かという予測を行う
• 本番環境への適用
3
© 2011 IBM Corporation
DB2の出力するログ
• DIAGPATH（DBM構成パラメーター）以下に出力される
• 診断ログ・ファイル
• 管理通知ログ・ファイル
主に確認するログ
• ダンプ・ファイル
• トラップ・ファイル
• アラート・ログ・ファイル
• First Occurrence Data Collection (FODC) パッケージに含まれて
いる DB2診断情報
4
© 2011 IBM Corporation
診断ログ（db2diag.log）
• DB2のエラー情報を出力するログファイル
• デフォルトでは「$HOME/sqllib/db2dump」配下に出力される
• 変更する場合DBM構成パラメーターのDIAGPATHで指定
• 出力する方法の詳細度をDIAGLEVEL DBM構成パラメーターで指定
•
• 0 - DIAG情報を出力しない
• 1 - 重大エラーのみ
• 2 - すべてのエラー
• 3 - すべてのエラーおよび警告
• 4 - すべてのエラー、警告、および通知メッセージ
デフォルト値は3、通常はデフォルト値のまま使用することを推奨
イベントの
重大度
• db2diagコマンドで整形やフィルターが可能
5
2009-06-25-08.42.26.203700-300 I7497A313
LEVEL: Event
PID
: 1466424
TID : 1
PROC : db2start
INSTANCE: tukiv97
NODE : 000
EDUID
: 1
FUNCTION: DB2 UDB, base sys utilities, sqleIssueStartStop, probe:21
DATA #1 : <preformatted>
Single node instance [0] is starting
プロセス名
イベントの内容を表す
メッセージ
© 2011 IBM Corporation
管理通知ログ（<インスタンス名>.nfy）
• 管理者が見るべきログだけが出力されるログファイル
•
ダンプ情報や内部のエラーコード等は出力されないため可読性が高い
•
ADMメッセージの内容は全てマニュアルに記載されているため、個別に監視の要・不
要を検討可能
• ADMメッセージ
• ADMxxxxC
：DB2のプロセスダウン等、クリティカルな障害
• ADMxxxxE
：重大度は高いが、サービスの全面停止には至らない事象
個別アプリケーションにエラーが戻る可能性がある
• ADMxxxxW
：警告メッセージ。多くの場合監視は不要
• ADMxxxxI
：インフォメーション。障害監視は不要
2009-08-08-20.31.12.844352
Instance:tukiv97
PID:1167498(db2wdog 0)
TID:258
Appid:none
base sys utilities sqleWatchDog Probe:20
Node:000
全てのメッセージにはADMxxxの
エラーコードが付与される
ADM0503C An unexpected internal processing error has occurred. All DB2
processes associated with this instance have been shutdown. Diagnostic
information has been recorded. Contact IBM Support for further assistance.
6
© 2011 IBM Corporation
診断ログと管理通知ログのファイルサイズ（diagsize）
• １つのログファイルのサイズを指定
• diagsize=0（デフォルト）
• 1つのファイルに書き出され、サイズは無限
• diagsize=2以上（単位MB）
• 2 x 90%=診断ログのファイルサイズ
• 2 x 10%=管理通知ログのファイルサイズ
• そのサイズのログファイルが最大10個まで作成される
• 10を超えると循環して再利用される
• ファイル名に番号が付与され、番号が一番大きいファイルが現在使用中のファイル
• db2diag.n.log、インスタンス名.n.nfy
db2diag.10.log
db2diag.0.log
db2diag.1.log
db2diag.2.log
db2diag.9.log
退避
7
© 2011 IBM Corporation
db2diagコマンド - db2diag.logファイルを整形する
• オプション指定により以下の操作が実施可能
• フィルタリング
• ファイル出力
• フォーマット設定
• モニタリング
• 保管
例
8
2010年2月2日以降にDB2が起動
されたログだけを表示
$ db2diag -g "proc=db2start" -time 2010-02-02
2010-02-02-15.13.55.201692+540 I986496A313
LEVEL: Event
PID
: 2351218
TID : 1
PROC : db2start
INSTANCE: yanav97
NODE : 000
EDUID
: 1
FUNCTION: DB2 UDB, base sys utilities, sqleIssueStartStop, probe:21
DATA #1 : <preformatted>
Single node instance [0] is starting
<省略>
© 2011 IBM Corporation
Monitoring DB2 and Oracle
• DB2のモニタリング
• Optim Performance Manager
(OPM)
• ブラウザにより複数のDB2を一括してモニタ
リング・管理するGUIツール
• DB2 管理ビュー
• DB2のアクティビティを知るための多数の管
理ビューが用意されている
• ビューとして提供されるため、SQLとの親和
性が高い
• 出力結果を定期的にテーブルに格納するこ
とで、statspackと同様のデータ蓄積が可能
9
• Oracleのモニタリング
• Enterprise manager
• ブラウザによるDB活動のモニタリ
ング
• Statspack
• Oracle標準で提供されているパ
フォーマンス・レポートツール
• v$ビューからデータと取得し、解析
する
• v$ ビュー
• 動的パフォーマンスビュー
• データベース活動に関する蓄積値
を提供する
© 2011 IBM Corporation
DB2 管理ビューとOracle v$ビュー
• DB2/Oracle共にインスタンス・データベースの稼働状態を取得するための
ビューが存在する
• 接続情報を取得するビューの使用例
• Oracle
• DB2
：
：
SELECT * FROM V$SESSION
SELECT * FROM SYSIBMADM.SNAPAPPL
• 管理ビューとv$ビューの対応
DB2 administrative view
10
Oracle
SYSIBMADM.SNAPDBM
V$INSTANCE
SYSIBMADM.SNAPDB
V$DATABASE
SYSIBMADM.SNAPTBSP
V$TABLESPACE
SYSIBMADM.SNAPCONTAINER
V$DATAFILE
SYSIBMADM.SNAPAPPL
V$SESSION
SYSIBMADM.SNAPSTMT
V$SQLTEXT
SYSIBMADM.SNAPLOCK
V$LOCK
SYSIBMADM.SNAPBP
V$SYSSTAT
SYSIBMADM.LONG_RUNNING_SQL
V$SESSION_LONGOPS
© 2011 IBM Corporation
DB2が提供するモニタリングツール
• GUIによるリアルタイムのモニタリングと分析
• Data Studio Admin Console、Optim Performance Manager
• リアルタイムのDB2稼働状況モニタリング（CUIベース）
• db2top (character based tool)
• ある一時点の稼働情報を取得
• Snapshot monitor、db2pd、モニター表関数
• ある期間に発生したイベントを網羅的に収集
• イベント・モニター
11
© 2011 IBM Corporation
ブランク・ページ
12
© 2011 IBM Corporation
Optim Performance Manager (OPM)
複数のDB2インスタンスを、統合されたインターフェースからモニタリング・
分析・管理することが可能
• OPM の機能:
緊急を要する状況への迅速な対応
データベース管理の効率化
システムの日常の状態を蓄積
DBの使用傾向から、HW資源有効活用
をプラン
• パフォーマンス・レポートの容易な作成
•
•
•
•
2
13
© 2011 IBM Corporation
Optim Performance Manager (OPM)
• Web Console基本画面遷移
OPM画面遷移
Heath Summary
Alert Summary
Dashboard
アクションと確認事項
データベースごとに問題の所在（ワー
ニング/アラートの有無）を確認
ワーニング/アラート･イベントの
発生時刻、内容を確認
・解析対象のイベントを選択して項目
に応じたDashboard画面へ遷移
Analyze
原因の解析と
対応
14
© 2011 IBM Corporation
db2top
• DB2の活動をリアルタイムでモニタリングするツール
db2top -d sample
•
telnetやssh等のターミナルセッションから起動する
•
データベースの挙動や問題点を素早く把握するために効果的
•
サポートされるバージョン
：V9.1 FP5以降, V9.5 FP2以降，V9.7
•
サポートするプラットフォーム
：AIX, Linux, 及び Solaris
15
© 2011 IBM Corporation
Snapshot monitor
• 稼動中のデータベースの、ある特定時点での状況を知る
• GET SNAPSHOTコマンドを利用して取得
db2 get snapshot for all on sample
•
管理ビューからはSQL経由で同等の情報が取得可能
• 稼働情報取得の流れ
•
•
•
モニタリング
開始
16
項目のモニタースイッチをON
• データベース・マネージャー構成パラメーターの設定、あるいは
• UPDATE MONITOR SWITCHESコマンド
モニター項目の値のリセット
• RESET MONITORコマンド
定期的にスナップショット・モニターを取得する
スナップショット取得
情報蓄積
スナップショット取得
情報蓄積
© 2011 IBM Corporation
Snapshot monitor
• データベースのスナップショット・モニター出力例
get snapshot for database on dbname
データベース・スナップショット
データベース名
データベース・パス
入力データベース別名
データベース状況
カタログ・データベース・パーティション番号
カタログ・ネットワーク・ノード名
データベース・サーバーで実行中のOS
データベースのロケーション
最初のデータベース接続タイム・スタンプ
最後のリセット・タイム・スタンプ
最後のバックアップ・タイム・スタンプ
スナップショット・タイム・スタンプ
=
=
=
=
=
=
=
=
=
=
=
=
TPCC
/db2/NODE0000/SQL00002/
TPCC
アクティブ
0
AIX
ローカル
08/04/2009 22:36:17.798958
08/04/2009 22:41:26.680407
接続用最高水準点
アプリケーション接続
2 次接続合計
現在のアプリケーション接続
db マネージャーで現在実行中のアプリケーション
アプリケーションに関連したエージェント
アプリケーションに関連した最大エージェント
最大調整エージェント
ロック保留
ロック待機
ロック上で待機される時間データベース (ms)
使用中のロック・リスト・メモリー (バイト)
デッドロック検出
08/04/2009 22:41:48.745114
17
=
=
=
=
=
=
=
=
=
=
=
=
=
5
3
0
3
3
3
5
5
27
0
177489
2808
0
ロック・エスカレーション
排他ロック・エスカレーション
ロック上で待機中のエージェント
ロック・タイムアウト
未確定トランザクション数
専用ソート・ヒープ割り振りの合計
共有ソート・ヒープ割り振りの合計
共有ソート・ヒープの最高水準点
ソートの合計
ソート時間の合計 (ms)
ソート・オーバーフロー
アクティブ・ソート
バッファー・プール・データ論理読み取り
バッファー・プール・データ物理読み取り
非同期プール・データ・ページ読み取り
バッファー・プール・データ書き込み
非同期プール・データ・ページ書き込み
バッファー・プール索引論理読み取り
バッファー・プール索引物理読み取り
非同期プール索引ページ読み取り
バッファー・プール索引書き込み
非同期プール索引ページ書き込み
バッファー・プール読み取り時間の合計 (ms)
バッファー・プール書き込み時間の合計 (ms)
非同期読み取り合計経過時間
非同期書き込み合計経過時間
非同期データ読み取り要求
非同期索引読み取り要求
LSN Gap クリーナー・トリガー
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
=
0
0
0
0
0
256
0
0
0
0
0
1
60921
56589
39875
8
7
68
55
0
0
0
49197
536
26121
531
3179
0
0
© 2011 IBM Corporation
db2pd
• データベースの状況を把握するために利用される
• 多くのオプションがあり、様々なケースやタイミングで活用できる
例 $ db2pd -d sample -bufferpools -repeat 2 5
SAMPLEデータベースのバッファープールの使用状況について2秒間隔で5回取得
• 特長
• 負荷が少なく、メモリ上の情報を参照する
• メモリは内部的なものを使用するため特にチューニングの必要はない
• DB2がハングしている状態でも取得可能
18
© 2011 IBM Corporation
（参考）db2pd出力例
EMPLOYEE表で表スキャンが
多発している
• 表ごとに発生している表スキャンや更新回数の調査
$ db2pd -d sample -tcbstats all
ORG表へのINSERT行数が多い
Database Partition 0 -- Database SAMPLE -- Active -- Up 0 days 00:08:15
TCB Table Information:
Address
TbspaceID
0x0780000220BF2378 2
0x0780000220BF1378 2
0x0780000220B86178 2
0x0780000220B86D78 2
0x0780000220BF33F8 2
TCB Table Stats:
Address
0x0780000220BF2378
0x0780000220BF1378
0x0780000220B86178
0x0780000220B86D78
0x0780000220BF33F8
TableID
6
8
14
15
17
TableName
EMPLOYEE
EMP_RESUME
ORG
STAFF
ADEFUSR
TCB Index Information:
Address
InxTbspace
0x0780000220BF2DC0 2
0x0780000220BF2DC0 2
0x0780000220BF1D40 2
0x0780000220BF47C0 2
TCB Index Stats:
Address
0x0780000220BF2DC0
0x0780000220BF2DC0
0x0780000220BF1D40
0x0780000220BF47C0
TableName
EMPLOYEE
EMPLOYEE
EMP_RESUME
STAFF
PartID
n/a
n/a
n/a
n/a
n/a
MasterTbs
2
2
2
2
2
Scans
382
1
2
8
0
UDI
0
0
4010
36
0
ObjectID
6
6
8
15
TbspaceID
2
2
2
2
IID
2
1
1
1
EmpPgDel
0
0
0
0
MasterTab
6
8
14
15
17
PgReorgs
0
0
0
0
0
TableID
6
6
8
15
<中略>
<中略>
<中略>
<中略>
<中略>
TableName
EMPLOYEE
EMP_RESUME
ORG
STAFF
ADEFUSR
NoChgUpdts
0
0
0
0
0
MasterTbs
2
2
2
2
Scans
0
1
130
330
SchemaNm
TUKIV9
TUKIV9
TUKIV9
TUKIV9
TUKIV9
Reads
0
0
0
0
0
MasterTab
6
6
8
15
KeyUpdates
0
0
0
0
FscrUpdates
0
0
0
0
0
ObjClass
Perm
Perm
Perm
Perm
Perm
Inserts
0
0
3820
35
0
TableName
EMPLOYEE
EMPLOYEE
EMP_RESUME
STAFF
InclUpdats
0
0
0
0
NonBndSpts
0
0
0
0
DataSize
2
1
1
1
1
Updates
0
0
0
1
0
SchemaNm
TUKIV9
TUKIV9
TUKIV9
TUKIV9
PgAllocs
0
0
0
1
LfSize
0
0
0
0
0
Deletes
0
0
0
0
0
LobSize
0
64
0
0
0
OvFlReads
0
0
0
0
0
XMLSize
0
0
0
0
0
OvFlCrtes
0
0
0
0
0
IID IndexObjSize
2
4
1
4
1
3
EMP_RESME表、STAFF表では
1
3
Merges
0
0
0
0
索引Scanが多い
PseuDels
0
0
0
0
DelClean
0
0
0
0
IntNodSpl
0
0
0
0
Table StatsのScans:表スキャンの回数 Inserts,Updates,Deletes：表の活動化後に実行された更新、削除、挿入の数
Index StatsのScans:索引スキャンの回数
表ごとのアクセス頻度を知ることができる
19
表スキャンが多発している表を特定できる
© 2011 IBM Corporation
モニター表関数 （MON_GET_*）
• db2pd同様、メモリから情報を参照する
• スナップショットのようなスイッチはなく、デフォルトで収集されている
• イベント･モニターのように開始・停止は必要ない
• 取得される情報によって３つレベルがある
• システム・レベル
• システムで実行中のすべての作業に関する詳細情報
• アクティビティー・レベル
• システムで実行中のアクティビティー に関する詳細情報
• データ・オブジェクト・レベル
• データベース・システムによる特定のデータベース・オブジェクト内での処
理に関する詳細情報
• 所要時間に関する情報も取得可能
20
© 2011 IBM Corporation
（参考）モニター表関数出力例
SQL
SELECT APPLICATION_HANDLE,
POOL_READ_TIME,POOL_WRITE_TIME,DIRECT_READ_TIME,DIRECT_WRITE_TIME,
IPC_RECV_WAIT_TIME,IPC_SEND_WAIT_TIME,TCPIP_RECV_WAIT_TIME,TCPIP_SEND_WAIT_TIME,
LOCK_WAIT_TIME,LOG_BUFFER_WAIT_TIME,LOG_DISK_WAIT_TIME,TOTAL_APP_RQST_TIME, TOTAL_RQST_TIME
FROM TABLE(MON_GET_CONNECTION(cast(NULL as bigint), -2)) AS t
実行結果
APPLICATION_HANDLE
POOL_READ_TIME
-------------------- -------------------32
49734
IPC_RECV_WAIT_TIME
IPC_SEND_WAIT_TIME
-------------------- -------------------0
0
LOG_BUFFER_WAIT_TIME LOG_DISK_WAIT_TIME
-------------------- -------------------78708
210
1 record(s) selected.
POOL_WRITE_TIME
-------------------1264
TCPIP_RECV_WAIT_TIME
-------------------0
TOTAL_APP_RQST_TIME
-------------------151247
DIRECT_READ_TIME
-------------------2
TCPIP_SEND_WAIT_TIME
-------------------0
TOTAL_RQST_TIME
-------------------151247
DIRECT_WRITE_TIME
-------------------0
LOCK_WAIT_TIME
-------------------0
ログ・バッファーへの書き込みで待ち状
態が発生していることがわかる。
21
© 2011 IBM Corporation
イベント・モニター
•
ある一定期間の活動を記録する
•
•
結果は表やファイルに書き出すことが可能
イベント・モニターの使用手順
開始
1. イベント・モニターの作成
•
CREATE EVENT MONITOR ステートメント
2. イベント・モニターの開始
•
SET EVENT MONITOR STATE 1
3. モニタリングしたい処理を実行
4. イベント・モニターの停止
•
SET EVENT MONITOR STATE 0
5. イベント・レコードの参照
•
22
モニター表、ファイル出力（db2evmon）、GUI
停止
© 2011 IBM Corporation
その他のモニタリング・ツール
• 一時点でDB2が使用しているメモリーについて分析
• db2mtrk
• 特定のSQL文に対するアクセス･プランを知りたい
• db2expln、db2exfmt、Visual Explain
• 現在実行中のユーティリティーの進捗をモニタリング
• db2 list utilities
23
© 2011 IBM Corporation
定常監視
• DB2稼動状況を監視
• プロセス監視 ： db2sysc
• 表スペース使用率の監視
• list tablespaces、db2top、Snapshot、db2pd
• ログ･スペースの監視
• アーカイブ･ログ･ファイル･ディレクトリなど
• ログ監視
• 診断ログ、管理通知ログなど
24
© 2011 IBM Corporation
問題判別実践編
課題
課題 ：： 「スループットが落ちている」
「スループットが落ちている」
環境
IHS/WAS
DB2
クライアント
25
© 2011 IBM Corporation
解析アプローチ
nmon
nmon
ps
ps
errpt
errpt
クライアント
DBサーバ（AIX)
APサーバ（AIX)
IHS
plugin
WAS
Web
コンテナ
データ
ソース
DB2
Server
JDBC
Driver
Access_log
http_plugin.log
JDBC
トレース
Snapshot
Error_log
Native_stderr
26
db2diag.log
javacore
Event
monitor
SystemErr.log
db2pd
SystemOut.log
db2exfmt
© 2011 IBM Corporation
解析手順
1.
サーバーの負荷確認
ƒ
何らかのパフォーマンストラブルが発生しているため、各サーバーにおけるリ
ソース使用状況に異常がないかをnmon, vmstat, iostat等で確認する。
DBサーバー、APサーバーでnmon, vmstat, iostatを1秒間隔で取得する
※APサーバーでの結果は省略 特に異常は見られない
CPU使用率は高くない
スレッド待ちもほとんど
発生していない
$ vmstat 1
DB Server
kthr
memory
page
faults
cpu
----- ----------- ------------------------ ------------ ----------r b avm fre re pi po fr sr cy in sy cs us sy id wa
1 1 447926 9074 0
0 0 0
0 0 857 36760 2927 64 8 18 11
製品側から見て
2 3 447287 9703 0
2 0 0
0 0 854 73852 2875 37 15 30 18
何か問題がないか？
0 1 447383 9601 0
0 0 0
0 0 1293 9335 4200 50 3 26 20
14 0 447382 9592 0 2 0 0
0 0 574 5167 2149 9 2 63 27
$ iostat 1
hdisk4からの読み込み
Disks:
% tm_act
Kbps
tps
Kb_read Kb_wrtn
が多発している
hdisk0
0.0
0.0
0.0
0
0
hdisk1
0.0
0.0
0.0
0
0
dac0
0.0
20264.0
494.0
19512
752
dac0utm
0.0
0.0
0.0
0
0
hdisk4
98.0
20264.0
494.0
19512
752
hdisk5
0.0
0.0
0.0
0
0
27
© 2011 IBM Corporation
解析手順
2. ミドルウェアプロセス確認
ƒ
ミドルウェアプロセスがダウンしていないことを確認する。
特に問題なし
3. IHSアクセス確認
IHSアクセスログ： ${IHS_root}/logs/access_log
$ view /usr/IBM/HTTPServer/logs/access_log
9.170.247.67 - - [26/Feb/2008:17:36:20 +0900]
9.170.247.67
- - [26/Feb/2008:17:36:20 +0900]
Servlet3に対するレスポンスが
9.170.247.67
- - [26/Feb/2008:17:36:20 +0900]
相対的に遅い
9.170.247.67 - - [26/Feb/2008:17:36:20 +0900]
9.170.247.67 - - [26/Feb/2008:17:36:20 +0900]
製品側のログを
9.170.247.67
- - [26/Feb/2008:17:36:20 +0900]
見てみるよう
9.170.247.67
- - [26/Feb/2008:17:36:20 +0900]
9.170.247.67 - - [26/Feb/2008:17:36:21 +0900]
9.170.247.67 - - [26/Feb/2008:17:36:20 +0900]
＜省略＞
28
AP Server
"GET
"GET
"GET
"GET
"GET
"GET
"GET
"GET
"GET
/Case2/Servlet1
/Case2/Servlet2
/Case2/Servlet2
/Case2/Servlet3
/Case2/Servlet3
/Case2/Servlet3
/Case2/Servlet3
/Case2/Servlet3
/Case2/Servlet3
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
HTTP/1.1"
200
200
200
200
200
200
200
200
200
771
643
643
614
614
614
614
614
614
483291
322517
287586
1525555
1079672
1380512
1674019
958376
1473825
© 2011 IBM Corporation
解析手順
4. WAS、DBのログ確認
•
問題発生時に、WASやDBのログにエラーが出力されていないことを確認する。
特に問題なし
データベースは
問題ないか？
5. DBスナップショットを取得
•
DBサーバーのディスクアクセスの負荷が高いため、DB内処理に問題がない
かを確認する
$ db2 get snapshot for database on test
DB Server
Database Snapshot
Rows selectedの件数に対して、Rows
Database name
= TEST
readが著しく多い（約5000対1）
Database path
= /dbpath_resi2008/resi2008/NODE0000/SQL00001/
Input database alias
= TEST
⇒不要なデータを読んでいる可能性大
Database status
= Active
～（中略）～
Rows deleted
= 0
Rows inserted
= 9000
Rows updated
= 2206
どの表が原因か？
Rows selected
= 89039
Rows read
= 502372864
29
© 2011 IBM Corporation
解析手順
6. db2pdによる情報取得
•
どのテーブルに対してRows readが多発しているのかを確認する
ため、db2pdコマンドを使用して表に関する情報を取得する。
$ db2pd -db test -tcbstats
Database Partition 0 -- Database TEST -- Active -- Up 0 days 08:02:59
DB Server
TCB Table Information:
TCB Table Stats:
Address
Deletes
0x0700000027959F38
0x0700000027959238
0x070000002795AC38
0x07000000279522B8
0x0700000027954CB8
LINEITEM1からの読み込みが
多発している
TableName
Scans
UDI
(省略) Reads
Inserts
Updates
どのSQLが原因か？
EMPLOYEE
DEPARTMENT
STAFF
LINEITEM1
LINEITEM2
0
0
0
6861
3320
0
0
980
348
18228
(省略)
(省略)
(省略)
(省略)
(省略)
0
0
0
0
4582
表スキャンの回数
30
172074
57358
438
1513749220
5675
0
0
980
1001
2190
0
0
0
0
0
読み込み行数
© 2011 IBM Corporation
解析手順
7. 動的SQLスナップショットの取得
•
STEP6で判明したテーブルに対して発行した動的SQLのうち、どのSQLに時間
がかかっているかを確認するため、動的SQLのスナップショットを取得する。
•
取得したスナップショット内をテーブル名（LINEITEM1）で検索し、処理時間の長いSQLを
特定する
$ db2 get snapshot for dynamic sql on test
Dynamic SQL Snapshot Result
DB Server
Database name
= TEST
Database path
= /dbpath_resi2008/resi2008/NODE0000/SQL00001/
処理時間が非常に長いSQLを特
～（中略）～
定
Number of executions
= 1000
⇒COL3をキーに検索を実施
～（中略）～
⇒SQL実行回数は1000回
Total execution time (sec.microsec)= 1495.794615
Total user cpu time (sec.microsec) = 118.372691
Total system cpu time (sec.microsec)= 0.754171
COL3に索引はあるか？
Total statistic fabrication time (milliseconds) = 0
Total synchronous runstats time (milliseconds) = 0
Statement text
= select * from RESI2008.LINEITEM1 where COL3=?
31
© 2011 IBM Corporation
解析手順
8. 索引情報確認
•
COL3列をキーに検索しているSQLのパフォーマンスに問題があるため、
索引が張られているかを確認する。
•
パフォーマンスに問題のあるテーブルに対する索引を確認する
$ db2 describe indexes for table LINEITEM1 show detail
DB Server
Index
Index
Unique
Number of
schema
COL1に対する索引のみ貼られている
name
rule
columns
Column names
⇒処理が遅いSQLで検索しているCOL3に
------------------------------------------------------------------------------------対する索引が貼張られていない
-- -------------- -------------- ----------------------------------------------------------RESI2008
IND_COL1
表スキャンに
D
1 +COL1
なっているかも？
1 record(s) selected.
32
© 2011 IBM Corporation
解析手順
9. アクセスパス取得
•
パフォーマンスに問題があるSQLのアクセスパスを確認するため、
db2exfmtコマンドを使用してアクセスパスを取得する。
Explainモードをオンにする
•
db2exfmtコマンドを使用してアクセスパスを取得する
$ db2 set current explain mode explain
DB20000I The SQL command completed successfully.
DB Server
アクセスパスを取得したいSQL
を実行する
$ db2 “select * from RESI2008.LINEITEM1 where COL3=?”
SQL0217W The statement was not executed as only Explain information requests
are being processed. SQLSTATE=01604
アクセスパスを取得する
$ db2exfmt –d test -1 –o db2exfmt.out
$ db2 set current explain mode no
DB20000I The SQL command completed successfully.
33
Explainモードをオフにする
© 2011 IBM Corporation
解析手順
• アクセスパス
$ view db2exfmt.out
Access Plan:
Total Cost:
Query Degree:
Rows
RETURN
(
1)
Cost
I/O
|
101.693
TBSCAN
(
2)
3139.57
9407
|
501141
TABLE: RESI2008
LINEITEM1
34
DB Server
3139.57
1
テーブルスキャンが行われており、
検索にコストがかかっていることがわかる
⇒不要な行を読み込んでいる要因
やはり表スキャン･･･
COL3に索引を作って
索引スキャンにした方が
効率的かも？
© 2011 IBM Corporation
解決策
1. 索引追加
•
COL3に対する索引を追加
2. 統計情報更新
対象表のRUNSTATS
•
3. 妥当性検証
1. アクセスパス確認
2. 読み取り行数と選択行数の確認
•
動的SQLスナップショット、db2pd、DBスナップショット
3. サーバー負荷の確認
35
© 2011 IBM Corporation
結果 ： アクセスパス
$ view db2exfmt.out
Access Plan:
----------Total Cost:
Query Degree:
DB Server
24.7238
1
Rows
RETURN
前回の値
(
1)
3139.57
Cost
I/O
|
99.9882
FETCH
(
2)
24.7238
34
/---+---¥
99.9882
501141
RIDSCN
TABLE: RESI2008
(
3)
LINEITEM1
15.2196
2
|
99.9882
SORT
(
4)
テーブルスキャンが行われなく
15.2192
2
なり、索引スキャンが実施され
|
99.9882
ていることがわかる。コストも大
IXSCAN
幅に削減されている。
(
5)
15.1979
2
|
501141
INDEX: RESI2008
CO3_IDX
36
© 2011 IBM Corporation
結果 ： OSの負荷
$ vmstat 1
CPU使用率は前回から変化なし
DB Server
kthr
memory
page
faults
cpu
----- ----------- ------------------------ ------------ ----------r b
avm
fre re pi po fr
sr cy in
sy cs us sy id wa
0 0 429940 30478
0
3
0
0
0
0 432 4050 1455 1 1 75 23
0 2 431180 29225
0
3
0
0
0
0 534 45507 1755 19 10 49 22
0 0 430279 35221
0
2
0
0
0
0 522 26690 1635 10 6 60 24
1 2 430466 40424
0
3
0
0
0
0 543 38108 1757 13 8 61 18
$ iostat 1
hdisk4に対する負荷は上がって
Disks:
% tm_act
Kbps
tps
Kb_read
Kb_wrtn
いるが、読み込みは多発してい
hdisk0
0.0
0.0
0.0
0
0
ない
hdisk1
0.0
0.0
0.0
0
0
dac0
0.0
836.0
209.0
0
836
dac0utm
0.0
0.0
0.0
0
0
hdisk4
100.0
836.0
209.0
0
836
hdisk5
0.0
0.0
0.0
0
0
37
© 2011 IBM Corporation
OPMを利用したデータベースの問題判別
課題
課題 ：： デッドロック発生の特定と原因解析
デッドロック発生の特定と原因解析
本番機
OPMサーバー
DB2 インスタンス
モニター対象
DB2データベース
(DB2 Database for
Linux,UNIX,Windows)
Optim Performance Manager
WebSphere
Application Server
Webベース・
コンソール
Webインターフェース：
Optim Performance Manager
- ブラウザ（IE または Firefox）
レポジトリーDB
Performance Expert Client
（オプション）
38
© 2011 IBM Corporation
問題解析の流れ
OPM画面遷移
Heath Summary
LockingのAlert Summary
Locking Dashboard
Analyze
アクションと確認事項
・Locking Alertの発生を検知
・Lockingイベントの発生回数や時刻を確認
・解析対象のイベントを選択してAnalyze画面へ遷移
・デッドロックに関係するアプリケーションの詳細を確認
・時系列でのSQLステートメント情報
・デッドロックに至ったロックの詳細情報
39
© 2011 IBM Corporation
Locking Alert の発生を確認
• OPMによる監視対象データベースを横串でサマリーする「Health
Summary」から該当データベースに複数のアラートが発生している
ことを確認
• デッドロックによる問題発生の場合、アプリケーション側でのエラー
検知（SQL0911,RC=2を検知）となる場合もある
Lockingのアラートをクリック
し、Alert Summaryに遷移
PEDEMOデータベースのみ
アラートが発生
40
© 2011 IBM Corporation
Lockingイベントの発生状況や時刻を確認
10:30から10:35にかけて4
回のデッドロックが発生
Lockingの発生状況を見るた
めLocking Dashboardへ遷
移
Analyzeから直接デッドロッ
クの詳細へ飛ぶことも可能
41
© 2011 IBM Corporation
Locking Dashboard から Analyze画面へ遷移
• Locking Dashboard画面で解析対象のイベントを選択して
Analyze画面へ遷移
最新のデッドロック発生を選択
Analyze画面へ遷移
42
© 2011 IBM Corporation
デッドロックに関係するアプリケーションの詳細を確認
デッドロックの原因となったアプ
リケーション名を確認
ここではサンプル・アプリ同士の
デッドロックとなっている。
本番環境ではWAS/WASや
WAS/バッチ処理といった接続
元の情報から両者の関連を類
推可能
パネルの最下部にデッドロック
の原因となったSQLステートメン
トが表示される。
この例では、RES_A表への全
件スキャンが2つのアプリケー
ションで重なっている
43
© 2011 IBM Corporation
時系列でのSQLステートメント情報を取得
• Statements画面の上半分
• 2つの接続から発行されたSQLが時系列で表示される
時系列
Participantsタブの情報から、デッド
ロックの直接の原因となったSQLの
一方が特定できる。
ここから、デッドロックに関連する
SQLを特定する
44
時系列
デッドロックに関連する2つのアプリ
ケーションで実行されたSQLが、時
系列に出力される。
これを手がかりに、問題となる処理
順序や処理対象行の特定を行う
© 2011 IBM Corporation
デッドロックに関連するSQLとロックの詳細情報
• Statements画面の下半分
• 前ページの各SQLごとに詳細情報が確認可能
READ ONLYのSQLだが、NSロックを要求してい
るため、他のアプリが排他ロックを保持する場合、
競合しロック待ちが発生する
複数のSQLが同じUOW IDの場合、１トランザクションで実
行されており、複数SQL分のロックが保持される
45
© 2011 IBM Corporation
デッドロック発生原因の特定
• 「statements」タブからデッドロックに直接関係するSQLを抽出
Participant ID=47
Participant ID=48
ACTID=1:
ACTID=3:
INSERT INTO pedemo.res_a VALUES
('SOMETHING',29,'NOMATTER')
ACTID=8:
INSERT INTO pedemo.res_a VALUES
('SOMETHING',91,'NOMATTER')
ACTID=4:
SELECT * FROM pedemo.res_a
SELECT * FROM pedemo.res_a
• 両方のアプリケーションが相手のINSERTコミットを待つ状態となっている
RES_A表
COL1
相手のINSERTに
よる排他ロックで
ロック待ち
排他ロック
46
COL2
COL3
AAA
1
AA
BBB
2
BB
CCC
3
CC
somthing
29
NOMATTHER
somthing
91
NOMATTHER
排他ロック
© 2011 IBM Corporation
考えられる対応策
1. SELECTの分離レベルをCurrently Committedへ変更する
• 読込スキャンが排他ロックの解放を待たずに読み飛ばすため、
ロック待ちが発生しない
2. 照会と更新のトランザクション・スコープを分離する
• 更新をいったん確定させてから、照会を行うことでロックの競合を
避ける
Participant ID=47
Participant ID=48
ACTID=1:
ACTID=3:
INSERT INTO pedemo.res_a VALUES
('SOMETHING',29,'NOMATTER')
ACTID=8:
SELECT * FROM pedemo.res_a
47
INSERT INTO pedemo.res_a VALUES
('SOMETHING',91,'NOMATTER')
ACTID=4:
SELECT * FROM pedemo.res_a
© 2011 IBM Corporation
参考情報
• DB2 V9.5 Troubleshooting Guide
• http://www-01.ibm.com/support/docview.wss?rs=71&uid=swg27009728#jp_main
• DB2問題判別 習熟シリーズ
• http://www.ibm.com/developerworks/jp/data/library/dataserver/support/
• Club DB2
• http://www.ibm.com/developerworks/wikis/display/clubdb2/finish
• Optim Performance Manager
• http://www-06.ibm.com/software/jp/data/optim/performance-expert/
48
© 2011 IBM Corporation
Let’s go to Lab6!!
49
© 2011 IBM Corporation