一次有意思的错选执行计划问题定位(涉及SYS_OP_C2)

  1. 云栖社区>
  2. 博客>
  3. 正文

一次有意思的错选执行计划问题定位(涉及SYS_OP_C2)

bisal 2015-05-29 01:25:32 浏览435
展开阅读全文

这两天和广分的兄弟看了一个问题,比较有意思,过程也比较曲折。。。


问题现象:

1. 11g的库,话说有一个应用程序新上线,应用中使用了绑定变量的方式执行一条简单的SQL,例如select a from b where c = :x,c列是该表复合主键的前导列,表定义是varchar2类型,从spotlight监控看这条SQL的执行计划是全表扫描,一次执行要1个小时,这张表是运行很久的引用分区表,数据量是亿级,测试的时候正常,但很显然测试的数据量可能和生产非常不一致,导致没察觉。

2. 在sqlplus中手工执行SQL,变量使用字面值,例如select a from b where c = 'abc',执行的非常快,查看执行计划,是用的索引范围扫描。


初步怀疑:

1. 对如此数据量的一张表,理应使用索引,但应用程序未使用索引,用的全表扫描,手工执行SQL时却可以用到索引,那么问题就在于为什么对于应用程序,Oracle选择了全表扫描的执行计划,而不是索引?


开始时的几种猜测:

1. 是否该表上线时有大量的数据变更,对执行计划产生影响,且未到达夜维统计信息收集的时间,造成因统计信息不准导致错误执行计划的可能?

> 经询问,确认上线时未有大量数据的变更,且上线后手工收集过统计信息。这种猜测不对。


2. 是否因为使用不同的查询条件会有不同的执行计划,由于绑定变量窥探的影响,导致采用了错误的执行计划?进一步解释猜测,例如第一次执行应用程序时,使用的条件值对应的执行计划是全表扫描,由于使用绑定变量窥探的作用,又由于应用使用了绑定变量,接下来的每次执行都会采用全表扫描,除非shared_pool被清空或对该表有DDL操作,才会重新硬解析,有可能采用另外的执行计划,这是绑定变量窥探的副作用。

> 因为他用的是引用分区,符合条件的记录在主表如果是存储于多个分区中,是否Oracle认为全表扫描效率高,如果存储于很少的分区,Oracle认为索引扫描效率高?

证明上述猜测的依据,就是无论哪种方式执行,应用程序或sqlplus,执行计划都是全表扫描,但实际是sqlplus执行SQL时并没有采用全表扫描,用的是索引范围扫描。这种猜测不对。


3. 是不是索引设置为了invisible?

> invisible是11g的新特性,允许设置索引为invisible,效果是DML操作仍会维护索引,但优化器会忽略索引的存在,除非设置参数optimizer_use_invisible_indexes,否则即使使用该索引字段,也不会使用索引。

但和问题2相同,使用sqlplus时会使用索引扫描,不可能应用程序执行时会临时设置该参数,因为这参数是系统级的,不是session级的,需要重启数据库生效,这不是应用程序能做的,而且也没有任何理由需要由应用程序来做这个操作。这种猜测不对。


究竟为什么应用程序运行时,这个SQL使用了全表扫描,但sqlplus执行SQL时却用的索引范围扫描呢?

越来越邪乎了。。。

但哲学观点证明,因果关联,肯定有某种因素让Oracle对不同场景使用了不同的执行计划,就像@dbsnake所说的,90%的Oracle问题都是SQL的书写不正确导致的,前两天有幸听了RWP中国巡讲,Tom同样提到了这点,不是Oracle做错了,而是你可能给Oracle的某些错误信息,让其出现了这种错误。


如何进一步证明?

首先跑了一个10046,第一次反馈没看出什么问题。

接着跑一个sqlplus下执行SQL的10053,发现优化器选择的就是索引范围扫描,其成本值最低,而全表扫描的成本值如下:

无论如何,是不会选择全表扫描的啊?

其实开始的时候并没有第一时间反应过来,一条SQL语句,Oracle计算的成本中索引范围扫描最优,但应用程序运行时没有用,而是用的全表扫描,排除上面几种猜测后,剩下的可能不多了。其实问题已经缩小到为什么应用程序执行的SQL索引失效了?

