Db2:性能評価にSQL平均応答時間を用いる

# データベースのパフォーマンスって？
データベースの性能を評価する指標は多々あります。IBM Db2ならMONREPORT.DBSUMMARYをcallすると指定した単位時間で以下のようなパフォーマンスサマリーを取得できます。
Db2 V11.5 Windows と Windows Server 2016で確認しています。

<details><summary>MONREPORT.DBSUMMARY （左の三角を下にすると展開します）</summary><div>

```MONREPORT.DBSUMMARY
  TEXT                                                                            
  --------------------------------------------------------------------------------
  --------------------------------------------------------------------------------
  Monitoring report - database summary                                            
  --------------------------------------------------------------------------------
  Database:                                 APIUS01                               
  Generated:                                2014-04-22 16:55:10                   
  Interval monitored:                       300                                   
                                                                                  
  ================================================================================
  Part 1 - System performance                                                     
                                                                                  
  Work volume and throughput                                                      
  --------------------------------------------------------------------------------
                                    Per second             Total                  
                                    ---------------------  -----------------------
  TOTAL_APP_COMMITS                 0                      18                     
  ACT_COMPLETED_TOTAL               2                      704                    
  APP_RQSTS_COMPLETED_TOTAL         4                      1416                   
                                                                                  
  TOTAL_CPU_TIME                    = 1232404                                     
  TOTAL_CPU_TIME per request        = 870                                         
                                                                                  
  Row processing                                                                  
    ROWS_READ/ROWS_RETURNED         = 3 (7327/2069)                               
    ROWS_MODIFIED                   = 0                                           
                                                                                  
  Wait times                                                                      
  --------------------------------------------------------------------------------
                                                                                  
  -- Wait time as a percentage of elapsed time --                                 
                                                                                  
                                           %    Wait time/Total time              
                                           ---  ----------------------------------
  For requests                             0    1469/306835                       
  For activities                           0    509/301763                        
                                                                                  
  -- Time waiting for next client request --                                      
                                                                                  
  CLIENT_IDLE_WAIT_TIME               = 302078                                    
  CLIENT_IDLE_WAIT_TIME per second    = 1006                                      
                                                                                  
  -- Detailed breakdown of TOTAL_WAIT_TIME --                                     
                                                                                  
                                %    Total                                        
                                ---  ---------------------------------------------
  TOTAL_WAIT_TIME               100  1469                                         
                                                                                  
  I/O wait time                                                                   
    POOL_READ_TIME              33   487                                          
    POOL_WRITE_TIME             0    0                                            
    DIRECT_READ_TIME            14   220                                          
    DIRECT_WRITE_TIME           0    0                                            
    LOG_DISK_WAIT_TIME          0    0                                            
  LOCK_WAIT_TIME                0    0                                            
  AGENT_WAIT_TIME               0    0                                            
  Network and FCM                                                                 
    TCPIP_SEND_WAIT_TIME        0    0                                            
    TCPIP_RECV_WAIT_TIME        0    0                                            
    IPC_SEND_WAIT_TIME          0    7                                            
    IPC_RECV_WAIT_TIME          0    3                                            
    FCM_SEND_WAIT_TIME          0    0                                            
    FCM_RECV_WAIT_TIME          0    0                                            
  WLM_QUEUE_TIME_TOTAL          0    0                                            
  CF_WAIT_TIME                  0    0                                            
  RECLAIM_WAIT_TIME             0    0                                            
  SMP_RECLAIM_WAIT_TIME         0    0                                            
                                                                                  
  Component times                                                                 
  --------------------------------------------------------------------------------
  -- Detailed breakdown of processing time --                                     
                                                                                  
                                      %                 Total                     
                                      ----------------  --------------------------
  Total processing                    100               305366                    
                                                                                  
  Section execution                                                               
    TOTAL_SECTION_PROC_TIME           0                 511                       
      TOTAL_SECTION_SORT_PROC_TIME    0                 9                         
  Compile                                                                         
    TOTAL_COMPILE_PROC_TIME           0                 990                       
    TOTAL_IMPLICIT_COMPILE_PROC_TIME  0                 0                         
  Transaction end processing                                                      
    TOTAL_COMMIT_PROC_TIME            0                 1                         
    TOTAL_ROLLBACK_PROC_TIME          0                 0                         
  Utilities                                                                       
    TOTAL_RUNSTATS_PROC_TIME          0                 0                         
    TOTAL_REORGS_PROC_TIME            0                 0                         
    TOTAL_LOAD_PROC_TIME              0                 0                         
                                                                                  
  Buffer pool                                                                     
  --------------------------------------------------------------------------------
  Buffer pool hit ratios                                                          
                                                                                  
  Type             Ratio            Reads (Logical/Physical)                      
  ---------------  ---------------  ----------------------------------------------
  Data             95               6243/297                                      
  Index            95               2782/139                                      
  XDA              0                0/0                                           
  Temp data        0                0/0                                           
  Temp index       0                0/0                                           
  Temp XDA         0                0/0                                           
  GBP Data         0                (0 - 0)/0                                     
  GBP Index        0                (0 - 0)/0                                     
  GBP XDA          0                (0 - 0)/0                                     
  LBP Data         98               (6717 - 589)/(6243 + 0)                       
  LBP Index        95               (2643 - 0)/(2782 + 0)                         
  LBP XDA          0                (0 - 0)/(0 + 0)                               
                                                                                  
  I/O                                                                             
  --------------------------------------------------------------------------------
  Buffer pool writes                                                              
    POOL_DATA_WRITES      = 0                                                     
    POOL_XDA_WRITES       = 0                                                     
    POOL_INDEX_WRITES     = 0                                                     
  Direct I/O                                                                      
    DIRECT_READS          = 1600                                                  
    DIRECT_READ_REQS      = 102                                                   
    DIRECT_WRITES         = 0                                                     
    DIRECT_WRITE_REQS     = 0                                                     
  Log I/O                                                                         
    LOG_DISK_WAITS_TOTAL  = 0                                                     
                                                                                  
  Locking                                                                         
  --------------------------------------------------------------------------------
                          Per activity                    Total                   
                          ------------------------------  ----------------------  
  LOCK_WAIT_TIME          0                               0                       
  LOCK_WAITS              0                               0                       
  LOCK_TIMEOUTS           0                               0                       
  DEADLOCKS               0                               0                       
  LOCK_ESCALS             0                               0                       
                                                                                  
  Routines                                                                        
  --------------------------------------------------------------------------------
                                Per activity              Total                   
                                ------------------------  ------------------------
  TOTAL_ROUTINE_INVOCATIONS     0                         237                     
  TOTAL_ROUTINE_TIME            427                       301090                  
                                                                                  
  TOTAL_ROUTINE_TIME per invocation   = 1270                                      
                                                                                  
  Sort                                                                            
  --------------------------------------------------------------------------------
  TOTAL_SORTS                         = 12                                        
  SORT_OVERFLOWS                      = 0                                         
  POST_THRESHOLD_SORTS                = 0                                         
  POST_SHRTHRESHOLD_SORTS             = 0                                         
                                                                                  
  Network                                                                         
  --------------------------------------------------------------------------------
  Communications with remote clients                                              
  TCPIP_SEND_VOLUME per send          = 0          (0/0)                          
  TCPIP_RECV_VOLUME per receive       = 0          (0/0)                          
                                                                                  
  Communications with local clients                                               
  IPC_SEND_VOLUME per send            = 363        (503863/1387)                  
  IPC_RECV_VOLUME per receive         = 129        (178817/1382)                  
                                                                                  
  Fast communications manager                                                     
  FCM_SEND_VOLUME per send            = 0          (0/0)                          
  FCM_RECV_VOLUME per receive         = 0          (0/0)                          
                                                                                  
  Other                                                                           
  --------------------------------------------------------------------------------
  Compilation                                                                     
    TOTAL_COMPILATIONS                = 32                                        
    PKG_CACHE_INSERTS                 = 42                                        
    PKG_CACHE_LOOKUPS                 = 484                                       
  Catalog cache                                                                   
    CAT_CACHE_INSERTS                 = 60                                        
    CAT_CACHE_LOOKUPS                 = 701                                       
  Transaction processing                                                          
    TOTAL_APP_COMMITS                 = 18                                        
    INT_COMMITS                       = 6                                         
    TOTAL_APP_ROLLBACKS               = 9                                         
    INT_ROLLBACKS                     = 0                                         
  Log buffer                                                                      
    NUM_LOG_BUFFER_FULL               = 0                                         
  Activities aborted/rejected                                                     
    ACT_ABORTED_TOTAL                 = 0                                         
    ACT_REJECTED_TOTAL                = 0                                         
  Workload management controls                                                    
    WLM_QUEUE_ASSIGNMENTS_TOTAL       = 0                                         
    WLM_QUEUE_TIME_TOTAL              = 0                                         
                                                                                  
  DB2 utility operations                                                          
  --------------------------------------------------------------------------------
    TOTAL_RUNSTATS                    = 0                                         
    TOTAL_REORGS                      = 0                                         
    TOTAL_LOADS                       = 0                                         
                                                                                  
  ================================================================================
  Part 2 - Application performance drill down                                     
                                                                                  
  Application performance database-wide                                           
  --------------------------------------------------------------------------------
  TOTAL_CPU_TIME          TOTAL_       TOTAL_APP_     ROWS_READ +                 
  per request             WAIT_TIME %  COMMITS        ROWS_MODIFIED               
  ----------------------  -----------  -------------  ----------------------------
  870                     0            18             7327                        
                                                                                  
  Application performance by connection                                           
  --------------------------------------------------------------------------------
  APPLICATION_   TOTAL_CPU_TIME        TOTAL_         TOTAL_APP_     ROWS_READ +  
  HANDLE         per request           WAIT_TIME %    COMMITS        ROWS_MODIFIED
  -------------  -------------------   -----------    -------------  -------------
  7              26832                 20             2              1179         
  18             31200                 0              0              75           
                                                                                  
  Application performance by service class                                        
  --------------------------------------------------------------------------------
  SERVICE_       TOTAL_CPU_TIME        TOTAL_         TOTAL_APP_     ROWS_READ +  
  CLASS_ID       per request           WAIT_TIME %    COMMITS        ROWS_MODIFIED
  --------       -------------------   -----------    -------------  -------------
  11             0                     0              0              0            
  12             264                   29             12             5907         
  13             15326                 0              6              1420         
                                                                                  
  Application performance by workload                                             
  --------------------------------------------------------------------------------
  WORKLOAD_      TOTAL_CPU_TIME          TOTAL_       TOTAL_APP_     ROWS_READ +  
  NAME           per request             WAIT_TIME %  COMMITS        ROWS_MODIFIED
  -------------  ----------------------  -----------  -------------  -------------
  SYSDEFAULTADM  0                       0            0              0            
  SYSDEFAULTUSE  16483                   0            6              1420         
                                                                                  
  ================================================================================
  Part 3 - Member level information                                               
                                                                                  
  - I/O wait time is                                                              
    (POOL_READ_TIME + POOL_WRITE_TIME + DIRECT_READ_TIME + DIRECT_WRITE_TIME).    
                                                                                  
          TOTAL_CPU_TIME          TOTAL_       RQSTS_COMPLETED_  I/O              
  MEMBER  per request             WAIT_TIME %  TOTAL             wait time        
  ------  ----------------------  -----------  ----------------  -----------------
  0       870                     0            1416              1072             
                                                                                  

  236 レコードが選択されました。

  リターン状況 = 0

```

