Top N需求SQL优化提升案例

前几日,朋友发来微信,测试系统中抓到一条即将上线的SQL,严重消耗数据库资源,SQL执行计划如下:

SELECT DT,TI,ST CONT,ANCT,PIID,CID FROM 
       (SELECT A.ID,a.INFO, 
             TO_CHAR(A.DT,'YYYY')||'年'||TO_CHAR(A.DT,'MM')||'月'||TO_CHAR(A.DT,'DD')||'日' AS DT,
             A.TI,
             A.MED,
             A.AT,
             B.ID AS CONT_ID,  
             to_char(SUBSTR(regexp_REPLACE(B.CONT, '\s',''),1,100)) AS ST, 
             E.ANNT,
             E.ID PIID,
             ROW_NUMBER() OVER(ORDER BY A.DT DESC,A.ID DESC)AS RN    
         FROM NWBAS A
         JOIN BASTXT B ON A.ID = B.OID
         JOIN NWSANN E ON A.ID=E.OID
       WHERE  EXISTS(SELECT 1 FROM NWSTYP C WHERE A.ID = C.ORID AND SUBSTR(C.code,1,2) in(11,12,13))        
              and a.PIC=1
       order by A.dt DESC
       )WHERE RN <=4;
---------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name            | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
---------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                 |      1 |        | 36016 (100)|          |      4 |00:00:04.52 |     267K|  74660 |
|*  1 |  VIEW                          |                 |      1 |   5237 | 36016   (1)| 00:07:13 |      4 |00:00:04.52 |     267K|  74660 |
|*  2 |   WINDOW SORT PUSHED RANK      |                 |      1 |   5237 | 36016   (1)| 00:07:13 |      5 |00:00:04.51 |     266K|  74660 |
|   3 |    NESTED LOOPS                |                 |      1 |   5237 | 36016   (1)| 00:07:13 |  67739 |00:00:04.38 |     266K|  74660 |
|   4 |     NESTED LOOPS               |                 |      1 |   5237 | 36016   (1)| 00:07:13 |  67739 |00:00:03.88 |     198K|  74660 |
|*  5 |      HASH JOIN                 |                 |      1 |   5237 | 27234   (1)| 00:05:27 |  67741 |00:00:03.59 |   93944 |  74660 |
|*  6 |       HASH JOIN RIGHT SEMI     |                 |      1 |  71164 | 25527   (1)| 00:05:07 |  68836 |00:00:03.36 |   91427 |  74660 |
|*  7 |        INDEX FAST FULL SCAN    | NWSTYP          |      1 |  71211 |  4120   (2)| 00:00:50 |    753K|00:00:02.14 |   16744 |      0 |
|*  8 |        TABLE ACCESS FULL       | NWSBAS          |      1 |   1281K| 21403   (1)| 00:04:17 |    102K|00:00:00.78 |   74683 |  74660 |
|   9 |       TABLE ACCESS FULL        | NWSANN          |      1 |  94294 |   653   (1)| 00:00:08 |  97456 |00:00:00.09 |    2517 |      0 |
|* 10 |      INDEX UNIQUE SCAN         | BASTXT          |  67741 |      1 |     1   (0)| 00:00:01 |  67739 |00:00:00.26 |     104K|      0 |
|  11 |     TABLE ACCESS BY INDEX ROWID| BASTXT          |  67739 |      1 |     2   (0)| 00:00:01 |  67739 |00:00:00.48 |   67813 |      0 |
---------------------------------------------------------------------------------------------------------------------------------------------

问题SQL单次消耗需要267K的逻辑读,大致需要4秒左右执行完成,并且执行计划中多数步骤中评估行数与实际返回行数严重不符,ID=10、11两步NESTED LOOP BASTXT表被驱动6万多次,效率低下。但是此SQL的逻辑是利用分析函数 ROW_NUMBER() OVER(ORDER BY A.DT DESC,A.ID DESC) 排序后,最终取4行而已,那么其实就是一个取Top N的SQL,可以将SQL改写为如下形式:

 SELECT created,object_name,owner,namespace FROM
       (SELECT /*+ INDEX_DESC(A t1_idx01) use_nl(A) use_nl(B) use_nl(C) use_nl(E) leading(A C B E)*/  A.object_id,
             A.object_name,
             a.CREATED,
             A.owner,
             B.object_id AS CONT_ID,
             E.namespace,
             E.OBJECT_ID PICTURE_ID
         FROM T1 A
         JOIN T2 B ON A.object_id = B.object_id
         JOIN T3 E ON A.object_id=E.object_id
        JOIN (SELECT DISTINCT D.OBJECT_ID FROM T4 D WHERE D.namespace in(29,30)) C on A.OBJECT_ID=C.OBJECT_ID
              where A.TEMPORARY='N'
       ORDER BY A.CREATED DESC,A.object_id DESC,A.LAST_DDL_TIME DESC --依照原SQL逻辑 order by A.LAST_DDL_TIME DESC其实可以去掉,此处加order by没有意义
       ) WHERE rownum <=4;
create index t1_idx01 on t1(TEMPORARY,CREATED,object_id,LAST_DDL_TIME,0);
create index t2_idx02 on t2(object_id,0);
create index t3_idx03 on t3(object_id,0);
create index t4_idx01 on t4(object_id,namespace,0);
利用索引有序特性,因SQL选择性很差,大部分记录都满足SQL关联条件,理想中的执行计划利用INDEX RANGE SCAN DESCENDING降序扫描,扫描少数记录后便满足需求停止扫描 count stop by key
-----------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name     | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |          |      1 |        |    33 (100)|          |      4 |00:00:00.01 |     344 |      7 |
|*  1 |  COUNT STOPKEY                    |          |      1 |        |            |          |      4 |00:00:00.01 |     344 |      7 |
|   2 |   VIEW                            |          |      1 |      5 |    33   (0)| 00:00:01 |      4 |00:00:00.01 |     344 |      7 |
|   3 |    NESTED LOOPS SEMI              |          |      1 |      5 |    33   (0)| 00:00:01 |      4 |00:00:00.01 |     344 |      7 |
|   4 |     NESTED LOOPS                  |          |      1 |      5 |    23   (0)| 00:00:01 |   1056 |00:00:00.01 |     331 |      4 |
|   5 |      NESTED LOOPS                 |          |      1 |      6 |    12   (0)| 00:00:01 |   1057 |00:00:00.01 |     170 |      0 |
|   6 |       TABLE ACCESS BY INDEX ROWID | T1       |      1 |      8 |     4   (0)| 00:00:01 |   1163 |00:00:00.01 |      88 |      0 |
|*  7 |        INDEX RANGE SCAN DESCENDING| T1_IDX01 |      1 |      8 |     3   (0)| 00:00:01 |   1163 |00:00:00.01 |      10 |      0 |
|*  8 |       INDEX RANGE SCAN            | T2_IDX02 |   1163 |      1 |     1   (0)| 00:00:01 |   1057 |00:00:00.01 |      82 |      0 |
|   9 |      TABLE ACCESS BY INDEX ROWID  | T3       |   1057 |      1 |     2   (0)| 00:00:01 |   1056 |00:00:00.01 |     161 |      4 |
|* 10 |       INDEX RANGE SCAN            | T3_IDX03 |   1057 |      1 |     1   (0)| 00:00:01 |   1056 |00:00:00.01 |      88 |      4 |
|  11 |     VIEW PUSHED PREDICATE         |          |   1056 |      2 |     2   (0)| 00:00:01 |      4 |00:00:00.01 |      13 |      3 |
|* 12 |      INDEX RANGE SCAN             | T4_IDX01 |   1056 |      2 |     2   (0)| 00:00:01 |      4 |00:00:00.01 |      13 |      3 |
-----------------------------------------------------------------------------------------------------------------------------------------

目标SQL优化后执行计划如下,单次执行只需要2000多个buffer,执行时间只需要几个毫秒即可

