[oracle] statspackは再現操作中じゃなくてOK(再現操作の前後でOK)

DBのパフォーマンス調査で再現テストしてstatspack取るときに、いまさらだけど、再現操作中(処理中)にstatspackスナップショット取らないといけないんだっけ?? 再現操作の前後でいいんだっけ(再現中にリアルタイムでスナップショット取る必要があるわけではなく、再現操作の開始前と、終了後のタイミングで1回ずつ取ればいいんだっけ)?があやしくなったので確認しました。特に実行時間が短い再現操作のDB調査で使えると思います

結果、後者でOKです(ただし累積系の値に限られます。ロードアベレージやCPU使用率などリアルタイムの値が出力される項目以外です)

# 確認した方法

- スナップショット取る
- 再現操作する -> 終わる
- スナップショット取る
- 直近2点間でレポート取得 (※ここには再現操作中の負荷がきっちり記録されてるか?)
- スナップショット取る
- 直近2点間でレポート取得 (※ここは無風状態が記録されてるか?)

# 確認結果

上記想定の通りでした。

具体的な操作は以下です

- execute statspack.snap(i_snap_level=>7); ※スナップ3
- 再現操作
    - select count(*) from huge_table;
    - 1分くらい?
- execute statspack.snap(i_snap_level=>7); ※スナップ4
- @?/rdbms/admin/spreport
    - 直近2点を指定 (begin:1, end:2)
- execute statspack.snap(i_snap_level=>7); ※スナップ5
- @?/rdbms/admin/spreport
    - 直近2点を指定 (begin:2, end:3)

※検証時スナップIDが3から始まってます

## sp_3_4.lst

```
Snapshot       Snap Id     Snap Time      Sessions Curs/Sess Comment
~~~~~~~~    ---------- ------------------ -------- --------- ------------------
Begin Snap:          3 12-1月 -23 16:04:51     178       1.5
  End Snap:          4 12-1月 -23 16:06:46     178       1.5
   Elapsed:       1.92 (mins) Av Act Sess:       0.7
   DB time:       1.33 (mins)      DB CPU:       0.40 (mins)

-- 

Top 5 Timed Events                                                    Avg %Total
~~~~~~~~~~~~~~~~~~                                                   wait   Call
Event                                            Waits    Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
Data Guard: Gap Manager                              2         121  60416   37.4
pman timer                                          38         114   3008   35.3
db file sequential read                      1,091,302          63      0   19.6
CPU time                                                        23           7.1
log file parallel write                            173           1      4     .2
          -------------------------------------------------------------
Host CPU  (CPUs: 4  Cores: 4  Sockets: 1)
~~~~~~~~              Load Average
                      Begin     End      User  System    Idle     WIO     WCPU
                    ------- -------   ------- ------- ------- ------- --------
                       0.18    1.08      6.64    3.65   88.85    8.31

--

SQL ordered by Elapsed time for DB: mydb  Instance: mydb  Snaps: 3 -4
-> Total DB Time (s):              80
-> Captured SQL accounts for   98.3% of Total DB Time
-> SQL reported below exceeded  1.0% of Total DB Time

  Elapsed                Elap per            CPU                        Old
  Time (s)   Executions  Exec (s)  %Total   Time (s)  Physical Reads Hash Value
---------- ------------ ---------- ------ ---------- --------------- ----------
     75.42            1      75.42   94.5      20.50       1,089,236 2099888218
Module: SQL*Plus
select count(*) from huge_table
```

## sp_4_5.lst

```
Snapshot       Snap Id     Snap Time      Sessions Curs/Sess Comment
~~~~~~~~    ---------- ------------------ -------- --------- ------------------
Begin Snap:          4 12-1月 -23 16:06:46     178       1.5
  End Snap:          5 12-1月 -23 16:10:55     181       1.5
   Elapsed:       4.15 (mins) Av Act Sess:       0.2
   DB time:       0.88 (mins)      DB CPU:       0.24 (mins)

--

Top 5 Timed Events                                                    Avg %Total
~~~~~~~~~~~~~~~~~~                                                   wait   Call
Event                                            Waits    Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
pman timer                                          83         250   3008   42.5
Data Guard: Gap Manager                              4         242  60416   41.1
log file sync                                   38,946          41      1    7.0
log file parallel write                         38,982          37      1    6.4
CPU time                                                        12           2.0
          -------------------------------------------------------------
Host CPU  (CPUs: 4  Cores: 4  Sockets: 1)
~~~~~~~~              Load Average
                      Begin     End      User  System    Idle     WIO     WCPU
                    ------- -------   ------- ------- ------- ------- --------
                       1.08    0.78      6.05    2.25   91.00    2.70

--

SQL ordered by Elapsed time for DB: mydb  Instance: mydb  Snaps: 4 -5
-> Total DB Time (s):              53
-> Captured SQL accounts for    7.8% of Total DB Time
-> SQL reported below exceeded  1.0% of Total DB Time

  Elapsed                Elap per            CPU                        Old
  Time (s)   Executions  Exec (s)  %Total   Time (s)  Physical Reads Hash Value
---------- ------------ ---------- ------ ---------- --------------- ----------
      0.68            1       0.68    1.3       0.66             101 2912400228
Module: SQL*Plus
BEGIN statspack.snap; END;
```

## 解説

pman timerとData Guard: Gap Manager は、Oralce内部のイベントで無視する必要があるやつです(12cから出力されるようになった。パッチ当てれば出力されなくなる。この環境では当たってない)
それ以外だと、再現操作前後のスナップを指定したsp_3_4.lstでは再現操作のSQLやDB全体の負荷が記録され、再現操作の後～さらに後のスナップを指定したsp_4_5.lstは無風状態になっていることが確認できました。
ただし、CPU使用率やロードアベレージなど、リアルタイム的なものは処理中のものでないと参考にならないようです。

上記の方法で取れることが分かりましたが、特に処理時間の短い再現操作の確認の場合、同じタイミングで別の処理が流れてるとその処理の方が記録されてしまう可能性があって分かりづらくなってしまうので、なるべく無風状態(かCPU使用率が落ち着いてることなどを確認して)やるのがいいと思います

こういう5分くらいでさくっと書ける記事を書くのが楽です(長大なやつは大体書き途中に自分で納得いかなくなってお蔵入りになる)