ORA-04031这个错误,几乎每一个专业的DBA都遇到过。这是一个相当严重的错误,Oracle进程在向SGA申请内存时,如果申请失败,则会报这个错误。大部分情况下是在向SGA中的shared pool申请内存时失败,而少有向large pool等池中申请内存失败。比如下面的报错:

Wed Apr 27 16:00:25 2011
Errors in file /oracle/app/oracle/admin/zxin/bdump/zxin1_ora_2052294.trc:
ORA-04031: unable to allocate 4128 bytes of shared memory 
("shared pool","unknown object","sga heap(3,0)","kgllk hash table")

这里很清楚地表示出来,是在向shared pool申请内存时失败。

shared pool内存申请(分配)失败,通常有如下的几种可能:

  • shared pool过小,比如在SGA Manual Management方式下,shared pool设置过小。比如一套数千连接的大系统,shared pool只设置了几百M。这种情况下,要解决问题很解单,增加shared pool的大小即可。
  • 应用没有使用绑定变量,硬解析非常多,导致shared pool内存碎片严重,分配大块内存时不能获得连续的内存空间。硬解析多的一个变种是虽然使用了绑定变量,但是由于某种原因,Cursor不能共享,导致Child Cursor非常多。实际上,如果shared pool较大(比如数GB大小),这种问题还是很少出现的,并且出现也通常出现在申请大块内存时。这种情况如果使用alter system flush shared_pool可以暂时缓解问题。但是这条命令又通常不适用于shared pool较大而且比较繁忙的系统。使用绑定变量
  • Cache的cursor很多,同时cursor_space_for_time这一参数设置为TRUE,可能会使shared pool碎片化严重,导致不能分配到大块的连续内存。
  • Oracle的BUG导致内存泄露,比如在一些版本中查询v$segment_statistics这样的视图导致内存泄露,使shared pool内存耗光。同样的情形还有类似于“obj stat memory”,"gcs resources","ges resources"等。通常这类内存为perm类型(permanet),这类内存通常是在分配时就确定了固定的用途,不能用于其他用途,因此极容易产生碎片。
  • Oracle从9i开始,根据shared pool的大小将shared pool分为多个子池(subpool),每个子池有独立的free list,同时在分配时单独管理(有其独立 的shared pool latch)。Oracle的BUG或者说是内存分配策略缺陷导致某一类shared pool的内存分配只在一个子池(subpool)中,即多个子池的使用极不均衡,导致向那个使用得最多的子池申请内存时失败。报错信息中的"sga heap(3,0)"即指明是在第3个子池申请内存时失败。本文案例中的ORA-04031错误其产生的原因可以归结为Oracle对shared pool的分配/使用策略问题。
  • 操作系统内存不足,这只会出现在shared pool的使用还没有达到最大值时才会出现,并且在操作系统都有swap的情况下,只有部分操作系统才可能有这种情况,比如在HP-UX下,reserved 内存过多导致swap满。
  • 其他原因,多数是因为BUG。请参考下面提及的MOS参考文档。

本文中的案例,其数据库是运行在AIX 5.3系统中的10.2.0.4 RAC,RAC节点数为2。数据库是从9i升级到10g,而目前处于正式升级前的测试阶段。数据库报的ORA-04031错误信息如本文前面所示(其中的数据库名称已经做了处理)。

在继续讲解案例之前,不得不提到MOS上的几篇关于ORA-04031错误的文档:

  • Master Note for Diagnosing ORA-4031 [ID 1088239.1]
  • Diagnosing and Resolving Error ORA-04031 on the Shared Pool or Other Memory Pools [Video] [ID 146599.1]
  • Interpreting the automatically generated ORA-4031 diagnostic trace. [ID 809560.1]
  • Troubleshooting and Diagnosing ORA-4031 Error [Video] [ID 396940.1]
  • ORA-4031 Common Analysis/Diagnostic Scripts [Video] [ID 430473.1]

其实分析ORA-04031错误,通常有以下几个要点:

  • 判断错误发生所有的内存区域,是shared pool,large pool还是streams pool等。这个很容易从错误信息中判断出来,本文主要描述shared pool的ORA-04031错误,这也是最常见的。
  • 检查Shared Pool的总大小以及free memory的大小。如果free memory看上去挺多,以subpool为单位检查是否存在是由于碎片导致没有足够的连续内存以供分配,特别是关注报错信息中提及的子池。
  • 如果Shared Pool相较于系统规模来说足够大(通常数GB都已经是很大的了),检查Shared Pool中有没有占用非常多的内存类型或内存组件,如果有,是什么样的类型的内存,在各个子池之间是否分布均匀。如果有异常占用较多的内存类型,根据此类型在MOS上搜寻是否是会有相应的BUG引起,或者分析这种类型的内存消耗较多的原因。比如如果是sql area很大,检查是不是硬解析特别多,或者是不是child cursor特别多引起。
  • 基于以上分析的数据,来判断shared pool内存分配失败的原因。

上面的步骤写得比较粗略,关于分析和解决ORA-04031问题,这里也有一篇不错的文章:Simplified Approach to Resolve ORA-4031

这里关键的是分析Shared Pool的内存数据。ORA-04031错误发生后如果有条件可以马上连接到数据库中查询相应的x$表和v$视图得到相应的数据,否则只能通过ORA-4031错误发生时产生的trace文件。_4031_dump_bitvec这个隐含参数用于控制发生ORA-04031错误时对SGA的dump行为,而trace文件的分析就不像使用SQL那样简单了。

下面再来详细地分析案例:
从错误信息来看,很显然,是向shared pool的第3个subpool申请内存时出错。
以下的数据是shared pool的数据:

Read the rest of this entry

ORA-01555错误是一种在Oracle数据库中很常见的错误。尤其在Oracle 8i及之前的版本最多。从9i开始的undo自动管理,至现在的10g、11g中的undo auto tuning,使得ORA-01555的错误越来越少。但是这个错误,仍然不可避免。而出现ORA-01555错误,通常有2种情况:

  • SQL语句执行时间太长,或者UNDO表空间过小,或者事务量过大,或者过于频繁的提交,导致执行SQL过程中进行一致性读时,SQL执行后修改的前镜像(即UNDO数据)在UNDO表空间中已经被覆盖,不能构造一致性读块。
  • SQL语句执行过程中,访问到的块,在进行延迟块清除时,不能确定该块的事务提交时间与SQL执行开始时间的先后次序。

第1种情况,是最常见的。解决的办法无非就是增加UNDO表空间大小,优化出错的SQL,或者避免频繁地提交。而第2种情况则是比第1种情况少很多。下面简单描述一下第2种情况发生的情景:

  • 有事务大量修改了A表的数据,或者A表的数据虽然被事务少量修改,但是一部分修改过的块已经刷出内存并写到了磁盘上。随即事务提交,提交时刻为SCN1。而提交时有数据块上的事务没有被清除。
  • 在SCN2时刻,开始执行SELECT查询A表,对A表进行全表扫描,而且A表很大。也可能是其他情况,比如是小表,但是是一个游标方式的处理过程,而处理过程中又非常耗时。注意,这里SCN2与SCN1之间可能相隔了很远,从时间上来说,甚至可能有数十天。不管怎么样,这在SCN1至SCN2时间之间,系统中存在大量的事务,使得UNDO表空间的块以及UNDO段头的事务表全部被重用过。
  • SELECT语句在读A表的一个块时,发现表上有活动事务,这是由于之前的事务没有清除所致。ORACLE根据数据块中ITL的XID检查事务表,这时会有2种情况:
    • XID对应的事务表中的记录仍然存在并发现事务已经提交,可以得到事务准确的提交SCN(commit scn),称为SCN3,等于SCN1。很显然,由于查询的时刻SCN2晚于事务提交的时刻SCN1,那么不需要构造一致性读块。
    • XID对应的事务表中的记录已经被重用,这个时候仍然表明表明事务已经被提交。那么这个时候,Oracle没办法准确地知道事务的提交时间,只能记录为这样一个事实,事务提交的SCN小于其UNDO段的事务表中最近一次重用的事务记录的SCN(即这个事务表最老的事务SCN)。这里称这个SCN为SCN4。
  • SCN4可能远小于SCN2,那是因为事务很早之前就已经提交。也可能SCN4大于SCN2,这是因为SELECT语句执行时间很长,同时又有大量的事务已经将事务表重用。对于后者,很显然,Oracle会认为该事务的提交时间可能在SELECT开始执行之后。这里为什么说可能,是因为ORACLE只能判断出事务是在SCN4之前提交的,并不是就刚好在SCN4提交。而此时,利用UNDO BLOCK进行一致性读数据的构造也很可能失败,因为UNDO BLOCK很可能已经被覆盖,特别是SCN1远小于SCN2的情况下。在这种情况下,ORA-01555错误就会出现。

