使用10046事件来跟踪解决oracle的许多问题,是非常常用的手段,但是实际上可能出现跟踪的sql执行计划与原来不同的情况,自己应该引起注意.
测试如下:
1.测试环境建立:
SQL> select * from v$version ;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
PL/SQL Release 11.2.0.1.0 - Production
CORE 11.2.0.1.0 Production
TNS for Linux: Version 11.2.0.1.0 - Production
NLSRTL Version 11.2.0.1.0 - Production
SQL> create table t as select rownum id , 'test' name from dual connect by level
Table created.
SQL> insert into t select 1e4+1 ,'book' from dual connect by level
10000 rows created.
SQL> create index i_t_id on t(id);
Index created.
--可以发现id分布不均匀,而且10001占了50%.建立直方图看看.
SQL> exec dbms_stats.gather_table_stats(ownname=>user,tabname=>'T',cascade=>true,method_opt=>'for all columns size 254');
PL/SQL procedure successfully completed.
2.开始测试:
SQL> variable v_id number ;
SQL> exec :v_id := 42;
PL/SQL procedure successfully completed.
SQL> select * from t where id=:v_id;
ID NAME
---------- ----
42 test
SQL> @dpc ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID d9msgvzah6u4p, child number 0
-------------------------------------
select * from t where id=:v_id
Plan hash value: 4153437776
--------------------------------------------------------------------
| Id | Operation | Name | E-Rows | Cost (%CPU)|
--------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | 2 (100)|
| 1 | TABLE ACCESS BY INDEX ROWID| T | 1 | 2 (0)|
|* 2 | INDEX RANGE SCAN | I_T_ID | 1 | 1 (0)|
--------------------------------------------------------------------
Peeked Binds (identified by position):
--------------------------------------
1 - (NUMBER): 42
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("ID"=:V_ID)
Note
-----
- Warning: basic plan statistics not available. These are only collected when:
* hint 'gather_plan_statistics' is used for the statement or
* parameter 'statistics_level' is set to 'ALL', at session or system level
30 rows selected.
将select * from t where id=:v_id;执行多次,避免ACS的影响.(我使用的是11G).
SQL> select sql_text,sql_id,child_number,executions from v$sql where sql_id='d9msgvzah6u4p';
SQL_TEXT SQL_ID CHILD_NUMBER EXECUTIONS
---------------------------------------- ------------- ------------ ----------
select * from t where id=:v_id d9msgvzah6u4p 0 9
3.打开10046跟踪看看:
SQL> exec :v_id := 10001;
PL/SQL procedure successfully completed.
SQL> alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL> select * from t where id=:v_id;
...
SQL> alter session set events '10046 trace name context off';
SQL> select sql_text,sql_id,child_number,executions from v$sql where sql_id='d9msgvzah6u4p';
SQL_TEXT SQL_ID CHILD_NUMBER EXECUTIONS
---------------------------------------- ------------- ------------ ----------
select * from t where id=:v_id d9msgvzah6u4p 0 9
select * from t where id=:v_id d9msgvzah6u4p 1 1
--查看视图V$SQL,发现生成了新的子光标.
SQL> select * from table(dbms_xplan.display_cursor('d9msgvzah6u4p',1,'ALLSTATS LAST PEEKED_BINDS cost'));
PLAN_TABLE_OUTPUT
-----------------------------------------------------------------------------------------------------------
SQL_ID d9msgvzah6u4p, child number 1
-------------------------------------
select * from t where id=:v_id
Plan hash value: 1601196873
-------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 14 (100)| 10000 |00:00:00.01 | 96 |
|* 1 | TABLE ACCESS FULL| T | 1 | 10039 | 14 (0)| 10000 |00:00:00.01 | 96 |
-------------------------------------------------------------------------------------------------
Peeked Binds (identified by position):
--------------------------------------
1 - (NUMBER): 10001
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=:V_ID)
23 rows selected.
--查看跟踪文件也可以发现,执行计划发生了变化:
SQL ID: d9msgvzah6u4p
Plan Hash: 1601196873
select *
from
t where id=:v_id
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 51 0.00 0.00 0 96 0 10000
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 53 0.00 0.01 0 96 0 10000
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Rows Row Source Operation
------- ---------------------------------------------------
10000 TABLE ACCESS FULL T (cr=96 pr=0 pw=0 time=11152 us cost=14 size=90351 card=10039)
4.看看什么导致的光标不能共享:
SQL> @share d9msgvzah6u4p
SQL_TEXT = select * from t where id=:v_id
SQL_ID = d9msgvzah6u4p
ADDRESS = 00000000DE2DC258
CHILD_ADDRESS = 00000000DE2DBE58
CHILD_NUMBER = 0
--------------------------------------------------
SQL_TEXT = select * from t where id=:v_id
SQL_ID = d9msgvzah6u4p
ADDRESS = 00000000DE2DC258
CHILD_ADDRESS = 00000000DE29D1B8
CHILD_NUMBER = 1
STATS_ROW_MISMATCH = Y
--------------------------------------------------
PL/SQL procedure successfully completed.
--可以发现实际上STATS_ROW_MISMATCH=Y.
也就是将在开启跟踪后,会话执行的SQL将不会重用以前的的执行计划，发生硬解析。由于硬解析时要发生绑定变量窥视，将会使硬解析产生的子游标，而这里由于
ID数据的分布变化,导致其执行计划可能发生了变化。
5.实际上这种情况很多:
比如设置optimizer_capture_sql_plan_baselines=true也会出现类似情况.
设置sql_trace =true等.
