lfree 日志
[20250722]21c查詢dba_sql_plan_directives緩慢.txt - 动态 详情
--//無意中發現查詢dba_sql_plan_directives非常緩慢.而且測試環境僅僅返回141條記錄,竟然最少接近7秒，而執行計劃看不出問題。
--//分析看看究竟是什麼回事。
1.環境：
SYS@book01p> @ver2
==============================
PORT_STRING : x86_64/Linux 2.4.xx
VERSION : 21.0.0.0.0
BANNER : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID : 0
PL/SQL procedure successfully completed.
2.測試：
SYS@book01p> @ sl all
alter session set statistics_level = all;
Session altered.
SYS@book01p> set arraysize 200
SYS@book01p> set timing on
SYS@book01p> select * from dba_sql_plan_directives;
...
141 rows selected.
Elapsed: 00:00:52.10
--//查詢需要52秒才完成。
--//如果不打開statistics_level = all，僅僅7秒完成。
SYS@book01p> @ dpc '' '' ''
PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID 90u00yf1sth14, child number 0
-------------------------------------
select * from dba_sql_plan_directives
Plan hash value: 1298473468
----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem |
----------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 6 (100)| | 141 |00:00:00.01 | 12 | | | |
|* 1 | HASH JOIN | | 1 | 141 | 8178 | 6 (0)| 00:00:01 | 141 |00:00:00.01 | 12 | 1061K| 1061K| 1333K (0)|
| 2 | TABLE ACCESS FULL| OPT_DIRECTIVE$ | 1 | 141 | 6063 | 3 (0)| 00:00:01 | 141 |00:00:00.01 | 6 | | | |
| 3 | TABLE ACCESS FULL| OPT_FINDING$ | 1 | 148 | 2220 | 3 (0)| 00:00:01 | 148 |00:00:00.01 | 6 | | | |
----------------------------------------------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$352367AA
2 - SEL$352367AA / "D"@"SEL$3"
3 - SEL$352367AA / "F"@"SEL$4"
Predicate Information (identified by operation id):
---------------------------------------------------
1 - access("D"."F_ID"="F"."F_ID")
--//查詢計劃的執行時間僅僅不到1秒可以完成。而且邏輯讀很少。
SYS@book01p> @ ashtop sql_id,event sql_id='90u00yf1sth14' &day
no rows selected
--//利用ashtop查詢看不到任何等待事件。
SYS@book01p> @desc dba_sql_plan_directives;
Name Null? Type
------------------------------- -------- ----------------------------
1 DIRECTIVE_ID NOT NULL NUMBER
2 TYPE VARCHAR2(23)
3 ENABLED VARCHAR2(3)
4 STATE VARCHAR2(10)
5 AUTO_DROP VARCHAR2(3)
6 REASON VARCHAR2(36)
7 CREATED TIMESTAMP(6)
8 LAST_MODIFIED TIMESTAMP(6)
9 LAST_USED TIMESTAMP(9)
10 NOTES XMLTYPE
--//存在1個notes字段，類型XMLTYPE。
--//嘗試不包括notes字段：
select rownum,DIRECTIVE_ID , TYPE from dba_sql_plan_directives;
--//幾乎馬上完成。視乎只要不包括notes字段查詢飛快。視乎與是否訪問notes字段有關。
select rownum,DIRECTIVE_ID , TYPE, to_clob(NOTES) c60 from dba_sql_plan_directives;
--//如果加入notes，轉換成to_clob ,在sqlplus下出現1行1行輸出的特點，這個因為clob輸出的特點，fetch=1.
3.採用10046跟蹤看看。
--//退出重新登錄，設置arraysize=200.
@10046on 12
select * from dba_sql_plan_directives;
@10046off
$ tkprof /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_3992.trc
output = a
TKPROF: Release 21.0.0.0.0 - Development on Tue Jul 22 16:11:23 2025
Copyright (c) 1982, 2021, Oracle and/or its affiliates. All rights reserved.
--//查看a.prf文件：
SQL ID: 90u00yf1sth14 Plan Hash: 1298473468
select *
from
dba_sql_plan_directives
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 30 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.08 0.08 0 12 0 141
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.09 0.09 0 42 0 141
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 109
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
141 141 141 HASH JOIN (cr=12 pr=0 pw=0 time=1030 us starts=1 cost=6 size=8178 card=141)
141 141 141 TABLE ACCESS FULL OPT_DIRECTIVE$ (cr=6 pr=0 pw=0 time=104 us starts=1 cost=3 size=6063 card=141)
148 148 148 TABLE ACCESS FULL OPT_FINDING$ (cr=6 pr=0 pw=0 time=166 us starts=1 cost=3 size=2220 card=148)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PGA memory operation 10 0.00 0.00
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
********************************************************************************
--//可以看這條語句並沒有問題。
--//真正的問題在於遞歸的執行語句：
SQL ID: baf7nazb8svng Plan Hash: 3410245087
SELECT OWNER, OBJECT_NAME, SUBOBJECT_NAME, OBJECT_TYPE,
DECODE(EXTRACTVALUE(NOTES,'/obj_note/equality_predicates_only'), 'YES', 'E')
ALLEQ, DECODE(EXTRACTVALUE(NOTES,'/obj_note/simple_column_predicates_only')
, 'YES', 'C') ALLCOLS, DECODE(EXTRACTVALUE(NOTES,
'/obj_note/index_access_by_join_predicates'), 'YES', 'J') NLJNIX,
DECODE(EXTRACTVALUE(NOTES,'/obj_note/filter_on_joining_object'), 'YES', 'F')
FILTER, NUM_ROWS
FROM
SYS.DBA_SQL_PLAN_DIR_OBJECTS WHERE DIRECTIVE_ID = :B1 ORDER BY OBJECT_TYPE
DESC, OWNER, OBJECT_NAME, SUBOBJECT_NAME
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 141 0.01 0.01 0 0 0 0
Fetch 141 5.92 5.96 0 489318 0 397
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 282 5.94 5.98 0 489318 0 397
--//執行時間需要6秒。
--//注意看執行次數，執行141次。
--//注意遞歸訪問的是SYS.DBA_SQL_PLAN_DIR_OBJECTS。
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: SYS (recursive depth: 1)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
PGA memory operation 45 0.00 0.00
********************************************************************************
SYS@book> @ ashtop sql_id,event,time_model_name sql_id='baf7nazb8svng' &day
Total Distinct Distinct Distinct
Seconds AAS %This SQL_ID EVENT TIME_MODEL_NAME FIRST_SEEN LAST_SEEN Execs Seen Tstamps Execs Seen1
--------- ------- ------- ------------- ---------------- ---------------- ------------------- ------------------- ---------- -------- -----------
24 .0 100% | baf7nazb8svng SQL_EXECUTION 2025-07-22 16:06:01 2025-07-22 16:07:14 24 24 24
--//可以簡單驗證：
SYS@book> select sql_id,executions from v$sqlarea where sql_id='baf7nazb8svng';
SQL_ID EXECUTIONS
------------- ----------
baf7nazb8svng 705
select * from dba_sql_plan_directives;
SYS@book> select sql_id,executions from v$sqlarea where sql_id='baf7nazb8svng';
SQL_ID EXECUTIONS
------------- ----------
baf7nazb8svng 846
--//846-705 = 141,確實是141次。
3.繼續分析：
SYS@book> @ v2 dba_sql_plan_directives
Show SQL text of views matching "dba_sql_plan_directives"...
V_OWNER VIEW_NAME TEXT
------------------------- ------------------------------ --------------------------------------------------------------------
SYS DBA_SQL_PLAN_DIRECTIVES SELECT
d.dir_id,
d.type,
d.enabled,
case when d.internal_state = 'HAS_STATS' or d.redundant = 'YES'
then 'SUPERSEDED'
when d.internal_state in ('NEW', 'MISSING_STATS', 'PERMANENT')
then 'USABLE'
else 'UNKNOWN' end case,
d.auto_drop,
f.reason,
d.created,
d.last_modified,
d.last_used,
xmltype(
'<spd_note>' ||
'<internal_state>' || d.internal_state || '</internal_state>' ||
'<redundant>' || d.redundant || '</redundant>' ||
'<spd_text>' || sys.dbms_spd_internal.get_spd_text(d.dir_id) ||
'</spd_text>' ||
'</spd_note>') notes
FROM
sys."_BASE_OPT_DIRECTIVE" d,
sys."_BASE_OPT_FINDING" f
WHERE d.f_id = f.f_id
--//注：在cdb層面查詢。sys."_BASE_OPT_DIRECTIVE" d, sys."_BASE_OPT_FINDING" f也是視圖,不再貼出。
--//如果仔細看notes字段的定義存在sys.dbms_spd_internal.get_spd_text(d.dir_id)函數調用。
SYS@book> @ desc_proc sys dbms_spd_internal get_spd_text
INPUT OWNER PACKAGE_NAME OBJECT_NAME
sample : @desc_proc sys dbms_stats gather_%_stats
OWNER PACKAGE_NAME OBJECT_NAME SEQUENCE ARGUMENT_NAME DATA_TYPE IN_OUT DEFAULTED
---------- ----------------- ------------- ---------- ------------- --------- --------- ----------
SYS DBMS_SPD_INTERNAL GET_SPD_TEXT 1 CLOB OUT N
2 DIRID NUMBER IN N
--//可以看出正是這個函數調用導致訪問dba_sql_plan_directives，涉及notes字段時執行緩慢。
--//這樣相當於每訪問1條記錄都需要調用sys.dbms_spd_internal.get_spd_text(d.dir_id)函數。
--//單獨做1個跟蹤就可以驗證：
SYS@book01p> set numw 20
SYS@book01p> select DIRECTIVE_ID,NOTES c160 from dba_sql_plan_directives where rownum=1;
DIRECTIVE_ID C160
-------------------- ----------------------------------------------------------------------------------------------------------------------------------------------------------------
13972766652855831375 <spd_note><internal_state>NEW</internal_state><redundant>NO</redundant><spd_text>{F(SYS.OBJ$) - F(SYS.X$KSPPCV) - F(SYS.X$KSPPI)}</spd_text></spd_note>
SYS@book01p> @ ti
New tracefile_identifier = /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_4624_0001.trc
SYS@book01p> @ 10046on 12
Session altered.
SYS@book01p> select sys.dbms_spd_internal.get_spd_text(13972766652855831375) c60 from dual ;
C60
------------------------------------------------------------
{F(SYS.OBJ$) - F(SYS.X$KSPPCV) - F(SYS.X$KSPPI)}
SYS@book01p> @ 10046off
Session altered.
$ ./extractsql.sh /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_4624_0001.trc
select sys.dbms_spd_internal.get_spd_text(13972766652855831375) c60 from dual
SELECT OWNER, OBJECT_NAME, SUBOBJECT_NAME, OBJECT_TYPE,
DECODE(EXTRACTVALUE(NOTES,
'/obj_note/equality_predicates_only'), 'YES', 'E') ALLEQ,
DECODE(EXTRACTVALUE(NOTES,
'/obj_note/simple_column_predicates_only'), 'YES', 'C') ALLCOLS,
DECODE(EXTRACTVALUE(NOTES,
'/obj_note/index_access_by_join_predicates'), 'YES', 'J') NLJNIX,
DECODE(EXTRACTVALUE(NOTES,
'/obj_note/filter_on_joining_object'), 'YES', 'F') FILTER, NUM_ROWS
FROM SYS.DBA_SQL_PLAN_DIR_OBJECTS
WHERE DIRECTIVE_ID = :B1
ORDER BY OBJECT_TYPE DESC, OWNER, OBJECT_NAME, SUBOBJECT_NAME
--//可以發現遞歸調用該sql語句。注做了格式化處理。
select toid from type$ where package_obj#=:1 and typ_name=:2
...
alter session set events '10046 trace name context off'
--//單獨執行返回如下：
SELECT OWNER
,OBJECT_NAME
,SUBOBJECT_NAME
,OBJECT_TYPE
,DECODE (EXTRACTVALUE (NOTES, '/obj_note/equality_predicates_only'), 'YES', 'E') ALLEQ
,DECODE (EXTRACTVALUE (NOTES, '/obj_note/simple_column_predicates_only'), 'YES', 'C') ALLCOLS
,DECODE (EXTRACTVALUE (NOTES, '/obj_note/index_access_by_join_predicates'), 'YES', 'J') NLJNIX
,DECODE (EXTRACTVALUE (NOTES, '/obj_note/filter_on_joining_object'), 'YES', 'F') FILTER
,NUM_ROWS
FROM SYS.DBA_SQL_PLAN_DIR_OBJECTS
WHERE DIRECTIVE_ID = 13972766652855831375
ORDER BY OBJECT_TYPE DESC
,OWNER
,OBJECT_NAME
,SUBOBJECT_NAME
OWNER OBJECT_NAME SUBOBJECT_NAME OBJECT_TYPE A A N FILTER NUM_ROWS
----- ----------- --------------- ----------- - - - ------------------------------ --------------------
SYS OBJ$ TABLE F
SYS X$KSPPCV TABLE F
SYS X$KSPPI TABLE F
SYS@book01p> select sys.dbms_spd_internal.get_spd_text(13972766652855831375) c60 from dual ;
C60
------------------------------------------------------------
{F(SYS.OBJ$) - F(SYS.X$KSPPCV) - F(SYS.X$KSPPI)}
--//基本將前面的3行變成1行拼接成字串輸出。
4.小結：
--//查詢dba_sql_plan_directives緩慢的主要原因在於視圖定義裏面包含sys.dbms_spd_internal.get_spd_text(d.dir_id)函數調用，相當於執行
--//每行都執行1次：
SELECT OWNER, OBJECT_NAME, SUBOBJECT_NAME, OBJECT_TYPE,
DECODE(EXTRACTVALUE(NOTES,'/obj_note/equality_predicates_only'), 'YES', 'E')
ALLEQ, DECODE(EXTRACTVALUE(NOTES,'/obj_note/simple_column_predicates_only')
, 'YES', 'C') ALLCOLS, DECODE(EXTRACTVALUE(NOTES,
'/obj_note/index_access_by_join_predicates'), 'YES', 'J') NLJNIX,
DECODE(EXTRACTVALUE(NOTES,'/obj_note/filter_on_joining_object'), 'YES', 'F')
FILTER, NUM_ROWS
FROM
SYS.DBA_SQL_PLAN_DIR_OBJECTS WHERE DIRECTIVE_ID = :B1 ORDER BY OBJECT_TYPE
DESC, OWNER, OBJECT_NAME, SUBOBJECT_NAME
