这个系列目前为止,我们讨论了关于如何解释一个执行计划以及理解优化器对于成本和基数预测的含义。最终我们来看看,当查询执行时,Oracle给我们的执行计划中优化器的预测与实际工作的匹配程度。


有2种方法可以查看具体的信息,1.启用隐含参数”_rowsource_execution_statistics”,之后调用dbms_xplan.display_cursor()展示具体的信息;2.启用sql_trace,之后使用tkprof来查看具体的信息;这篇文章会使用第1种方法。


Rowsource Execution Statistics


在执行语句时,Oracle能够积累关于计划中每个操作所做的工作量的信息,包括调用每个操作的时间,buffer的访问量,访问的是当前模式还是一致性模式,物理读和写,每个操作的总时间还有workarea使用的信息。这些信息在动态视图v$sql_plan_statistics_all中是可见的,在11.2.0.4中的描述如下:


1: ADDRESS               RAW(8)
2: HASH_VALUE            NUMBER
3: SQL_ID                VARCHAR2(13)
4: PLAN_HASH_VALUE       NUMBER
5: CHILD_ADDRESS         RAW(8)
6: CHILD_NUMBER          NUMBER
7: TIMESTAMP             DATE
8: OPERATION             VARCHAR2(30)
9: OPTIONS               VARCHAR2(30)
10: OBJECT_NODE          VARCHAR2(40)
11: OBJECT#              NUMBER
12: OBJECT_OWNER         VARCHAR2(30)
13: OBJECT_NAME          VARCHAR2(30)
14: OBJECT_ALIAS         VARCHAR2(65)
15: OBJECT_TYPE          VARCHAR2(20)
16: OPTIMIZER            VARCHAR2(20)
17: ID                   NUMBER
18: PARENT_ID            NUMBER
19: DEPTH                NUMBER
20: POSITION             NUMBER
21: SEARCH_COLUMNS       NUMBER
22: COST                 NUMBER
23: CARDINALITY          NUMBER
24: BYTES                NUMBER
25: OTHER_TAG            VARCHAR2(35)
26: PARTITION_START      VARCHAR2(64)
27: PARTITION_STOP       VARCHAR2(64)
28: PARTITION_ID         NUMBER
29: OTHER                VARCHAR2(4000)
30: DISTRIBUTION         VARCHAR2(20)
31: CPU_COST             NUMBER
32: IO_COST              NUMBER
33: TEMP_SPACE           NUMBER
34: ACCESS_PREDICATES    VARCHAR2(4000)
35: FILTER_PREDICATES    VARCHAR2(4000)
36: PROJECTION           VARCHAR2(4000)
37: TIME                 NUMBER
38: QBLOCK_NAME          VARCHAR2(30)
39: REMARKS              VARCHAR2(4000)
40: OTHER_XML            CLOB
41: EXECUTIONS           NUMBER
42: LAST_STARTS          NUMBER
43: STARTS               NUMBER
44: LAST_OUTPUT_ROWS     NUMBER
45: OUTPUT_ROWS          NUMBE
46: LAST_CR_BUFFER_GETS  NUMBER
47: CR_BUFFER_GETS       NUMBER
48: LAST_CU_BUFFER_GETS  NUMBER
49: CU_BUFFER_GETS       NUMBER
50: LAST_DISK_READS      NUMBER
51: DISK_READS           NUMBER
52: LAST_DISK_WRITES     NUMBER
53: DISK_WRITES          NUMBER
54: LAST_ELAPSED_TIME    NUMBER
55: ELAPSED_TIME         NUMBER
56: POLICY               VARCHAR2(10)
57: ESTIMATED_OPTIMAL_SIZE  NUMBER
58: ESTIMATED_ONEPASS_SIZE  NUMBER
59: LAST_MEMORY_USED     NUMBER
60: LAST_EXECUTION       VARCHAR2(10)
61: LAST_DEGREE          NUMBER
62: TOTAL_EXECUTIONS     NUMBER
63: OPTIMAL_EXECUTIONS   NUMBER
64: ONEPASS_EXECUTIONS   NUMBER
65: MULTIPASSES_EXECUTIONS  NUMBER
66: ACTIVE_TIME          NUMBER
67: MAX_TEMPSEG_SIZE     NUMBER
68: LAST_TEMPSEG_SIZE    NUMBER

如果仔细看这些列,会发现,前40行就是重复v$sql_plan里的列,基本的内存里执行计划的信息,第41 - 55行是来自v$sql_plan_statistics的非键列,第56-68行来自v$sql_workare,最后一组列是v$sql_plan_statistics_all中报告的有用的信息,即使你没有开启rowsource execution statistics。


Workarea


在我们继续研究v$sql_plan_statistics_all之前,我们很有必要利用一下v$sql_workarea中的有用信息,这些信息在故障排除时往往被忽略。我们从一个对sys对象简单的查询开始,之后调用dbms_xplan.display_cursor(),这里并没有开启rowsource execution statistics:


