この記事は約50分32秒で読むことができます。

sql oracle statspack tkprof hard parse回数の確認

初期化パラメータの確認

job_queue_processesの確認

ジョブ実行用に作成できるプロセスの最大数を指定。ジョブキュー内のジョブを実行するために、少なくとも1以上を指定する必要。

コード表示

col name for a24;
col value for a12;
select name,value from V$PARAMETER where NAME like '%job_queue_processes%';

dockerコンテナ内で出力したspool結果をdocker起動時に指定したdockerホストから見えるディレクトリに移動させ、winscpで出力したスプールファイルを刈り取り。というか/mntに移動してからsqlplus起動してスプールすればいい。。

コード表示

set markup html on
spool test.html
select * from STATS$PARAMETER where NAME like '%timed_statistics%';
spool off
set markup html off
コード表示

[oracle@centos7 ~]$ docker exec -it orcl_18cr3_1 bash
[oracle@6898242bcdd5 ~]$ sqlplus perfstat/perfstat@pdb1

SQL*Plus: Release 18.0.0.0.0 - Production on Sat Jan 26 17:18:52 2019
Version 18.3.0.0.0

Copyright (c) 1982, 2018, Oracle.  All rights reserved.

Last Successful login time: Sat Jan 26 2019 17:16:12 +09:00

Connected to:
Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.3.0.0.0

PERFSTAT@pdb1> host pwd
/home/oracle

PERFSTAT@pdb1> host ls -lt
total 212
-rw-r--r--. 1 oracle oinstall    913 Jan 26 17:16 test.html
-rw-r--r--. 1 oracle oinstall 162575 Jan 26 14:39 test_statspack.lst
-rw-r--r--. 1 oracle oinstall    237 Jan 26 09:41 spcpkg.lis
-rw-r--r--. 1 oracle oinstall  12864 Jan 26 09:41 spctab.lis
-rw-r--r--. 1 oracle oinstall   4570 Jan 26 09:41 spcusr.lis
drwxr-xr-x. 2 oracle oinstall   4096 Jan 20 10:58 rlwrap-extensions
-rw-r--r--. 1 root   root      15080 Jan 20 10:52 epel-release-7-11.noarch.rpm
lrwxrwxrwx. 1 root   root         26 Jan 19 23:19 setPassword.sh -> /opt/oracle/setPassword.sh

PERFSTAT@pdb1> set markup html on
PERFSTAT@pdb1> spool test.html
PERFSTAT@pdb1> select * from STATS$PARAMETER where NAME like '%job_queue_processes%';
PERFSTAT@pdb1> spool off

PERFSTAT@pdb1> set markup html off

