找回密码
 立即注册
首页 业界区 安全 [20250722]21c查询dba_sql_plan_directives缓慢.txt

[20250722]21c查询dba_sql_plan_directives缓慢.txt

森萌黠 前天 20:18
[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


来源:程序园用户自行投稿发布,如果侵权,请联系站长删除
免责声明:如果侵犯了您的权益,请联系站长,我们会及时删除侵权内容,谢谢合作!
您需要登录后才可以回帖 登录 | 立即注册