alter session set statistics_level = typical;

select ct, count(*) from (
select obj#, count(*) ct from sys.source$ group by obj#
)
group by ct order by ct

select * from table(dbms_xplan.display_cursor(null,null,"allstats last"))

SQL_ID  33vchu53wj57a, child number 0
-------------------------------------
select ct, count(*) from (select obj#, count(*) ct from sys.source$
group by obj#) group by ct order by ct

Plan hash value: 2879348764

---------------------------------------------------------------------------------
| Id  | Operation               | Name      | E-Rows |  OMem |  1Mem | Used-Mem |
---------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |           |        |       |       |          |
|   1 |  SORT GROUP BY          |           |   5513 | 36864 | 36864 |32768  (0)|
|   2 |   VIEW                  |           |   5513 |       |       |          |
|   3 |    HASH GROUP BY        |           |   5513 |    37M|  8100K| 2719K (0)|
|   4 |     INDEX FAST FULL SCAN| I_SOURCE1 |    670K|       |       |          |
---------------------------------------------------------------------------------

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

在调用时,我使用了(null,null,allstats last)参数,这个参数应该会打印出上一次执行的数据源执行统计数据,但是我设置了statistics_level值为”typical”,所以除了与wokarea (PGA)使用相关的统计信息外,没有其他可用的执行统计信息。Note部分也输出了一个warning,统计数据不可用,并且告诉我们两种可以获得的方法,其实还有第三种,就是将隐含参数”_rowsource_execution_statistics”设置为true。

通过上一次执行的计划可以得到以下工作区相关的信息:


OMem:Oracle认为的所有操作都可以在内存里完成的内存大小。


1Mem:只需要写入一次数据到临时空间时的内存大小。


Used_Mem:上一次执行我们实际使用的内存。


如果我们使用 allstats 而不是 allstats last ,我们会得到子游标首次执行以来所有的活动总和,下面是我的例子:


---------------------------------------------------------------------------------
| Id  | Operation               | Name      | E-Rows |  OMem |  1Mem |  O/1/M   |
---------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |           |        |       |       |          |
|   1 |  SORT GROUP BY          |           |   5513 | 36864 | 36864 |     2/0/0|
|   2 |   VIEW                  |           |   5513 |       |       |          |
|   3 |    HASH GROUP BY        |           |   5513 |    37M|  8100K|     2/0/0|
|   4 |     INDEX FAST FULL SCAN| I_SOURCE1 |    670K|       |       |          |
---------------------------------------------------------------------------------

最后一列会输出每个操作是最优操作的次数,有多少是属于one-pass(内存不足,写入一次临时空间),有多少是属于multi-pass(内存不足,多次写入临时空间)。这个例子中(一共执行两次),两次都是最优执行,没有操作溢出到磁盘上。


我这个版本的Oracle也存在一些bug,如果第3行的HASH GROUP BY有几次one-pass操作,则O/1/M列就会为空。当然,这种情况也可以通过一些线索发现,比如Used-Tmp列或者Max-Tmp列,为了更好地利用v$sql_workarea视图和dbms_xplan.display_cursor()的组合,你可以使用以下查询语句来查询这个视图:


select
    sql_id, child_number, estimated_optimal_size,
    total_executions, optimal_executions, onepass_executions, multipasses_executions,
    max_tempseg_size
from
    v$sql_workarea
where
    max_tempseg_size > 65535
or      onepass_executions > 10
or      multipasses_executions > 0
;

执行这个查询后,你可以通过dbms_xplan.display_cursor()查询任何列出的sql_id和child_number来获得可能对系统资源造成巨大压力的语句。这个查询会对系统造成不小的压力,所以建议不要频繁执行。


Execution Stats


我通过设置statistics_level的值为all来开启数据源执行统计数据,我的测试里有两个明显的改变。第一点,执行时间从0.12s延长至3.73s(大部分消耗在CPU上),第二点,dbms_xplan.display_cursor()的输出生成了更多的列。


------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation               | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem | Used-Mem | Used-Tmp|
------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |           |      1 |        |    563 |00:00:03.73 |    1623 |   1632 |     16 |       |       |          |         |
|   1 |  SORT GROUP BY          |           |      1 |   5513 |    563 |00:00:03.73 |    1623 |   1632 |     16 | 37888 | 37888 |32768  (0)|         |
|   2 |   VIEW                  |           |      1 |   5513 |   5514 |00:00:03.71 |    1623 |   1632 |     16 |       |       |          |         |
|   3 |    HASH GROUP BY        |           |      1 |   5513 |   5514 |00:00:03.69 |    1623 |   1632 |     16 |    36M|  8304K|  421K (0)|    1024 |
|   4 |     INDEX FAST FULL SCAN| I_SOURCE1 |      1 |    670K|    670K|00:00:01.84 |    1623 |   1616 |      0 |       |       |          |         |
------------------------------------------------------------------------------------------------------------------------------------------------------

额外的CPU消耗是与平台有关的,并且与调用O/S计时函数所花费的时间有关;出于这个原因,你可能希望对自己的平台进行一些测试,并希望使用另一种启用统计信息的机制。就像我们看到的之前的执行计划的Note部分,可以在语句中添加/*+gather_plan_statistics*/ hint来实现,但是,当统计信息由hint驱动时,计时是通过抽样完成的,在我的例子中,查询花费0.18秒(而不是0.12或3.75秒)。这里有一个陷阱;下面是我将statistics_level设置成typical并且使用hint的输出。


------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation               | Name      | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem | Used-Mem | Used-Tmp|
------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT        |           |      1 |        |    563 |00:00:00.15 |    1623 |     42 |     16 |       |       |          |         |
|   1 |  SORT GROUP BY          |           |      1 |   5513 |    563 |00:00:00.15 |    1623 |     42 |     16 | 37888 | 37888 |32768  (0)|         |
|   2 |   VIEW                  |           |      1 |   5513 |   5514 |00:00:00.21 |    1623 |     42 |     16 |       |       |          |         |
|   3 |    HASH GROUP BY        |           |      1 |   5513 |   5514 |00:00:00.17 |    1623 |     42 |     16 |    36M|  8304K|  431K (0)|    1024 |
|   4 |     INDEX FAST FULL SCAN| I_SOURCE1 |      1 |    670K|    670K|00:00:02.31 |    1623 |     26 |      0 |       |       |          |         |
------------------------------------------------------------------------------------------------------------------------------------------------------

Reads值的变化是因为数据在缓存里了,但是通过观察两个执行计划的A-Time列,它应该是子操作的累加,但是很明显这里出现了问题。这个执行计划非常简单,每个操作只会调用唯一的子操作,所以执行计划中的累加也十分简单,但是索引快速全扫描显示花费了2.31s,总共的时间也才0.15s,当我们从下往上看执行计划时,时间也是时长时短。所以当你使用/*+gather_plan_statistics*/ hint时,不要相信A-Time这列的值。

我们刚刚着重介绍了A-Time这列,下面是其他列的描述:

Starts:操作真实发生的执行次数。

E-rows:操作每次执行预估的行数。

A-rows:这个操作累加的行数。

A-Time:这个操作累计花费的时间-包括它的子操作。

Buffers:这个操作累计访问的buffer-包括它的子操作。

Reads:这个操作累计从磁盘读取的数据块-包括它的子操作。

Writes:这个操作累计写到磁盘的数据块-包括它的子操作。

在解释带有执行统计信息的计划时,需要记住两个关键点;第一个是理解Oracle 向上累加的含义,第二个是starts列的意义。


Interpretation


这篇文章我提供的例子并不能很好的帮助我们理解这两点,我会在下面几篇文章中使用更好的例子,但至少我们可以看到一些是累加操作的特征。


一个很好的阅读执行计划的规则是“子操作先执行”,一个父操作会依次调用它的子操作,它的子操作也可能调用它自己的子操作返回数据给它的父操作。这样我们就很容易理解,操作所做的工作包括操作本身所做的工作(例如,对输入的数据进行排序),以及每个子操作为其提供数据所做的工作。


上面的例子中每个操作都只有一个子操作,但是我们也能通过第3跟第4行看到简单的‘父+子’计算方法。”hash group by”操作本质上并不会使用buffer cache,所以第3行并不会记录Buffers的值,但是第4行中使用了buffer,并将数据传递给第3行进行聚合,所以第3行才有了Buffers的值。


另一方面,如果一个”hash group by”操作溢出到磁盘上,它会写入到临时表空间上,之后再重新读取回来。第3行显示有16个块被写入并且读取了42个块,为什么读取的会大于写入的,多余出来的26个块的读,是在第4行对i_source1做索引快速全扫描时发生的。


从第3行起就没有资源的增量使用了,因为”sort group by”操作都是在内存里完成的,所以不需要物理读和写。还有很重要的Starts列,在这个执行计划中也不明显,因为每个操作只执行了一次。我们会在下篇文章中我们会仔细研究这部分,但是这个示例中的大部分操作,E-rows和A-rows的值是十分匹配的,我们应该感到高兴,因为优化器通过我们的查询,对数据处理做了一个比较好的预测。但是这两列值的相近是因为Start列为1:E-rows表示每次操作执行预估的行数,所以每次我们去判断优化器预测的准确度时,我们需要比对A-rows和E-rows*Start的值,我们同样也需要注意,在什么情况下比对是有用的,在什么情况下比对是无意义的。



沃趣科技,让客户用上更好的数据库技术!