PERFSTAT@pdb1> host ls -lt
total 212
-rw-r--r--. 1 oracle oinstall    913 Jan 26 17:20 test.html
-rw-r--r--. 1 oracle oinstall 162575 Jan 26 14:39 test_statspack.lst
-rw-r--r--. 1 oracle oinstall    237 Jan 26 09:41 spcpkg.lis
-rw-r--r--. 1 oracle oinstall  12864 Jan 26 09:41 spctab.lis
-rw-r--r--. 1 oracle oinstall   4570 Jan 26 09:41 spcusr.lis
drwxr-xr-x. 2 oracle oinstall   4096 Jan 20 10:58 rlwrap-extensions
-rw-r--r--. 1 root   root      15080 Jan 20 10:52 epel-release-7-11.noarch.rpm
lrwxrwxrwx. 1 root   root         26 Jan 19 23:19 setPassword.sh -> /opt/oracle/setPassword.sh
PERFSTAT@pdb1> Disconnected from Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.3.0.0.0
[oracle@6898242bcdd5 ~]$ ll
total 212
-rw-r--r--. 1 root   root      15080 Jan 20 10:52 epel-release-7-11.noarch.rpm
drwxr-xr-x. 2 oracle oinstall   4096 Jan 20 10:58 rlwrap-extensions
lrwxrwxrwx. 1 root   root         26 Jan 19 23:19 setPassword.sh -> /opt/oracle/setPassword.sh
-rw-r--r--. 1 oracle oinstall    237 Jan 26 09:41 spcpkg.lis
-rw-r--r--. 1 oracle oinstall  12864 Jan 26 09:41 spctab.lis
-rw-r--r--. 1 oracle oinstall   4570 Jan 26 09:41 spcusr.lis
-rw-r--r--. 1 oracle oinstall    913 Jan 26 17:20 test.html
-rw-r--r--. 1 oracle oinstall 162575 Jan 26 14:39 test_statspack.lst
[oracle@6898242bcdd5 ~]$ mv test.html /mnt
[oracle@6898242bcdd5 ~]$ ll
total 208
-rw-r--r--. 1 root   root      15080 Jan 20 10:52 epel-release-7-11.noarch.rpm
drwxr-xr-x. 2 oracle oinstall   4096 Jan 20 10:58 rlwrap-extensions
lrwxrwxrwx. 1 root   root         26 Jan 19 23:19 setPassword.sh -> /opt/oracle/setPassword.sh
-rw-r--r--. 1 oracle oinstall    237 Jan 26 09:41 spcpkg.lis
-rw-r--r--. 1 oracle oinstall  12864 Jan 26 09:41 spctab.lis
-rw-r--r--. 1 oracle oinstall   4570 Jan 26 09:41 spcusr.lis
-rw-r--r--. 1 oracle oinstall 162575 Jan 26 14:39 test_statspack.lst
[oracle@6898242bcdd5 ~]$ cd /mnt
[oracle@6898242bcdd5 mnt]$ ll
total 4
drwxrwxrwx. 5   1000     1001  46 Jan  2 15:05 11gr2
drwxrwxrwx. 5   1000     1001  46 Jan  2 15:05 12cr2
drwxrwxrwx. 5   1000     1001  46 Jan 12 22:21 18cr3
-rw-r--r--. 1 oracle oinstall 913 Jan 26 17:20 test.html
SNAP_ID DBID INSTANCE_NUMBER NAME VALUE ISDEFAULT ISMODIFIED
2 1525818796 1 job_queue_processes 4000 TRUE FALSE
1 1525818796 1 job_queue_processes 4000 TRUE FALSE

timed_statisticsの確認

時間に関する統計情報を収集するか否かを決定するパラメータ。デフォは収集する。

コード表示

select * from STATS$PARAMETER where NAME like '%timed_statistics%';
SNAP_ID DBID INSTANCE_NUMBER NAME VALUE ISDEFAULT ISMODIFIED
2 1525818796 1 timed_statistics TRUE TRUE FALSE
1 1525818796 1 timed_statistics TRUE TRUE FALSE

statistics_levelの確認

収集される統計情報量を調節できる。

コード表示

select * from STATS$PARAMETER where NAME like '%statistics_level%';
SNAP_ID DBID INSTANCE_NUMBER NAME VALUE ISDEFAULT ISMODIFIED
2 1525818796 1 statistics_level TYPICAL TRUE FALSE
1 1525818796 1 statistics_level TYPICAL TRUE FALSE

スナップショットの閾値の確認

スナップショットを取得すると、ライブラリ・キャッシュにあるSQL情報はSTATS$SUMMARYテーブルに格納されるが、すべて格納すると、膨大になるため、閾値を越えたSQLだけを格納するように組まれているぽい。そこで閾値を確認してみる。なお$ORACLE_HOME/rdbms/admin/spdoc.txtが原文。