</div></details>

どうでしょう、ピンときたでしょうか。私はピンときません。だから、なに？と言った感じです。データベースの専門家が見れば、わかるのでしょうが第三者に説明しずらいです。もっと、パッと見て素人でも納得感のある性能情報を取れないものでしょうか。

# 何を知りたいのか
そもそも、パフォーマンスの何を測れば、納得感があるのでしょうか。私は何を知りたいのでしょうか。Webアプリケーションに代表されるトランザクション処理ならターンアラウンドタイム、つまり、応答時間が重要な性能指標です。そう考えるとデータベースならSQLの応答時間であれば、しっくりきます。SQL平均応答時間が時系列に並べば良いのでは！　イメージはこんな感じです。

``` :5分単位にSQL平均応答時間とSQL実行回数を表示
DATE       TIME     SQL_AVG_TIME     ACT_COMPLETED_TOTAL  ACT_COMPLETED_TOTAL  TOTAL_ACT_TIME       TOTAL_CPU_TIME       TOTAL_WAIT_TIME      TOTAL_COMPILE_TIME   LOCK_WAIT_TIME       POOL_READ_TIME       POOL_WRITE_TIME      LOG_DISK_WAIT_TIME  
---------- -------- ---------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- --------------------
2021-03-12 08:00:03            0.234 **                                 108233                25408            105640625                17179                69812                  531                 5463                  822                 4461
2021-03-12 08:05:03            0.194 **                                 118817                23116             66125000                12627                31142                  185                10924                 2657                 1930
2021-03-12 08:10:03            0.212 ***                                166159                35345             90171875                23356                43337                  409                14279                 1098                 2871
2021-03-12 08:15:03            0.293 **                                 134872                39606             88343750                23271                42726                  190                14007                 1634                 2095
2021-03-12 08:20:03            0.232 *****                              255068                59385            164921875                30765                83400                  691                22087                 1923                 2729
2021-03-12 08:25:03            0.227 *****                              286130                65114            168203125                35558                80317                 1146                22880                 1890                 2964
2021-03-12 08:30:03            0.218 *****                              261607                57188            172671875                29156                88775                 1653                14065                 2831                 3581
2021-03-12 08:35:03            0.261 ********                           405944               106021            260015625                59630               133654                 1088                43014                 2995                 4471
2021-03-12 08:40:03            0.212 *********                          473994               100602            305921875                56576               160269                 2480                29064                 4887                 7094
2021-03-12 08:45:03            0.231 *********                          460303               106767            299125000                61996               158771                 1695                33690                 4293                 5636
2021-03-12 08:50:03            0.211 **********                         512336               108549            329015625                62329               180038                 2668                30417                 5011                 7070
2021-03-12 08:55:03            0.289 *********                          465219               134581            347390625                86306               199397                 1762                55881                 4914                 8315
```
5分単位でSQL平均応答時間(SQL_AVG_TIME)とSQL実行回数(ACT_COMPLETED_TOTAL)を表示しています。午前8時のSQL平均応答時間は0.234ミリ秒でSQL実行回数は108,233回という具合です。SQL実行回数は量をイメージしやすいように棒グラフでも表示しています。