对于上面最后一段,在SCN4大于SCN2的情况下,之后的描述,我提到了几个“可能”,是因为我对此也不能完全确定,Oracle是否还会有其他的方法来判断 事务的提交时间早于SCN2。而我自己的模拟测试始终没有模拟出ORA-01555。我的测试过程是这样子的:

  • 修改表T1,注意T1表已经足够大,比如几十万行数据以上。
  • flush buffer_cache,使未提交的事务修改的块全部刷出内存。
  • 提交事务。
  • 使用大量的事务(注意这些事务不含表T1),将UNDO表空间填满并确保所有事务表已经被全部重用过。
  • 写一段代码,以游标方式打开表T1,在游标的循环中使用dbms_lock.sleep故意增加时间。
  • 同时多个JOB会话产生大量与表T1无关的事务,将UNDO表空间填满并确保所有事务表已经被全部重用过。

在我的期望中,上面的测试,对于游标处理部分,应该会报ORA-01555错误。但实际测试并没有出现,对于这类情形,看起来Oracle还有其他的机制来发现块上的事务提交时间早于查询开始时间。

虽然测试没有达到预期的结果,但是对于事务提交后块没有清除引起的ORA-01555错误,需要几个充分的条件:表足够大,表上的事务提交后有没有事务清除的块,对大表进行长时间的查询比如全表扫描,查询开始后有大量的事务填充和UNDO表空间和重用了事务表。

而下面则是延迟块清除时引起的ORA-01555错误的一则案例。

首先进行简单的环境介绍,运行在HP-UX环境下的Oracle 10.2.0.3,主机只有4颗比较老的PA-RISC CPU。这个系统的特点是大数据量的批量处理,基本上都是大数据量的插入。每个月的数据有单独的表,表一般都是在几十G以上,大的表超过100G。CPU利用率长期保持在100%。

由于空间限制,需要定期将一些N个月之前的表导出备份到磁带上,然后将表删除。这些表,在导出时是不可能会有DML操作的。由于性能原因,导出时间过长(几个小时以上),在导出时经常会遇到ORA-01555错误而失败。这里不讨论怎么样提高性能使导出时间更短,这里只提出一种方法来解决ORA-01555错误。

从之前对ORA-01555错误的成因分析可以知道,这个ORA-01555错误,正是由于表上存在未清除的事务,同时导出时间过长,UNDO段头的事务表被全部重用,ORACLE在查询到有未清除事务的块时不能确定事务提交时间是否早于导出(查询)开始时间,这时候就报ORA-01555错误。

要解决这个错误,除了提高性能,那么从另一个角度来思考这个问题,可以想办法先清除掉表上的事务(即延迟块清除)。那么我们可以通过一个简单的SELECT语句来解决:

SELECT /*+ FULL(A) */ COUNT(*) FROM BIG_TABLE A;

SELECT COUNT(*),速度显然大大高于SELECT *,所需的时间也更短,出现ORA-01555错误的可能性就非常低了。

注意这里需要加上FULL HINT,以避免查询进行索引快速全扫描,而不是对表进行全表扫描。另外,需要注意的是,这里不能为了提高性能而使用PARALLEL(并行),测试表明,在表上进行并行查询,以DIRECT READ方式读取表并不会清除掉表上的事务。

如果表过大,SELECT COUNT(*)的时间过长,那么我们可以用下面的代码将表分成多个段,进行分段查询。


  select dbms_rowid.rowid_create(1, oid1, fid1, bid1, 0) rowid1,
         dbms_rowid.rowid_create(1, oid2, fid2, bid2, 9999) rowid2
    from (select a.*, rownum rn
            from (select chunk_no,
                         min(oid1) oid1,
                         max(oid2) oid2,
                         min(fid1) fid1,
                         max(fid2) fid2,
                         min(bid1) bid1,
                         max(bid2) bid2
                    from (select chunk_no,
                                 FIRST_VALUE(data_object_id) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) oid1,
                                 LAST_VALUE(data_object_id) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) oid2,
                                 FIRST_VALUE(relative_fno) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) fid1,
                                 LAST_VALUE(relative_fno) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) fid2,
                                 FIRST_VALUE(block_id) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) bid1,
                                 LAST_VALUE(block_id + blocks - 1) OVER(PARTITION BY chunk_no ORDER BY data_object_id, relative_fno, block_id ROWS BETWEEN UNBOUNDED PRECEDING AND UNBOUNDED FOLLOWING) bid2
                            from (select data_object_id,
                                         relative_fno,
                                         block_id,
                                         blocks,
                                         ceil(sum2 / chunk_size) chunk_no
                                    from (select /*+ rule */ b.data_object_id,
                                                 a.relative_fno,
                                                 a.block_id,
                                                 a.blocks,
                                                 sum(a.blocks) over(order by b.data_object_id, a.relative_fno, a.block_id) sum2,
                                                 ceil(sum(a.blocks)
                                                      over() / &trunks) chunk_size
                                            from dba_extents a, dba_objects b
                                           where a.owner = b.owner
                                             and a.segment_name = b.object_name
                                             and nvl(a.partition_name, '-1') =
                                                 nvl(b.subobject_name, '-1')
                                             and b.data_object_id is not null
                                             and a.owner = upper('&owner')
                                             and a.segment_name = upper('&table_name'))))
                   group by chunk_no
                   order by chunk_no) a);

在上面的代码中trunks变量表示表分为的段数。
代入trunks,owner,table_name三条SQL,执行上面的代码,出来的结果类似如下:

ROWID1             ROWID2
------------------ ------------------
AAAER9AAIAAABGJAAA AAAER9AAIAAABIICcP
AAAER9AAIAAABIJAAA AAAER9AAIAAABMICcP
AAAER9AAIAAABMJAAA AAAER9AAIAAABQICcP
AAAER9AAIAAABQJAAA AAAER9AAIAAABWICcP
AAAER9AAIAAABWJAAA AAAER9AAIAAABaICcP
AAAER9AAIAAABaJAAA AAAER9AAIAAABcICcP
AAAER9AAIAAABcJAAA AAAER9AAIAAABgICcP
AAAER9AAIAAABgJAAA AAAER9AAIAAABkICcP
AAAER9AAIAAABkJAAA AAAER9AAIAAABoICcP
AAAER9AAIAAABoJAAA AAAER9AAIAAABsICcP

然后对每一个ROWID段执行类似下面的SQL:

SELECT /*+ NO_INDEX(A) */ COUNT(*) FROM BIG_TABLE A WHERE ROWID>='AAAER9AAIAAABGJAAA' AND ROWID< ='AAAER9AAIAAABIICcP';

对表进行分段处理,除了此处的用法,完全可以用于手工多进程处理大批量数据。更完整的功能已经在11g中实现,此处不做过多介绍。

对于本文提到的导出数据遇到ORA-01555错误的表,按上述方法处理后,问题得到解决,表顺利导出。

在上一篇《SQL Profiles-Part I》,我向大家介绍了什么是SQL Profiles及其作用,如何使用SQL Tuning Advisor来生成SQL Profile,以及生成的SQL Profile产生的Hint。同时也介绍了SQL的signature。那么在今天,将向大家介绍如何手工创建SQL Profiles(即不通过SQL Tuning Advisor)来达成2个目的:

  • 锁定或者说稳定SQL执行计划。
  • 在不能修改应用的SQL的情况下,来改变或者说是强制使SQL使用我们指定的执行计划,即使原始的SQL包含了Hints。

那么,这里最关键的一点是,如何来手工创建SQL Profiles?
答案是,正如上一篇中有朋友的留言,使用DBMS_SQLTUNE.IMPORT_SQL_PROFILE过程。

SQL> desc dbms_sqltune
...
PROCEDURE IMPORT_SQL_PROFILE
参数名称                       类型                    输入/输出默认值?
------------------------------ ----------------------- ------ --------
 SQL_TEXT                       CLOB                    IN
 PROFILE                        SQLPROF_ATTR            IN
 NAME                           VARCHAR2                IN     DEFAULT
 DESCRIPTION                    VARCHAR2                IN     DEFAULT
 CATEGORY                       VARCHAR2                IN     DEFAULT
 VALIDATE                       BOOLEAN                 IN     DEFAULT
 REPLACE                        BOOLEAN                 IN     DEFAULT
 FORCE_MATCH                    BOOLEAN                 IN     DEFAULT
...

这个过程其名字与实际功能有所差异,其实可以理解为CREATE OR REPLACE SQL_PROFILE。过程中的PROFILE参数为SYS.SQLPROF_ATTR,这种类型其实就是VARCHAR2的集合类型(COLLECTION):

