[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(
'' ||
'' || d.internal_state || '' ||
'' || d.redundant || '' ||
'' || sys.dbms_spd_internal.get_spd_text(d.dir_id) ||
'' ||
'') 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 NEWNO{F(SYS.OBJ$) - F(SYS.X$KSPPCV) - F(SYS.X$KSPPI)}
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
来源:程序园用户自行投稿发布,如果侵权,请联系站长删除
免责声明:如果侵犯了您的权益,请联系站长,我们会及时删除侵权内容,谢谢合作! |