閾値 概要 原文(引用)
i_executions_th SQLの実行回数。デフォルト値は100 SQL Threshold: number of times the statement was executed
i_disk_reads_th SQLによるディスク・アクセス数。デフォルト値は1000 SQL Threshold: number of disk reads
the statement made
i_parse_calls_th SQLが実行する解析コール数。デフォルト値は1000 SQL Threshold: number of parse
calls the statement made
i_buffer_gets_th SQLがアクセスされたバッファのフロック取得数。デフォルト値は10000 SQL Threshold: number of buffer
gets the statement made
i_sharable_mem_th SQLの共有可能メモリ量(単位:byte)。デフォルトは1048576バイト SQL Threshold: amount of sharable
memory
i_version_count_th SQLの種類の数。デフォルト値は20 SQL Threshold: number of versions
of a SQL statement
i_seg_log_reads_th セグメントに対する論理読み込み数。デフォルト値は10000 Segment statistic Threshold: number
of logical reads on a segment.
i_seg_phy_reads_th セグメントに対する物理読み込み数。デフォルト値は1000 Segment statistic Threshold: number
of physical reads on a segment.
i_seg_buff_busy_th セグメントに対するバッファビジー待機数。デフォルト値は100 Segment statistic Threshold: number
of buffer busy waits for a segment.
i_seg_rowlock_w_th セグメントに対する行ロック待機数。デフォルト値は100 Segment statistic Threshold: number
of row lock waits for a segment.
i_seg_itl_waits_th セグメントに対するITL待機数。デフォルト値は100 Segment statistic Threshold: number
of ITL waits for a segment.
i_seg_cr_bks_sd_th セグメントに対する、指定インスタンスのCRブロック転送数。デフォル
ト値は1000(RAC環境のみ)
Segment statistic Threshold: number
of Consistent Reads blocks served by
the instance for the segment*.
i_seg_cu_bks_sd_th セグメントに対する、指定インスタンスのカレントブロック転送数。デフ
ォルト値は1000(RAC環境のみ)
Segment statistic Threshold: number
of CUrrent blocks served by the
instance for the segment*.

今設定されてあるパラメータ値の確認はSTATS$STATSPACK_PARAMETERより確認できる。

コード表示

select * from STATS$STATSPACK_PARAMETER;
Name Null? Type
DBID NOT NULL NUMBER
INSTANCE_NUMBER NOT NULL NUMBER
SESSION_ID NOT NULL NUMBER
SNAP_LEVEL NOT NULL NUMBER
NUM_SQL NOT NULL NUMBER
EXECUTIONS_TH NOT NULL NUMBER
PARSE_CALLS_TH NOT NULL NUMBER
DISK_READS_TH NOT NULL NUMBER
BUFFER_GETS_TH NOT NULL NUMBER
SHARABLE_MEM_TH NOT NULL NUMBER
VERSION_COUNT_TH NOT NULL NUMBER
PIN_STATSPACK NOT NULL VARCHAR2(10)
ALL_INIT NOT NULL VARCHAR2(5)
LAST_MODIFIED DATE
UCOMMENT VARCHAR2(160)
JOB NUMBER
SEG_PHY_READS_TH NOT NULL NUMBER
SEG_LOG_READS_TH NOT NULL NUMBER
SEG_BUFF_BUSY_TH NOT NULL NUMBER
SEG_ROWLOCK_W_TH NOT NULL NUMBER
SEG_ITL_WAITS_TH NOT NULL NUMBER
SEG_CR_BKS_RC_TH NOT NULL NUMBER
SEG_CU_BKS_RC_TH NOT NULL NUMBER
OLD_SQL_CAPTURE_MTH NOT NULL VARCHAR2(10)

hard parseに時間のかかるsqlを実行してみる。

sqlは以下の参考文献より拝借。

Hard Parseに時間が掛かるお手軽なSQLを作ってみる。(Oracle Database)

コード表示

WITH a AS (
	SELECT /*+ inline */
		1
	FROM
		dual
		, dual
		, dual
		, dual
		, dual
		, dual
		, dual
		, dual
		, dual
		, dual
), b AS (
	SELECT /*+ inline */
		1
	FROM
		a
		, a
		, a
		, a
		, a
		, a
		, a
		, a
		, a
		, a
) SELECT
	1
  FROM
	b
	, b
	, b;