--------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name               | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
--------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |                    |      1 |        |   228 (100)|          |      4 |00:00:00.05 |    2905 |    780 |
|*  1 |  COUNT STOPKEY                   |                    |      1 |        |            |          |      4 |00:00:00.05 |    2905 |    780 |
|   2 |   VIEW                           |                    |      1 |      4 |   228   (0)| 00:00:03 |      4 |00:00:00.05 |    2905 |    780 |
|   3 |    NESTED LOOPS SEMI             |                    |      1 |      4 |   228   (0)| 00:00:03 |      4 |00:00:00.04 |    1631 |      0 |
|   4 |     NESTED LOOPS                 |                    |      1 |      4 |   216   (0)| 00:00:03 |      8 |00:00:00.04 |    1616 |      0 |
|   5 |      NESTED LOOPS                |                    |      1 |     55 |   104   (0)| 00:00:02 |      8 |00:00:00.04 |    1595 |      0 |
|   6 |       TABLE ACCESS BY INDEX ROWID| NWSBAS             |      1 |   1282K|    12   (0)| 00:00:01 |      8 |00:00:00.04 |    1571 |      0 |
|*  7 |        INDEX FULL SCAN DESCENDING| IDX_NWSBAS_01      |      1 |     64 |     3   (0)| 00:00:01 |      8 |00:00:00.04 |    1566 |      0 |
|   8 |       TABLE ACCESS BY INDEX ROWID| BASTXT             |      8 |      1 |     2   (0)| 00:00:01 |      8 |00:00:00.01 |      24 |      0 |
|*  9 |        INDEX UNIQUE SCAN         | BASTXT             |      8 |      1 |     1   (0)| 00:00:01 |      8 |00:00:00.01 |      16 |      0 |
|  10 |      TABLE ACCESS BY INDEX ROWID | NWSANN             |      8 |      1 |     3   (0)| 00:00:01 |      8 |00:00:00.01 |      21 |      0 |
|* 11 |       INDEX RANGE SCAN           | NWSANN             |      8 |      1 |     2   (0)| 00:00:01 |      8 |00:00:00.01 |      17 |      0 |
|  12 |     VIEW PUSHED PREDICATE        |                    |      8 |      1 |     3   (0)| 00:00:01 |      4 |00:00:00.01 |      15 |      0 |
|* 13 |      INDEX RANGE SCAN            | NWSTYP             |      8 |      1 |     3   (0)| 00:00:01 |      4 |00:00:00.01 |      15 |      0 |
--------------------------------------------------------------------------------------------------------------------------------------------------

SQL EXISTS写法遭遇FILTER

前几天,看到一篇公众号文章谈到一个SQL优化的问题,原SQL逻辑大致如下,看到这个SQL,发现其中一个小问题感觉需要提示出来,否则很容易忽视。

select min(created)
FROM t1
WHERE '1606270446000' = '1606270446000'
  AND EXISTS
    (SELECT 1
     FROM t2 m
     WHERE m.object_type = t1.object_type
       AND m.owner = t1.owner
       AND m.object_id = '33'
       AND t1.namespace = '4')
  OR EXISTS
    (SELECT 1
     FROM t3 n
     WHERE n.object_type = t1.object_type
       AND n.owner = t1.owner
       AND n.object_id = '33'
       AND t1.namespace = '4');

Plan hash value: 1283715866

-----------------------------------------------------------------------------------------------------------------------------
| Id  | Operation			| Name	  | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |	 A-Time   | Buffers |
-----------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT		|	  |	 1 |	    |	395 (100)|	    |	   1 |00:00:00.15 |   14591 |
|   1 |  SORT AGGREGATE 		|	  |	 1 |	  1 |		 |	    |	   1 |00:00:00.15 |   14591 |
|*  2 |   FILTER			|	  |	 1 |	    |		 |	    |	2628 |00:00:00.15 |   14591 |
|   3 |    TABLE ACCESS FULL		| T1	  |	 1 |	101K|	391   (1)| 00:00:05 |	 203K|00:00:00.04 |    2867 |
|   4 |    UNION-ALL			|	  |   7925 |	    |		 |	    |	   1 |00:00:00.03 |   11724 |
|*  5 |     FILTER			|	  |   7925 |	    |		 |	    |	   1 |00:00:00.01 |    5863 |
|*  6 |      TABLE ACCESS BY INDEX ROWID| T3	  |   2929 |	  1 |	  2   (0)| 00:00:01 |	   1 |00:00:00.01 |    5863 |
|*  7 |       INDEX RANGE SCAN		| N_IDX01 |   2929 |	  1 |	  1   (0)| 00:00:01 |	2929 |00:00:00.01 |    2934 |
|*  8 |     FILTER			|	  |   7924 |	    |		 |	    |	   0 |00:00:00.01 |    5861 |
|*  9 |      TABLE ACCESS BY INDEX ROWID| T2	  |   2928 |	  1 |	  2   (0)| 00:00:01 |	   0 |00:00:00.01 |    5861 |
|* 10 |       INDEX RANGE SCAN		| M_IDX01 |   2928 |	  1 |	  1   (0)| 00:00:01 |	2928 |00:00:00.01 |    2933 |
-----------------------------------------------------------------------------------------------------------------------------

COLUMN_NAME			      NDV NUL  NUM_NULLS DATA_TYPE    LOW_VAL_25		HIGH_VAL_25		  LAST_ANALYZED        HISTOGRAM
------------------------------ ---------- --- ---------- ------------ ------------------------- ------------------------- -------------------- ---------
CREATED 			    28480 Y	       0 DATE	      78760202122A38		78790318010404		  2021-03-07 10:26:30  NONE
DATA_OBJECT_ID			    29582 Y	  144370 NUMBER       80			C31A3E5F		  2021-03-07 10:26:30  NONE
EDITION_NAME				0 Y	  203482 VARCHAR2							  2021-03-07 10:26:30  NONE
GENERATED				2 Y	       0 VARCHAR2     4E			59			  2021-03-07 10:26:30  NONE
LAST_DDL_TIME			     3050 Y	      10 DATE	      78760201122A38		787903040E3124		  2021-03-07 10:26:30  NONE
NAMESPACE			       19 Y	      10 NUMBER       C102			C141			  2021-03-07 10:26:30  FREQUENCY
OBJECT_ID			   203482 Y	       0 NUMBER       C102			C3152353		  2021-03-07 10:26:30  NONE
OBJECT_NAME			    48784 Y	       0 VARCHAR2     2F31303030333233645F44656 73756E2F7574696C2F7265736 2021-03-07 10:26:30  NONE
OBJECT_TYPE			       44 Y	       0 VARCHAR2     434C5553544552		57494E444F57		  2021-03-07 10:26:30  FREQUENCY
OWNER				      251 Y	       0 VARCHAR2     414752			5A4142424958		  2021-03-07 10:26:30  FREQUENCY
SECONDARY				1 Y	       0 VARCHAR2     4E			4E			  2021-03-07 10:26:30  NONE
STATUS					2 Y	       0 VARCHAR2     494E56414C4944		56414C4944		  2021-03-07 10:26:30  NONE
SUBOBJECT_NAME			      171 Y	  202738 VARCHAR2     5030			575248245F5741495453545F3 2021-03-07 10:26:30  NONE
TEMPORARY				2 Y	       0 VARCHAR2     4E			59			  2021-03-07 10:26:30  NONE
TIMESTAMP			     3887 Y	      10 VARCHAR2     313939372D30342D31323A313 323032312D30332D30343A313 2021-03-07 10:26:30  NONE

从执行计划中看到,采用了FILTER的方式,原文中该SQL执行了“2小时39分钟40秒,逻辑读2874多万,物理读270多万”,T表数据量很大Filter 主查询结果集大,子查询结果小,也不能影响驱动关系,驱动表只能是主查询。驱动表驱动次数越多,效率越差。主查询结果集大,只能利用改写的方式消除FILTER。原文作者利用了如下方式进行改写:

SELECT min(t.created)
FROM t1 t,
     t2 m ,
     t3 n
WHERE ('1606270446000' = '1606270446000')
  AND m.object_type = t.object_type
  AND m.owner = t.owner
  AND m.object_id = '33'
  AND t.namespace = '1'
  OR (n.object_type = t.object_type
      AND n.owner = t.owner
      AND n.object_id = '33'
      AND t.namespace = '4');

因为最终的结果集取MIN,则将半连接直接改为了inner join,无需考虑重复数据的问题,但是需要注意的是,半连接(in或exists)改为inner join时,如果最终结果集没有去重逻辑,需要将中间涉及关联的结果集去重后,再改写为内连接,从而体现“半”连接,这是在我们日常SQL改写中,常见却又容易忽略的问题:

create index t1_idx01 on t1(object_type,owner,namespace,created);
create index m_idx01 on t2(object_id);
create index n_idx01 on t3(object_id);

SELECT created  --普通结果集
FROM t1,
  (SELECT DISTINCT m.object_type,  --distinct去重
                   m.owner
   FROM t2 m
   WHERE m.object_id = '33') x1,
  (SELECT DISTINCT n.object_type,  --distinct去重
                   n.owner
   FROM t3 n
   WHERE n.object_id = '33') x2
