记一次隐式转化引起的数据库性能故障

上周给客户数据库从Oralce 9.2.0.4升级到10.2.0.5之后，系统稳定运行。但昨天打电话给我说，数据库出现性能问题，主要表现为保存提交时非常缓慢，比升级之前慢了好多。正好，同一天，同一个客户的另一个rac数据库二号节点宕机，需要现场支持。帮助客户分析好rac宕机原因之后，开始分析数据库性能分析。通常来讲，数据库升级之后，出现业务响应缓慢，一般都是执行计划变更引起的。由于客户不能提供性能变坏业务模块SQL语句，于是只好从AWR报告开始分析。我们分析问题时，有一点需要注意的是，客户告之的故障之后，对故障要有一般要有自己的判断，不能被客户牵着鼻子走，否则容易误入歧途，给故障诊断，带来不利的影响。闲话不说，步入正题，首先分析awr报告。
awr报告采样自业务高峰期间，具有一定的典型性:



从profile来看，物理读比例有点高，达到了每秒8,211次。硬解析也偏高，达到了每秒14.09次，这两项指标也直接导致了buffer cache命中率和library cache命中率偏低，分别只有
82.59%和81.31%。指标偏低只能给我们指明数据库可能出问题的方向，由于没有做性能指标baseline，通过这指标偏低数据库可能存在2个问题：1、SQL执行计划执行效率有问题，导致
大量的物理读。2、硬解析过多，可能引起shared pool中latch的争用。



通过查看top 5等待事件，数据库存在的问题，渐渐浮出水面。可以看到除了CPU TIME之外，read by other session和db file scattered read排在前2位，一般来讲，这2个等待事件。同时出现，也就意味着数据库中正在并发的执行全表扫描，而硬解析过多引起的故障可以暂时不予考虑。



一般来讲定位全表扫描的语句可以查看SQL ordered by Gets或者SQL ordered by Reads或者SQL ordered by CPU Time。
通过查找发现在SQL ordered by Gets，SQL ordered by Reads，SQL ordered by CPU Time，以下2条SQL语句排名均占前2位，现在问题越来越明朗了。



我们着重分析第一条SQL，查看其的执行计划，确定有无child，注意到字段BIND_DATA，该SQL可能有绑定变量窥视（bind peeking），在Oracle 11g之前，绑定变量窥视一直是执行计划不稳定的重要原因之一。
SQL> select CHILD_NUMBER,LAST_ACTIVE_TIME,BIND_DATA from v$sql where sql_id='cx0dsyvc8gmfp';

CHILD_NUMBER LAST_ACTIVE_TIME BIND_DATA
------------ ------------------------------ ----------------------------------------------------------------------
0 2011-04-20 10:08:11 BEDA0A2005004DAE3D43000101C002160BCA041F1501010B0831105E