SQL> select text from dba_source where name='SQLPROF_ATTR' and owner='SYS';

TYPE     sqlprof_attr
 AS VARRAY(2000) of VARCHAR2(500)

下面我们就用这个过程来创建SQL PROFILE:
为避免干扰,将上一篇测试中生成的SQL Profile删除掉,同时恢复T1表的统计信息中的表行数:

SQL> exec dbms_sqltune.drop_sql_profile('SYS_SQLPROF_014b39f084c88000');

PL/SQL 过程已成功完成。

SQL> exec dbms_stats.set_table_stats('TEST1','T1',numrows=>49953);

PL/SQL 过程已成功完成。

现在我们手工创建一个SQL Profile:

SQL> declare
  2    v_hints sys.sqlprof_attr;
  3  begin
  4    v_hints:=sys.sqlprof_attr('USE_NL(T1 T2)','INDEX(T2)');
  5    dbms_sqltune.import_sql_profile('select t1.*,t2.owner from t1,t2 where t1.object_name like ''%T1%'' and t1.object_id=t2.object_id',
  6                v_hints,'SQLPROFILE_NAME1',force_match=>true);
  7  end;
  8  /

PL/SQL 过程已成功完成。

SQL> select attr_val from dba_sql_profiles a, sys.sqlprof$attr b
  2  where a.signature = b.signature
  3  and a.name='SQLPROFILE_NAME1';

ATTR_VAL
----------------------------------------
USE_NL(T1 T2)
INDEX(T2)

下面执行SQL Profiles对应的SQL:

SQL> select  t1.*,t2.owner
  2       from t1,t2
  3       where t1.object_name like '%T1%'
  4       and t1.object_id=t2.object_id;

已选择29行。

执行计划
----------------------------------------------------------
Plan hash value: 1838229974

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |  2498 | 99920 |   219   (4)| 00:00:03 |
|*  1 |  HASH JOIN         |      |  2498 | 99920 |   219   (4)| 00:00:03 |
|*  2 |   TABLE ACCESS FULL| T1   |  2498 | 72442 |    59   (6)| 00:00:01 |
|   3 |   TABLE ACCESS FULL| T2   | 49954 |   536K|   159   (2)| 00:00:02 |
---------------------------------------------------------------------------

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

   1 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")
   2 - filter("T1"."OBJECT_NAME" LIKE '%T1%')

Note
-----
   - SQL profile "SQLPROFILE_NAME1" used for this statement

统计信息
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        933  consistent gets
        

可以看到,SQL使用了SQL Profile,不过没有达到我们预期的效果。

看起来是SQL Profile使用的Hints有问题。我们重新设置SQL Profile的Hints,在Hints中加上“Query Block Name"。这一次在执行IMPORT_SQL_PROFILE过程时,将REPLACE参数设置为TRUE,以替换现有的SQL Profile:

SQL> declare
  2    v_hints sys.sqlprof_attr;
  3  begin
  4    v_hints:=sys.sqlprof_attr('USE_NL(T1@SEL$1 T2@SEL$1)','INDEX(T2@SEL$1)');
  5    dbms_sqltune.import_sql_profile('select t1.*,t2.owner from t1,t2 where t1.object_name like ''%T1%'' and t1.object_id=t2.object_id',
  6                v_hints,'SQLPROFILE_NAME1',force_match=>true,replace=>true);
  7  end;
  8  /

PL/SQL 过程已成功完成。

SQL> select attr_val from dba_sql_profiles a, sys.sqlprof$attr b
  2  where a.signature = b.signature
  3  and a.name='SQLPROFILE_NAME1';

ATTR_VAL
----------------------------------------
USE_NL(T1@SEL$1 T2@SEL$1)
INDEX(T2@SEL$1)  

再次执行下面的SQL:

SQL> select  t1.*,t2.owner
  2       from t1,t2
  3       where t1.object_name like '%T1%'
  4       and t1.object_id=t2.object_id;

已选择29行。

执行计划
----------------------------------------------------------
Plan hash value: 3787413387

--------------------------------------------------------------------------------------
| Id  | Operation                   | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |        |  2498 | 99920 |  5061   (1)| 00:01:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T2     |     1 |    11 |     2   (0)| 00:00:01 |
|   2 |   NESTED LOOPS              |        |  2498 | 99920 |  5061   (1)| 00:01:01 |
|*  3 |    TABLE ACCESS FULL        | T1     |  2498 | 72442 |    59   (6)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN         | T2_IDX |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------

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

   3 - filter("T1"."OBJECT_NAME" LIKE '%T1%')
   4 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")

Note
-----
   - SQL profile "SQLPROFILE_NAME1" used for this statement

统计信息
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        294  consistent gets

这一次达到了预期的效果。看起来在SQL Profiles中对Hints还有一定的要求。
那么我们再一次手工修改T1表的统计信息,看看结果如何:

Read the rest of this entry

,

Oracle 11g从发布到现在,也有几个年头了。而在国内来说,Oracle 10g仍然是主流,甚至一些电信运营商的核心系统仍然在使用9i。作为Oracle 10g的一项新特性,SQL Profiles被使用得并不太多。不管是在论坛、个人的BLOG还是其他一些地方,SQL Profiles的介绍也相对较少。对我个人来说,已经在多个优化场合中使用SQL Profiles,在这里向大家介绍SQL Profiles,就是希望能够了解Oracle数据库的这一功能。

SQL Profiles可以说是Outlines的进化。Outlines能够实现的功能SQL Profiles也完全能够实现,而SQL Profiles具有Outlines不具备的优化,个人认为最重要的有2点:

  • SQL Profiles更容易生成、更改和控制。
  • SQL Profiles在对SQL语句的支持上做得更好,也就是适用范围更广。

关于这2方面的优点,我后面会详细地阐述。

现在我在使用Outlines的场合,均使用SQL Profiles来替代。有一次准备对1条SQL语句使用Outline进行执行计划的稳定,结果使用Outline之后,系统出现大量的library cache latch的争用,不得不关闭Outline的使用,但是改用SQL Profiles不再有这个问题。这或许是个BUG,不过既然能用SQL Profiles代替,也就没再深入去研究这个问题。

使用SQL Profiles无非是两个目的:

  • 锁定或者说是稳定执行计划。
  • 在不能修改应用中的SQL的情况下使SQL语句按指定的执行计划运行。

那么SQL Profile到底是什么?在我看来,SQL Profile就是为某一SQL语句提供除了系统统计信息、对象(表和索引等)统计信息之外的其他信息,比如运行环境、额外的更准确的统计信息,以帮助优化器为SQL语句选择更适合的执行计划。这些说法显得比较枯燥,还是来看看下面的测试。

首先建2个测试表:

SQL> create table t1 as select object_id,object_name from dba_objects where rownum<=50000;

表已创建。

SQL> create table t2 as select * from dba_objects;

表已创建。

SQL> create index t2_idx on t2(object_id);

索引已创建。

SQL> exec dbms_stats.gather_table_stats(user,'t1',cascade=>true,method_opt=>'for all columns size 1');

PL/SQL 过程已成功完成。

SQL> exec dbms_stats.gather_table_stats(user,'t2',cascade=>true,method_opt=>'for all columns size 1');

PL/SQL 过程已成功完成。

然后看看下面这一条SQL:

SQL> select t1.*,t2.owner from t1,t2 where t1.object_name like '%T1%' and t1.object_id=t2.object_id;

已选择29行。


执行计划
----------------------------------------------------------
Plan hash value: 1838229974

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |  2498 | 99920 |   219   (4)| 00:00:03 |
|*  1 |  HASH JOIN         |      |  2498 | 99920 |   219   (4)| 00:00:03 |
|*  2 |   TABLE ACCESS FULL| T1   |  2498 | 72442 |    59   (6)| 00:00:01 |
|   3 |   TABLE ACCESS FULL| T2   | 49954 |   536K|   159   (2)| 00:00:02 |
---------------------------------------------------------------------------

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

   1 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")
   2 - filter("T1"."OBJECT_NAME" LIKE '%T1%')


统计信息
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        932  consistent gets
          0  physical reads
          0  redo size
       1352  bytes sent via SQL*Net to client
        385  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         29  rows processed