WHERE 1=1
  AND (x1.object_type = t1.object_type
       AND x1.owner = t1.owner)
  OR (x2.object_type = t1.object_type
      AND x2.owner = t1.owner)
  AND t1.namespace = '4';

Plan hash value: 3647106578

--------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation			  | Name     | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT		  |	     |	    1 |        |    16 (100)|	       |   2628 |00:00:00.01 |	   215 |
|   1 |  CONCATENATION			  |	     |	    1 |        |	    |	       |   2628 |00:00:00.01 |	   215 |
|   2 |   NESTED LOOPS			  |	     |	    1 |      3 |     8	(25)| 00:00:01 |   2628 |00:00:00.01 |	   195 |
|   3 |    MERGE JOIN CARTESIAN 	  |	     |	    1 |      1 |     6	(34)| 00:00:01 |      1 |00:00:00.01 |	     6 |
|   4 |     VIEW			  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|   5 |      HASH UNIQUE		  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|   6 |       TABLE ACCESS BY INDEX ROWID | T2	     |	    1 |      1 |     2	 (0)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|*  7 |        INDEX RANGE SCAN 	  | M_IDX01  |	    1 |      1 |     1	 (0)| 00:00:01 |      1 |00:00:00.01 |	     2 |
|   8 |     BUFFER SORT 		  |	     |	    1 |      1 |     6	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|   9 |      VIEW			  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|  10 |       HASH UNIQUE		  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|  11 |        TABLE ACCESS BY INDEX ROWID| T3	     |	    1 |      1 |     2	 (0)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|* 12 | 	INDEX RANGE SCAN	  | N_IDX01  |	    1 |      1 |     1	 (0)| 00:00:01 |      1 |00:00:00.01 |	     2 |
|* 13 |    INDEX RANGE SCAN		  | T1_IDX01 |	    1 |      3 |     2	 (0)| 00:00:01 |   2628 |00:00:00.01 |	   189 |
|  14 |   NESTED LOOPS			  |	     |	    1 |      1 |     8	(25)| 00:00:01 |      0 |00:00:00.01 |	    20 |
|  15 |    NESTED LOOPS 		  |	     |	    1 |      1 |     5	(20)| 00:00:01 |   2628 |00:00:00.01 |	    17 |
|  16 |     VIEW			  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|  17 |      HASH UNIQUE		  |	     |	    1 |      1 |     3	(34)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|  18 |       TABLE ACCESS BY INDEX ROWID | T2	     |	    1 |      1 |     2	 (0)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|* 19 |        INDEX RANGE SCAN 	  | M_IDX01  |	    1 |      1 |     1	 (0)| 00:00:01 |      1 |00:00:00.01 |	     2 |
|* 20 |     INDEX RANGE SCAN		  | T1_IDX01 |	    1 |      1 |     2	 (0)| 00:00:01 |   2628 |00:00:00.01 |	    14 |
|* 21 |    VIEW 			  |	     |	 2628 |      1 |     3	(34)| 00:00:01 |      0 |00:00:00.01 |	     3 |
|  22 |     SORT UNIQUE 		  |	     |	 2628 |      1 |     3	(34)| 00:00:01 |   2628 |00:00:00.01 |	     3 |
|  23 |      TABLE ACCESS BY INDEX ROWID  | T3	     |	    1 |      1 |     2	 (0)| 00:00:01 |      1 |00:00:00.01 |	     3 |
|* 24 |       INDEX RANGE SCAN		  | N_IDX01  |	    1 |      1 |     1	 (0)| 00:00:01 |      1 |00:00:00.01 |	     2 |
--------------------------------------------------------------------------------------------------------------------------------

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

   1 - SEL$1
   4 - SEL$2   / X1@SEL$1
   5 - SEL$2
   6 - SEL$2   / M@SEL$2
   7 - SEL$2   / M@SEL$2
   9 - SEL$3   / X2@SEL$1
  10 - SEL$3
  11 - SEL$3   / N@SEL$3
  12 - SEL$3   / N@SEL$3
  13 - SEL$1_1 / T1@SEL$1
  16 - SEL$2   / X1@SEL$1_2
  18 - SEL$2   / M@SEL$2
  19 - SEL$2   / M@SEL$2
  20 - SEL$1_2 / T1@SEL$1_2
  21 - SEL$3   / X2@SEL$1_2
  23 - SEL$3   / N@SEL$3
  24 - SEL$3   / N@SEL$3

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

  /*+
      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('11.2.0.4')
      DB_VERSION('11.2.0.4')
      OPT_PARAM('_optim_peek_user_binds' 'false')
      OPT_PARAM('_optimizer_use_feedback' 'false')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$2")
      OUTLINE_LEAF(@"SEL$3")
      OUTLINE_LEAF(@"SEL$1")
      OUTLINE_LEAF(@"SEL$1_1")
      USE_CONCAT(@"SEL$1" 8 OR_PREDICATES(1))
      OUTLINE_LEAF(@"SEL$1_2")
      OUTLINE(@"SEL$1")
      NO_ACCESS(@"SEL$1_1" "X1"@"SEL$1")
      NO_ACCESS(@"SEL$1_1" "X2"@"SEL$1")
      INDEX(@"SEL$1_1" "T1"@"SEL$1" ("T1"."OBJECT_TYPE" "T1"."OWNER" "T1"."NAMESPACE" "T1"."CREATED"))
      NO_ACCESS(@"SEL$1_2" "X1"@"SEL$1_2")
      INDEX(@"SEL$1_2" "T1"@"SEL$1_2" ("T1"."OBJECT_TYPE" "T1"."OWNER" "T1"."NAMESPACE" "T1"."CREATED"))
      NO_ACCESS(@"SEL$1_2" "X2"@"SEL$1_2")
      LEADING(@"SEL$1_1" "X1"@"SEL$1" "X2"@"SEL$1" "T1"@"SEL$1")
      LEADING(@"SEL$1_2" "X1"@"SEL$1_2" "T1"@"SEL$1_2" "X2"@"SEL$1_2")
      USE_MERGE_CARTESIAN(@"SEL$1_1" "X2"@"SEL$1")
      USE_NL(@"SEL$1_1" "T1"@"SEL$1")
      USE_NL(@"SEL$1_2" "T1"@"SEL$1_2")
      USE_NL(@"SEL$1_2" "X2"@"SEL$1_2")
      INDEX_RS_ASC(@"SEL$2" "M"@"SEL$2" ("T2"."OBJECT_ID"))
      USE_HASH_AGGREGATION(@"SEL$2")
      INDEX_RS_ASC(@"SEL$3" "N"@"SEL$3" ("T3"."OBJECT_ID"))
      END_OUTLINE_DATA
  */

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

   7 - access("M"."OBJECT_ID"=33)
  12 - access("N"."OBJECT_ID"=33)
  13 - access("X2"."OBJECT_TYPE"="T1"."OBJECT_TYPE" AND "X2"."OWNER"="T1"."OWNER" AND "T1"."NAMESPACE"=4)
  19 - access("M"."OBJECT_ID"=33)
  20 - access("X1"."OBJECT_TYPE"="T1"."OBJECT_TYPE" AND "X1"."OWNER"="T1"."OWNER")
  21 - filter((LNNVL("X2"."OBJECT_TYPE"="T1"."OBJECT_TYPE") OR LNNVL("X2"."OWNER"="T1"."OWNER") OR
	      LNNVL("T1"."NAMESPACE"=4)))
  24 - access("N"."OBJECT_ID"=33)

SQL优化,写法很关键

近期听到一位Oracle业界前辈,说道:”SQL优化,关键在写法”。我在生产过程中碰到的SQL问题,因为写法有误造成SQL产生严重的性能问题非常多,开发人员可能更关心我的代码功能是否实现,SQL上线前因测试系统环境、数据量与生产存在差异,导致SQL在生产上实际运行时效率远远小于预期,前几天,碰到如下这个SQL案例,个人感觉非常典型,SQL写法很关键!

SELECT count(*)
FROM pnrresultdata
WHERE TO_NUMBER(SYSDATE - CREATEtime)* 86400 > 5*60
  AND TO_NUMBER(SYSDATE - CREATEtime)* 86400 < 4*60*60
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

SQL逻辑很简单,只是单纯输出一下符合条件的count(*),资源消耗如下图所示

然而,表中CREATETIME字段选择性很好,NUM_ROWS:64186660 NDV:2497536,此字段上没有索引,但是因为写法问题,常规组合索引中包含此字段也没有办法利用上索引,非常常见的原因:字段上参与了运算。

将SQL等价改写为:

SELECT count(*)
FROM pnrresultdata
WHERE CREATETIME < SYSDATE - interval '5' MINUTE
  AND CREATETIME > SYSDATE - interval '4' hour
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

