一次ORA-4030问题诊断及解决(二)


在报表数据库的后台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的值,也就导致了问题的产生。

  看来正是由于版本的差异,从而导致了这个问题在目标数据库中暴露了出来

本文作者:
« 
» 
快速导航

Copyright © 2016 phpStudy | 豫ICP备2021030365号-3