这里省略了SELECT出来的具体数据,但是我们关心的是返回的结果行数、执行计划以及逻辑读这些信息。
首先从执行计划可以看到,这条SQL语句在2个表上都是全表扫描。在第1个表T1上,有 like '%T1%'这样的条件,导致只能全表扫描,这没有问题。但是第2个表,也是全表扫描,这里有没有问题呢?或者说是有没有优化的余地,答案显然是肯定的。
这里的问题在于执行计划ID=1的那一行,Oracle优化器评估T1 like '%T1%'返回的结果行数为2498行,即T1表总行数的5%,如果2个表采用index range scan+nested loop连接,oracle评估的成本会高于full table scan+hash join。下面可以看到Oracle优化器评估的index range_scan+nested loop的成本:

SQL> explain plan for select /*+ use_nl(t1 t2) index(t2) */ t1.*,t2.owner 
     from t1,t2 
     where t1.object_name like '%T1%' 
     and t1.object_id=t2.object_id;

已解释。

SQL> @showplan

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------
Plan hash value: 3787413387
--------------------------------------------------------------------------------------
| Id  | Operation                   | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |        |  2498 | 99920 |  5061   (1)| 00:01:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T2     |     1 |    11 |     2   (0)| 00:00:01 |
|   2 |   NESTED LOOPS              |        |  2498 | 99920 |  5061   (1)| 00:01:01 |
|*  3 |    TABLE ACCESS FULL        | T1     |  2498 | 72442 |    59   (6)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN         | T2_IDX |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   3 - filter("T1"."OBJECT_NAME" LIKE '%T1%')
   4 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")

从执行计划可以看到Oracle优化器评估的成本为5061,远远高于原来的219。
但是实际的逻辑读是多少呢?

统计信息
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        290  consistent gets
          0  physical reads
          0  redo size
       1352  bytes sent via SQL*Net to client
        385  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         29  rows processed

加了HINT之后实际的逻辑读只有290,低于原始SQL的932。所以这里可以看出来,由于Oracle优化器过高地估计了T1表经过like操作过滤返回的行数,也就过高地估计了nest loop的成本,最终也就选择了不是最优的执行计划。

下面我们用Oracle的SQL Tuning Advisor来尝试这条SQL:

SQL> var tuning_task varchar2(100);
SQL> DECLARE
  2    l_sql_id v$session.prev_sql_id%TYPE;
  3    l_tuning_task VARCHAR2(30);
  4  BEGIN
  5    l_sql_id:='4zbqykx89yc8v';
  6    l_tuning_task := dbms_sqltune.create_tuning_task(sql_id => l_sql_id);
  7    :tuning_task:=l_tuning_task;
  8    dbms_sqltune.execute_tuning_task(l_tuning_task);
  9    dbms_output.put_line(l_tuning_task);
 10  END;
 11  /
任务_74

PL/SQL 过程已成功完成。

SQL> print tuning_task;

TUNING_TASK
---------------------------------------------------------------------------------------------------------
任务_74

SQL> SELECT dbms_sqltune.report_tuning_task(:tuning_task) FROM dual;

DBMS_SQLTUNE.REPORT_TUNING_TASK(:TUNING_TASK)
--------------------------------------------------------------------------------
GENERAL INFORMATION SECTION
-------------------------------------------------------------------------------
Tuning Task Name                  : 任务_74
Tuning Task Owner                 : TEST1
Scope                             : COMPREHENSIVE
Time Limit(seconds)               : 1800
Completion Status                 : COMPLETED
Started at                        : 12/15/2010 09:56:02
Completed at                      : 12/15/2010 09:56:03
Number of SQL Profile Findings    : 1

-------------------------------------------------------------------------------
Schema Name: TEST1
SQL ID     : 4zbqykx89yc8v
SQL Text   : select t1.*,t2.owner from t1,t2 where t1.object_name like '%T1%'
             and t1.object_id=t2.object_id

-------------------------------------------------------------------------------
FINDINGS SECTION (1 finding)
-------------------------------------------------------------------------------

1- SQL Profile Finding (see explain plans section below)
--------------------------------------------------------
 为此语句找到了性能

  Recommendation (estimated benefit: 46.62%)
  ------------------------------------------
  -考虑接受推荐的 SQL
    executedbms_sqltune.accept_sql_profile(task_name => '任务_74', replace =
            TRUE);

-------------------------------------------------------------------------------
EXPLAIN PLANS SECTION
-------------------------------------------------------------------------------

1- Original With Adjusted Cost
------------------------------
Plan hash value: 1838229974

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |      |    29 |  1160 |   219   (4)| 00:00:03 |
|*  1 |  HASH JOIN         |      |    29 |  1160 |   219   (4)| 00:00:03 |
|*  2 |   TABLE ACCESS FULL| T1   |    29 |   841 |    59   (6)| 00:00:01 |
|   3 |   TABLE ACCESS FULL| T2   | 49954 |   536K|   159   (2)| 00:00:02 |
---------------------------------------------------------------------------

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

   1 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")
   2 - filter("T1"."OBJECT_NAME" LIKE '%T1%')

2- Using SQL Profile
--------------------
Plan hash value: 3787413387

--------------------------------------------------------------------------------------
| Id  | Operation                   | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |        |    29 |  1160 |   117   (3)| 00:00:02 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T2     |     1 |    11 |     2   (0)| 00:00:01 |
|   2 |   NESTED LOOPS              |        |    29 |  1160 |   117   (3)| 00:00:02
 |
|*  3 |    TABLE ACCESS FULL        | T1     |    29 |   841 |    59   (6)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN         | T2_IDX |     1 |       |     1   (0)| 00:00:01 |
--------------------------------------------------------------------------------------

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

   3 - filter("T1"."OBJECT_NAME" LIKE '%T1%')
   4 - access("T1"."OBJECT_ID"="T2"."OBJECT_ID")

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

Read the rest of this entry

,

前几日收到好友崔华(dbsnake)给我寄来的《海量数据库解决方案》--一本来自韩国的数据库技术书籍,我随之以极大的兴趣投了入此已书的阅读之中。读了大部分内容之后,我觉得有必要在这里写一写,向大家介绍介绍一下此书。

其实在此前,我已经知道崔华在参与《海量数据库解决方案》一书的审校工作。有几次我们聊到这个事情,他提到经常要为此书工作到深更半夜,而对此他却告诉我说非常值得,因为这的确是一本值得引入国内的数据库技术书籍。他对我如此推崇此书,同时参与此书翻译审核还包括盖国强(eygle)张乐奕(kamus),这让我为对此书充满了期待,也坚信这本书的质量。

实际上关于本书的作者,在韩国有数据库泰斗之称的李华植,请恕我孤漏寡闻,我之前没有任何了解。也许是因为不是英语国家的缘故,导致我们对此缺乏了解。就像国内很少有Oracle高手专门写英文博客,或者在OTN上发表文章。通常我们知晓的国外Oracle大牛基本上来源于英语国家。而另一位来自于韩国的Oracle ACE, Dion Cho则是在WORDPRESS上开设了英文博客才被我们有所了解。(他同样有一本书在09年引入到了国内,《高级OWI与Oracle性能调整》,这其实是非常好的一本介绍Oracle等待事件以及调优化的书,不知道为什么在国内此书如此的默默无闻。而此书的翻译,丝毫不会让人感觉到是一本翻译的书,反而像是一本以中文为母语写就的Oracle技术书籍。)

拿到《海量数据库解决方案》一书,通过短短几页的阅读就足以使我对此书的翻译和审校质量有了很高的评价。这让我找回到了阅读《Expert Oracle Database Architecture 9i and 10g Programming Techniques and Solutions》(中文名《Oracle 9i&10 编程艺术-深入数据库体系结构》)和《高级OWI与Oracle性能调整》这样的书的感觉,完全没有翻译的生涩感。

从书名上看,开始时给了我一个误导。我开始以为是一本关于类似于数据仓库方面的,有关海量数据管理和性能方面的书。其实这是一本以Oracle为主的(大型)数据库性能方面的数据库技术书籍。与其他书动辄有十几二十几章节不同,这本400多页的厚厚的书仅仅只有6个章节,仅仅浓缩在几个与性能有关的最主要的主题方面。这不是一本大而全的泛泛而谈的书,也不是step by step的教科书。仅仅"SQL的执行计划“一章就有100多页的篇幅。就算我自认为对Oracle的执行计划有相当程度的理解,从这一章节中仍然获取了以往不曾想到或接触的执行计划方面的知识。而其他关于索引和表连接的章节,也花了相当多的笔墨。可以说,这是一本类似于大名鼎鼎的Thomas Kyle的《Expert Oracle Database Architecture 9i and 10g Programming Techniques and Solutions》的书,是让我们从原理上掌握数据库性能技术的书。而书中大量的比较,插图,让我们从原理上理解技术时,又避免了技术原理过于抽象的问题。这两本书都有一个共同点,虽然侧重于原理和本质,但并不是泛泛而谈,而是深入到技术细节。