经过进一步排查,发现应用程序中对查询条件变量使用了OracleDbType.NVarchar2的定义,但实际字段类型是VARCHAR2,即where VARCHAR2 = NVARCHAR2,那么是否因为这种类型不匹配,造成做了隐式转换,导致索引失效?可能用过NVARCHAR2的朋友就已经发现问题了,由于以前基本没用过这种类型,所以只是怀疑,需要验证。


实验:

1. 定义了一张测试表,定义NVARCHAR2类型的变量,模拟应用程序。

SQL> create table t_n as select * from dba_objects;

Table created.

SQL> create index idx_t_n on t_n (object_name);

Index created.

SQL> var x nvarchar2(128);
SQL> exec :x := 'ABC';

PL/SQL procedure successfully completed.

2. 首先使用explain plan for查看执行计划

SQL> explain plan for select count(*) from t_n where object_name = :x;

Explained.

SQL> select * from table(dbms_xplan.display());

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 3062759669

-----------------------------------------------------------------------------
| Id  | Operation	  | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |	    |	  1 |	 66 |	  3   (0)| 00:00:01 |
|   1 |  SORT AGGREGATE   |	    |	  1 |	 66 |		 |	    |
|*  2 |   INDEX RANGE SCAN| IDX_T_N |	722 | 47652 |	  3   (0)| 00:00:01 |
-----------------------------------------------------------------------------

Predicate Information (identified by operation id):

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

   2 - access("OBJECT_NAME"=:X)

Note
-----
   - dynamic sampling used for this statement (level=2)

18 rows selected.
发现是用的索引范围扫描啊,没有任何问题???


3. explain plan for方式得到的执行计划有可能是不准的,@dbsnake的书中有详细介绍,那么看看display_cursor方式得到的执行计划有不同

SQL> select count(*) from t_n where object_name = :x;

  COUNT(*)
----------
	 1

SQL> select sql_text,sql_id,version_count from v$sqlarea where sql_text like 'select count(*) from t_n where object_name%';

SQL_TEXT
--------------------------------------------------------------------------------
SQL_ID	      VERSION_COUNT
------------- -------------
select count(*) from t_n where object_name = :x
630ztwp0w2b6f		  1

SQL> select * from table(dbms_xplan.display_cursor('630ztwp0w2b6f',0,'advanced'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
SQL_ID	630ztwp0w2b6f, child number 0
-------------------------------------
select count(*) from t_n where object_name = :x

Plan hash value: 4075463224

---------------------------------------------------------------------------
| Id  | Operation	   | Name | Rows  | Bytes | Cost (%CPU)| Time	  |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |	  |	  |	  |   290 (100)|	  |
|   1 |  SORT AGGREGATE    |	  |	1 |    66 |	       |	  |

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
|*  2 |   TABLE ACCESS FULL| T_N  |    12 |   792 |   290   (1)| 00:00:04 |
---------------------------------------------------------------------------

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

   1 - SEL$1
   2 - SEL$1 / T_N@SEL$1

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

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

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('11.2.0.1')
      DB_VERSION('11.2.0.1')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$1")
      FULL(@"SEL$1" "T_N"@"SEL$1")
      END_OUTLINE_DATA
  */

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

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

   1 - :X (NVARCHAR2(30), CSID=2000): 'ABC'

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter(SYS_OP_C2C("OBJECT_NAME")=:X)


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

   1 - (#keys=0) COUNT(*)[22]

Note
-----
   - dynamic sampling used for this statement (level=2)


53 rows selected.
看到不同了。。。

注意filter中显示SYS_OP_C2C("OBJECT_NAME")=:X,说明Oracle对左值使用了一个叫SYS_OP_C2C的函数,我们都知道这个常识,如果对索引字段使用了函数,那么是不会采用这个索引作为执行计划的,肯定是全表扫描。

看来问题是找到关键了,但还没完,这个SYS_OP_C2C是什么,为什么对VARCHAR2 = NVARCHAR2这种情况会调用这个函数?


首先搜到了MOS有篇文章SYS_OP_C2C Causing Full Table/Index Scans (文档 ID 732666.1),简明扼要地说明了这个问题:

1) You are executing a query using bind variables.

2) The binding occurs via an application (eg. .NET, J2EE ) using a "string" variable to bind.

3) The query is incorrectly performing a full table/index scan instead of an unique/range index scan.  