确定child_number为0之后，利用Oracle 10g提供的dbms_xplan.display_awr工具包可以知道此SQL在awr报告里的执行计划，在Oracle 9i需要将statspack级别设置成6级之后，才能查看sql在statspack的执行计划。可以看到SQL采用了全表扫描的执行计划，其cost高达15397。注意到字段RYYWBM采用绑定变量赋值。
SQL> select * from table(dbms_xplan.display_awr('cx0dsyvc8gmfp'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID cx0dsyvc8gmfp
--------------------
SELECT HJDPPBZ,HJDSSXQ,HJDXZ,HJDXQ,HJDDZBM,CLBZ FROM PZT_CZRK_DJ WHERE
RYYWBM=:B1

Plan hash value: 593801944

--------------------------------------------------------------------------------
-

| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
|

--------------------------------------------------------------------------------
-

| 0 | SELECT STATEMENT | | | | 15397 (100)|
|

| 1 | TABLE ACCESS FULL| PZT_CZRK_DJ | 1 | 97 | 15397 (1)| 00:03:36
|


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
-


14 rows selected.

为避免绑定变量窥视带来的执行计划不稳定，可以看到RYYWBM选择性很好
SQL> select count(*) from hz2004.PZT_CZRK_DJ;

COUNT(*)
----------
5003467

SQL> select count(distinct RYYWBM) from hz2004.PZT_CZRK_DJ;

COUNT(DISTINCTRYYWBM)
---------------------
5003471
进一步查看得知，RYYWBM为表格PZT_CZRK_DJ的主键
SQL> select INDEX_OWNER,INDEX_NAME,COLUMN_NAME from all_ind_columns where TABLE_OWNER='HZ2004' and TABLE_NAME='PZT_CZRK_DJ';
INDEX_OWNER INDEX_NAME COLUMN_NAME
------------------------------ ------------------------------ ------------------------------
HZ2004 PK_PZT_CZRK_DJ RYYWBM
HZ2004 IDX_PZT_CZRK_DJ_CJSJ CJSJ
HZ2004 IDX_PZT_CZRK_DJ_GMSFHM GMSFHM
HZ2004 IDX_PZT_CZRK_DJ_HJDDZBM HJDDZBM
HZ2004 IDX_PZT_CZRK_DJ_HJDXQ HJDXQ
HZ2004 IDX_PZT_CZRK_DJ_RKBM RKBM
HZ2004 IDX_PZT_CZRK_DJ_XM XM
HZ2004 IDX_PZT_CZRK_DJ_XZDDZBM XZDDZBM
HZ2004 IDX_PZT_CZRK_DJ_HHNBID HHNBID

SQL> select dbms_metadata.get_ddl('INDEX',U.INDEX_NAME,u.owner) from dba_indexes u where u.index_name='PK_PZT_CZRK_DJ';

CREATE UNIQUE INDEX "HZ2004"."PK_PZT_CZRK_DJ" ON "HZ2004"
."PZT_CZRK_DJ" ("RYYWBM")
PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTI
CS
STORAGE(INITIAL 1048576 NEXT 1048576 MINEXTENTS 1 MAXE
XTENTS 2147483645
PCTINCREASE 0 FREELISTS 1 FREELIST GROUP
S 1 BUFFER_POOL DEFAULT)
TABLESPACE "HZ2004_PRM"
同时主键状态为有效，这就排除了因主键索引失效导致全表扫描或者绑定变量窥视而导致全表扫描
SQL> select status from dba_indexes where owner='HZ2004' and INDEX_NAME='PK_PZT_CZRK_DJ';

STATUS
--------
[color=red]VALID[/color]
这就奇怪了，唯一索引明明存在，但Oracle为什么不选择索引执行呢？
进一步利用dbms_xplan.display_cursor查看其SQL在shared pool中的执行计划，可以看到依然是全表扫描，但通过加参数advanced，我们得到了更多详细的信息。如绑定变量的值是3302000001005624885，并注意到Oracle对绑定变量值进行了隐式转换TO_NUMBER("RYYWBM")=:B1。
SQL> select * from table(dbms_xplan.display_cursor('cx0dsyvc8gmfp',0,'advanced'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID cx0dsyvc8gmfp, child number 0
-------------------------------------
SELECT HJDPPBZ,HJDSSXQ,HJDXZ,HJDXQ,HJDDZBM,CLBZ FROM PZT_CZRK_DJ WHERE
RYYWBM=:B1

Plan hash value: 593801944

--------------------------------------------------------------------------------
-

| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
|

--------------------------------------------------------------------------------
-

| 0 | SELECT STATEMENT | | | | 48777 (100)|
|

|* 1 | TABLE ACCESS FULL| PZT_CZRK_DJ | 1 | 89 | 48777 (1)| 00:11:23
|


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
--------------------------------------------------------------------------------
-


Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

1 - SEL$1 / PZT_CZRK_DJ@SEL$1

Outline Data
-------------

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------

/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('10.2.0.5')
OPT_PARAM('query_rewrite_enabled' 'false')
OPT_PARAM('optimizer_index_cost_adj' 40)
OPT_PARAM('optimizer_index_caching' 90)
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
FULL(@"SEL$1" "PZT_CZRK_DJ"@"SEL$1")

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
END_OUTLINE_DATA
*/

Peeked Binds (identified by position):
--------------------------------------

1 - :B1 ([color=red]NUMBER[/color]): [color=red]3302000001005624885
[/color]
Predicate Information (identified by operation id):
---------------------------------------------------


PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
1 - filter([color=red]TO_NUMBER("RYYWBM")=:B1[/color])

Column Projection Information (identified by operation id):
-----------------------------------------------------------

1 - "HJDSSXQ"[VARCHAR2,6], "HJDXZ"[VARCHAR2,150],
"HJDXQ"[VARCHAR2,12], "HJDDZBM"[VARCHAR2,32], "HJDPPBZ"[VARCHAR2,1],
"CLBZ"[VARCHAR2,1]


52 rows selected.
为证明了确实是隐式转换的问题，直接将绑定变量的值以具体值3302000001005624885代入，其执行计划却是出人意料的全表扫描。
SQL> set autotrace traceonly exp
SQL> SELECT HJDPPBZ, HJDSSXQ, HJDXZ, HJDXQ, HJDDZBM, CLBZ FROM hz2004.PZT_CZRK_DJ WHERE RYYWBM=3302000001005624885;

Execution Plan
----------------------------------------------------------

----------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
----------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 93 | 48777 (1)|
| 1 | TABLE ACCESS FULL| PZT_CZRK_DJ | 1 | 93 | 48777 (1)|
----------------------------------------------------------------------

Note
-----
- 'PLAN_TABLE' is old version
马上查看其表结构，可以看到RYYWBM为varchar类型
SQL> desc hz2004.PZT_CZRK_DJ
Name Null? Type
----------------------------------------- -------- ----------------------------
RYYWBM NOT NULL [color=red]VARCHAR2(32)[/color]
。。。。
到这里问题应该很明显了：
由于我们代入的值是number类型3302000001005624885，而在RYYWBM在表中定义为varchar2类型，估计是程序直接以number类型传入，为了匹配number类型
Oracle进行了类型隐式转换：TO_NUMBER("RYYWBM")。相当于在列RYYWBM建立了函数to_number。考虑以下情况：
如表格test中id列有唯一索引，但由于加上了函数to_number，将使得SQL不能使用索引，而进行全表扫描。
select id from test where to_number(id)=1
如果要使用索引，需要建立函数索引。如
create index test_id_idx on test(to_number(id));
知道了原因之后，处理就很简单了，即程序传入varchar类型即可，问题也得到了圆满解决
SQL> SELECT HJDPPBZ, HJDSSXQ, HJDXZ, HJDXQ, HJDDZBM, CLBZ FROM hz2004.PZT_CZRK_DJ WHERE RYYWBM='3302000001005624885';

Execution Plan
----------------------------------------------------------

--------------------------------------------------------------------------------
---

| Id | Operation | Name | Rows | Bytes | Cost (%CP
U)|

--------------------------------------------------------------------------------
---

| 0 | SELECT STATEMENT | | 1 | 93 | 1 (
0)|

| 1 | TABLE ACCESS BY INDEX ROWID| PZT_CZRK_DJ | 1 | 93 | 1 (
0)|

| 2 | [color=red]INDEX UNIQUE SCAN[/color] | PK_PZT_CZRK_DJ | 1 | | 1 (
0)|


--------------------------------------------------------------------------------
--- 阅读更多