这本书不仅适合于DBA,而我认为同样更适合于系统设计和开发人员。比如”构建索引的战略方案“一章内容,帮助我们在开发和设计系统阶段,如何有效设计索引,而不是在系统上线运行后,由于性能问题才去被动的增加索引。

虽然这本书以Oracle为主介绍海量(大型)数据库解决方案,但书中并没有提到Oracle特有的比如Latch、10046 trace、SGA结构这样的东西。因此,这本书同样适合于其他非Oracle数据库工作者。我相信,这些原理同样适用于其他关系型数据库。

之所以愿意为大家介绍这样一本书,是因为我希望Oracle技术社区能够有更多的人,能够吸取到更多的技术营养。如果以后有可能,我也希望能够把自己的更多的东西写出来,为Oracle技术社会贡献一点微薄的力量。

Mutex是Oracle从10g开始使用的一种数据结构,与latch极其类似,也是用于SGA内存结构的并发访问控制。在10g中,Mutex主要用于保护Cursor相关的内存结构,Parent Cursor, Child Cursor , Cursor Stat,同时兼有Pin Cursor的并发访问控制作用。

而从11g开始,Mutex又代替了library cache latch等多个与library cache相关的latch。

Mutex与latch相比,有哪些优点?我个人认为最重要的有2点:

  • Mutex通常在被保护对象内部,这样mutex的数量就多了很多,争用就更少。比如11g中,每一个Latch Latch Hash Bucket由一个mutex保护,而bucket数量高达131072,相比library cache latch最多只有67个child latch,数量上多了很多。很显然,分布在131072个Mutex上的竞争比67个Library cache latch上的竞争少得多。
  • Mutex从结构上来讲比latch更多简单,整个Mutex只有十几个字节,而Oracle在对Latch的结构优化和精简的情况下最少也有100多个字节。这样更小的结构意味着在处理Mutex时也只需要更少的指令,而更快。
  • Mutex代替Cursor上的library cache pin,比library cache pin更有效率。

本文主要描述如何通过system state dump来分析mutex的等待,因此对Mutex的工作机制以及相应的等待事件详解不做过多介绍。有机会我会在另外的文章中专门来讲这两部分。

我们来分析的system state dump来源于一个朋友,他的系统里面出现大量的'cursor: pin S wait on X'和'cursor: Mutex X'等待事件。他将产生的system state dump发给我,以分析出产生问题的root cause。由于system state dump比较在在,同时里面涉及的一些内容不适合放在网上,因此本文只给出分析过程,没有上传trace文件。数据库的版本是11.1.0.7。

首先试图找到'cursor: pin S wait on X'等待的阻塞进程,随便找到一个等待cursor:pin S wait on X的会话,在dump trace 文件中查找waiting for 'cursor: pin S wait on X':

    (session) sid: 1471 ser: 57513 trans: (nil), creator: 0x450d504f0
              flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40008) -/-
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 3, prv: 0, sql: 0x455d15680, psql: 0x45bd0c8c8, user: 92/XXXX
    ksuxds FALSE at location: 0
    service name: SYS$USERS
    client details:
      O/S info: user: idol, term: unknown, ospid: 1234
      machine:     program: JDBC Thin Client
      application name: JDBC Thin Client, hash value=2546894660
    Current Wait Stack:
     0: waiting for 'cursor: pin S wait on X'
        idn=de12d336, value=5cf00000000, where|sleeps=572cf03e3
        wait_id=56059196 seq_num=26772 snap_id=1
        wait times: snap=0.001772 sec, exc=0.001772 sec, total=0.001772 sec
        wait times: max=0.010000 sec
        wait counts: calls=1 os=1
        in_wait=1 iflags=0x5a2
    There is at least one session blocking this session.
    Dumping one blocker:
      inst: 1, sid: 1487, ser: 5556

其实这里已经指出“inst: 1, sid: 1487, ser: 5556”,表示阻塞的会话是sid,serial#为1487,5556。那么如果这里没有这个信息,那么我们从哪里去寻找blocker?注意前面一段信息:idn=de12d336(对cursor来说其实是sql的hash value的低4字节), value=5cf00000000, where|sleeps=572cf03e3,这里idn表示mutex的identifier,即mutex的标识,value的高8字节(64位系统是高8字节,而32位系统是高4位字节)是SID,0x5cf即10进制的1487。

而在稍后面部分,可以看到:

      KGX Atomic Operation Log 0x455507d20
       Mutex 0x3ff3c3d28(1487, 0) idn de12d336 oper GET_SHRD
       Cursor Pin uid 1471 efd 0 whr 5 slp 13085
       opr=2 pso=0x454d03f00 flg=0
       pcs=0x3ff3c3ca8 nxt=0x41720aca0 flg=35 cld=0 hd=0x455d0dda8 par=0x3ff3c4650
       ct=0 hsh=0 unp=(nil) unn=0 hvl=ff3c4448 nhv=1 ses=0x45181f760
       hep=0x3ff3c3d28 flg=80 ld=1 ob=0x3ff3c3868 ptr=0x412040780 fex=0x41203faf0

这里有Mutex请求的更详细的信息,Mutex 0x3ff3c3d28(1487, 0) idn de12d336 oper GET_SHRD表明这个请求是以SHARE方式请求,但是Mutex被1487这个会话持有。idn与前面idn相匹配。Cursor Pin uid 1471 efd 0 whr 5 slp 13085 这里表明Mutex的类型是Cursor Pin,正是前面提到的Mutex的一种。uid 1471表明是当前请求的SID为1471。

'cursor: pin S wait on X'等待类似于以往的library cache pin等待,表示需要将cursor pin在内存中。这个等待出现,表明有会话正在修改这个cursor,比如正在执行解析,生成执行计划等。

接下来我们看SID=1487的会话正在等待什么,或者说是在执行什么操作,查找'(session) sid: 1487':

    (session) sid: 1487 ser: 5556 trans: (nil), creator: 0x450d514f0
              flags: (0x45) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x40008) -/-
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 3, prv: 0, sql: 0x455d15680, psql: 0x45bd0c8c8, user: 92/XXXXX
    ksuxds FALSE at location: 0
    service name: SYS$USERS
    client details:
      O/S info: user: idol, term: unknown, ospid: 1234
      machine:       program: JDBC Thin Client
      application name: JDBC Thin Client, hash value=2546894660
    Current Wait Stack:
     0: waiting for 'cursor: mutex X'
        idn=5336, value=1, where|sleeps=3385a5f33
        wait_id=500096450 seq_num=64401 snap_id=1
        wait times: snap=0.000000 sec, exc=0.000000 sec, total=0.000000 sec
        wait times: max=0.000000 sec
        wait counts: calls=0 os=0
        in_wait=0 iflags=0x15e0

可以看到,这个会话正在等待'cursor: mutex X'。不幸的是,这一次没有直接表明holder是谁了。idn=5336, value=1, where|sleeps=3385a5f33,这里value=1,很简单,但是表明的意义却不简单,这表明什么?低8字节为1,表明这个Mutex是被共享持有,而高8字节为0,这是共享持有的Mutex的正常状况,Mutex可能被多个会话共享持有,因此只有引用计数,而不会有持有的SID。这里1就是引用计数,表示被1个会话持有。只有在会话获取Mutex的过程中,才会暂时性的将Mutex的SID设为正在获取的SID,而一旦完成获取,就将Mutex中的SID即value的高8字节部分清0。

继续往后查看:

      KGX Atomic Operation Log 0x4543ce390
       Mutex 0x3ff3c3d28(1487, 0) idn de12d336 oper EXCL
       Cursor Pin uid 1487 efd 0 whr 1 slp 0
       opr=3 pso=0x454daaa50 flg=0
       pcs=0x3ff3c3ca8 nxt=0x41720aca0 flg=35 cld=0 hd=0x455d0dda8 par=0x3ff3c4650
       ct=0 hsh=0 unp=(nil) unn=0 hvl=ff3c4448 nhv=1 ses=0x45181f760
       hep=0x3ff3c3d28 flg=80 ld=1 ob=0x3ff3c3868 ptr=0x412040780 fex=0x41203faf0

上面一段信息表明,正是1487这个会话以EXCLUSIVE方式持有idn=de12d336的这个mutex,这正是1471会话正需要以SHARE方式获取的Mutex。

      KGX Atomic Operation Log 0x45a2b7908
       Mutex 0x44b764498(0, 1) idn 7fff00005336 oper GET_EXCL
       Cursor Stat uid 1487 efd 8 whr 3 slp 28652
       oper=OPERATION_DEFAULT pt1=(nil) pt2=(nil) pt3=(nil)
       pt4=(nil) u41=0 stt=0