原SQL执行计划,采用了ISSUCCESS列上的低效索引:

-------------------------------------
SQL_ID  76d58v13x8z90, child number 0
-------------------------------------
SELECT count(*)
FROM pnrresultdata
WHERE TO_NUMBER(SYSDATE - CREATEtime)* 86400 > 5*60
  AND TO_NUMBER(SYSDATE - CREATEtime)* 86400 < 4*60*60
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

Plan hash value: 3822156680

-----------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name                    | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |                         |      1 |        |       | 14814 (100)|          |      1 |00:00:01.03 |     296K|   4761 |
|   1 |  SORT AGGREGATE              |                         |      1 |      1 |    26 |            |          |      1 |00:00:01.03 |     296K|   4761 |
|*  2 |   TABLE ACCESS BY INDEX ROWID| PNRRESULTDATA           |      1 |      1 |    26 | 14814   (1)| 00:02:58 |    429 |00:00:01.03 |     296K|   4761 |
|*  3 |    INDEX RANGE SCAN          | PNRRESULTDATA_ISSUCCESS |      1 |    452K|       |  2765   (1)| 00:00:34 |    413K|00:00:00.06 |    2949 |     34 |
-----------------------------------------------------------------------------------------------------------------------------------------------------------

2 - filter(("USERNAME"='baosheng_dps' AND "POSTTYPE"='R' AND TO_NUMBER(SYSDATE@!-"CREATETIME")*86400>300 AND
              TO_NUMBER(SYSDATE@!-"CREATETIME")*86400<14400 AND "GETTIME">0))
   3 - access("ISSUCCESS"=0)

改写后,因其他字段缺失索引,目前状态仍不为最佳,同时出现了BITMAP CONVERSION

-------------------------------------
SQL_ID  00xz7m7u33wgg, child number 1
-------------------------------------
SELECT count(*)
FROM pnrresultdata
WHERE CREATETIME < SYSDATE - interval '5' MINUTE
  AND CREATETIME > SYSDATE - interval '4' hour
  AND username ='baosheng_dps'
  AND (getTime >0)
  AND postType='R'
  AND isSuccess=0

Plan hash value: 2537524006

------------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                          | Name                     | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers | Reads  |
------------------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                   |                          |      1 |        |       |  9313 (100)|          |      1 |00:00:00.23 |    4339 |   1531 |
|   1 |  SORT AGGREGATE                    |                          |      1 |      1 |    26 |            |          |      1 |00:00:00.23 |    4339 |   1531 |
|*  2 |   FILTER                           |                          |      1 |        |       |            |          |    429 |00:00:00.23 |    4339 |   1531 |
|*  3 |    TABLE ACCESS BY INDEX ROWID     | PNRRESULTDATA            |      1 |    429 | 11154 |  9313   (1)| 00:01:52 |    429 |00:00:00.23 |    4339 |   1531 |
|   4 |     BITMAP CONVERSION TO ROWIDS    |                          |      1 |        |       |            |          |   1164 |00:00:00.23 |    3477 |   1531 |
|   5 |      BITMAP AND                    |                          |      1 |        |       |            |          |      1 |00:00:00.23 |    3477 |   1531 |
|   6 |       BITMAP CONVERSION FROM ROWIDS|                          |      1 |        |       |            |          |      6 |00:00:00.06 |    1937 |      0 |
|*  7 |        INDEX RANGE SCAN            | PNRRESULTDATA_ISSUCCESS  |      1 |    452K|       |  2765   (1)| 00:00:34 |    288K|00:00:00.03 |    1937 |      0 |
|   8 |       BITMAP CONVERSION FROM ROWIDS|                          |      1 |        |       |            |          |      2 |00:00:00.17 |    1540 |   1531 |
|   9 |        SORT ORDER BY               |                          |      1 |        |       |            |          |    177K|00:00:00.16 |    1540 |   1531 |
|* 10 |         INDEX RANGE SCAN           | PNRRESULTDATA_CREATETIME |      1 |    452K|       |  1593   (1)| 00:00:20 |    177K|00:00:00.10 |    1540 |   1531 |
------------------------------------------------------------------------------------------------------------------------------------------------------------------

结合字段的选择性与在索引中的过滤必要,需要创建:

create index t1_idx01 on t1(username,postType,isSuccess,CREATEtime) &tablespace parallel ∥

MRP0进程Hung?

前天晚上,同事发来微信求助,监控到一套2节点数据库RAC 数据库主备库同步状态异常,并且同事经过分析发现造成此问题的是因为Dataguard MRP0进程存在,但是停止在某一个seqence#上,应用的sequnce#与block不进行恢复。

随即登录备库数据库查看同步状态,发现MRP0进程停滞在sequnce:197788与block:186030上,实际上并没有进行“APPLYING_LOG”。

SQL> set linesize 200
select process,status,client_process,thread#,sequence#,block#,active_agents,known_agents from gv$managed_standby where process in ('LNS','RFS','MRP0') and  THREAD# <> 0
SQL>   2  ;

PROCESS   STATUS       CLIENT_P    THREAD#  SEQUENCE#     BLOCK# ACTIVE_AGENTS KNOWN_AGENTS
--------- ------------ -------- ---------- ---------- ---------- ------------- ------------
RFS       IDLE         LGWR              1     199217     123144             0            0
RFS       IDLE         LGWR              2     142409      77956             0            0
MRP0      APPLYING_LOG N/A               1     197788     186030             9            9

此日志197788归档日志文件存在与备库,并且同事反馈尝试alter database register logfile、主库RMAN重新恢复此197788归档日志,均无效。

查询v$archived_log确认197788这个归档文件为20210109 15:00左右主库产生的,分别查看一下主库/备库的alert日志,看看那时数据库有无异常情况发生:

节点1,传输至备时出现异常:
Thread 1 advanced to log sequence 197788 (LGWR switch)
  Current log# 5 seq# 197788 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_5.287.1003922183
  Current log# 5 seq# 197788 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_5.286.1003922183
Sat Jan 09 15:32:25 2021
Archived Log entry 275332 added for thread 1 sequence 197787 ID 0x9c755e67 dest 1:
Sat Jan 09 15:32:25 2021
ARCj: Standby redo logfile selected for thread 1 sequence 197787 for destination LOG_ARCHIVE_DEST_2
Sat Jan 09 15:33:14 2021
LNS: Standby redo logfile selected for thread 1 sequence 197788 for destination LOG_ARCHIVE_DEST_2
Sat Jan 09 15:43:17 2021
Thread 1 advanced to log sequence 197789 (LGWR switch)
  Current log# 1 seq# 197789 mem# 0: +DG_REDO/Travelskydba/onlinelog/group_1.295.1003922179
  Current log# 1 seq# 197789 mem# 1: +DG_REDO/Travelskydba/onlinelog/group_1.294.1003922179
Sat Jan 09 15:43:17 2021
Archived Log entry 275335 added for thread 1 sequence 197788 ID 0x9c755e67 dest 1:
Sat Jan 09 15:47:06 2021
WARN: ARC1: Terminating pid 4047 hung on an I/O operation
Killing 1 processes with pids 4047 (Process by index) in order to remove hung processes. Requested by OS process 31580 on instance 1
ARC1: Error 16198 due to hung I/O operation to LOG_ARCHIVE_DEST_2
ARCo: Standby redo logfile selected for thread 1 sequence 197788 for destination LOG_ARCHIVE_DEST_2

节点2,传输至备库时出现异常:
Sat Jan 09 15:47:15 2021
Archived Log entry 275337 added for thread 2 sequence 141662 ID 0x9c755e67 dest 1:
Sat Jan 09 15:47:35 2021
WARN: ARC2: Terminating pid 27590 hung on an I/O operation
Killing 1 processes with pids 27590 (Process by index) in order to remove hung processes. Requested by OS process 27465 on instance 2
ARC2: Error 16198 due to hung I/O operation to LOG_ARCHIVE_DEST_2
Sat Jan 09 15:47:37 2021
NSA2 started with pid=29, OS id=2625
Sat Jan 09 15:47:42 2021


备库节点:
Archived Log entry 77427 added for thread 1 sequence 197786 ID 0x9c755e67 dest 1:
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/2_141661_853598219.arc
Media Recovery Waiting for thread 2 sequence 141662 (in transit)
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937
Media Recovery Waiting for thread 1 sequence 197788 (in transit)
Recovery of Online Redo Log: Thread 1 Group 7 Seq 197788 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_7.282.1003923169
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_7.280.1003923169