# SQL平均応答時間の計算方法
Db2ですとモニター表関数でMON_GET_DATABASEを実行するとパフォーマンスに関する指標を取得できます。その中にある TOTAL_ACT_TIME を ACT_COMPLETED_TOTAL で割るとSQL平均応答時間を求めることができます。

**SQL平均応答時間(ミリ秒) ＝ TOTAL_ACT_TIME ÷ ACT_COMPLETED_TOTAL**

| モニター・エレメント|内容 |単位|
|:------------|:------------|:------------|
|TOTAL_ACT_TIME |SQL総実行時間|ミリ秒|
|ACT_COMPLETED_TOTAL |SQL実行回数|回|

こちらについての詳細な情報はIBMのウェブサイトをご覧ください。
[Db2 を「見える化」するためのモニタリング運用](https://developer.ibm.com/jp/articles/j-d-db2bestpractice04/ "IBMのウェブサイト")
※IBMのコンテンツが移行中のためリンク切れしている可能性があります(2021-03-22)。

# 性能情報を記録する
モニター表関数で取得できる指標の値はデータベースが開始してからの積算、つまり、その時点での総合計です。単位時間ごとに推移を見たいのであれば、単位時間ごとに値を記録する必要があります。ここでは記録用のテーブルをcreateし、モニター表関数の値をinsertするSQLを用意、Windowsのタスクスケジューラに登録します。

1.記録用のテーブルをcreateするDDL

```sql:create_mon_get_db.ddl
create table mon_get_db  (
    ts,  
    act_completed_total,
    total_act_time, 
    total_cpu_time, 
    total_wait_time,
    total_compile_time, 
    lock_wait_time, 
    pool_read_time, 
    pool_write_time, 
    log_disk_wait_time 
) as (
select current timestamp, 
    act_completed_total, 
    total_act_time, 
    total_cpu_time, 
    total_wait_time,
    total_compile_time, 
    lock_wait_time, 
    pool_read_time, 
    pool_write_time, 
    log_disk_wait_time 
from table(mon_get_database(-2))) 
with no data in USERSPACE1 ;

create index idx_mon_get_db_1 on mon_get_db 
   (ts     asc) allow reverse scans ;
```

Db2コマンド・ウィンドウからテーブルをcreateします。
db2 -tvf create_mon_get_db.ddl

2.モニター表関数の値をinsertするSQL

```sql:insert_mon_get_db_mydatabase.sql
connect to mydatabase user db2admin using mypassword ;

INSERT INTO mon_get_db 
select current timestamp, 
    act_completed_total, 
    total_act_time, 
    total_cpu_time, 
    total_wait_time,
    total_compile_time, 
    lock_wait_time, 
    pool_read_time, 
    pool_write_time, 
    log_disk_wait_time 
from table(mon_get_database(-2)) ;

connect reset ;
```
接続するデータベースとユーザー、パスワードを環境に合わせて編集してください。

3.SQLを実行するバッチファイル

```bat:insert_mon_get_db_mydatabase.bat
D:\SQLLIB\BIN\db2cmd /w /c /i "db2 -tvf D:\my_task\sqlavg\insert_mon_get_db_mydatabase.sql"
```

このバッチファイルを単位時間（例では5分）ごとに実行するよう、タスクスケジューラに登録します。登録はPowershellで行うと簡単です。

4.タスクスケジューラに登録するPowershell

```powershell:タスク登録.ps1
Param([String]$password)

$taskname = "mydatabaseモニター表関数"
$action   = New-ScheduledTaskAction -Execute "D:\my_task\sqlavg\insert_mon_get_db_mydatabase.bat"
$trigger  = New-ScheduledTaskTrigger -DaysInterval 1 -Daily -At "00:55:00"
$user     = "Administrator"

$Task = Register-ScheduledTask -TaskPath \ -TaskName $taskname -Action $action -Trigger $trigger -User $user -Password $password -Force

$Task.Triggers.Repetition.Duration = "PT23H" 
$Task.Triggers.Repetition.Interval = "PT5M"
$Task | Set-ScheduledTask -User $user -Password $password
```

以下のコマンドでタスクスケジューラに登録します。
powershell .\タスク登録.ps1 {Administratorのパスワード}

# 性能情報を表示する
記録した性能情報を単純にselectしてみます。

```sql:select_simple.sql
select * from mon_get_db where date(ts) = current date and time(ts) between '08:00:00' and '09:00:00' order by ts ;
```

Db2コマンド・ウィンドウからSQLファイルを実行します。
db2 -tvf select_simple.sql

```log:select_simple.sqlの実行結果
select * from mon_get_db where date(ts) = current date and time(ts) between '08:00:00' and '09:00:00' order by ts 

TS                         ACT_COMPLETED_TOTAL  TOTAL_ACT_TIME       TOTAL_CPU_TIME       TOTAL_WAIT_TIME      TOTAL_COMPILE_TIME   LOCK_WAIT_TIME       POOL_READ_TIME       POOL_WRITE_TIME      LOG_DISK_WAIT_TIME  
-------------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- --------------------
2021-03-16-08.00.03.779000             14742243              4969146          19874546292              2780203              6875625               154056              2383383               370939               198112
2021-03-16-08.05.03.791000             14774819              4980881          19915452542              2785417              6896106               154091              2386115               371496               198497
2021-03-16-08.10.03.772000             14842853              5002631          19958593167              2790193              6913566               154091              2389311               372055               199160
2021-03-16-08.15.03.802000             14883452              5019426          20002968167              2795354              6930419               154163              2393117               372169               199576
2021-03-16-08.20.03.845000             14946946              5044740          20078218167              2803382              6966482               154243              2402336               373273               200373
2021-03-16-08.25.03.812000             15013303              5066530          20158030667              2811981              7009366               154381              2407998               373966               201002
2021-03-16-08.30.03.799000             15105414              5096334          20262811917              2823867              7065035               154468              2415395               374535               202065
2021-03-16-08.35.03.821000             15201085              5126500          20370765042              2835620              7123726               154534              2421734               375903               203271
2021-03-16-08.40.03.742000             15316212              5158479          20490686917              2849722              7189198               154576              2429962               377038               204986
2021-03-16-08.45.03.821000             15429010              5192443          20621108792              2864827              7263679               154662              2444971               379303               206551
2021-03-16-08.50.03.825000             15560552              5229290          20751546292              2882317              7336472               154765              2467925               381155               208314
2021-03-16-08.55.03.848000             15682599              5263918          20870546292              2897044              7397522               154966              2478376               383758               209706

  12 レコードが選択されました。
```


記録した指標の値はデータベースを開始してからの積算値です。つまり、値はどんどん増えていきます。単位時間ごとの値を算出するためには、**一つ前のレコードの値との差**を求める必要があります。
エクセルを使うのも面倒なのでSQLで書いてみます。具体的には一つ前のレコードの値との差をOLAP関数であるLAGを使って求めます。WITH句を使って求めた差分の中間テーブルを作成し、見た目を整えるSQLを書きました。

```sql:select_mon_get_db.sql
with snap_diffs as (
  select ts,
         act_completed_total - lag(act_completed_total,1,act_completed_total)  over (order by ts)  as act_completed_total, 
         total_act_time      - lag(total_act_time,     1,total_act_time)       over (order by ts)  as total_act_time,      
         total_cpu_time      - lag(total_cpu_time,     1,total_cpu_time)       over (order by ts)  as total_cpu_time,      
         total_wait_time     - lag(total_wait_time,    1,total_wait_time)      over (order by ts)  as total_wait_time,     
         total_compile_time  - lag(total_compile_time, 1,total_compile_time)   over (order by ts)  as total_compile_time,  
         lock_wait_time      - lag(lock_wait_time,     1,lock_wait_time)       over (order by ts)  as lock_wait_time,      
         pool_read_time      - lag(pool_read_time,     1,pool_read_time)       over (order by ts)  as pool_read_time,      
         pool_write_time     - lag(pool_write_time,    1,pool_write_time)      over (order by ts)  as pool_write_time,     
         log_disk_wait_time  - lag(log_disk_wait_time, 1,log_disk_wait_time)   over (order by ts)  as log_disk_wait_time   
  from  mon_get_db 
  where  date(ts) = current date - 0 day 
     and time(ts) between '08:00:00' and '09:00:00'
)

select date(ts) as date,
       time(ts) as time,
       case act_completed_total
         when 0 then 0
                else decimal((decimal(total_act_time) / act_completed_total), 8, 3)
       end as sql_avg_time,
       case act_completed_total
         when 0 then ''
         else substr(repeat('*',(act_completed_total / 50000)),1,20)
       end as act_completed_total,
       act_completed_total, 
       total_act_time,      
       total_cpu_time,      
       total_wait_time,     
       total_compile_time,  
       lock_wait_time,      
       pool_read_time,      
       pool_write_time,     
       log_disk_wait_time   
from   snap_diffs 
order by ts ;
```

Db2コマンド・ウィンドウからSQLファイルを実行します。
db2 -tvf select_mon_get_db.sql

```log:select_mon_get_db.sqlの実行結果
with snap_diffs as ( select ts, act_completed_total - lag(act_completed_total,1,act_completed_total)  over (order by ts)  as act_completed_total, total_act_time      - lag(total_act_time,     1,total_act_time)       over (order by ts)  as total_act_time, total_cpu_time      - lag(total_cpu_time,     1,total_cpu_time)       over (order by ts)  as total_cpu_time, total_wait_time     - lag(total_wait_time,    1,total_wait_time)      over (order by ts)  as total_wait_time, total_compile_time  - lag(total_compile_time, 1,total_compile_time)   over (order by ts)  as total_compile_time, lock_wait_time      - lag(lock_wait_time,     1,lock_wait_time)       over (order by ts)  as lock_wait_time, pool_read_time      - lag(pool_read_time,     1,pool_read_time)       over (order by ts)  as pool_read_time, pool_write_time     - lag(pool_write_time,    1,pool_write_time)      over (order by ts)  as pool_write_time, log_disk_wait_time  - lag(log_disk_wait_time, 1,log_disk_wait_time)   over (order by ts)  as log_disk_wait_time from  mon_get_db where  date(ts) = current date - 0 day and time(ts) between '08:00:00' and '09:00:00' ) select date(ts) as date, time(ts) as time, case act_completed_total when 0 then 0 else decimal((decimal(total_act_time) / act_completed_total), 8, 3) end as sql_avg_time, case act_completed_total when 0 then '' else substr(repeat('*',(act_completed_total / 50000)),1,20) end as act_completed_total, act_completed_total, total_act_time, total_cpu_time, total_wait_time, total_compile_time, lock_wait_time, pool_read_time, pool_write_time, log_disk_wait_time from   snap_diffs order by ts 

DATE       TIME     SQL_AVG_TIME     ACT_COMPLETED_TOTAL  ACT_COMPLETED_TOTAL  TOTAL_ACT_TIME       TOTAL_CPU_TIME       TOTAL_WAIT_TIME      TOTAL_COMPILE_TIME   LOCK_WAIT_TIME       POOL_READ_TIME       POOL_WRITE_TIME      LOG_DISK_WAIT_TIME  
---------- -------- ---------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- -------------------- --------------------
2021-03-18 08:00:03            0.000                                         0                    0                    0                    0                    0                    0                    0                    0                    0
2021-03-18 08:05:03            0.302 *                                   80660                24433             49765625                12973                19927                  369                 9230                 1196                  996
2021-03-18 08:10:03            0.287 ***                                153696                44139            111453125                27635                60007                  745                16883                 1358                 2516
2021-03-18 08:15:03            0.264 ***                                194856                51616            183640625                33674               121153                  562                18196                 1553                 5334
2021-03-18 08:20:03            0.266 ***                                197913                52730            117906250                33975                58484                  560                27169                 2530                 2987
2021-03-18 08:25:03            0.238 *****                              260442                62196            167187500                33469                83654                  928                21856                 2502                 3738
2021-03-18 08:30:03            0.216 ******                             306731                66360            202593750                35487               107329                 1570                16760                 3632                 3524
2021-03-18 08:35:03            0.214 ********                           442872                95042            285796875                51032               150848                 1448                17968                 3350                 4834
2021-03-18 08:40:03            0.213 **********                         516655               110104            320593750                61859               169012                 2945                28179                 5255                 4622
2021-03-18 08:45:03            0.227 **********                         532909               121341            360687500                72780               200698                 2588                38129                 5023                 6142
2021-03-18 08:50:03            0.228 **********                         543220               124013            393968750                73121               231882                 2233                37931                 5984                 6667
2021-03-18 08:55:03            0.222 **********                         509297               113424            357437500                67362               208918                 1697                32955                 5907                 6598

  12 レコードが選択されました。
```

単位時間ごとの差分が時系列に並びました（例では5分ごと）。SQL実行回数がアスタリスクの棒グラフでも表示され量のイメージがつかみやすくなっています。

# さいごに
このような**単位時間当たりのSQL総実行時間とSQL実行回数**を普段から取得しておくとシステムが遅延したときに役立ちます。例えば、過去と比較してみて

- 昔に比べてSQL平均応答時間(SQL_AVG_TIME)が増えている
- 昔と比べてSQL実行回数(ACT_COMPLETED_TOTAL)が増えている

のであれば、トランザクションが増えているからパフォーマンスが落ちていると推測ができます。
また、他施設の性能情報を取得できれば、性能を評価するうえで基準(相場)を知ることができて有益です。