[翻译]——Why my execution plan is not in AWR

发布时间 2023-09-11 23:01:42作者: 潇湘隐者

为什么我的执行计划不在AWR中呢?本文是Why my execution plan is not in AWR?[1]的翻译,如有翻译不对或翻译不当的地方,敬请指出不足

前一周,我参加“使用AWR报告诊断 Oracle RAC 性能”的网络研讨会时关注到一个问题,有很多人提出了一个问题,为什么他们的SQL_ID存在于dba_hist_active_sess_history (AWR) 中,但他们却无法通过SQL_ID从AWR中获取其相应的执行计划。这是在短短几个月内,我第三次看到有人提出这个了问题。现在是时候回答这个问题了。

为了回答这个问题,我们需要知道 dba_hist_active_sess_history 是从gvsql、v$version 等)获取数据。

在这种情况下,标记为复制到AWR中的行(记录)从 gvsql、v$session 等)仅在 AWR 采样时间(通常默认为每小时,跟AWR的设置有关系)转储到 AWR 历史表(dba_hist_sqlstat 等)中。

此外,你知道 Oracle不会像处理vsql、v$session 和其他性能动态视图的数据转储到AWR中(flushing data)。ASH中刷新数据的频率很大程度上取决于_ash_size参数值定义的大小

SQL> @pd _ash_size
Show all parameters and session values from x$ksppi/x$ksppcv...
 
NAME       VALUE     DESCRIPTION
 ---------- --------- -------------------------------------------------------------
 _ash_size  1048618   To set the size of the in-memory Active Session History buffers

当然,它这还取决于ASH 承受的压力有多大,什么情况下刷出数据。

SQL> select
        inst_id
       ,total_size/power(1024,2) MB
       ,awr_flush_emergency_count
     from gv$ash_info;  2    3    4    5
 
   INST_ID         MB AWR_FLUSH_EMERGENCY_COUNT
---------- ---------- -------------------------
         1          4                         0

但是,通常,在现实运行的系统当中, v$active_session_history 几乎总是保留超过几个小时的数据(有时甚至是一整天),因此,Oracle 将所有标记的ASH 记录 ( is_awr_sample ) 转储到 dba_hist_active_sess_history 中,而不会有任何数据丢失。

另一方面,您不能忽视其他动态性能视图刷出数据遵循了完全不同的算法规则。因此,很可能出现这么一种情况,虽然 sql_id 以相对较小的延迟转储到 dba_hist_active_sess_history 中,但在一小时后生成AWR 快照时,相同的 sql_id的记录可能已经从v$sql中被刷出去了。这就是为什么dba_hist_active_sess_history 中存在的 sql_id 无法从AWR中获取执行计划的原因。

让我们用一个简单的模型来演示这一点:

create table t1
  as
  with generator as (
      select  --+ materialize
          rownum id
      from dual
      connect by
          level <= 10000)
  select
      rownum                  id,
      trunc(dbms_random.value(1,1000))    n1,
      lpad(rownum,10,'0') small_vc,
      rpad('x',100)       padding
  from
      generator   v1,
      generator   v2
  where
      rownum <= 1000000;
 
create index t1_n1 on t1(id, n1);
  
create table t2
   as
   with generator as (
       select  --+ materialize
           rownum id
       from dual
       connect by
           level <= 10000)
   select
       rownum                  id,
       trunc(dbms_random.value(10001,20001))   x1,
       lpad(rownum,10,'0') small_vc,
       rpad('x',100)       padding
   from
       generator   v1,
       generator   v2
   where
       rownum <= 1000000;
  
create index t2_i1 on t2(x1);

我创建了两个带有索引的表并运行了下面查询语句

select *
   from t1 
 where id
   in (select id from t2 where x1 = 17335)
order by id;
 
93 rows selected.
 
Elapsed: 00:03:05.22

但是,在执行上述查询之前,我已将优化器模式从 all_rows 更改为first_rows,以便在按 id 对结果进行排序时使用昂贵的INDEX FULL SCAN来避免 order by 操作。

当查询语句运行时,我对 ASH 和 AWR 执行了以下查询,以查看转储是如何进行的:

SELECT    
    sample_time
   ,is_awr_sample
   ,COUNT(1)
FROM
    gv$active_session_history
WHERE
    sql_id = '069t64t6ws5mx'
AND  is_awr_sample = 'Y'  
GROUP BY
    sample_time
    ,is_awr_sample
order by sample_time ;
 
