在报表数据库的后台alert文件中发现了这个错误,简单记录一下问题的诊断和解决过程。数据库版本9204 for Solaris sparc64。
继续寻找源数据库和目标数据库执行计划不同的原因。
在前面的文章中,已经解决了问题,但是事情并没有结束。还没有找到导致问题的原因。
上文以及提到,导致问题的三种可能性分别是本地设置问题、版本问题和迁移问题。
现在通过第一篇文章的诊断,基本上排除了本地设置的问题,那么只有两种可能性了,版本问题和迁移问题。
首先,9201到9204更多的是修改了bug,优化器的改动并不算太大,因此版本变化引发问题的可能性并不算太大,这里更多的是怀疑迁移造成的问题。
由于这个用户是刚刚通过EXP/IMP从9201导入到本地环境的,因此,很可能迁移过程中的错误导致了这个问题。
检查过程的脚本,果然发现,在导入ORD_HIT_COMM表的数据后,继续导入统计信息时出现了错误:
. . 正在导入表 "ORD_HIT_COMM" 1688957行被导入IMP-00017: 由于 ORACLE 的 6550 错误,以下的语句失败
"DECLARE SREC DBMS_STATS.STATREC; BEGIN SREC.MINVAL := '454D454431303030303"
"03030343035383238393730303030'; SREC.MAXVAL := '454D45443130303030303030343"
"139393232303130303030'; SREC.EAVS := 4; SREC.CHVALS := DBMS_STATS.CHARARRAY"
"(DECLARE SREC DBMS_STATS.STATREC; BEGIN SREC.MINVAL := '454D45443130303030"
"303030343035383238393730303030'; SREC.MAXVAL := '454D4544313030303030303034"
"3139393232303130303030'; SREC.EAVS := 4; SREC.CHVALS := DBMS_STATS.CHARARRA"
"Y(,,164,165,166,167,168,170,178,179,184,188,189,190,191,192,196,198,199,200"
",201,202,203,210,212,213,217,221,226,227,228,229,230,232,245,246,249,250,25"
"1,252,253,254); SREC.NOVALS := DBMS_STATS.NUMARRAY(359835716626043000000000"
"000000000000,359835716626043000000000000000000000); SREC.BKVALS := DBMS_STA"
"TS.NUMARRAY(0,1); SREC.EPC := 2; DBMS_STATS.SET_COLUMN_STATS(NULL,'"ORD_HIT"
"_COMM"','"GROUP_PROJECT_ID"', NULL ,NULL,NULL,2,.0000320292670849273,164925"
"8,srec,2,2); END;"
IMP-00003: 遇到 ORACLE 错误 6550
ORA-06550: 第 1 行, 第 227 列:
PLS-00103: 出现符号 "DECLARE"在需要下列之一时:
( ) - + case mod new
not null others
table avg count current exists max min prior sql stddev sum
variance execute multiset the both leading trailing forall
merge year month DAY_ hour minute second timezone_hour
timezone_minute timezone_region timezone_abbr time timestamp
interval date
表本身的统计信息已经成功导入,只是处理列的统计信息时出现了错误,所以导入结束之后,进行检查的时候,发现表的统计信息已经成功导入,因此并没有发现其他的异常
这个现象正好可以说明为什么同样的问题在源数据库没有发生,而在目标数据库却发生了。
不过根据错误信息显示,当前在处理统计信息的列是GROUP_PROJECT_ID,而不是ENABLE_FLAG。这其实并没有关系,只要源数据库中的列的统计信息与当前数据库中的不一致,就可以说明问题了,因为导入的时候很可能由于中途出现错误,而使得随后的一些统计信息的处理没有完成。
下面检查源数据库和目标数据库的统计信息是否有差异:
SQL> SELECT * FROM GLOBAL_NAME;
GLOBAL_NAME
---------------------------------------------------------------------------------
BJTEST
SQL> SELECT COLUMN_NAME, NUM_DISTINCT, NUM_NULLS, DENSITY, NUM_BUCKETS
2 FROM USER_TAB_COLUMNS
3 WHERE TABLE_NAME = 'ORD_HIT_COMM'
4 AND COLUMN_NAME = 'ENABLE_FLAG';
COLUMN_NAME NUM_DISTINCT NUM_NULLS DENSITY NUM_BUCKETS
------------ ------------ ---------- ---------- -----------
ENABLE_FLAG 2 0 2.9971E-07 1
SQL> SELECT * FROM USER_TAB_HISTOGRAMS
2 WHERE TABLE_NAME = 'ORD_HIT_COMM'
3 AND COLUMN_NAME = 'ENABLE_FLAG';
TABLE_NAME COLUMN_NAME ENDPOINT_NUMBER ENDPOINT_VALUE ENDPOINT_ACTUAL_VALUE
------------- ------------ --------------- -------------- ----------------------
ORD_HIT_COMM ENABLE_FLAG 0 2.4988E+35
ORD_HIT_COMM ENABLE_FLAG 1 2.5507E+35
这是现在目标数据库的相关统计信息,在看源数据库的统计信息:
SQL> SELECT * FROM GLOBAL_NAME;
GLOBAL_NAME
--------------------------------------------------------------------------
ORCL
SQL> SELECT COLUMN_NAME, NUM_DISTINCT, NUM_NULLS, DENSITY, NUM_BUCKETS
2 FROM USER_TAB_COLUMNS
3 WHERE TABLE_NAME = 'ORD_HIT_COMM'
4 AND COLUMN_NAME = 'ENABLE_FLAG';
COLUMN_NAME NUM_DISTINCT NUM_NULLS DENSITY NUM_BUCKETS
------------ ------------ ---------- ---------- -----------
ENABLE_FLAG 2 0 2.9971E-07 1
SQL> SELECT * FROM USER_TAB_HISTOGRAMS
2 WHERE TABLE_NAME = 'ORD_HIT_COMM'
3 AND COLUMN_NAME = 'ENABLE_FLAG';
TABLE_NAME COLUMN_NAME ENDPOINT_NUMBER ENDPOINT_VALUE ENDPOINT_ACTUAL_VALUE
------------- ------------ --------------- -------------- ----------------------
ORD_HIT_COMM ENABLE_FLAG 0 2.4988E+35
ORD_HIT_COMM ENABLE_FLAG 1 2.5507E+35
从上面的查询上看,所有的统计信息完全一致。既然统计信息完全一致,为什么Oracle认为SQL语句的返回记录会有这么大的差别呢,从而导致了SQL执行计划的不同
看来前面推断迁移过程中的错误导致问题的产生是不正确的,因为现在看到这个列上的统计信息是完全一致的。那么完全相同的统计信息如何产生不同的结果呢,莫非真的是9204和9201版本之间的差异,看来只能通过10053事件来进行分析了。
在目标数据库9204上设置10053事件,并检查得到的trace文件:
[oracle@bjtest data]$ sqlplus jiangsu/jiangsu
SQL*Plus: Release 9.2.0.4.0 - Production on 星期四 5月 1 03:02:11 2008
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
连接到:
Oracle9i Enterprise Edition Release 9.2.0.4.0 - 64bit Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.4.0 - Production
SQL> ALTER SESSION SET EVENTS '10053 TRACE NAME CONTEXT FOREVER, LEVEL 1';
会话已更改。
SQL> EXPLAIN PLAN FOR SELECT * FROM ORD_HIT_COMM WHERE ENABLE_FLAG = 1;
已解释。
SQL> HOST
[oracle@bjtest udump]$ more /opt/oracle/admin/bjtest/udump/bjtest_ora_5933.trc
/opt/oracle/admin/bjtest/udump/bjtest_ora_5933.trc
Oracle9i Enterprise Edition Release 9.2.0.4.0 - 64bit Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.4.0 - Production
ORACLE_HOME = /opt/oracle/product/9.2
System name: Linux
Node name: bjtest
Release: 2.6.18-8.el5xen
Version: #1 SMP Tue Jun 5 23:53:34 EDT 2007
Machine: x86_64
Instance name: bjtest
Redo thread mounted by this instance: 1
Oracle process number: 10
Unix process pid: 5933, image: oracle@bjtest (TNS V1-V3)
*** 2008-05-01 03:03:02.106
*** SESSION ID:(25.3298) 2008-05-01 03:03:02.084
QUERY
EXPLAIN PLAN FOR SELECT * FROM ORD_HIT_COMM WHERE ENABLE_FLAG = 1
***************************************
PARAMETERS USED BY THE OPTIMIZER
********************************
OPTIMIZER_FEATURES_ENABLE = 9.2.0
OPTIMIZER_MODE/GOAL = Choose
.
.
.
_CPU_TO_IO = 0
_PRED_MOVE_AROUND = TRUE
***************************************
BASE STATISTICAL INFORMATION
***********************
Table stats Table: ORD_HIT_COMM Alias: ORD_HIT_COMM
TOTAL :: CDN: 1681983 NBLKS: 89780 AVG_ROW_LEN: 733
_OPTIMIZER_PERCENT_PARALLEL = 0
***************************************
SINGLE TABLE ACCESS PATH
Column: ENABLE_FLA Col#: 21 Table: ORD_HIT_COMM Alias: ORD_HIT_COMM
NDV: 2 NULLS: 0 DENS: 2.9971e-07
NO HISTOGRAM: #BKT: 1 #VAL: 2
TABLE: ORD_HIT_COMM ORIG CDN: 1681983 ROUNDED CDN: 1 CMPTD CDN: 1
Access path: tsc Resc: 8636 Resp: 8636
BEST_CST: 8636.00 PATH: 2 Degree: 1
***************************************
OPTIMIZER STATISTICS AND COMPUTATIONS
***************************************
GENERAL PLANS
***********************
Join order[1]: ORD_HIT_COMM [ORD_HIT_COMM]
Best so far: TABLE#: 0 CST: 8636 CDN: 1 BYTES: 733
Final:
CST: 8636 CDN: 1 RSC: 8636 RSP: 8636 BYTES: 733
IO-RSC: 8636 IO-RSP: 8636 CPU-RSC: 0 CPU-RSP: 0
PLAN
Cost of plan: 8636
Operation...........Object name.....Options.........Id...Pid..
SELECT STATEMENT 0
TABLE ACCESS ORD_HIT_COMM FULL 1
分析9204上的执行计划,没有什么特殊的地方,下面在看看源数据库9201上的事件分析结果:
$ sqlplus shgov
SQL*Plus: Release 9.2.0.1.0 - Production on 星期三 4月 30 18:52:16 2008
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
请输入口令:
连接到:
Oracle9i Enterprise Edition Release 9.2.0.1.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.1.0 - Production
SQL> alter session set events '10053 trace name context forever, level 1';
会话已更改。
SQL> explain plan for select * from ord_hit_comm where enable_flag = 1;
已解释。
SQL> host
$ more $ORACLE_BASE/admin/orcl/udump/orcl_ora_17582.trc
/oracle/admin/orcl/udump/orcl_ora_17582.trc
Oracle9i Enterprise Edition Release 9.2.0.1.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.1.0 - Production
ORACLE_HOME = /oracle/app/product/9.2.0
System name: SunOS
Node name: jssf4900a
Release: 5.10
Version: Generic_118822-23
Machine: sun4u
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 187
Unix process pid: 17582, image: oracle@jssf4900a (TNS V1-V3)
*** 2008-04-30 18:53:16.849
*** SESSION ID:(187.390) 2008-04-30 18:53:16.848
QUERY
explain plan for select * from ord_hit_comm where enable_flag = 1
***************************************
PARAMETERS USED BY THE OPTIMIZER
********************************
OPTIMIZER_FEATURES_ENABLE = 9.2.0
OPTIMIZER_MODE/GOAL = Choose
.
.
.
_CPU_TO_IO = 0
_PRED_MOVE_AROUND = TRUE
***************************************
BASE STATISTICAL INFORMATION
***********************
Table stats Table: ORD_HIT_COMM Alias: ORD_HIT_COMM
TOTAL :: CDN: 1681983 NBLKS: 89780 AVG_ROW_LEN: 733
_OPTIMIZER_PERCENT_PARALLEL = 0
***************************************
SINGLE TABLE ACCESS PATH
Column: ENABLE_FLA Col#: 21 Table: ORD_HIT_COMM Alias: ORD_HIT_COMM
NDV: 2 NULLS: 0 DENS: 5.0000e-01
NO HISTOGRAM: #BKT: 1 #VAL: 2
TABLE: ORD_HIT_COMM ORIG CDN: 1681983 ROUNDED CDN: 840992 CMPTD CDN: 840992
Access path: tsc Resc: 8636 Resp: 8636
BEST_CST: 8636.00 PATH: 2 Degree: 1
***************************************
OPTIMIZER STATISTICS AND COMPUTATIONS
***************************************
GENERAL PLANS
***********************
Join order[1]: ORD_HIT_COMM [ORD_HIT_COMM]
Best so far: TABLE#: 0 CST: 8636 CDN: 840992 BYTES: 616447136
Final:
CST: 8636 CDN: 840992 RSC: 8636 RSP: 8636 BYTES: 616447136
IO-RSC: 8636 IO-RSP: 8636 CPU-RSC: 0 CPU-RSP: 0
PLAN
Cost of plan: 8636
Operation...........Object name.....Options.........Id...Pid..
SELECT STATEMENT 0
TABLE ACCESS ORD_HIT_COMM FULL 1
现在问题已经很显然了,Oracle分析的时候认为DENSITY是0.5,而不是从统计信息查询处理的结果:2.9971e-07。而使用0.5作为DENSITY的值,显然是可以得到正确的返回记录数的。这个值也是目标数据库删除统计信息,并重新生成统计信息后的值。
看来在9201中Oracle并没有采用统计信息中DENSITY的值,而是使用了1/ NUM_DISTINCT作为DENSITY的值,虽然对于当前的问题,这样使用恰好可以得到“正确”的返回记录数,但是这种方式显然是存在问题的,比如列中包含了大量NULL的情况,这样直接使用1/ NUM_DISTINCT就是不准确的。
而9204中修正了这个bug,使用了统计信息中的DENSITY的值,也就导致了问题的产生。
看来正是由于版本的差异,从而导致了这个问题在目标数据库中暴露了出来