[Oracle] autotrace traceonly explain で表示されるSQL_IDが変わってしまう

SQL_ID取得

[Oracle] SQL*PlusでSQL_IDを取得するでは、sqlplusの set feedback on sql_id を使って特定SQLのSQLIDを取得する方法を紹介した。

SQL> set feedback on sql_id
SQL> select sysdate from dual;

SYSDATE
---------
15-AUG-20

1 row selected.

SQL_ID: 7h35uxf5uhmm1

オートトレース

autotrace traceonly explain にすると、SQL_IDが結果の先頭行に表示される。

SQL> set autotrace traceonly explain
SQL> select sysdate from dual;
SQL_ID: 7h35uxf5uhmm1
SQL_ID: g72kdvcacxvtf

Execution Plan
----------------------------------------------------------
SQL_ID: 7a9pkyu8zp8bc
Plan hash value: 1388734953

-----------------------------------------------------------------
| Id  | Operation        | Name | Rows  | Cost (%CPU)| Time     |
-----------------------------------------------------------------
|   0 | SELECT STATEMENT |      |     1 |     2   (0)| 00:00:01 |
|   1 |  FAST DUAL       |      |     1 |     2   (0)| 00:00:01 |
-----------------------------------------------------------------
SQL_ID: 3s1hh8cvfan6w

SQL_ID: g72kdvcacxvtf

traceonly explainではない、通常のオートトレースでもやってみよう。

SQL> set autotrace on

SYSDATE
---------
15-AUG-20

1 row selected.

SQL_ID: 7h35uxf5uhmm1
SQL_ID: g72kdvcacxvtf

Execution Plan
----------------------------------------------------------
SQL_ID: 7a9pkyu8zp8bc
Plan hash value: 1388734953

-----------------------------------------------------------------
| Id  | Operation        | Name | Rows  | Cost (%CPU)| Time     |
-----------------------------------------------------------------
|   0 | SELECT STATEMENT |      |     1 |     2   (0)| 00:00:01 |
|   1 |  FAST DUAL       |      |     1 |     2   (0)| 00:00:01 |
-----------------------------------------------------------------
SQL_ID: 3s1hh8cvfan6w

SQL_ID: g72kdvcacxvtf

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          0  consistent gets
          0  physical reads
          0  redo size
        579  bytes sent via SQL*Net to client
        366  bytes received via SQL*Net from client
          3  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

1 row selected. に続くトレース結果の先頭行にSQL_IDが表示されている。

共有プールをクリア

いずれも先頭に SQL_ID: 7h35uxf5uhmm1 が表示されていて、これが select sysdate from dual のSQL_IDとなっている。
ところが、共有プールをクリアしてから set autotrace traceonly explain で実行すると結果が変わってくる。

SQL> alter system flush shared_pool;

System FLUSHが変更されました。

SQL> set autotrace traceonly explain
SQL> select sysdate from dual;
SQL_ID: g72kdvcacxvtf
SQL_ID: g72kdvcacxvtf

Execution Plan
----------------------------------------------------------
SQL_ID: 7a9pkyu8zp8bc
Plan hash value: 1388734953

-----------------------------------------------------------------
| Id  | Operation        | Name | Rows  | Cost (%CPU)| Time     |
-----------------------------------------------------------------
|   0 | SELECT STATEMENT |      |     1 |     2   (0)| 00:00:01 |
|   1 |  FAST DUAL       |      |     1 |     2   (0)| 00:00:01 |
-----------------------------------------------------------------
SQL_ID: 3s1hh8cvfan6w

SQL_ID: g72kdvcacxvtf

結果の先頭行が SQL_ID: 7h35uxf5uhmm1 ではなくなっている。

SQLを実際に実行しているか？

v$sql の実行回数を見ると

SQL> set feedback off
SQL> set autotrace off
SQL> select executions from v$sql where sql_id = '7h35uxf5uhmm1';

EXECUTIONS
----------
         0

select sysdate from dual の実行回数が0回になっている。

SQL> select executions from v$sql where sql_id = '7h35uxf5uhmm1';

EXECUTIONS
----------
         0

当然、通常はSQLを実行する度にexecutionsの値が増えていく。

SQL> select from sysdate from dual;

SYSDATE
---------
15-AUG-20
SQL> select executions from v$sql where sql_id = '7h35uxf5uhmm1';

EXECUTIONS
----------
         1
SQL> select from sysdate from dual;

SYSDATE
---------
15-AUG-20
SQL> select executions from v$sql where sql_id = '7h35uxf5uhmm1';

EXECUTIONS
----------
         2

これは autotrace traceonly explain ではSQLの実行計画は生成するが、実際にはSQLを実行しないことが原因のようだ。

select以外

ちなみに、autotrace traceonly explain でもselect以外のinsert, update, deleteは実際にSQLが実行されてしまうので、要注意。