备库节点在1月9日 16:24:31时已经应用完成197788日志
Sat Jan 09 16:24:31 2021
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/1_197788_853598219.arc

197788这个日志已经应用完毕,并且197789日志也完好的存在与备库节点 ,那么很有可能目前备库MRP0进程不工作的原因是在等其他日志应用完毕,。备库应用日志需要连续,那么是否有可能其他节点或本节点的其他日志?

我们可以利用主库如下sql查询进行确认:

SQL> SELECT FIRST_CHANGE#,
       THREAD#,
       DEST_ID,
       STATUS,
       FAL,
       APPLIED,
       DELETED,
       to_char(FIRST_TIME,'yyyymmdd hh24:mi:ss') FIRST_TIME,
       to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') COMPLETION_TIME,
       sequence#
FROM v$archived_log
WHERE to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') BETWEEN '20210109 15:00:17' AND '20210109 16:00:17'  order by 1,5  2    3    4    5    6    7    8    9   10   11   12  ;

   FIRST_CHANGE#          THREAD#          DEST_ID S FAL APPLIED   DEL FIRST_TIME        COMPLETION_TIME          SEQUENCE#
---------------- ---------------- ---------------- - --- --------- --- ----------------- ----------------- ----------------
   9555246783243                2                2 A NO  YES       NO  20210109 14:32:30 20210109 15:04:31           141659
   9555246783243                2                1 D NO  NO        YES 20210109 14:32:30 20210109 15:04:32           141659
   9555247407959                1                1 D NO  NO        YES 20210109 14:54:15 20210109 15:04:31           197783
   9555247407959                1                2 A NO  YES       NO  20210109 14:54:15 20210109 15:04:31           197783
   9555247700807                1                2 A NO  YES       NO  20210109 15:04:30 20210109 15:15:10           197784
   9555247700807                1                1 D NO  NO        YES 20210109 15:04:30 20210109 15:15:10           197784
   9555247701783                2                2 A NO  YES       NO  20210109 15:04:31 20210109 15:32:20           141660
   9555247701783                2                1 D NO  NO        YES 20210109 15:04:31 20210109 15:32:21           141660
   9555248017764                1                1 D NO  NO        YES 20210109 15:15:10 20210109 15:25:40           197785
   9555248017764                1                2 A NO  YES       NO  20210109 15:15:10 20210109 15:25:40           197785
   9555248313954                1                2 A NO  YES       NO  20210109 15:25:40 20210109 15:33:14           197786
   9555248313954                1                1 D NO  NO        YES 20210109 15:25:40 20210109 15:32:19           197786
   9555248508993                1                1 D NO  NO        YES 20210109 15:32:19 20210109 15:32:25           197787
   9555248508993                1                2 A YES YES       NO  20210109 15:32:19 20210109 15:32:26           197787
   9555248509181                2                1 D NO  NO        YES 20210109 15:32:20 20210109 15:32:23           141661
   9555248509181                2                2 A NO  YES       NO  20210109 15:32:20 20210109 15:32:23           141661
   9555248510236                2                1 D NO  NO        YES 20210109 15:32:23 20210109 15:47:15           141662
   9555248510774                1                1 D NO  NO        YES 20210109 15:32:25 20210109 15:43:17           197788
   9555248831803                1                1 D NO  NO        YES 20210109 15:43:17 20210109 15:47:14           197789
   9555248831803                1                2 A YES NO        NO  20210109 15:43:17 20210109 15:52:30           197789
   9555248943929                1                1 D NO  NO        YES 20210109 15:47:14 20210109 15:52:14           197790
   9555248944032                2                1 D NO  NO        YES 20210109 15:47:15 20210109 15:47:42           141663
   9555248944032                2                2 A YES NO        NO  20210109 15:47:15 20210109 15:53:18           141663
   9555248950448                2                1 D NO  NO        YES 20210109 15:47:42 20210109 15:53:18           141664
   9555248950448                2                2 A YES NO        NO  20210109 15:47:42 20210109 15:55:13           141664

25 rows selected.

上述查询确认后,每个sequence应当归档到dest_id=1(本地),dest_id=2(备库),但是发现thread 2的141662,未显示归档到DEST_ID=2,并且下一个日志便是197788
Media Recovery Log /oracle/archive_Travelskydba/Travelskydba/2_141661_853598219.arc
Media Recovery Waiting for thread 2 sequence 141662 (in transit)
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937
Media Recovery Waiting for thread 1 sequence 197788 (in transit)
Recovery of Online Redo Log: Thread 1 Group 7 Seq 197788 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_7.282.1003923169
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_7.280.1003923169
Sat Jan 09 15:49:02 2021
RFS[31]: Possible network disconnect with primary database
后续,备库一值在读取141662这个日志文件,但

Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937

Mon Jan 18 20:42:42 2021
Managed Standby Recovery starting Real Time Apply
Parallel Media Recovery started with 8 slaves
Waiting for all non-current ORLs to be archived...
All non-current ORLs have been archived.
Recovery of Online Redo Log: Thread 2 Group 11 Seq 141662 Reading mem 0
  Mem# 0: /oracle/redo_Travelskydba/Travelskydba/group_11.301.1003923935
  Mem# 1: /oracle/redo_Travelskydba/Travelskydba/group_11.304.1003923937

此时,主库141662这个归档认为已经传输到备库并且已经删除,但备库实际并未接收到。Threa#1 的197788无法应用的根因为Thread# 2 归档141662并未应用。

让同事将141662归档从主库归档备份中恢复出来 ,拷贝至备库注册或等待备库(fal_client)从主库(fal_server)中获取。同事恢复此归档文件后,备库MRP0进程立即开始工作,进行正常的日志应用,同时主库的v$archived_log中的日志记录变成了复合预期的状态:

SQL> SELECT FIRST_CHANGE#,
       THREAD#,
       DEST_ID,
       STATUS,
       FAL,
       APPLIED,
       DELETED,
       to_char(FIRST_TIME,'yyyymmdd hh24:mi:ss') FIRST_TIME,
       to_char(COMPLETION_TIME,'yyyymmdd hh24:mi:ss') COMPLETION_TIME,
       sequence#
FROM v$archived_log
WHERE sequence#=141662  2    3    4    5    6    7    8    9   10   11   12  ;

   FIRST_CHANGE#          THREAD#          DEST_ID S FAL APPLIED   DEL FIRST_TIME        COMPLETION_TIME          SEQUENCE#
---------------- ---------------- ---------------- - --- --------- --- ----------------- ----------------- ----------------
   9555248510236                2                1 D NO  NO        YES 20210109 15:32:23 20210109 15:47:15           141662
   9555248510236                2                1 A NO  NO        NO  20210109 15:32:23 20210118 21:39:53           141662
   9555248510236                2                2 A YES YES       NO  20210109 15:32:23 20210118 21:40:33           141662

利用sysmetric_history与dba_hist_event_histogram定位IO性能问题

近期发现,公司生产4套数据库从12月9日起,每周三22:00-22:30时间段均有应用事务DML缓慢的现象,IO等待事件明显增多:

IO等待类事件明显均有显著抬头的现象,例如log file sync等,但是我们如何定位是否真正的数据库IO真正出现问题?是因还是果?是否是io requeset变多还是IO真正出现问题?

问题时间段的AWR:

AWR中的Avg Wait极有可能被平均
另外一套库的显示的较为直观,log file sync平均等待高达17ms之多

换一个角度,我们从Oracle提供的数据库内部的v$metric_history与dba_hist_sysmetric_history动态视图中可以从“ Average Synchronous Single-Block Read Latency、I/O Megabytes per Second、I/O Requests per Second”等指标中辅助定位:

select to_char(end_time, 'yyyymmdd hh24:mi:ss') as time,
       max(case
             when metric_name = 'Average Synchronous Single-Block Read Latency' then
              round(value,2)
             else null
           end) as "Single Block Read Latency",
       max(case
             when metric_name = 'I/O Megabytes per Second' then
              round(value,2)
             else null
           end) as "IO Megabytes per Second",
       max(case
             when metric_name = 'I/O Requests per Second' then
              round(value,2)
             else null
           end) as "I/O Requests per Second"
  from dba_hist_sysmetric_history where instance_number=1 and to_char(end_time, 'yyyymmdd hh24:mi:ss') between '20210106 22:00:00' and '20210106 23:00:00'
 group by to_char(end_time, 'yyyymmdd hh24:mi:ss') order by 1