v$sysstatでsql実行前の状況を確認してみる。

9.96 V$SYSSTAT

システム全体でのサマリを参照することができる。

コード表示

col name for a24
col value for 999999999999
select * from v$sysstat where NAME like 'parse%';
コード表示

AINE@pdb1> col name for a24
AINE@pdb1> col value for 999999999999
AINE@pdb1> select * from v$sysstat where NAME like 'parse%';

   STATISTIC# NAME                             CLASS         VALUE       STAT_ID        CON_ID
------------- ------------------------ ------------- ------------- ------------- -------------
         1892 parse time cpu                      64         12981     206905303             3
         1893 parse time elapsed                  64         13826    1431595225             3
         1894 parse count (total)                 64        784665      63887964             3
         1895 parse count (hard)                  64         33672     143509059             3
         1896 parse count (failures)              64          1793    1118776443             3
         1897 parse count (describe)              64           161     469016317             3

6 rows selected.

Elapsed: 00:00:00.01

hard parseの回数を確認する。

sqlトレースファイルをtkprofで整形して確認する。

処理 sql
検索系・更新系 alter system flush shared_pool;
検索系・更新系 alter system flush buffer_cache;
更新系 alter system checkpoint;
更新系 alter system switch logfile;
コード表示

col name for a24;
col value for a12;
select name,value from V$PARAMETER where NAME like '%tracefile_identifier%';
alter session set tracefile_identifier='test_trace';
col name for a24;
col value for a12;
select name,value from V$PARAMETER where NAME like '%sql_trace%';
ALTER SESSION SET sql_trace=TRUE;
alter system checkpoint;
alter system switch logfile;
alter system flush shared_pool;
alter system flush buffer_cache;
ALTER SESSION SET sql_trace=FASLE;
コード表示

[oracle@6898242bcdd5 ~]$ sqlplus aine/ORACLE_PWD@pdb1

SQL*Plus: Release 18.0.0.0.0 - Production on Sun Jan 27 11:52:06 2019
Version 18.3.0.0.0

Copyright (c) 1982, 2018, Oracle.  All rights reserved.

Last Successful login time: Sun Jan 27 2019 11:38:51 +09:00

Connected to:
Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.3.0.0.0

AINE@pdb1> col name for a24;
AINE@pdb1> col value for a12;
AINE@pdb1> select name,value from V$PARAMETER where NAME like '%tracefile_identifier%';

NAME                     VALUE
------------------------ ------------
tracefile_identifier

1 row selected.

Elapsed: 00:00:00.01
AINE@pdb1> alter session set tracefile_identifier='test_trace';

Session altered.

Elapsed: 00:00:00.00
AINE@pdb1> select name,value from V$PARAMETER where NAME like '%tracefile_identifier%';

NAME                     VALUE
------------------------ ------------
tracefile_identifier     test_trace

1 row selected.

Elapsed: 00:00:00.01
AINE@pdb1> col name for a24;
AINE@pdb1> col value for a12;
AINE@pdb1> select name,value from V$PARAMETER where NAME like '%sql_trace%';

NAME                     VALUE
------------------------ ------------
sql_trace                FALSE

1 row selected.

Elapsed: 00:00:00.02
AINE@pdb1> ALTER SESSION SET sql_trace=TRUE;

Session altered.

Elapsed: 00:00:00.01
AINE@pdb1> select name,value from V$PARAMETER where NAME like '%sql_trace%';

NAME                     VALUE
------------------------ ------------
sql_trace                TRUE

1 row selected.

Elapsed: 00:00:00.01
AINE@pdb1> alter system flush shared_pool;

System altered.

Elapsed: 00:00:00.21
AINE@pdb1> alter system flush buffer_cache;

System altered.

