这个系列目前为止,我们讨论了关于如何解释一个执行计划以及理解优化器对于成本和基数预测的含义。最终我们来看看,当查询执行时,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
通过上一次执行的计划可以得到以下工作区相关的信息:
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
;
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 | | | | |
------------------------------------------------------------------------------------------------------------------------------------------------------
在解释带有执行统计信息的计划时,需要记住两个关键点;第一个是理解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做索引快速全扫描时发生的。