TIME              Single Block Read Latency IO Megabytes per Second I/O Requests per Second
----------------- ------------------------- ----------------------- -----------------------
20210106 21:00:44                      1.75                   23.69                 2060.17
20210106 21:01:44                       2.1                   13.32                 1474.73
20210106 21:02:43                      1.99                    18.6                 1716.56
20210106 21:03:43                      1.43                   11.54                 1089.31
20210106 21:04:43                      1.69                   20.77                 1567.28
20210106 21:05:43                      1.61                   17.92                 1806.92
20210106 21:06:44                      2.21                   27.95                 2466.91
20210106 21:07:44                      1.63                   11.29                 1052.18
20210106 21:08:44                      2.01                   17.23                 1729.85
20210106 21:09:43                      1.63                   12.53                  1309.2
20210106 21:10:43                      1.36                   15.53                 1180.81
20210106 21:11:43                      2.57                   12.97                 1399.38
20210106 21:12:43                      1.42                   16.71                 1323.95
20210106 21:13:44                      1.65                   10.37                 1367.22
20210106 21:14:44                      1.42                   20.49                    1493
20210106 21:15:44                      1.66                    8.21                 1186.28
20210106 21:16:43                      2.39                   23.23                 2012.56
20210106 21:17:43                       1.3                   11.34                 1219.04
20210106 21:18:43                      1.15                   15.06                 1219.79
20210106 21:19:43                      1.66                       7                 1057.58
20210106 21:20:44                      1.38                   19.74                 1402.93
20210106 21:21:44                      2.59                    7.66                 1086.08
20210106 21:22:44                      1.22                   16.51                 1307.65
20210106 21:23:43                      1.39                   12.68                 1391.17
20210106 21:24:43                      1.43                   15.38                 1255.99
20210106 21:25:43                      1.37                   13.82                 1489.76
20210106 21:26:44                       1.9                   24.64                 2456.92
20210106 21:27:44                      1.49                    7.35                 1232.54
20210106 21:28:44                      1.06                   50.22                  1287.7
20210106 21:29:44                      2.06                   31.16                 1516.66
20210106 21:30:43                      1.21                   67.67                 1750.49
20210106 21:31:43                      2.52                   67.19                  1398.3
20210106 21:32:43                      1.68                   38.94                 1831.17
20210106 21:33:44                      1.46                    9.81                 1366.68
20210106 21:34:44                      1.61                   17.64                 1447.77
20210106 21:35:44                      1.52                   15.25                 1860.36
20210106 21:36:44                      1.61                   26.07                 2350.26
20210106 21:37:43                      2.18                   11.01                 1161.19
20210106 21:38:43                      1.38                   16.08                 1438.71
20210106 21:39:44                      1.56                   10.44                 1005.47
20210106 21:40:44                      1.23                   15.76                 1202.61
20210106 21:41:44                      2.21                    8.56                 1374.73
20210106 21:42:44                      1.71                    19.9                 1298.54
20210106 21:43:44                      1.49                    9.08                 1196.41
20210106 21:44:43                      1.79                   18.07                 1715.96
20210106 21:45:43                      1.86                   11.46                 1055.36
20210106 21:46:44                      1.36                   22.71                  1960.6
20210106 21:47:44                      1.13                    27.1                 1589.31
20210106 21:48:44                      1.39                   18.62                 1142.78
20210106 21:49:44                      1.88                    6.48                  904.06
20210106 21:50:44                      1.22                   20.12                  1420.4
20210106 21:51:43                      1.79                    7.54                 1054.08
20210106 21:52:44                      1.32                   16.79                 1246.04
20210106 21:53:44                       1.5                   12.89                 1509.54
20210106 21:54:44                      1.59                   14.58                  961.99
20210106 21:55:44                      1.75                    8.41                 1114.03
20210106 21:56:44                      1.42                   29.02                 2388.62
20210106 21:57:44                       1.7                    6.22                  815.38
20210106 21:58:43                      1.36                   14.27                 1024.69
20210106 21:59:44                      1.89                   10.66                 1133.77
20210106 22:00:44                      1.02                   52.87                 3232.29
20210106 22:01:44                       .71                   94.45                 4846.43
20210106 22:02:44                      5.28                   83.54                 2627.49
20210106 22:03:44                      7.04                   69.19                 2067.08
20210106 22:04:44                      7.07                   74.68                 2382.61
20210106 22:05:43                      4.87                   79.73                 2654.56
20210106 22:06:44                      5.94                   90.77                 3937.21
20210106 22:07:44                      8.01                   31.11                 1074.18
20210106 22:08:44                      6.16                   26.27                 1639.99
20210106 22:09:44                      2.71                    31.5                 1797.32
20210106 22:10:44                      5.12                   37.47                 1533.45
20210106 22:11:44                      5.04                   62.63                 1520.07
20210106 22:12:44                      3.81                   35.91                 1402.06
20210106 22:13:44                      3.66                   18.25                 1626.73
20210106 22:14:44                      3.01                   61.43                  2179.6
20210106 22:15:44                      2.59                   75.41                 1789.91
20210106 22:16:44                      3.13                    91.9                 2745.88
20210106 22:17:44                      2.97                   86.56                  1798.5
20210106 22:18:45                      2.33                   84.64                 1505.69
20210106 22:19:44                      1.74                    72.1                 1378.42
20210106 22:20:44                      1.84                   91.02                 1957.69
20210106 22:21:44                      2.72                   68.14                 1447.02
20210106 22:22:44                      2.18                   80.76                 1649.19
20210106 22:23:44                      2.75                   75.58                 1676.43
20210106 22:24:44                       2.2                   36.45                 1502.78
20210106 22:25:45                      2.21                   21.77                 1429.71
20210106 22:26:44                      2.61                   40.56                 2667.25
20210106 22:27:44                      2.09                   19.95                 1068.11
20210106 22:28:44                      1.39                   57.66                 1419.02
20210106 22:29:44                      1.61                   44.66                 1701.81
20210106 22:30:44                       1.2                   74.61                 2328.65
20210106 22:31:45                      1.29                   83.01                 2020.88
20210106 22:32:45                       .76                   94.96                 2706.07
20210106 22:33:44                      1.02                   22.84                 2032.87
20210106 22:34:44                       .74                   58.67                 2297.62
20210106 22:35:44                      1.76                   81.66                 1727.17
20210106 22:36:44                       .58                    66.2                 4839.24
20210106 22:37:44                       .87                   29.04                 1617.19
20210106 22:38:45                      1.54                   53.16                 1539.99
20210106 22:39:45                      1.21                    51.9                  1420.5
20210106 22:40:44                         1                   49.76                 1646.52
20210106 22:41:44                      2.23                   74.05                 1761.78
20210106 22:42:44                      1.17                  146.94                 1505.77
20210106 22:43:44                      1.39                   75.94                 1620.12
20210106 22:44:45                      1.07                   73.43                 2045.32
20210106 22:45:45                       .44                   82.36                 2572.26
20210106 22:46:44                         2                   54.02                 1909.32
20210106 22:47:44                      1.61                   43.08                 1479.45
20210106 22:48:44                      1.29                   47.81                 1296.04
20210106 22:49:44                      1.39                    50.6                 1337.25
20210106 22:50:44                       1.3                   55.93                 1497.06
20210106 22:51:45                      1.85                   43.28                 1074.38
20210106 22:52:45                      1.06                   93.48                 1559.25
20210106 22:53:44                      1.17                   39.43                 2132.45
20210106 22:54:44                       .54                   50.37                 2259.39
20210106 22:55:44                      1.35                   47.12                 1347.34
20210106 22:56:44                      2.09                   57.55                 2647.21
20210106 22:57:45                      1.33                   46.67                  980.51
20210106 22:58:45                       .68                   74.52                 1480.33
20210106 22:59:45                      1.19                    51.5                 1871.55

可以从上述三个指标中观察,Single Block Read Latency高的时候,IO请求量并不匹配,并非因为IO请求量导致IO效率下降,延时变高。
延时指标高,IO量并不大
继续阅读

诡异的ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O

今年以来,公司多套RAC数据库(版本:11.2.0.4)ASM实例频繁报出ORA-27090: Unable to reserve kernel resources for asynchronous disk I/O错误。这些数据库早在2016年时印象中便出现了此类报错,并且报错并非单个数据库偶发现象,而是大面积爆发,从3月至今仍然有些许数据库会抛出零星错误出现。

什么是ORA-27090?<参考 Doc ID 579108.1 >文中提到,此类报错的原因是操作系统异步IO请求参数 aio-max-nr 过低并且需要调整并发未完成的异步请求数目,避免异步IO请求失败的情况, Oracle官方文档中的建议值如下:

The "aio-max-nr" kernel limit is too low.
io_setup(4096, 0x66e1588) = -1 EAGAIN (Resource temporarily unavailable),