Elapsed: 00:00:00.03
AINE@pdb1> host ls -lt
total 212
-rw-r--r--. 1 oracle oinstall    265 Jan 27 11:41 test.sql
-rw-r--r--. 1 oracle oinstall 162575 Jan 26 14:39 test_statspack.lst
-rw-r--r--. 1 oracle oinstall    237 Jan 26 09:41 spcpkg.lis
-rw-r--r--. 1 oracle oinstall  12864 Jan 26 09:41 spctab.lis
-rw-r--r--. 1 oracle oinstall   4570 Jan 26 09:41 spcusr.lis
drwxr-xr-x. 2 oracle oinstall   4096 Jan 20 10:58 rlwrap-extensions
-rw-r--r--. 1 root   root      15080 Jan 20 10:52 epel-release-7-11.noarch.rpm
lrwxrwxrwx. 1 root   root         26 Jan 19 23:19 setPassword.sh -> /opt/oracle/setPassword.sh

AINE@pdb1> host vim test.sql
AINE@pdb1> @test.sql

別セッションにてtraceファイルが吐かれているかを確認する。

コード表示

[oracle@6898242bcdd5 ~]$ cd /opt/oracle/diag/rdbms/orcl/ORCL/trace
[oracle@6898242bcdd5 trace]$ ll -lt | grep test_trace
-rw-r-----. 1 oracle oinstall  551104 Jan 27 12:00 ORCL_ora_3725_test_trace.trc
-rw-r-----. 1 oracle oinstall   84736 Jan 27 12:00 ORCL_ora_3725_test_trace.trm
-rw-r--r--. 1 oracle oinstall   60233 Jan 27 09:43 ORCL_ora_29903_test_trace.trc.tkprof
-rw-r-----. 1 oracle oinstall  395099 Jan 27 09:20 ORCL_ora_29903_test_trace.trc
-rw-r-----. 1 oracle oinstall   31189 Jan 27 09:20 ORCL_ora_29903_test_trace.trm
[oracle@6898242bcdd5 trace]$ tkprof ORCL_ora_3725_test_trace.trc ORCL_ora_3725_test_trace.trc.tkprof

TKPROF: Release 18.0.0.0.0 - Development on Sun Jan 27 12:02:46 2019

Copyright (c) 1982, 2018, Oracle and/or its affiliates.  All rights reserved.


[oracle@6898242bcdd5 trace]$ ll -lt | grep test_trace
-rw-r--r--. 1 oracle oinstall  161006 Jan 27 12:02 ORCL_ora_3725_test_trace.trc.tkprof
-rw-r-----. 1 oracle oinstall  551104 Jan 27 12:00 ORCL_ora_3725_test_trace.trc
-rw-r-----. 1 oracle oinstall   84736 Jan 27 12:00 ORCL_ora_3725_test_trace.trm
-rw-r--r--. 1 oracle oinstall   60233 Jan 27 09:43 ORCL_ora_29903_test_trace.trc.tkprof
-rw-r-----. 1 oracle oinstall  395099 Jan 27 09:20 ORCL_ora_29903_test_trace.trc
-rw-r-----. 1 oracle oinstall   31189 Jan 27 09:20 ORCL_ora_29903_test_trace.trm

コード表示

[oracle@6898242bcdd5 trace]$ cat -n ORCL_ora_3725_test_trace.trc.tkprof | head -n 2062 | tail -`expr 2062 - 1407 + 1`
  1407  ********************************************************************************
  1408
  1409  WITH a AS (
  1410          SELECT /*+ inline */
  1411                  1
  1412          FROM
  1413                  dual
  1414                  , dual
  1415                  , dual
  1416                  , dual
  1417                  , dual
  1418                  , dual
  1419                  , dual
  1420                  , dual
  1421                  , dual
  1422                  , dual
  1423  ), b AS (
  1424          SELECT /*+ inline */
  1425                  1
  1426          FROM
  1427                  a
  1428                  , a
  1429                  , a
  1430                  , a
  1431                  , a
  1432                  , a
  1433                  , a
  1434                  , a
  1435                  , a
  1436                  , a
  1437  ) SELECT
  1438          1
  1439    FROM
  1440          b
  1441          , b
  1442          , b
  1443
  1444  call     count       cpu    elapsed       disk      query    current        rows
  1445  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1446  Parse        1     18.05      18.05          0          0          0           0
  1447  Execute      1      0.00       0.00          0          0          0           0
  1448  Fetch        2      0.00       0.00          0          0          0           1
  1449  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1450  total        4     18.05      18.05          0          0          0           1