4) When looking at advanced explain plan, sqltxplain or 10053 trace, you notice that the "Predicate Information" shows is doing a "filter(SYS_OP_C2C)".

e.g select * from table(dbms_xplan.display_cursor(&sql_id,null,'ADVANCED'));

Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(SYS_OP_C2C("COL1")=:B1)            <=== filter operation occurring

CAUSE

The bind variable "string" is using a different datatype to the column that is being queried.  
This means that an implicit conversion of the data is required to execute the query.  SYS_OP_C2C is the implicit function which is used to convert the column between nchar and char.

SOLUTION

  1. Create a function based index on the column.

e.g create index <index_name> on <table_name> (SYS_OP_C2C(<column>));

OR
  2. Ensure that your bind "string" datatype and column datatype are the same.
      A java example where this can occurs is when defaultNChar=TRUE.  This will cause strings to bind as NVARCHAR2 causing the predicate that are subset datatypes to be converted to NVARCHAR2.
      e.g.    -Doracle.jdbc.defaultNChar=true
                <connection-property name="defaultNChar">true</connection-property>

说明的很是详细了,如果应用程序(例如.NET,Java)中使用了“string”的绑定变量,查询语句就会使用全表扫描/索引全扫描,不会使用到唯一索引扫描/索引范围扫描。使用advanced选项的explain plan或10053等方式才能发现这个问题。

原因就是“string”的绑定变量是使用了另外一种和查询列定义不同的数据类型。Oracle需要使用SYS_OP_C2C函数在NCHAR和CHAR类型之间做隐式转换。

解决方法:

1. 创建函数索引。

2. 确保应用程序中使用的“string”类型和列字段类型一致。


另外,杨长老对这个问题也有过说明(http://blog.itpub.net/4227/viewspace-531728/)。


后话是,开发同事之前没用过Oracle,写程序时不知怎的就用了NVARCHAR2的定义,且测试和生产环境不一致,才导致了这个在上线后才出现的问题。


总结:

1. 一个很小的字段定义,有可能造成意想不到的后果,说明了解Oracle一些基本原理的重要性,这里不仅指提到的字段类型。

2. 分析一个问题,要有正确的思路,要能抓到问题本质,像这个问题,就是不同方式执行同一条SQL,会有不同的执行计划,那么为什么Oracle选择了错误的执行计划?是有原因的,不是Oracle自己选择错了,更多情况是我们给他的信息错了,影响了其选择执行计划的准确性。如果能排除一些参数影响,定位到什么原因导致索引失效,进而查看列字段定义和应用程序中的字段类型定义,这个问题就可能更快的找到原因。这点还有待加强。

3. 要有分析的方法,这里10046、10053,包括display_cursor,都是可能找到问题的重要手段,一是要知道什么场景下使用这些工具,二是知道如何使用这些工具,像explain plan for得到的执行计划有可能是不准的,尤其在有绑定变量的情况,上述就论证了这点,关键看是否真正执行了这条SQL语句;还有就像使用display_cursor,前提是执行过这条SQL,并且执行计划仍在缓存中,通过v$sqlarea可以找到对应的SQLID,这都是基础。

4. 要细心,对于上述问题,可能从10046中就可以看到谓词条件带有隐式转换的线索,进而可以找到问题的真正原因,即使之前不知道SYS_OC_C2C,不知道NVARCHAR2和VARCHAR2之间的区别,也可以让我们有正确的认识。

5. 要能模拟出问题,像这里使用var x nvarchar2的方式,就是模拟了应用程序使用绑定变量的逻辑。

6. 自己需要提高的地方还很多,宽度深度都如此,加油。

网友评论

登录后评论
0/500
评论
bisal
+ 关注