但是很诡异的是,我们的数据库早在2016年左右(第一次触发此问题)时,已经将该参数调整至4194304,理论上是不应该触发异步IO不足的问题。并且此报错风险性较高,ASM实例异步IO失败会导致数据库面临crash问风险,例如DBWR将脏块落盘(数据文件)时,如果此时DBWR进程无法进行时,数据库崩溃等其他异常行为会有极大可能性的。虽然可以将systcl.conf中的aio-max-nr一直调大,但是总归不是长久之计,并且在某年某月时会再次“爆发”。

最可怕的是,通过分析alert中的trace文件时,并没有发现任何有价值信息,所有的线索就是异步IO请求超过最大限制,导致某些IO请求失败抛出错误。。。

通过查看cat /proc/sys/fs/aio-nr查看当前的异步IO请求数量,此值偶尔下降但总量一直处于增长态势, 此时严重怀疑是否数据库中有某些进程执行异步IO请求后并没有释放IO描述符?造成异步IO描述符泄露?

我们数据库集群后发现异步IO请求变回归到正常范围内,但是态势仍然处于上升趋势:

ora11g@travelskydba-rac$ cat /proc/sys/fs/aio-nr 
22784
继续阅读

ORA-00704: bootstrap process failure故障修复

近日,同事反馈一套测试测试数据库宕机,进行重启数据库操作时发现数据库无法open,抛出ORA-00704: bootstrap process failure错误,版本为11.2.0.4

SQL> startup;
ORACLE instance started.

Total System Global Area 1068937216 bytes
Fixed Size		    2260088 bytes
Variable Size		  671089544 bytes
Database Buffers	  390070272 bytes
Redo Buffers		    5517312 bytes
Database mounted.
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00704: bootstrap process failure
ORA-00604: error occurred at recursive SQL level 1
ORA-00942: table or view does not exist
Process ID: 57338
Session ID: 96 Serial number: 3

错误一并抛出了ORA-00942: table or view does not exist错误,应该是系统表丢失导致的bootstrap失败,并且alert日志中没有任何其他日志输出。

将数据库启动到nomount与mount状态,利用10046 event跟踪bootstrap过程:
SQL> oradebug setmypid
Statement processed.
SQL> oradebug tracefile_name
/opt/app/ora11g/albert/diag/rdbms/prod3/PROD3/trace/PROD3_ora_57585.trc
SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.
SQL> alter database mount;

Database altered.

SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-00704: bootstrap process failure
ORA-00604: error occurred at recursive SQL level 1
ORA-00942: table or view does not exist
Process ID: 57585
Session ID: 96 Serial number: 3

访问/opt/app/ora11g/albert/diag/rdbms/prod3/PROD3/trace/PROD3_ora_57585.trc发现访问access$表时抛出异常:

继续阅读

核心系统表关联顺序错误导致的低效SQL

同事发来一个核心业务库的TOP SQL,占据并浪费了大量的服务器CPU资源,此SQL执效率信息如下:

SELECT a.ID,
       a.SEG_FLIGHT_ID,
       a.SEG_DEP_STATION_CODE,
       a.SEG_ARR_STATION_CODE,
       a.SEG_CLASS_SEQUENCE,
       a.SEG_TRAFFIC_RESTRICTION_CODE,
       a.SEG_DEP_TERMINAL,
       a.SEG_ARR_TERMINAL,
       a.SEG_OC_TYPE,
       a.SEG_OC_MAP_NUMBER,
       a.SEG_OC_CLASS_MAPPING,
       a.SEG_DATA_SOURCE
FROM T_SEGMENT a,
  (SELECT id
   FROM
     (SELECT t.id
      FROM T_FLIGHT t,
           T_TASK ta
      WHERE 1=1
        AND ta.id IN ('11008',
                      '11003',
                      '11014',
                      '11012',
                      '14001',
                      '11001')
        AND t.FLT_AIRLINE_CODE = ta.FLT_AIRLINE_CODE
        AND t.FLT_FLIGHT_NO = ta.FLT_FLIGHT_NO
        AND t.FLT_FLIGHT_DATE = ta.FLT_FLIGHT_DATE
        AND t.FLT_OC_FLIGHT_ID IS NULL
        AND t.IS_VALID = 1
        AND nullif('AAAA',t.FLT_OFFICE) IS NOT NULL )
   LEFT JOIN t_dep_schema s ON id = s.flt_id
   WHERE s.flt_id IS NULL
     OR (s.flt_id IS NOT NULL
         AND (s.FLT_IN_TCARD_PROCESS_FLAG ='N'
              OR s.FLT_IN_TCARD_PROCESS_FLAG IS NULL))
     OR (s.flt_id IS NOT NULL
         AND (s.FLT_IN_INIT_PROCESS_FLAG IS NULL
              OR s.FLT_IN_INIT_PROCESS_FLAG ='N')) ) f
WHERE 1=1
  AND a.SEG_FLIGHT_ID = f.ID
  AND a.IS_VALID = 1

SQL执行计划如下:

从执行计划中看到,估算行数与实际行数差别巨大,实际行数只是899行,但是NESTED LOOP之后估算结果集为46K,并且TASK表与S表选择了HASH JOIN,在未收集个性化扩展统计信息的情况,针对这种复杂情况,估算不准的情况是比较常见的,通常需要利用HINT来调整表连接顺序来优化。此SQL的涉及表都不存在索引缺失的情况,只是行数估算错误导致表连接顺序有误,从而选择了低效的执行计划。

继续阅读

执行效率高但“低效”的SQL优化

近期整理案例时发现,同事曾咨询过一个问题,数据库服务器CPU频繁报警,同事最终定位到一个TOP SQL,但是执行效率已经”算不错“,是否还有优化的余地?

SQL_TEXT如下:

SELECT DISTINCT S.*,
                BD.*,
                SD.*,
                UD.*
FROM T S
LEFT JOIN T1 BD ON S.DATA_OBJECT_ID = BD.DATA_OBJECT_ID
AND S.OBJECT_ID = BD.OBJECT_ID
LEFT JOIN T2 SD ON S.DATA_OBJECT_ID = SD.DATA_OBJECT_ID
AND S.OBJECT_ID = SD.OBJECT_ID
LEFT JOIN T3 UD ON S.DATA_OBJECT_ID = UD.DATA_OBJECT_ID
AND S.OBJECT_ID = UD.OBJECT_ID
WHERE S.OBJECT_ID = 88
  AND 1 = 1

原执行计划如下:
Plan hash value: 1035031963

----------------------------------------------------------------------------------------------------------------
| Id  | Operation             | Name | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT      |      |      1 |        | 84081 (100)|          |      1 |00:00:00.60 |     309K|
|   1 |  HASH UNIQUE          |      |      1 |      1 | 84081   (1)| 00:16:49 |      1 |00:00:00.60 |     309K|
|*  2 |   HASH JOIN OUTER     |      |      1 |      1 | 84080   (1)| 00:16:49 |      1 |00:00:00.60 |     309K|
|*  3 |    HASH JOIN OUTER    |      |      1 |      1 | 79935   (1)| 00:16:00 |      1 |00:00:00.55 |     294K|
|*  4 |     HASH JOIN OUTER   |      |      1 |      1 | 75791   (1)| 00:15:10 |      1 |00:00:00.50 |     278K|
|*  5 |      TABLE ACCESS FULL| T    |      1 |      1 | 71647   (1)| 00:14:20 |      1 |00:00:00.44 |     263K|
|*  6 |      TABLE ACCESS FULL| T3   |      1 |    168 |  4144   (1)| 00:00:50 |      1 |00:00:00.05 |   15260 |
|*  7 |     TABLE ACCESS FULL | T2   |      1 |    168 |  4144   (1)| 00:00:50 |      1 |00:00:00.05 |   15260 |
|*  8 |    TABLE ACCESS FULL  | T1   |      1 |    168 |  4145   (1)| 00:00:50 |      1 |00:00:00.05 |   15260 |
----------------------------------------------------------------------------------------------------------------

 

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

   2 - access("S"."OBJECT_ID"="BD"."OBJECT_ID" AND "S"."DATA_OBJECT_ID"="BD"."DATA_OBJECT_ID")
   3 - access("S"."OBJECT_ID"="SD"."OBJECT_ID" AND "S"."DATA_OBJECT_ID"="SD"."DATA_OBJECT_ID")
   4 - access("S"."OBJECT_ID"="UD"."OBJECT_ID" AND "S"."DATA_OBJECT_ID"="UD"."DATA_OBJECT_ID")
   5 - filter("S"."OBJECT_ID"=88)
   6 - filter("UD"."OBJECT_ID"=88)
   7 - filter("SD"."OBJECT_ID"=88)
   8 - filter("BD"."OBJECT_ID"=88)