********************************************************************************

サマリ。Parse行のcpu列とelapsed列に着目。

コード表示

  1444  call     count       cpu    elapsed       disk      query    current        rows
  1445  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1446  Parse        1     18.05      18.05          0          0          0           0
  1447  Execute      1      0.00       0.00          0          0          0           0
  1448  Fetch        2      0.00       0.00          0          0          0           1
  1449  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1450  total        4     18.05      18.05          0          0          0           1

v$sysstatでsql実行後の状況を確認してみる。

9.96 V$SYSSTAT

システム全体でのサマリを参照することができる。

コード表示

col name for a24
col value for 999999999999
select * from v$sysstat where NAME like 'parse%';
コード表示

AINE@pdb1> col name for a24
AINE@pdb1> col value for 999999999999
AINE@pdb1> select * from v$sysstat where NAME like 'parse%';

   STATISTIC# NAME                             CLASS         VALUE       STAT_ID        CON_ID
------------- ------------------------ ------------- ------------- ------------- -------------
         1892 parse time cpu                      64         14793     206905303             3
         1893 parse time elapsed                  64         15639    1431595225             3
         1894 parse count (total)                 64        784920      63887964             3
         1895 parse count (hard)                  64         33797     143509059             3
         1896 parse count (failures)              64          1793    1118776443             3
         1897 parse count (describe)              64           161     469016317             3

6 rows selected.

Elapsed: 00:00:00.02
AINE@pdb1> host expr 33797 - 33672
125

tkprofで加工されたsqlトレースファイルに出力されている項目に関して

コード表示

  1444  call     count       cpu    elapsed       disk      query    current        rows
  1445  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1446  Parse        1     18.05      18.05          0          0          0           0
  1447  Execute      1      0.00       0.00          0          0          0           0
  1448  Fetch        2      0.00       0.00          0          0          0           1
  1449  ------- ------  -------- ---------- ---------- ---------- ----------  ----------
  1450  total        4     18.05      18.05          0          0          0           1

トレース統計(表側)

項目名 概要
Parse もろもろのチェックを行って、SQLを実行計画に変換する。
Execute Oracleによって実行されるSQL。INSERT文、UPDATE文、DELETE文、SFIECT文、MERGE文とかとか。
Fetch 問い合わせを満たす行数。

トレース統計(表頭)

項目名 概要
count 表側の項目に対する回数。
cpu 表側の項目に対するcpuの処理時間の合計(秒)。TIMED_STATISTICSがONになっている場合のみ。
elapsed 表側の項目に対する経過時間の合計(秒)。TIMED_STATISTICSがONになっている場合のみ。
disk ディスク上のデータファイルから物理読み込みしたデータブロックの総数。
query 一貫モードで取得されたバッファの総数。SELECT文は一貫モード。
current 一貫モードで取得されたバッファの総数。DML文は現行モード。
rows 処理された行数。サブクエリの総数は含まない。

トレース統計(実行計画)

項目名 概要
cr 行単位での結果に対して、バッファから読み取ったブロック総数
pr 行単位での結果に対して、物理読み込みブロックの総数
pw 行単位での結果に対して、物理書き込みブロックの総数
time 処理にかかった時間(単位:マイクロ秒)

Leave a Reply

Your email address will not be published. Required fields are marked *