上面一段信息表明,1487这个会话正在以EXCLUSIVE请求的mutex是idn=7fff00005336,Mutex类型是Cursor Stat。Cursor Stat类型的EXCLUSIVE方式请求通常是需要更新cursor的统计信息。而以SHARE方式请求通常是查询cursor的统计信息,比如说查询v$sqlstat视图。注意这里GET_EXCL表示正在以EXCLUSIVE方式请求获取(持有)mutex,而EXCL表示已经以EXCLUSIVE方式持有mutex。延伸开来,GET_SHRD表示请求SHARE方式的mutex,SHRD表示以SHARE方式持有mutex。REL_SHRD表示正在释放SHARE方式持有的mutex,也就是递减引用计数。

那么,接下来我们就要寻找是哪个会话持有了idn=7fff00005336的mutex。查找'idn 7fff00005336 oper‘,找到如下内容:

      KGX Atomic Operation Log 0x45955b2f0
       Mutex 0x44b764498(0, 1) idn 7fff00005336 oper SHRD
       Cursor Stat uid 1497 efd 7 whr 6 slp 0
       oper=OPERATION_DEFAULT pt1=(nil) pt2=(nil) pt3=(nil)
       pt4=(nil) u41=0 stt=0

可以看到的确有会话(1497)正在以共享方式持有idn=7fff00005336的mutex。往前查看,可以看到会话信息:

    (session) sid: 1497 ser: 29349 trans: (nil), creator: 0x45cccc3f0
              flags: (0x51) USR/- flags_idl: (0x1) BSY/-/-/-/-/-
              flags2: (0x408) -/-
              DID: , short-term DID: 
              txn branch: (nil)
              oct: 0, prv: 0, sql: (nil), psql: (nil), user: 0/SYS
    ksuxds FALSE at location: 0
    service name: SYS$BACKGROUND
    Current Wait Stack:
      Not in wait; last wait ended 14005 min 23 sec ago 
    Wait State:
      auto_close=0 flags=0x21 boundary=(nil)/-1
    Session Wait History:
     0: waited for 'db file sequential read'
        file#=2, block#=1952c, blocks=1
        wait_id=1171 seq_num=1174 snap_id=1
        wait times: snap=0.018420 sec, exc=0.018420 sec, total=0.018420 sec
        wait times: max=infinite
        wait counts: calls=0 os=0
        occurred after 0.000034 sec of elapsed time

再往前可以找到进程信息:

PROCESS 38:
  ----------------------------------------
  SO: 0x45cccc3f0, type: 2, owner: (nil), flag: INIT/-/-/0x00 if: 0x3 c: 0x3
   proc=0x45cccc3f0, name=process, file=ksu.h LINE:10706, pg=0
  (process) Oracle pid:38, ser:76, calls cur/top: 0x440d0ae48/0x43c5e5f88
            flags : (0x2) SYSTEM
            flags2: (0x30),  flags3: (0x0) 
            int error: 0, call error: 0, sess error: 0, txn error 0
  ksudlp FALSE at location: 0
  (post info) last post received: 0 0 42
              last post received-location: ksv2.h LINE:1603 ID:ksvpst: run
              last process to post me: 450d4b4f0 1 2
              last post sent: 0 0 151
              last post sent-location: kcrf.h LINE:3095 ID:kcrfw_redo_gen: wake LGWR after redo copy
              last process posted by me: 45ccbe3f0 1 6
    (latch info) wait_event=0 bits=0
    Process Group: DEFAULT, pseudo proc: 0x4510353e0
    O/S info: user: oracle, term: UNKNOWN, ospid: 13549 
    OSD pid info: Unix process pid: 13549, image: oracle@xxxxx (m001)

可以看到m001这个进程持有了mutex。但是会话没有在执行任何sql语句,而从会话的等待来看,last wait ended 14005 min 23 sec ago ,这个是不正常的,m001进程应该是出现了异常。

m001进程是什么,这是mmon的slave进程,其中一个作用就是执行awr snapshot。很显然这个进程要访问v$sqlstat,是需要持有Cursor Stat类型的mutex的。

至此就找到了所有等待的root holder。不过把这个结果告诉维护这个库的朋友时,告知服务器之前“死”了,已经重启了。重启后检查数据库,发现在故障期间很长一段时间内的确是没有产生awr snapshot。至于m001进程出了什么异常,为什么会出现异常,本文就不再详细讨论。实际上服务器重启之后也没有继续跟踪这一问题。

mutex从设计上来说,与latch相比有着很明显的优点,只是作为新生事务(相对于目前仍然在广泛使用的10g来说), 存在BUG的可能性比较大。深入了解mutex,可以帮助我们更好地诊断mutex引起的相关问题。

在这里,给我的好友崔华(dbnake)做一个关于Oracle Recovery进阶培训的宣传。

关于崔华,其实不用做过多的介绍,国内研究oracle interal的专家,我常常与他进行oracle方面的讨论,从他那里我获益非浅。

培训时间是2010-10- 21 ~ 2010-10-24, 合计四天课程,培训大纲如下:

培训模块内容

培训提纲

学时

OracleRedo机制解析

掌握Oracleredo log写入原理----Physiological Logging

3学时

深入解析redo log结构----SCNRBAChange VectorCheckpoint Structure

解析oracle recovery的实现机制-Page Fix、写日志优先、Checkpoint

OracleUndo机制解析

回滚段的作用与结构

3学时

深入解析XIDUBA的结构与作用

深入解析KTUXC的结构与作用

深入解析undo chain的结构与作用

Oracle恢复的内部实现

BBED的用法

3学时

Control文件的格式和内容解析

利用control文件借尸还魂的实例

OS Header Block的格式和内容解析

9i中通过修改OS header block实现跨平台迁移的实例

Datafile Header的格式和内容解析----Datafile Header的常规结构、独家披露Datafile Header中一个我们从来未触及过的区域及其作用

通过修改Datafile Header规避ORA-01190: controlfile or data file XXX is from before the last RESETLOGS错误的实例

OracleOffline文件的解析与恢复

offline datafile的实质

3学时

缺失归档日志后的offline datafile的强制恢复实例

offline tablespace的种类与实质

缺失datafile和归档日志后的offline tablespace的强制恢复实例

OracleRedoUndo损坏后的恢复

current redo log损坏后的恢复

3学时

缺失current online redo log后的恢复实例

深入解析undo损坏后的恢复及恢复实例

Oracle中常规恢复案例精讲

oracledelete操作的实质,如何恢复被delete掉的数据及恢复实例

3学时

oracledrop操作的实质,如何恢复被drop掉的表、存储过程及恢复实例

oracletruncate操作的实质,如何恢复被truncate的表及恢复实例

oracle中数据块损坏的种类及恢复实例,从单个坏块中抢救出数据的恢复实例

Oracle中特殊恢复案例精讲

9i中跨越resetlog恢复的实例

6学时

如何跳过缺失的归档及恢复实例

Allow 1 Corruption失效后我们如何处理stuck recovery

深入解析ORA-600[4000]错误及恢复实例

深入解析system回滚段损坏导致的ora-600[4193]/ora-600[4194]错误及恢复实例

深入解析DEPENDENCY$对象的恢复及恢复实例

深入解析ASM Disk Header的结构及ASM Disk Header损坏后的恢复实例

关于培训,详情可见《我第一次独挑大梁的培训》

在以前的一篇文章中,我提到千万不能将Oracle数据库的global_name更新为空。这不,事儿来了。我的一个同事,提到了一个解决办法,不过那个办法实际上是一种不完全恢复的办法,如果没有备份,就行不通。如果没有备份,可以使用BBED来修改块来解决这个问题,不过使用bbed仍然比较麻烦。

下面是我一时心血来潮进行的一次测试。测试环境,10.2.0.4 for Linux AS 5.5。注意,不要在生产库上模仿。

首先UPDATE GLOBAL_NAME为空,COMMIT后以abort方式关闭数据库,以abort方式只是为了增加点难度。之后再启动数据库。

SQL> update global_name set global_name='';

1 row updated.

SQL> commit;

Commit complete.

SQL> shutdown abort
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.
ORA-01092: ORACLE instance terminated. Disconnection forced

启动失败,不出意料出现ORA-600 [18062]错误:

Mon Sep  6 15:43:31 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []
QMNC started with pid=16, OS id=3151
Mon Sep  6 15:43:33 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []
Mon Sep  6 15:43:33 2010
Errors in file /oracle/app/oracle/admin/xty/udump/xty_ora_3149.trc:
ORA-00600: internal error code, arguments: [18062], [], [], [], [], [], [], []

下面来解决这个问题。

第1步,重启数据库到MOUNT状态:

[oracle@xty ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.4.0 - Production on Mon Sep 6 15:43:47 2010

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.

Connected to an idle instance.

SQL> startup mount
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.

第2步,在另一个窗口中,使用gdb

[oracle@xty ~]$ ps -ef | grep LOCAL
oracle    3186  3156  0 15:43 ?        00:00:00 oraclexty (DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))
oracle    3188  2978  0 15:44 pts/3    00:00:00 grep LOCAL
[oracle@xty ~]$ gdb $ORACLE_HOME/bin/oracle 3186
GNU gdb (GDB) Red Hat Enterprise Linux (7.0.1-23.el5)
...(省略)...
Reading symbols from /oracle/app/oracle/product/10.2.0/bin/oracle...(no debugging symbols found)...done.
Attaching to program: /oracle/app/oracle/product/10.2.0/bin/oracle, process 3186
Reading symbols from /etc/libcwait.so...(no debugging symbols found)...done.
Loaded symbols for /etc/libcwait.so
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libskgxp10.so...(no debugging symbols found)...done.
Loaded symbols for /oracle/app/oracle/product/10.2.0/lib/libskgxp10.so
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libhasgen10.so...(no debugging symbols found)...done.
...(省略)...
Reading symbols from /oracle/app/oracle/product/10.2.0/lib/libnnz10.so...(no debugging symbols found)...done.
Loaded symbols for /oracle/app/oracle/product/10.2.0/lib/libnnz10.so
Reading symbols from /usr/lib/libaio.so.1...(no debugging symbols found)...done.
Loaded symbols for /usr/lib/libaio.so.1
Reading symbols from /lib/libdl.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libm.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /lib/libpthread.so.0...(no debugging symbols found)...done.
[Thread debugging using libthread_db enabled]
Loaded symbols for /lib/libpthread.so.0
Reading symbols from /lib/libnsl.so.1...(no debugging symbols found)...done.
Loaded symbols for /lib/libnsl.so.1
Reading symbols from /lib/libc.so.6...(no debugging symbols found)...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libnss_files.so.2
0x0025d402 in __kernel_vsyscall ()
(gdb)  break kokiasg
Breakpoint 1 at 0xa3d404d
(gdb) continue
Continuing.

第3步,OPEN数据库:

SQL> alter database open;

约等一会儿,在alert日志里面可以看到:

Mon Sep  6 15:44:41 2010
SMON: enabling cache recovery
SMON: enabling tx recovery
Mon Sep  6 15:44:41 2010
Database Characterset is ZHS16GBK

在gdb的输出可以看到:

Breakpoint 1, 0x0a3d404d in kokiasg ()

第4步,在gdb那里中止OPEN:

(gdb) kill
Kill the program being debugged? (y or n) y     
(gdb) quit

sqlplus会提示:

alter database open
*
ERROR at line 1:
ORA-03113: end-of-file on communication channel

这一次,Instance并没有terminated。只是Server process被KILL了。

第5步,还原GLOBAL_NAME:

[oracle@xty ~]$ sqlplus / as sysdba

SQL*Plus: Release 10.2.0.4.0 - Production on Mon Sep 6 15:45:09 2010

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> select status from v$instance;

STATUS
------------
OPEN

SQL> update global_name set global_name='XTY';

1 row updated.

SQL> commit
  2  ;
commit
*
ERROR at line 1:
ORA-01109: database not open

虽然可以执行UPDATE,但是不能COMMIT。再试试能不能做DDL:

SQL> create table t1 ( a int);

Table created.

成功了。

在另会一个会话中查看GLOBAL_NAME:

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
XTY

GLOBAL_NAME回来了。

这里通过DDL的隐式提交特性来UPDATE GLOBAL_NAME。其实还有更简单的办法:OCI主动断开连接时的自动提交。如果UPDATE之后,直接退出sqlplus,UPDATE GLOBAL_NAME的事务实际也提交了。看起来ORACLE这时只是不能执行显式的COMMIT语句。

第6步,重启数据库:

SQL> shutdown immediate
ORA-00604: error occurred at recursive SQL level 1
ORA-01109: database not open


SQL> shutdown abort
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area  209715200 bytes
Fixed Size                  1266632 bytes
Variable Size              75500600 bytes
Database Buffers          130023424 bytes
Redo Buffers                2924544 bytes
Database mounted.
Database opened.

看起来只能以abort方式关闭数据库:
成功了,数据库起来了。没有数据丢失,没有使用备份。不需要基于时间点的恢复,不需要BBED,不需要Resetlog。

,

关于全局索引和本地索引的优缺点,分别应该在什么情况下使用,这方面的资料很多,本文不作讨论。本文讨论一种特殊情况,即建立在分区键之上的本地索引。9i也算是很老的Oracle版本了,只是很多系统包括很多大型的核心的系统都在用,因此本文介绍建立在分区键列上的本地索引存在的问题。下面是一些测试:

SQL> create table t1 ( a int, b varchar2(300)) partition by range(a)
  2  (
  3   partition p01 values less than (1000),
  4   partition p02 values less than (2000),
  5   partition p03 values less than (3000),
  6   partition p04 values less than (4000),
  7   partition p05 values less than (5000),
  8   partition p06 values less than (6000),
  9   partition p07 values less than (7000),
 10   partition p08 values less than (8000),
 11   partition p09 values less than (9000),
 12   partition p10 values less than (10000),
 13   partition p11 values less than (11000),
 14   partition p12 values less than (12000),
 15   partition p13 values less than (13000),
 16   partition p14 values less than (14000),
 17   partition p15 values less than (15000),
 18   partition p16 values less than (16000),
 19   partition p17 values less than (17000),
 20   partition p18 values less than (18000),
 21   partition p19 values less than (19000),
 22   partition p20 values less than (20000)
 23  )
 24  /

表已创建。

SQL> insert into t1 select rownum,lpad('x',200,'x') from dual connect by rownum<20000;

已创建19999行。

SQL> commit;

提交完成。

SQL> insert /*+ append */ into t1 select * from t1;

已创建19999行。

SQL> commit;

提交完成。

SQL> insert /*+ append */ into t1 select * from t1;

已创建39998行。

SQL> commit;

提交完成。

SQL> insert /*+ append */ into t1 select * from t1;

已创建79996行。

SQL> commit;

提交完成。

SQL> insert /*+ append */ into t1 select * from t1;

已创建159992行。

SQL> commit;

提交完成。

SQL> insert /*+ append */ into t1 select * from t1;

已创建319984行。

SQL> commit;

提交完成。

首先建立一个测试范围分区表,分区键列是"a",共20个分区,在这个测试表中生成约64万行数据。下面在列a上建本地索引并收集统计信息:

SQL> create index t1_idx on t1(a) local;

索引已创建。

SQL> exec dbms_stats.gather_table_stats(user,'T1',
    method_opt=>'for all columns size 1',cascade=>true);

PL/SQL 过程已成功完成。
SQL> @sosi

Please enter Name of Table Owner (Null = TEST):
Please enter Table Name to show Statistics for: t1

***********
Table Level
***********


Table                   Number                 Empty
Name                   of Rows   Blocks       Blocks
--------------- -------------- -------- ------------
T1                     639,968   18,880            0

Column                    Column                       Distinct            Number       Number
Name                      Details                        Values   Density Buckets        Nulls
------------------------- ------------------------ ------------ --------- ------- ------------
A                         NUMBER(22)                     19,999   .000050       1            0
B                         VARCHAR2(300)                       1  1.000000       1            0

                              B
Index                      Tree     Leaf       Distinct         Number      Cluster
Name            Unique    Level     Blks           Keys        of Rows       Factor
--------------- --------- ----- -------- -------------- -------------- ------------
T1_IDX          NONUNIQUE     1    1,390         19,999        639,968      639,968

Index           Column                     Col Column
Name            Name                       Pos Details
--------------- ------------------------- ---- ------------------------
T1_IDX          A                            1 NUMBER(22)

***************
Partition Level
***************

  Part Partition               Number                 Empty
   Pos Name                   of Rows   Blocks       Blocks
------ --------------- -------------- -------- ------------
     1 P01                     31,968      944            0
     2 P02                     32,000      944            0
     3 P03                     32,000      944            0
     4 P04                     32,000      944            0
     5 P05                     32,000      944            0
     6 P06                     32,000      944            0
     7 P07                     32,000      944            0
     8 P08                     32,000      944            0
     9 P09                     32,000      944            0
    10 P10                     32,000      944            0
    11 P11                     32,000      944            0
    12 P12                     32,000      944            0
    13 P13                     32,000      944            0
    14 P14                     32,000      944            0
    15 P15                     32,000      944            0
    16 P16                     32,000      944            0
    17 P17                     32,000      944            0
    18 P18                     32,000      944            0
    19 P19                     32,000      944            0
    20 P20                     32,000      944            0
                                    B