SQL涉及四张表T,T1,T2,T3,数据量均在100万+。OBJECT_ID选择率非常好(相当于主键),因为缺乏多个索引,执行计划选择全表扫描+HASH_JOIN的方式针对此SQL是严重低效的,即使执行效率还能接受,平均单次执行时间需要0.237秒,但是309K的BUFFER GET。SQL执行效率高不等于一定是高效率的。

优化建议:T表谓词创建索引,返回行数少(驱动表),剩余表连接列上创建索引(被驱动表),使得SQL走Nested Loop关联方式,小结果集驱动大结果集,最终只需要4000多个BUFFER即可。

模拟案例SQL:

create index t_idx01 on t(object_id);
create index t1_idx01 on t1(data_object_id);
create index t2_idx01 on t2(data_object_id);
create index t3_idx01 on t3(data_object_id);

Plan hash value: 3722872203

------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation			| Name	   | Starts | E-Rows | Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT		|	   |	  1 |	     |	 782 (100)|	     |	    1 |00:00:00.01 |	4018 |
|   1 |  HASH UNIQUE			|	   |	  1 |	   1 |	 782   (1)| 00:00:10 |	    1 |00:00:00.01 |	4018 |
|   2 |   NESTED LOOPS OUTER		|	   |	  1 |	   1 |	 781   (0)| 00:00:10 |	    1 |00:00:00.01 |	4018 |
|   3 |    NESTED LOOPS OUTER		|	   |	  1 |	   1 |	 522   (0)| 00:00:07 |	    1 |00:00:00.01 |	2680 |
|   4 |     NESTED LOOPS OUTER		|	   |	  1 |	   1 |	 263   (0)| 00:00:04 |	    1 |00:00:00.01 |	1342 |
|   5 |      TABLE ACCESS BY INDEX ROWID| T	   |	  1 |	   1 |	   4   (0)| 00:00:01 |	    1 |00:00:00.01 |	   4 |
|*  6 |       INDEX RANGE SCAN		| T_IDX01  |	  1 |	   1 |	   3   (0)| 00:00:01 |	    1 |00:00:00.01 |	   3 |
|*  7 |      TABLE ACCESS BY INDEX ROWID| T1	   |	  1 |	   1 |	 259   (0)| 00:00:04 |	    1 |00:00:00.01 |	1338 |
|*  8 |       INDEX RANGE SCAN		| T1_IDX01 |	  1 |	 258 |	   2   (0)| 00:00:01 |	 4608 |00:00:00.01 |	  12 |
|*  9 |     TABLE ACCESS BY INDEX ROWID | T2	   |	  1 |	   1 |	 259   (0)| 00:00:04 |	    1 |00:00:00.01 |	1338 |
|* 10 |      INDEX RANGE SCAN		| T2_IDX01 |	  1 |	 258 |	   2   (0)| 00:00:01 |	 4608 |00:00:00.01 |	  12 |
|* 11 |    TABLE ACCESS BY INDEX ROWID	| T3	   |	  1 |	   1 |	 259   (0)| 00:00:04 |	    1 |00:00:00.01 |	1338 |
|* 12 |     INDEX RANGE SCAN		| T3_IDX01 |	  1 |	 258 |	   2   (0)| 00:00:01 |	 4608 |00:00:00.01 |	  12 |
------------------------------------------------------------------------------------------------------------------------------

很多时候,执行效率浪费资源严重的TOP SQL往往被日益逐渐增强的系统资源所掩盖,记得一位前辈说过的话,TOP SQL不要看单纯的执行效率,要看所谓的”TOP”来综合判断是否有优化的余地,例如参考平均buffer get与平均返回行数等其他SQL性能指标,是否是合适,还是“血亏”。

ROW CACHE LOCK导致数据库CPU高案例分析

近期整理案例,发现前不久同事反馈一个数据库服务器CPU居高不下,无法找到根因过来询问,详情如下:

EVENT                                      COUNT(*)
---------------------------------------- ----------
row cache lock                                 1007
                                                213
buffer busy waits                               165
log file switch (checkpoint incomplete)         137
free buffer waits                               114
db file async I/O submit                         75
log file sync                                    73
db file sequential read                          62
read by other session                            36
log file parallel write                          15
resmgr:cpu quantum                               15
enq: TX - row lock contention                    13
enq: HW - contention                              9
direct path read                                  8
enq: SQ - contention                              4
latch: undo global data                           3
write complete waits                              2
log file sequential read                          1
null event                                        1
db file scattered read                            1
Log archive I/O                                   1
LNS wait on SENDREQ                               1
enq: US - contention                              1

从ASH中看到,CPU高的时间段内,等待事件最多的为ROW CACHE LOCK,

TIME                              USER_ID SQL_ID        EVENT                                            P1
------------------------------ ---------- ------------- ---------------------------------------- ----------
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 c25ar03n0p5sz row cache lock                                   13
20200929 01:11:25                      91 c25ar03n0p5sz row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 c25ar03n0p5sz row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 c25ar03n0p5sz row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 11xs00r4qzb7n row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13
20200929 01:11:25                      91 7265mcg5kwyc3 row cache lock                                   13

确认该时间段内的具体SQL,发现均存在SEQUENCE调用

SQL_ID          COUNT(*)
------------- ----------
7265mcg5kwyc3        357
11xs00r4qzb7n        341
c25ar03n0p5sz        277
f9ym730zzf1s2         12
9dnygr7asqmy9         12
dksd9txy8vuk6          6
9qzwmgp034kx2          2

SQL> SELECT DISTINCT sql_id,
                sql_text
FROM v$sql
WHERE sql_id IN ('dksd9txy8vuk6',
                 '11xs00r4qzb7n',
                 '9qzwmgp034kx2',
                 '9dnygr7asqmy9',
                 '7265mcg5kwyc3',
                 'c25ar03n0p5sz',
                 'f9ym730zzf1s2');

SQL_ID        SQL_TEXT
------------- ------------------------------------------------------------------------------------------------------------------------
9qzwmgp034kx2 INSERT INTO opfqresultdata VALUES(OPFQRESULTDATA_SEQUENCE_ID.Nextval,:1 ,:2 ,:3 ,:4 ,:5 ,:6 ,:7 ,:8 )
f9ym730zzf1s2 select SUBSFLT_HISTORY_SEQUENCE_ID.nextval from dual
7265mcg5kwyc3 INSERT INTO pnrresultdata VALUES(PNRRESULTDATA_SEQUENCE_ID.NEXTVAL,:1 ,:2 ,:3 ,:4 ,:5 ,:6 ,:7 ,:8 ,:9 )
c25ar03n0p5sz INSERT INTO etresultdata VALUES(ETRESULTDATA_SEQUENCE_ID.Nextval,:1 ,:2 ,:3 ,:4 ,:5 ,:6 ,:7 ,:8 ,:9 ,:10 ,:11 )
9dnygr7asqmy9 select SUBSFLTREQUEST_SEQUENCE_ID.nextval from dual
11xs00r4qzb7n INSERT INTO unknowdata VALUES(UNKNOWDATA_SEQUENCE_ID.Nextval,:1 ,:2 ,:3 )
dksd9txy8vuk6 INSERT INTO fltresultdata VALUES(FLTRESULTDATA_SEQUENCE_ID.Nextval,:1 ,:2 ,:3 ,:4 ,:5 ,:6 ,:7 ,:8 ,:9 ,:10 ,:11 ,:12 ,:1

SQL> select DISTINCT P1
FROM
  (SELECT to_char(SAMPLE_TIME,'YYYYMMDD hh24:mi:ss') time,
          USER_ID,
          SQL_ID,
          EVENT,
          P1
   FROM dba_hist_active_sess_history
   WHERE SAMPLE_TIME>to_date('20200929 01:00:00','YYYYMMDD hh24:mi:ss')
     AND SAMPLE_TIME<to_date('20200929 01:15:00','YYYYMMDD hh24:mi:ss')
     AND EVENT = 'row cache lock');


        P1
----------
        13  --正是dc_sequences

SQL> select parameter,gets,getmisses,MODIFICATIONS from v$rowcache where cache#=13;

PARAMETER                              GETS  GETMISSES MODIFICATIONS
-------------------------------- ---------- ---------- -------------
dc_sequences                      766929021       5065     766929020

发现此sequence中的cache size均为0,出现row cache lock与cpu高便不足为奇

将频繁调用的sequence cache size调整至500后,等待与cpu高的现象随之解决,不再复现。