SAMPLE_TIME                   I   COUNT(1)
----------------------------- - ----------
26-JUN-21 03.17.29.878 PM     Y          1
26-JUN-21 03.17.40.117 PM     Y          1
26-JUN-21 03.17.50.357 PM     Y          1
26-JUN-21 03.18.00.598 PM     Y          1
26-JUN-21 03.18.10.839 PM     Y          1
26-JUN-21 03.18.21.141 PM     Y          1
26-JUN-21 03.18.31.510 PM     Y          1
26-JUN-21 03.18.41.750 PM     Y          1
26-JUN-21 03.18.51.991 PM     Y          1
26-JUN-21 03.19.02.229 PM     Y          1
26-JUN-21 03.19.12.470 PM     Y          1
26-JUN-21 03.19.22.709 PM     Y          1
26-JUN-21 03.19.32.949 PM     Y          1
26-JUN-21 03.19.43.188 PM     Y          1
26-JUN-21 03.19.53.493 PM     Y          1
 
8 rows selected.
 
SELECT
    sql_id,
    sample_time
FROM
    dba_hist_active_sess_history
WHERE
    sql_id = '069t64t6ws5mx'
ORDER BY
    2;
 
no rows selected
 
SQL> select * from table(dbms_xplan.display_awr('069t64t6ws5mx'));
 
no rows selected;

依此类推,直到本次查询结束

SELECT    
    sample_time
   ,is_awr_sample
   ,COUNT(1)
FROM
    gv$active_session_history
WHERE
    sql_id = '069t64t6ws5mx'
AND  is_awr_sample = 'Y'  
GROUP BY
    sample_time
    ,is_awr_sample
order by sample_time ;
 
 
SAMPLE_TIME                 I   COUNT(1)
--------------------------- - ----------
26-JUN-21 03.17.29.878 PM   Y          1
26-JUN-21 03.17.40.117 PM   Y          1
26-JUN-21 03.17.50.357 PM   Y          1
26-JUN-21 03.18.00.598 PM   Y          1
26-JUN-21 03.18.10.839 PM   Y          1
26-JUN-21 03.18.21.141 PM   Y          1
26-JUN-21 03.18.31.510 PM   Y          1
26-JUN-21 03.18.41.750 PM   Y          1
26-JUN-21 03.18.51.991 PM   Y          1
26-JUN-21 03.19.02.229 PM   Y          1
26-JUN-21 03.19.12.470 PM   Y          1
26-JUN-21 03.19.22.709 PM   Y          1
26-JUN-21 03.19.32.949 PM   Y          1
26-JUN-21 03.19.43.188 PM   Y          1
26-JUN-21 03.19.53.493 PM   Y          1
26-JUN-21 03.20.03.733 PM   Y          1
26-JUN-21 03.20.14.102 PM   Y          1
26-JUN-21 03.20.24.342 PM   Y          1
 
18 rows selected.
 
SELECT
    sql_id,
    sample_time
FROM
    dba_hist_active_sess_history
WHERE
    sql_id = '069t64t6ws5mx'
ORDER BY
    2;
 
SQL_ID        SAMPLE_TIME
------------- -----------------------------
069t64t6ws5mx 26-JUN-21 03.17.29.878 PM
069t64t6ws5mx 26-JUN-21 03.17.40.117 PM
069t64t6ws5mx 26-JUN-21 03.17.50.357 PM
069t64t6ws5mx 26-JUN-21 03.18.00.598 PM
069t64t6ws5mx 26-JUN-21 03.18.10.839 PM
069t64t6ws5mx 26-JUN-21 03.18.21.141 PM
069t64t6ws5mx 26-JUN-21 03.18.31.510 PM
069t64t6ws5mx 26-JUN-21 03.18.41.750 PM
069t64t6ws5mx 26-JUN-21 03.18.51.991 PM
069t64t6ws5mx 26-JUN-21 03.19.02.229 PM
069t64t6ws5mx 26-JUN-21 03.19.12.470 PM
069t64t6ws5mx 26-JUN-21 03.19.22.709 PM
069t64t6ws5mx 26-JUN-21 03.19.32.949 PM
069t64t6ws5mx 26-JUN-21 03.19.43.188 PM
069t64t6ws5mx 26-JUN-21 03.19.53.493 PM
069t64t6ws5mx 26-JUN-21 03.20.03.733 PM
069t64t6ws5mx 26-JUN-21 03.20.14.102 PM
069t64t6ws5mx 26-JUN-21 03.20.24.342 PM
 
18 rows selected.
 
SQL> select * from table(dbms_xplan.display_awr('069t64t6ws5mx'));
 
no rows selected

可以看到,只要下一次AWR快照还没有生成,AWR中就没有对应的执行计划:

select
   snap_id,
   to_char(begin_interval_time, 'dd/mm/yyyy hh24:mi:ss'begin
  ,to_char(end_interval_time, 'dd/mm/yyyy hh24:mi:ss'end
from
   dba_hist_snapshot
order by 1 desc
fetch first 5 rows only;
 
  SNAP_ID BEGIN               END
---------- ------------------- -------------------
       392 26/06/2021 13:58:56 26/06/2021 15:00:07
       391 26/06/2021 13:00:33 26/06/2021 13:58:56
       390 26/06/2021 12:00:48 26/06/2021 13:00:33
       389 26/06/2021 11:01:00 26/06/2021 12:00:48
       388 26/06/2021 10:00:11 26/06/2021 11:01:00

然后我们强制生成AWR快照,以便将执行计划转储到 AWR 中

SQL> EXECUTE DBMS_WORKLOAD_REPOSITORY.CREATE_SNAPSHOT();
 
PL/SQL procedure successfully completed.
 
select
   snap_id,
   to_char(begin_interval_time, 'dd/mm/yyyy hh24:mi:ss'begin
  ,to_char(end_interval_time, 'dd/mm/yyyy hh24:mi:ss'end
from
   dba_hist_snapshot
order by 1 desc
fetch first 5 rows only;
 
       SNAP_ID BEGIN               END
---------- ------------------- -------------------      
       393 26/06/2021 15:00:07 26/06/2021 15:46:40
       392 26/06/2021 13:58:56 26/06/2021 15:00:07
       391 26/06/2021 13:00:33 26/06/2021 13:58:56
       390 26/06/2021 12:00:48 26/06/2021 13:00:33
       389 26/06/2021 11:01:00 26/06/2021 12:00:48
 
SQLselect * from table(dbms_xplan.display_awr('069t64t6ws5mx'));
 
SQL_ID 069t64t6ws5mx
--------------------
--------------------------------------------------------------------------------------
| Id  | Operation                    | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |       |       |       |   102M(100)|          |
|   1 |  NESTED LOOPS SEMI           |       |   100 | 13100 |   102M  (1)| 01:06:26 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1    |  1000K|   115M| 20332   (1)| 00:00:01 |
|   3 |    INDEX FULL SCAN           | T1_N1 |  1000K|       |  2779   (1)| 00:00:01 |
|   4 |   TABLE ACCESS BY INDEX ROWID| T2    |     1 |    10 |   102   (0)| 00:00:01 |
|   5 |    INDEX RANGE SCAN          | T2_I1 |   100 |       |     2   (0)| 00:00:01 |
--------------------------------------------------------------------------------------

如果我重复相同的实验,但这一次,我将在生成新的AWR快照之前将sql_id刷出share pool,那么您将看到,不会有对应的执行计划转储到 AWR 中

SELECT *
   from t1 
 where id
   in (select id from t2 where x1 = 17335)
ORDER BY id;    
 
SELECT    
    sample_time
   ,is_awr_sample
   ,COUNT(1)
FROM
    gv$active_session_history
WHERE
    sql_id = '65gw9y7cw56k1'
AND  is_awr_sample = 'Y'  
GROUP BY
    sample_time
    ,is_awr_sample
order by sample_time ;
 
SAMPLE_TIME                    I   COUNT(1)
------------------------------ - ----------
27-JUN-21 09.01.47.733 AM      Y          1
27-JUN-21 09.01.57.973 AM      Y          1
27-JUN-21 09.02.08.277 AM      Y          1
27-JUN-21 09.02.18.518 AM      Y          1
27-JUN-21 09.02.28.757 AM      Y          1
27-JUN-21 09.02.39.026 AM      Y          1
27-JUN-21 09.02.49.301 AM      Y          1
27-JUN-21 09.02.59.609 AM      Y          1
 
8 rows selected.
 
SELECT
    sql_id,
    sample_time
FROM
    dba_hist_active_sess_history
WHERE
    sql_id = '65gw9y7cw56k1'
ORDER BY 2;
 
no rows selected ----> still no rows dumped into AWR
 
SELECT    
    sample_time
   ,is_awr_sample
   ,COUNT(1)
FROM
    gv$active_session_history
WHERE
    sql_id = '65gw9y7cw56k1'
AND  is_awr_sample = 'Y'  
GROUP BY
    sample_time
    ,is_awr_sample
order by sample_time;
 
SAMPLE_TIME                 I   COUNT(1)
--------------------------- - ----------
27-JUN-21 09.01.47.733 AM   Y          1
27-JUN-21 09.01.57.973 AM   Y          1
27-JUN-21 09.02.08.277 AM   Y          1
27-JUN-21 09.02.18.518 AM   Y          1
27-JUN-21 09.02.28.757 AM   Y          1
27-JUN-21 09.02.39.026 AM   Y          1
27-JUN-21 09.02.49.301 AM   Y          1
27-JUN-21 09.02.59.609 AM   Y          1
27-JUN-21 09.03.09.846 AM   Y          1
27-JUN-21 09.03.20.085 AM   Y          1
27-JUN-21 09.03.30.454 AM   Y          1
27-JUN-21 09.03.40.693 AM   Y          1
27-JUN-21 09.03.50.997 AM   Y          1
27-JUN-21 09.04.01.365 AM   Y          1
27-JUN-21 09.04.11.606 AM   Y          1
 
15 rows selected.
 
SELECT
    sql_id,
    sample_time
FROM
    dba_hist_active_sess_history
WHERE
    sql_id = '65gw9y7cw56k1'
ORDER BY 2;
 
no rows selected  ----> still no rows dumped into AWR
 
SELECT    
    sample_time
   ,is_awr_sample
   ,COUNT(1)
FROM
    gv$active_session_history
WHERE
    sql_id = '65gw9y7cw56k1'
AND  is_awr_sample = 'Y'  
GROUP BY
    sample_time
    ,is_awr_sample
order by sample_time ;
 
SAMPLE_TIME                    I   COUNT(1)
------------------------------ - ----------
27-JUN-21 09.01.47.733 AM      Y          1
27-JUN-21 09.01.57.973 AM      Y          1
27-JUN-21 09.02.08.277 AM      Y          1
27-JUN-21 09.02.18.518 AM      Y          1
27-JUN-21 09.02.28.757 AM      Y          1
27-JUN-21 09.02.39.026 AM      Y          1
27-JUN-21 09.02.49.301 AM      Y          1
27-JUN-21 09.02.59.609 AM      Y          1
27-JUN-21 09.03.09.846 AM      Y          1
27-JUN-21 09.03.20.085 AM      Y          1
27-JUN-21 09.03.30.454 AM      Y          1
27-JUN-21 09.03.40.693 AM      Y          1
27-JUN-21 09.03.50.997 AM      Y          1
27-JUN-21 09.04.01.365 AM      Y          1
27-JUN-21 09.04.11.606 AM      Y          1
27-JUN-21 09.04.21.846 AM      Y          1
27-JUN-21 09.04.32.086 AM      Y          1
27-JUN-21 09.04.42.326 AM      Y          1
 
18 rows selected.
 
SELECT
    sql_id,
    sample_time
FROM
    dba_hist_active_sess_history
WHERE
    sql_id = '65gw9y7cw56k1'
ORDER BY 2;
 
SQL_ID        SAMPLE_TIME
------------- ---------------------------
65gw9y7cw56k1 27-JUN-21 09.01.47.733 AM
65gw9y7cw56k1 27-JUN-21 09.01.57.973 AM
65gw9y7cw56k1 27-JUN-21 09.02.08.277 AM
65gw9y7cw56k1 27-JUN-21 09.02.18.518 AM
65gw9y7cw56k1 27-JUN-21 09.02.28.757 AM
65gw9y7cw56k1 27-JUN-21 09.02.39.026 AM
65gw9y7cw56k1 27-JUN-21 09.02.49.301 AM
65gw9y7cw56k1 27-JUN-21 09.02.59.609 AM
65gw9y7cw56k1 27-JUN-21 09.03.09.846 AM
65gw9y7cw56k1 27-JUN-21 09.03.20.085 AM
65gw9y7cw56k1 27-JUN-21 09.03.30.454 AM
65gw9y7cw56k1 27-JUN-21 09.03.40.693 AM
65gw9y7cw56k1 27-JUN-21 09.03.50.997 AM
65gw9y7cw56k1 27-JUN-21 09.04.01.365 AM
65gw9y7cw56k1 27-JUN-21 09.04.11.606 AM
65gw9y7cw56k1 27-JUN-21 09.04.21.846 AM
65gw9y7cw56k1 27-JUN-21 09.04.32.086 AM
65gw9y7cw56k1 27-JUN-21 09.04.42.326 AM
 
18 rows selected. ----> all ASH rows dumped into AWR
 
select * from table(dbms_xplan.display_awr('65gw9y7cw56k1'));
 
no rows selected ----> but there is no execution plan into AWR

正如您所看到的,AWR 中还没有执行计划。通常,如上所示,它将在 AWR 采样时间(下一小时)转储。除非这个 sql_id 被从内存中刷出去了:

SQL> select * from table(dbms_xplan.display_cursor('65gw9y7cw56k1'));
 
--------------------------------------------------------------
| Id  | Operation                    | Name  | Rows  | Bytes |
--------------------------------------------------------------
|   0 | SELECT STATEMENT             |       |       |       |
|   1 |  NESTED LOOPS SEMI           |       |   100 | 13100 |
|   2 |   TABLE ACCESS BY INDEX ROWID| T1    |  1000K|   115M|
|   3 |    INDEX FULL SCAN           | T1_N1 |  1000K|       |
|*  4 |   TABLE ACCESS BY INDEX ROWID| T2    |     1 |    10 |
|*  5 |    INDEX RANGE SCAN          | T2_I1 |   100 |       |
--------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
   4 - filter("ID"="ID")
   5 - access("X1"=17335)
    
    
SELECT
     p.sql_id
    ,p.plan_hash_value
    ,p.child_number
    ,p.last_load_time
    ,p.executions    
 FROM   
    gv$sql p
where
    p.sql_id = '65gw9y7cw56k1'
and    
  p.is_shareable ='Y';
   
SQL_ID        PLAN_HASH_VALUE CHILD_NUMBER LAST_LOAD_TIME      EXECUTIONS
------------- --------------- ------------ ------------------- ----------
65gw9y7cw56k1      1518369540            0 2021-06-27/09:01:40          1  
 
 
select address, hash_value from v$sqlarea where sql_id='65gw9y7cw56k1';
 
ADDRESS          HASH_VALUE
---------------- ----------
000000006754FB80 3653409345
 
 
SQL> exec dbms_shared_pool.purge ('000000006754FB80, 3653409345''C');
 
PL/SQL procedure successfully completed.
 
SELECT
     p.sql_id
    ,p.plan_hash_value
    ,p.child_number
    ,p.last_load_time
    ,p.executions    
 FROM   
    gv$sql p
where
    p.sql_id = '65gw9y7cw56k1';
     
 
no rows selected ----> cursor is now purged from memory

现在我已经从内存中刷出了对应的SQL_ID,下一个 AWR 快照将无法转储其执行计划(和 cie),如下所示:

select
   snap_id,
   to_char(begin_interval_time, 'dd/mm/yyyy hh24:mi:ss'begin
  ,to_char(end_interval_time, 'dd/mm/yyyy hh24:mi:ss'end
from
   dba_hist_snapshot
order by 1 desc
fetch first 5 rows only;
 
  SNAP_ID BEGIN               END
---------- ------------------- -------------------
       398 27/06/2021 08:02:48 27/06/2021 09:00:32
       397 26/06/2021 19:00:18 27/06/2021 08:02:48
       396 26/06/2021 18:00:31 26/06/2021 19:00:18
       395 26/06/2021 17:00:43 26/06/2021 18:00:31
       394 26/06/2021 15:46:40 26/06/2021 17:00:43
        
        
SQLEXECUTE DBMS_WORKLOAD_REPOSITORY.CREATE_SNAPSHOT();
 
PL/SQL procedure successfully completed.
 
select
   snap_id,
   to_char(begin_interval_time, 'dd/mm/yyyy hh24:mi:ss'begin
  ,to_char(end_interval_time, 'dd/mm/yyyy hh24:mi:ss'end
from
   dba_hist_snapshot
order by 1 desc
fetch first 5 rows only;
 
   SNAP_ID BEGIN               END
---------- ------------------- -------------------
       399 27/06/2021 09:00:32 27/06/2021 09:17:52
       398 27/06/2021 08:02:48 27/06/2021 09:00:32
       397 26/06/2021 19:00:18 27/06/2021 08:02:48
       396 26/06/2021 18:00:31 26/06/2021 19:00:18
       395 26/06/2021 17:00:43 26/06/2021 18:00:31     
        
SQLselect * from table(dbms_xplan.display_awr('65gw9y7cw56k1'));
 
no rows selected
 
SQL> select count(1from dba_hist_active_sess_history where sql_id = '65gw9y7cw56k1';
 
  COUNT(1)
----------
        18

总之,由于性能动态视图中收集的信息会在AWR采样时转储到 AWR 中,因此当您找不到游标的执行计划时,请不要感到惊讶,尽管该游标存在于 dba_hist_active_sess_history 中。这可能是因为该游标在 AWR 采样时间之前已从内存中清除。

参考资料

[1]

1: https://hourim.wordpress.com/2021/06/27/why-my-execution-plan-is-not-in-awr