Index           Partition        Tree     Leaf       Distinct         Number
Name            Name            Level     Blks           Keys        of Rows
--------------- --------------- ----- -------- -------------- --------------
T1_IDX          P01                 1       67            999         31,968
T1_IDX          P02                 1       67          1,000         32,000
T1_IDX          P03                 1       67          1,000         32,000
T1_IDX          P04                 1       67          1,000         32,000
T1_IDX          P05                 1       67          1,000         32,000
T1_IDX          P06                 1       67          1,000         32,000
T1_IDX          P07                 1       67          1,000         32,000
T1_IDX          P08                 1       67          1,000         32,000
T1_IDX          P09                 1       67          1,000         32,000
T1_IDX          P10                 1       67          1,000         32,000
T1_IDX          P11                 1       72          1,000         32,000
T1_IDX          P12                 1       72          1,000         32,000
T1_IDX          P13                 1       72          1,000         32,000
T1_IDX          P14                 1       72          1,000         32,000
T1_IDX          P15                 1       72          1,000         32,000
T1_IDX          P16                 1       72          1,000         32,000
T1_IDX          P17                 1       72          1,000         32,000
T1_IDX          P18                 1       72          1,000         32,000
T1_IDX          P19                 1       72          1,000         32,000
T1_IDX          P20                 1       72          1,000         32,000

下面执行查询:

Read the rest of this entry

,

有客户遇到SQL性能不稳定,突然变差导致系统性能出现严重问题的情况。对于大型的系统来说,SQL性能不稳定,有时突然变差,这是常常遇到的问题。这也是一些DBA的挑战。

对于使用Oracle数据库的应用系统,有时会出现运行得好好的SQL,性能突然变差。特别是对于OLTP类型系统执行频繁的核心SQL,如果出现性能问题,通常会影响整个数据库的性能,进而影响整个系统的正常运行。对于个别的SQL,比如较少使用的查询报表之类的SQL,如果出现问题,通常只影响少部分功能模块,而不会影响整个系统。

那么应该怎么样保持SQL性能的稳定性?

SQL的性能变差,通常是在SQL语句重新进行了解析,解析时使用了错误的执行计划出现的。下列情况是SQL会重新解析的原因:

  • 1. SQL语句没有使用绑定变量,这样SQL每次执行都要解析。
  • 2. SQL长时间没有执行,被刷出SHARED POOL,再次执行时需要重新解析。
  • 3. 在SQL引用的对象(表、视图等)上执行了DDL操作,甚至是结构发生了变化,比如建了一个索引。
  • 4. 对SQL引用的对象进行了权限更改。
  • 5. 重新分析(收集统计信息)了SQL引用的表和索引,或者表和索引统计信息被删除。
  • 6. 修改了与性能相关的部分参数。
  • 7. 刷新了共享池。
  • 8. 当然重启数据库也会使所有SQL全部重新解析。

SQL重新解析后,跟以前相比,性能突然变差,通常是下列原因:

  • 1. 表和索引的优化统计信息被删除,或者重新收集后统计信息不准确。重新收集统计信息通常是由于收集策略(方法)不正确引起。比如对分区表使用analyze命令而不是用dbms_stats包、收集统计信息时采样比例过小等等。Oracle优化器严重依赖于统计信息,如果统计信息有问题,则很容易导致SQL不能使用正确的执行计划。
  • 2. SQL绑定变量窥探(bind peeking),同时绑定变量对应的列上有直方图;或者绑定变量的值变化范围过大、分区数据分布极不均匀:
    • 1) 绑定变量的列上有直方图:
      假如表orders存储所有的订单,state列有3种不同的值:0表示未处理,1表示处理成功完成,2表示处理失败。State列上有一个索引,表中绝大部分数据的state列为1,0和2占少数。有下面的SQL:

      select * from orders where state=:b1
      

      这里:b1是变量,在大多数情况下这个值为0,则应该使用索引,但是如果SQL被重新解析,而第一次执行时应用传给变量b1值为1,则不会使用索引,采用全表扫描的方式来访问表。对于绑定变量的SQL,只在第一次执行时才会进行绑定变量窥探,并以此确定执行计划,该SQL后续执行时全部按这个执行计划。这样在后续执行时,b1变量传入的值为0的时候,仍然是第一次执行时产生的执行计划,即使用的是全表扫描,这样会导致性能很差。

    • 2) 绑定变量的值变化范围过大:
      同样假如orders表有一列created_date表示一笔订单的下单时间,orders表里面存储了最近1年的数据,有如下的SQL:

      Select * from orders where created_date >=:b1;
      

      假如大多数情况下,应用传入的b1变量值为最近几天内的日期值,那么SQL使用的是created_date列上的索引,而如果b1变量值为5个月之前的一个值,那么就会使用全表扫描。与上面描述的直方图引起的问题一样,如果SQL第1次执行时传入的变量值引起的是全表扫描,那么将该SQL后续执行时都使用了全表扫描,从而影响了性能。

    • 3) 分区数据量不均匀:
      对于范围和列表分区,可能存在各个分区之间数据量极不均匀的情况下。比如分区表orders按地区area进行了分区,P1分区只有几千行,而P2分区有200万行数据。同时假如有一列product_id,其上有一个本地分区索引,有如下的SQL:

      select * from orders where area=:b1 and product_id =:b2
      

      这条SQL由于有area条件,因此会使用分区排除。如果第1 次执行时应用传给b1变量的值正好落在P1分区上,很可能导致SQL采用全表扫描访问,如前面所描述的,导致SQL后续执行时全部使用了全表扫描。

  • 3. 其他原因,比如表做了类似于MOVE操作之后,索引不可用,对索引进行了更改。当然这种情况是属于维护不当引起的问题,不在本文讨论的范围。

综上所述,SQL语句性能突然变差,主要是因为绑定变量和统计信息的原因。注意这里只讨论了突然变差的情况,而对于由于数据量和业务量的增加性能逐步变差的情况不讨论。
为保持SQL性能或者说是执行计划的稳定性,需要从以下几个方面着手:

  • 1. 规划好优化统计信息的收集策略。对于Oracle 10g来说,默认的策略能够满足大部分需求,但是默认的收集策略会过多地收集列上的直方图。由于绑定变量与直方图固有的矛盾,为保持性能稳定,对使用绑定变量的列,不收集列上的直方图;对的确需要收集直方图的列,在SQL中该列上的条件就不要用绑定变量。统计信息收集策略,可以考虑对大部分表,使用系统默认的收集策略,而对于有问题的,可以用DBMS_STATS.LOCK_STATS锁定表的统计信息,避免系统自动收集该表的统计信息,然后编写脚本来定制地收集表的统计信息。脚本中类似如下:

    exec dbms_stats.unlock_table_stats…
    exec dbms_stats.gather_table_stats…
    exec dbms_stats.lock_table_stats…
    
  • 2. 修改SQL语句,使用HINT,使SQL语句按HINT指定的执行计划进行执行。这需要修改应用,同时需要逐条SQL语句进行,加上测试和发布,时间较长,成本较高,风险也较大。
  • 3. 修改隐含参数” _optim_peek_user_binds”为FALSE,修改这个参数可能会引起性能问题(这里讨论的是稳定性问题)。
  • 4. 使用OUTLINE。对于曾经出现过执行计划突然变差的SQL语句,可以使用OUTLINE来加固其执行计划。在10g中DBMS_OUTLN.CREATE_OUTLINE可以根据已有的执行正常的SQL游标来创建OUTLINE。如果事先对所有频繁执行的核心SQL使用OUTLINE加固执行计划,将最大可能地避免SQL语句性能突然变差。
    注:DBMS_OUTLN可以通过$ORACLE_HOME/rdbms/admin/dbmsol.sql脚本来安装。
  • 5. 使用SQL Profile。SQL Profile是Oracle 10g之后的新功能,此处不再介绍,请参考相应的文档。

除此之外,可以调整一些参数避免潜在的问题,比如将"_btree_bitmap_plans"参数设置为FALSE(这个参数请参考互联网上的文章或Oracle文档)。

而在实际工作中,通过使用定制的统计信息收集策略,以及在部分系统上使用OUTLINE,系统基本上不会出现已有的SQL性能突然变差的情况。当然也有维护人员操作不当引起的SQL性能突然变差,比如建了某个索引而没有收集统计信息,导致SQL使用了新建的索引,而该索引并不适合于那条SQL;维护人员意外删除了表个索引的统计信息。

,