目的
- Db2上で処理時間の長いSQLを後から確認したい
- 全てのSQLを記録する必要はなく、長いものだけ把握したい
方法
他にも方法は数多ありそうですが、今回は
- DB2 ワークロード・マネージャー (WLM) で長時間SQLを検出
- 検出されたSQLのステートメントおよびコンパイル環境のデータをアクティビティ・イベントモニターへ送信
の二段階で、詳細情報をログファイルに残せるかどうか確認します。
→ イベントモニターの出力先ファイルに出力されたので、目的は達成できました
設定手順
以下、WLM/イベントモニターの構成コマンドをスクリプト化した内容をそのまま添付しています。Db2インスタンスオーナーにて db2 -tvf <ファイル名>
で実行すると、構成できます。
1. Db2 WLM構成
以下のワークロードと閾値の定義を作成します
- 対象アプリ:コマンド行からのSQL実行時(db2bp)
- 詳細情報の収集:アクティビティイベントモニターへの送信
- 閾値:1分
- 閾値を超えた場合のアクション:実行停止
- 対象ユーザ:PUBLIC(全員)
-- コマンド行プロセッサ(db2bp)からのアクセス時に有効となるワークロードを定義
CREATE WORKLOAD work1_wl
APPLNAME('db2bp')
POSITION AT 1
;
-- 閾値を定義(1分以上かかるSQLがあったらアクティビティデータを収集の上、実行停止)
CREATE THRESHOLD th_totalacttime
FOR WORKLOAD work1_wl ACTIVITIES
ENFORCEMENT DATABASE
WHEN ACTIVITYTOTALTIME > 1 MINUTES
COLLECT ACTIVITY DATA WITH DETAILS, SECTION AND VALUES
STOP EXECUTION
;
-- ワークロードの利用権限を付与
GRANT USAGE ON WORKLOAD work1_wl TO PUBLIC
;
2. Db2 アクティビティイベントモニター構成
以下のアクティビティイベントモニターを作成します
- 出力先:ファイル (指定したディレクトリ配下にファイルが作成される)
-- 詳細なアクティビティー情報を記録するためのアクティビティー・イベント・モニターを作成
CREATE EVENT MONITOR ACTIVITIES FOR ACTIVITIES WRITE TO FILE '/database/uktmp/act/logs'
;
-- 作成したイベント・モニターを使用可能にする
SET EVENT MONITOR ACTIVITIES STATE 1
;
長時間SQLの実行とログ出力確認
1. 長時間SQL実行
実際に長時間かかるSQLを流してみます
$ db2 connect to testdb
--- 中略 ---
$ date ; time db2 "select CAST(sum(1) as BIGINT) from t1 a, t1 b, t1 c, t1 d, t1 e, t1 f, t1 g, t1 h, t1 i, t1 j, t1 k, t1 l, t1 m, t1 n, t1 o, t1 p, t1 q, t1 r, t1 s, t1 t, t1 u, t1 v, t1 w, t1 x, t1 y, t1 z" ; date
Wed Dec 27 07:48:40 UTC 2023
1
--------------------
SQL4712N The activity or request was stopped because the threshold
"TH_TOTALACTTIME" has been exceeded. Reason code: "9". SQLSTATE=5U026
real 1m0.906s
user 0m0.000s
sys 0m0.018s
Wed Dec 27 07:49:41 UTC 2023
→ 1分を超えた時点で想定通り中断されました
2. ログ出力確認
イベントモニター作成時に指定したパスに、ファイル 00000000.evt が生成されていることを確認します
$ ls -ltr
total 140
-rw-r----- 1 db2inst1 db2iadm1 36 Dec 27 07:40 db2event.ctl
-rw-r--r-- 1 db2inst1 db2iadm1 115552 Dec 27 07:49 00000000.evt
→ ファイルが生成されておりタイムスタンプもSQL実行時刻近辺で更新されています
3. イベントモニター出力のフォーマット
バイナリフォーマットで出力されるため、フォーマットします
出力量が多いため、適当なファイルにリダイレクトしておきます
$ db2evmon -path '/database/uktmp/act/logs' > actmon.text.log
4. フォーマット後のログ確認
想定通り、1分をえて実行されたSQLについてのみ、出力されています
以下のような情報が収集されます
- イベント発生時のタイムスタンプ
- アプリケーション名(db2bp)
- 接続ユーザ名(DB2CL1)
- 接続元アドレス
- 閾値に抵触したSQL(ステートメント)
- 閾値に抵触したSQLの見積もりコスト
- 閾値に抵触したSQLの実行時間(言うても1分)
- 閾値に抵触したSQLのPrepare所要時間
- 閾値に抵触したSQLの種別(動的 / 静的)
- 閾値に抵触したSQLの分離レベル
- 統計ファブリケーション所要時間
- 同期Runstats所要時間
- ソートやHash Join, Hash Group by などの実行状況
- ロックタイムアウト値
--------------------------------------------------------------------------
EVENT LOG HEADER
Event Monitor name: ACTIVITIES
Server Product ID: SQL11058
Version of event monitor data: 12
Byte order: LITTLE ENDIAN
Number of nodes in db2 instance: 1
Codepage of database: 1208
Territory code of database: 1
Server instance name: db2inst1
--------------------------------------------------------------------------
--------------------------------------------------------------------------
Database Name: TESTDB
Database Path: /database/data/db2inst1/NODE0000/SQL00001/MEMBER0000/
First connection timestamp: 12/27/2023 07:23:07.863062
Event Monitor Start time: 12/27/2023 07:40:50.239539
--------------------------------------------------------------------------
3) Activity ...
Activity ID : 1
Activity Secondary ID : 0
Appl Handle : 1666
UOW ID : 14
Service Superclass Name : SYSDEFAULTUSERCLASS
Service Subclass Name : SYSDEFAULTMANAGEDSUBCLASS
Tenant ID : 0
Tenant Name : SYSTEM
Activity Type : READ_DML
Parent Activity ID : 0
Parent UOW ID : 0
Coordinating Partition : 0
Workload ID : 3
Workload Occurrence ID : 2
Database Work Action Set ID : 0
Database Work Class ID : 0
Service Class Work Action Set ID : 2147483647
Service Class Work Class ID : 2147483647
Workload Work Action Set ID : 0
Workload Work Class ID : 0
Time Created : 12/27/2023 07:48:40.475596
Time Started : 12/27/2023 07:48:40.475606
Time Completed : 12/27/2023 07:49:41.359494
Event Timestamp : 12/27/2023 07:49:41.359582
Time Created at Coordinator Member : 12/27/2023 07:48:40.475596
Activity captured while in progress: FALSE
Application ID : 127.0.0.1.35180.231227072307
Application Name : db2bp
Session Auth ID : DB2CL1
Client Userid :
Client Workstation Name :
Client Applname :
Client Accounting String :
Address : 127.0.0.1
SQLCA:
sqlcode: -4712
sqlstate: 5U026
Message: SQL4712N The activity or request was stopped because the threshold "TH_TOTALACTTIME" has been exceeded. Reason code: "9". SQLSTATE=5U026
Query Cost Estimate : 9223372036854775807
Query Card Estimate : 1
Execution time : 60.883888 seconds
Rows Returned : 0
Query Actual Degree : 1
Effective Query Degree : 1
Prep time: 2
Number of remaps: 0
Total stats fabrication time: 0
Total stats fabrications: 0
Total sync runstats time: 0
Total sync runstats: 0
Monitoring Interval ID : 0
Query Data Tag List :
Active Hash Group Bys Top : 0
Active Hash Joins Top : 0
Active OLAP Functions Top : 0
Active Partial Early Aggregations Top : 0
Active Partial Early Distincts Top : 0
Active Sort Consumers Top : 0
Active Sorts Top : 0
Active Columnar Vector Consumers Top : 0
Sort Consumer Heap Top : 0
Sort Consumer Shared Heap Top : 0
Sort Heap Top : 0
Sort Shared Heap Top : 0
Admission Control Bypassed : FALSE
Estimated Sort Shared Heap Top : 0
Estimated Sort Consumers Top : 0
Estimated Runtime : 9223372036854775807
Admission Resource Actuals : N
Agents Top : 0
Session Priority : MEDIUM
Details XML : <activity_metrics xmlns="http://www.ibm.com/xmlns/prod/db2/mon" release="11050800"><wlm_queue_time_total>0</wlm_queue_time_total><wlm_queue_assignments_total>0</wlm_queue_assignments_total><fcm_tq_recv_wait_time>0</fcm_tq_recv_wait_time><fcm_message_recv_wait_time>0</fcm_message_recv_wait_time><fcm_tq_send_wait_time>0</fcm_tq_send_wait_time><fcm_message_send_wait_time>0</fcm_message_send_wait_time><lock_wait_time>0</lock_wait_time><lock_waits>0</lock_waits><direct_read_time>0</direct_read_time><direct_read_reqs>0</direct_read_reqs><direct_write_time>0</direct_write_time><direct_write_reqs>0</direct_write_reqs><log_buffer_wait_time>0</log_buffer_wait_time><num_log_buffer_full>0</num_log_buffer_full><log_disk_wait_time>0</log_disk_wait_time><log_disk_waits_total>0</log_disk_waits_total><pool_write_time>0</pool_write_time><pool_read_time>0</pool_read_time><audit_file_write_wait_time>0</audit_file_write_wait_time><audit_file_writes_total>0</audit_file_writes_total><audit_subsystem_wait_time>0</audit_subsystem_wait_time><audit_subsystem_waits_total>0</audit_subsystem_waits_total><diaglog_write_wait_time>0</diaglog_write_wait_time><diaglog_writes_total>0</diaglog_writes_total><fcm_send_wait_time>0</fcm_send_wait_time><fcm_recv_wait_time>0</fcm_recv_wait_time><total_act_wait_time>0</total_act_wait_time><total_section_sort_proc_time>0</total_section_sort_proc_time><total_section_sort_time>0</total_section_sort_time><total_section_sorts>0</total_section_sorts><total_act_time>60884</total_act_time><rows_read>1454672895</rows_read><rows_modified>288247596</rows_modified><pool_data_l_reads>98</pool_data_l_reads><pool_index_l_reads>0</pool_index_l_reads><pool_temp_data_l_reads>4341242</pool_temp_data_l_reads><pool_temp_index_l_reads>0</pool_temp_index_l_reads><pool_xda_l_reads>0</pool_xda_l_reads><pool_temp_xda_l_reads>0</pool_temp_xda_l_reads><total_cpu_time>60858298</total_cpu_time><pool_data_p_reads>0</pool_data_p_reads><pool_temp_data_p_reads>0</pool_temp_data_p_reads><pool_xda_p_reads>0</pool_xda_p_reads><pool_temp_xda_p_reads>0</pool_temp_xda_p_reads><pool_index_p_reads>0</pool_index_p_reads><pool_temp_index_p_reads>0</pool_temp_index_p_reads><pool_data_writes>0</pool_data_writes><pool_xda_writes>0</pool_xda_writes><pool_index_writes>0</pool_index_writes><direct_reads>0</direct_reads><direct_writes>0</direct_writes><rows_returned>0</rows_returned><deadlocks>0</deadlocks><lock_timeouts>0</lock_timeouts><lock_escals>0</lock_escals><fcm_sends_total>0</fcm_sends_total><fcm_recvs_total>0</fcm_recvs_total><fcm_send_volume>0</fcm_send_volume><fcm_recv_volume>0</fcm_recv_volume><fcm_message_sends_total>0</fcm_message_sends_total><fcm_message_recvs_total>0</fcm_message_recvs_total><fcm_message_send_volume>0</fcm_message_send_volume><fcm_message_recv_volume>0</fcm_message_recv_volume><fcm_tq_sends_total>0</fcm_tq_sends_total><fcm_tq_recvs_total>0</fcm_tq_recvs_total><fcm_tq_send_volume>0</fcm_tq_send_volume><fcm_tq_recv_volume>0</fcm_tq_recv_volume><tq_tot_send_spills>0</tq_tot_send_spills><post_threshold_sorts>0</post_threshold_sorts><post_shrthreshold_sorts>0</post_shrthreshold_sorts><sort_overflows>0</sort_overflows><audit_events_total>0</audit_events_total><total_sorts>0</total_sorts><stmt_exec_time>60884</stmt_exec_time><coord_stmt_exec_time>60884</coord_stmt_exec_time><total_routine_non_sect_proc_time>0</total_routine_non_sect_proc_time><total_routine_non_sect_time>0</total_routine_non_sect_time><total_section_proc_time>60884</total_section_proc_time><total_section_time>60884</total_section_time><total_app_section_executions>1</total_app_section_executions><total_routine_user_code_proc_time>0</total_routine_user_code_proc_time><total_routine_user_code_time>0</total_routine_user_code_time><total_routine_time>0</total_routine_time><thresh_violations>1</thresh_violations><num_lw_thresh_exceeded>0</num_lw_thresh_exceeded><total_routine_invocations>0</total_routine_invocations><lock_wait_time_global>0</lock_wait_time_global><lock_waits_global>0</lock_waits_global><reclaim_wait_time>0</reclaim_wait_time><spacemappage_reclaim_wait_time>0</spacemappage_reclaim_wait_time><lock_timeouts_global>0</lock_timeouts_global><lock_escals_maxlocks>0</lock_escals_maxlocks><lock_escals_locklist>0</lock_escals_locklist><lock_escals_global>0</lock_escals_global><cf_wait_time>0</cf_wait_time><cf_waits>0</cf_waits><pool_data_gbp_l_reads>0</pool_data_gbp_l_reads><pool_data_gbp_p_reads>0</pool_data_gbp_p_reads><pool_data_lbp_pages_found>4341340</pool_data_lbp_pages_found><pool_data_gbp_invalid_pages>0</pool_data_gbp_invalid_pages><pool_index_gbp_l_reads>0</pool_index_gbp_l_reads><pool_index_gbp_p_reads>0</pool_index_gbp_p_reads><pool_index_lbp_pages_found>0</pool_index_lbp_pages_found><pool_index_gbp_invalid_pages>0</pool_index_gbp_invalid_pages><pool_xda_gbp_l_reads>0</pool_xda_gbp_l_reads><pool_xda_gbp_p_reads>0</pool_xda_gbp_p_reads><pool_xda_lbp_pages_found>0</pool_xda_lbp_pages_found><pool_xda_gbp_invalid_pages>0</pool_xda_gbp_invalid_pages><evmon_wait_time>0</evmon_wait_time><evmon_waits_total>0</evmon_waits_total><total_extended_latch_wait_time>0</total_extended_latch_wait_time><total_extended_latch_waits>1</total_extended_latch_waits><total_disp_run_queue_time>0</total_disp_run_queue_time><pool_queued_async_data_reqs>0</pool_queued_async_data_reqs><pool_queued_async_index_reqs>0</pool_queued_async_index_reqs><pool_queued_async_xda_reqs>0</pool_queued_async_xda_reqs><pool_queued_async_temp_data_reqs>90663</pool_queued_async_temp_data_reqs><pool_queued_async_temp_index_reqs>0</pool_queued_async_temp_index_reqs><pool_queued_async_temp_xda_reqs>0</pool_queued_async_temp_xda_reqs><pool_queued_async_other_reqs>12</pool_queued_async_other_reqs><pool_queued_async_data_pages>0</pool_queued_async_data_pages><pool_queued_async_index_pages>0</pool_queued_async_index_pages><pool_queued_async_xda_pages>0</pool_queued_async_xda_pages><pool_queued_async_temp_data_pages>2901350</pool_queued_async_temp_data_pages><pool_queued_async_temp_index_pages>0</pool_queued_async_temp_index_pages><pool_queued_async_temp_xda_pages>0</pool_queued_async_temp_xda_pages><pool_failed_async_data_reqs>0</pool_failed_async_data_reqs><pool_failed_async_index_reqs>0</pool_failed_async_index_reqs><pool_failed_async_xda_reqs>0</pool_failed_async_xda_reqs><pool_failed_async_temp_data_reqs>0</pool_failed_async_temp_data_reqs><pool_failed_async_temp_index_reqs>0</pool_failed_async_temp_index_reqs><pool_failed_async_temp_xda_reqs>0</pool_failed_async_temp_xda_reqs><pool_failed_async_other_reqs>0</pool_failed_async_other_reqs><total_peds>0</total_peds><disabled_peds>0</disabled_peds><post_threshold_peds>0</post_threshold_peds><total_peas>0</total_peas><post_threshold_peas>0</post_threshold_peas><tq_sort_heap_requests>0</tq_sort_heap_requests><tq_sort_heap_rejections>0</tq_sort_heap_rejections><prefetch_wait_time>0</prefetch_wait_time><prefetch_waits>0</prefetch_waits><pool_data_gbp_indep_pages_found_in_lbp>4341340</pool_data_gbp_indep_pages_found_in_lbp><pool_index_gbp_indep_pages_found_in_lbp>0</pool_index_gbp_indep_pages_found_in_lbp><pool_xda_gbp_indep_pages_found_in_lbp>0</pool_xda_gbp_indep_pages_found_in_lbp><fcm_tq_recv_waits_total>0</fcm_tq_recv_waits_total><fcm_message_recv_waits_total>0</fcm_message_recv_waits_total><fcm_tq_send_waits_total>0</fcm_tq_send_waits_total><fcm_message_send_waits_total>0</fcm_message_send_waits_total><fcm_send_waits_total>0</fcm_send_waits_total><fcm_recv_waits_total>0</fcm_recv_waits_total><ida_send_wait_time>0</ida_send_wait_time><ida_sends_total>0</ida_sends_total><ida_send_volume>0</ida_send_volume><ida_recv_wait_time>0</ida_recv_wait_time><ida_recvs_total>0</ida_recvs_total><ida_recv_volume>0</ida_recv_volume><rows_deleted>0</rows_deleted><rows_inserted>0</rows_inserted><rows_updated>0</rows_updated><total_hash_joins>0</total_hash_joins><total_hash_loops>0</total_hash_loops><hash_join_overflows>0</hash_join_overflows><hash_join_small_overflows>0</hash_join_small_overflows><post_shrthreshold_hash_joins>0</post_shrthreshold_hash_joins><total_olap_funcs>0</total_olap_funcs><olap_func_overflows>0</olap_func_overflows><int_rows_deleted>0</int_rows_deleted><int_rows_inserted>0</int_rows_inserted><int_rows_updated>0</int_rows_updated><comm_exit_wait_time>0</comm_exit_wait_time><comm_exit_waits>0</comm_exit_waits><pool_col_l_reads>0</pool_col_l_reads><pool_temp_col_l_reads>0</pool_temp_col_l_reads><pool_col_p_reads>0</pool_col_p_reads><pool_temp_col_p_reads>0</pool_temp_col_p_reads><pool_col_lbp_pages_found>0</pool_col_lbp_pages_found><pool_col_writes>0</pool_col_writes><pool_col_gbp_l_reads>0</pool_col_gbp_l_reads><pool_col_gbp_p_reads>0</pool_col_gbp_p_reads><pool_col_gbp_invalid_pages>0</pool_col_gbp_invalid_pages><pool_col_gbp_indep_pages_found_in_lbp>0</pool_col_gbp_indep_pages_found_in_lbp><pool_queued_async_col_reqs>0</pool_queued_async_col_reqs><pool_queued_async_temp_col_reqs>0</pool_queued_async_temp_col_reqs><pool_queued_async_col_pages>0</pool_queued_async_col_pages><pool_queued_async_temp_col_pages>0</pool_queued_async_temp_col_pages><pool_failed_async_col_reqs>0</pool_failed_async_col_reqs><pool_failed_async_temp_col_reqs>0</pool_failed_async_temp_col_reqs><total_col_proc_time>0</total_col_proc_time><total_col_time>0</total_col_time><total_col_executions>0</total_col_executions><post_threshold_hash_joins>0</post_threshold_hash_joins><pool_caching_tier_page_read_time>0</pool_caching_tier_page_read_time><pool_caching_tier_page_write_time>0</pool_caching_tier_page_write_time><pool_data_caching_tier_l_reads>0</pool_data_caching_tier_l_reads><pool_index_caching_tier_l_reads>0</pool_index_caching_tier_l_reads><pool_xda_caching_tier_l_reads>0</pool_xda_caching_tier_l_reads><pool_col_caching_tier_l_reads>0</pool_col_caching_tier_l_reads><pool_data_caching_tier_page_writes>0</pool_data_caching_tier_page_writes><pool_index_caching_tier_page_writes>0</pool_index_caching_tier_page_writes><pool_xda_caching_tier_page_writes>0</pool_xda_caching_tier_page_writes><pool_col_caching_tier_page_writes>0</pool_col_caching_tier_page_writes><pool_data_caching_tier_page_updates>0</pool_data_caching_tier_page_updates><pool_index_caching_tier_page_updates>0</pool_index_caching_tier_page_updates><pool_xda_caching_tier_page_updates>0</pool_xda_caching_tier_page_updates><pool_col_caching_tier_page_updates>0</pool_col_caching_tier_page_updates><pool_data_caching_tier_pages_found>0</pool_data_caching_tier_pages_found><pool_index_caching_tier_pages_found>0</pool_index_caching_tier_pages_found><pool_xda_caching_tier_pages_found>0</pool_xda_caching_tier_pages_found><pool_col_caching_tier_pages_found>0</pool_col_caching_tier_pages_found><pool_data_caching_tier_gbp_invalid_pages>0</pool_data_caching_tier_gbp_invalid_pages><pool_index_caching_tier_gbp_invalid_pages>0</pool_index_caching_tier_gbp_invalid_pages><pool_xda_caching_tier_gbp_invalid_pages>0</pool_xda_caching_tier_gbp_invalid_pages><pool_col_caching_tier_gbp_invalid_pages>0</pool_col_caching_tier_gbp_invalid_pages><pool_data_caching_tier_gbp_indep_pages_found>0</pool_data_caching_tier_gbp_indep_pages_found><pool_index_caching_tier_gbp_indep_pages_found>0</pool_index_caching_tier_gbp_indep_pages_found><pool_xda_caching_tier_gbp_indep_pages_found>0</pool_xda_caching_tier_gbp_indep_pages_found><pool_col_caching_tier_gbp_indep_pages_found>0</pool_col_caching_tier_gbp_indep_pages_found><total_hash_grpbys>0</total_hash_grpbys><hash_grpby_overflows>0</hash_grpby_overflows><post_threshold_hash_grpbys>0</post_threshold_hash_grpbys><post_threshold_olap_funcs>0</post_threshold_olap_funcs><post_threshold_col_vector_consumers>0</post_threshold_col_vector_consumers><total_col_vector_consumers>0</total_col_vector_consumers><total_index_build_proc_time>0</total_index_build_proc_time><total_index_build_time>0</total_index_build_time><total_indexes_built>0</total_indexes_built><ext_table_recv_wait_time>0</ext_table_recv_wait_time><ext_table_recvs_total>0</ext_table_recvs_total><ext_table_recv_volume>0</ext_table_recv_volume><ext_table_read_volume>0</ext_table_read_volume><ext_table_send_wait_time>0</ext_table_send_wait_time><ext_table_sends_total>0</ext_table_sends_total><ext_table_send_volume>0</ext_table_send_volume><ext_table_write_volume>0</ext_table_write_volume><col_vector_consumer_overflows>0</col_vector_consumer_overflows><total_col_synopsis_proc_time>0</total_col_synopsis_proc_time><total_col_synopsis_time>0</total_col_synopsis_time><total_col_synopsis_executions>0</total_col_synopsis_executions><col_synopsis_rows_inserted>0</col_synopsis_rows_inserted><lob_prefetch_wait_time>0</lob_prefetch_wait_time><lob_prefetch_reqs>0</lob_prefetch_reqs><fed_rows_deleted>0</fed_rows_deleted><fed_rows_inserted>0</fed_rows_inserted><fed_rows_updated>0</fed_rows_updated><fed_rows_read>0</fed_rows_read><fed_wait_time>0</fed_wait_time><fed_waits_total>0</fed_waits_total><adm_overflows>0</adm_overflows><adm_bypass_act_total>0</adm_bypass_act_total></activity_metrics>
4) Activity Statement ...
Activity ID : 1
Activity Secondary ID : 0
Application Handle : 1666
Application ID : 127.0.0.1.35180.231227072307
UOW ID : 14
Lock timeout value : -1
Query ID : 0
Package cache ID : 4050154160129
Statement ID : 5746028695146687320
Plan ID : -7165985729113726549
Semantic Env ID : 4836717360601346174
Package creator : NULLID
Package name : SQLC2P31
Package version :
Section No : 201
Statement No : 1
Num Routines : 0
Executable ID : 0x01000000000000003B0000000000000000000000020020231227074840475395
Type : Dynamic
Nesting level of stmt : 0
Source ID : 0
Invocation ID : 0
Routine ID : 0
Isolation level : Cursor Stability
Statement text : select CAST(sum(1) as BIGINT) from t1 a, t1 b, t1 c, t1 d, t1 e, t1 f, t1 g, t1 h, t1 i, t1 j, t1 k, t1 l, t1 m, t1 n, t1 o, t1 p, t1 q, t1 r, t1 s, t1 t, t1 u, t1 v, t1 w, t1 x, t1 y, t1 z
Effective statement text :
Stmt first use time : 12/27/2023 07:48:40.475596
Stmt last use time : 12/27/2023 07:48:40.475596
Event Timestamp : 12/27/2023 07:49:41.359582
Time Created at Coordinator Member : 12/27/2023 07:48:40.475596
SQL実行履歴取得、これ以外のユースケース
今回試した以外にも、様々なユースケース/情報収集ツールがあります。
要件に沿っていろいろな構成方法・情報収集・抽出の方法が取れそうです。
遅いSQLのパラメーターマーカー値を特定したい場合
状況に応じた、様々なSQL処理時間・処理内容追跡方法
-
Db2:遅いSQLを見つける方法
- ロックによる遅延の把握,DBを流れるSQLの概況把握,全SQLの捕捉‥などさまざまな要件に応じた追跡方法とメリデメが紹介されていて勉強になります
実行されたすべてのSQLを履歴として記録に残したい場合
参考情報
- CREATE WORKLOAD ステートメント
-
ACTIVITYTOTALTIME しきい値
アクティビティー・イベント・モニター - CREATE EVENT MONITOR (アクティビティー) ステートメント
- db2evmon - イベント・モニター生産性向上ツール・コマンド
- 例: ステートメントの実行に関連したアクティビティー情報のキャプチャー
補足
調べたことメモ。
アクティビティ・イベント・モニターとは?
Db2のマニュアルによれば以下のような機能だそうです。
- ステートメントのパフォーマンスと動作、ならびにシステム全般のロードのパフォーマンスと動作をより深く理解するために役立つデータを収集
- 以下の表関数が戻すデータを補完するデータを戻す
- MON_GET_ACTIVITY_DETAILS
- MON_GET_PKG_CACHE_STMT
- MON_GET_PKG_CACHE_STMT_DETAILS
- 他のイベント・モニターと一緒に使用すると特に有用
- 例えば、定義したしきい値に違反するステートメントの実行に関する情報をキャプチャーする(※今回はこの用途で利用)
- 収集されたデータの書き込み先はDb2の表/名前付きパイプ/ファイル を選択可能
しきい値違反イベントモニターとの併用?
類似の手順がマニュアルの「例: ステートメントの実行に関連したアクティビティー情報のキャプチャー」に取り上げられています。
このキャプチャー例では、イベントモニターを2つ仕掛けています。
- しきい値違反イベントモニター
- アクティビティーイベントモニター
しきい値違反イベントモニターは、しきい値違反を記録するためのモニターで、これもあわせて設定してみると、しきい値違反の発生についても別途、記録が取れるようになります。
アクティビティーイベントモニターの出力内容自体には差異がありませんでしたので、今回の目的であれば、必須ではないと感じました。
(逆に、しかけた閾値に何回抵触したかをカウントしたいだけの目的ならば、このイベントモニターをしかけておくだけでいいのかもしれません。ファイルサイズも小さく収まる)
--------------------------------------------------------------------------
EVENT LOG HEADER
Event Monitor name: STMT_THRESH_VIOLATIONS
Server Product ID: SQL11057
Version of event monitor data: 12
Byte order: LITTLE ENDIAN
Number of nodes in db2 instance: 1
Codepage of database: 1208
Territory code of database: 1
Server instance name: db2inst1
--------------------------------------------------------------------------
--------------------------------------------------------------------------
Database Name: TESTDB
Database Path: /database/data/db2inst1/NODE0000/SQL00001/MEMBER0000/
First connection timestamp: 12/28/2023 01:28:24.891704
Event Monitor Start time: 12/28/2023 01:36:14.167410
--------------------------------------------------------------------------
3) Threshold Violation ...
Threshold ID : 1
Activity ID : 1
Appl Handle : 63
Application ID : *LOCAL.db2inst1.231228014225
Application Name : db2bp
UOW ID : 2
Workload ID : 3
Coordinating Partition : 0
Partition Number : 0
Tenant Name : SYSTEM
Tenant Id : 0
Connection Start Time : 12/28/2023 01:42:25.005277
Time of Violation : 12/28/2023 01:44:19.000000
Threshold Max Value : 60
Threshold Queue Size : 0
Activity Collected? : Yes
Threshold Predicate : ActivityTotalTime
Threshold Action : Stop
Source Service Class ID : 0
Destination Service Class ID : 0
Client User ID :
Client Workstation Name :
Client Application Name :
Client Account String :
Session Authorization ID : DB2CL1
System Authorization ID : DB2CL1
Client PID : 21766
Client Product ID : SQL11057
Client Hostname : 23460cf8ce40
Client Platform : LINUXX8664
Client Communication Protocol: LOCAL
Client Port Number : 0