月度归档：2013年09月

SQL优化对CPU Cost的意义

2条回复

最近，客户的一套数据库系统服务器CPU及内存消耗持续高涨，后采集AWR及ASH报告分析，发现由于存在性能问题的SQL，导致Top User Event中出现大量的CPU等待，优化存在性能问题的SQL后，CPU使用率大幅降低。下面几条SQL语句是优化前后其执行计划及统计信息的对比情况：

--- SQL 1:
select distinct r.kpiname, r.deptid, r.recordtime, r.kpivalue value
  from sde.rs_record r
 where upper(r.kpiname) = upper('BusinessSystemRunningTime')
   and r.recordtime =
       (select max(recordtime)
          from sde.rs_record
         where deptid = '437247bafb6746ea8f29925ac03258a102120100000'
           and upper(kpiname) = upper('BusinessSystemRunningTime'))
   and r.deptid = '437247bafb6746ea8f29925ac03258a102120100000'
 order by r.recordtime asc

— 原执行计划及统计信息

SQL> set lines 200
SQL> select distinct r.kpiname, r.deptid, r.recordtime, r.kpivalue value
  2    from sde.rs_record r
  3   where upper(r.kpiname) = upper('BusinessSystemRunningTime')
  4     and r.recordtime =
  5         (select max(recordtime)
  6            from sde.rs_record
  7           where deptid = '437247bafb6746ea8f29925ac03258a102120100000'
  8             and upper(kpiname) = upper('BusinessSystemRunningTime'))
  9     and r.deptid = '437247bafb6746ea8f29925ac03258a102120100000'
 10   order by r.recordtime asc
 11  ;
 
Elapsed: 00:00:00.45
 
Execution Plan
----------------------------------------------------------
Plan hash value: 2705261340
 
--------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name          | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |               |     1 |    75 | 19237   (1)| 00:03:51 |
|   1 |  SORT ORDER BY                   |               |     1 |    75 |            |          |
|   2 |   HASH UNIQUE                    |               |     1 |    75 | 19237   (1)| 00:03:51 |
|*  3 |    TABLE ACCESS BY INDEX ROWID   | RS_RECORD     |     1 |    75 |    19   (0)| 00:00:01 |
|*  4 |     INDEX RANGE SCAN             | RS_RECORDTIME |   154 |       |     3   (0)| 00:00:01 |
|   5 |      SORT AGGREGATE              |               |     1 |    73 |            |          |
|*  6 |       TABLE ACCESS BY INDEX ROWID| RS_RECORD     |  1517 |   108K| 19217   (1)| 00:03:51 |
|*  7 |        INDEX RANGE SCAN          | RS_DEPTID     |   151K|       |  1173   (1)| 00:00:15 |
--------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   3 - filter("R"."DEPTID"='437247bafb6746ea8f29925ac03258a102120100000' AND
              UPPER("R"."KPINAME")='BUSINESSSYSTEMRUNNINGTIME')
   4 - access("R"."RECORDTIME"= (SELECT MAX("RECORDTIME") FROM "SDE"."RS_RECORD"
              "RS_RECORD" WHERE "DEPTID"='437247bafb6746ea8f29925ac03258a102120100000' AND
              UPPER("KPINAME")='BUSINESSSYSTEMRUNNINGTIME'))
   6 - filter(UPPER("KPINAME")='BUSINESSSYSTEMRUNNINGTIME')
   7 - access("DEPTID"='437247bafb6746ea8f29925ac03258a102120100000')
 
 
Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
      20385  consistent gets
          0  physical reads
          0  redo size
        789  bytes sent via SQL*Net to client
        492  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
          1  rows processed

— 优化后执行计划及统计信息

SQL> select distinct r.kpiname, r.deptid, r.recordtime, r.kpivalue value
  2    from sde.rs_record r
  3   where upper(r.kpiname) = upper('BusinessSystemRunningTime')
  4     and r.recordtime =
  5         (select max(recordtime)
  6            from sde.rs_record
  7           where deptid = '437247bafb6746ea8f29925ac03258a102120100000'
  8             and upper(kpiname) = upper('BusinessSystemRunningTime'))
  9     and r.deptid = '437247bafb6746ea8f29925ac03258a102120100000'
 10   order by r.recordtime asc;
 
Elapsed: 00:00:00.43
 
Execution Plan
----------------------------------------------------------
Plan hash value: 4202252648
 
------------------------------------------------------------------------------------------------------
| Id  | Operation                        | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                 |                   |     1 |    75 |  2174   (1)| 00:00:27 |
|   1 |  SORT ORDER BY                   |                   |     1 |    75 |            |          |
|   2 |   HASH UNIQUE                    |                   |     1 |    75 |  2174   (1)| 00:00:27 |
|*  3 |    TABLE ACCESS BY INDEX ROWID   | RS_RECORD         |     1 |    75 |    19   (0)| 00:00:01 |
|*  4 |     INDEX RANGE SCAN             | RS_RECORDTIME     |   154 |       |     3   (0)| 00:00:01 |
|   5 |      SORT AGGREGATE              |                   |     1 |    73 |            |          |
|   6 |       TABLE ACCESS BY INDEX ROWID| RS_RECORD         |  1517 |   108K|  2154   (1)| 00:00:26 |
|*  7 |        INDEX RANGE SCAN          | RS_RECORD_DEPTKPI |  3392 |       |    41   (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   3 - filter("R"."DEPTID"='437247bafb6746ea8f29925ac03258a102120100000' AND
              UPPER("R"."KPINAME")='BUSINESSSYSTEMRUNNINGTIME')
   4 - access("R"."RECORDTIME"= (SELECT MAX("RECORDTIME") FROM "SDE"."RS_RECORD" "RS_RECORD"
              WHERE UPPER("KPINAME")='BUSINESSSYSTEMRUNNINGTIME' AND
              "DEPTID"='437247bafb6746ea8f29925ac03258a102120100000'))
   7 - access("DEPTID"='437247bafb6746ea8f29925ac03258a102120100000' AND
              UPPER("KPINAME")='BUSINESSSYSTEMRUNNINGTIME')
 
 
Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
      13972  consistent gets
          0  physical reads
          0  redo size
        789  bytes sent via SQL*Net to client
        492  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
          1  rows processed


--- SQL 2:
select distinct u.username, u.userid, p.depid
  from sde.sys_user u, sde.conf_runlog run, sde.sys_person p
 where u.userid = run.operatorid
   and u.personid = p.personid
   and run.operatetype = 'CS????'
   and to_char(run.operatetime, 'yyyy-mm-dd') = '2013-09-04'

— 原执行计划统计信息

SQL> select distinct u.username, u.userid, p.depid
  2    from sde.sys_user u, sde.conf_runlog run, sde.sys_person p
  3   where u.userid = run.operatorid
  4     and u.personid = p.personid
  5     and run.operatetype = 'CS????'
  6     and to_char(run.operatetime, 'yyyy-mm-dd') = '2013-09-04';
 
no rows selected
 
Elapsed: 00:00:00.53
 
Execution Plan
----------------------------------------------------------
Plan hash value: 1967854316
 
----------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                   |     1 |   236 | 11242   (1)| 00:02:15 |
|   1 |  HASH UNIQUE                   |                   |     1 |   236 | 11242   (1)| 00:02:15 |
|   2 |   NESTED LOOPS                 |                   |     1 |   236 | 11241   (1)| 00:02:15 |
|   3 |    NESTED LOOPS                |                   |     1 |   148 | 11240   (1)| 00:02:15 |
|*  4 |     TABLE ACCESS FULL          | CONF_RUNLOG       |     1 |    51 | 11239   (1)| 00:02:15 |
|   5 |     TABLE ACCESS BY INDEX ROWID| SYS_USER          |     1 |    97 |     1   (0)| 00:00:01 |
|*  6 |      INDEX UNIQUE SCAN         | SYS_INDEX_SYS_003 |     1 |       |     0   (0)| 00:00:01 |
|   7 |    TABLE ACCESS BY INDEX ROWID | SYS_PERSON        |     1 |    88 |     1   (0)| 00:00:01 |
|*  8 |     INDEX UNIQUE SCAN          | SYS_INDEX_SYS_002 |     1 |       |     0   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - filter("RUN"."OPERATETYPE"='CS????' AND
              TO_CHAR(INTERNAL_FUNCTION("RUN"."OPERATETIME"),'yyyy-mm-dd')='2013-09-04')
   6 - access("U"."USERID"="RUN"."OPERATORID")
   8 - access("U"."PERSONID"="P"."PERSONID")
 
 
Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
      51048  consistent gets
          0  physical reads
          0  redo size
        452  bytes sent via SQL*Net to client
        481  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed

— 优化后执行计划统计信息

SQL> select distinct u.username, u.userid, p.depid
  2    from sde.sys_user u, sde.conf_runlog run, sde.sys_person p
  3   where u.userid = run.operatorid
  4     and u.personid = p.personid
  5     and run.operatetype = 'CS????'
  6     and to_char(run.operatetime, 'yyyy-mm-dd') = '2013-09-04';
 
no rows selected
 
Elapsed: 00:00:00.02
 
Execution Plan
----------------------------------------------------------
Plan hash value: 2603909728
 
-------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name                 | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                      |     1 |   236 |     7  (15)| 00:00:01 |
|   1 |  HASH UNIQUE                   |                      |     1 |   236 |     7  (15)| 00:00:01 |
|   2 |   NESTED LOOPS                 |                      |     1 |   236 |     6   (0)| 00:00:01 |
|   3 |    NESTED LOOPS                |                      |     1 |   148 |     5   (0)| 00:00:01 |
|   4 |     TABLE ACCESS BY INDEX ROWID| CONF_RUNLOG          |     1 |    51 |     4   (0)| 00:00:01 |
|*  5 |      INDEX RANGE SCAN          | CONF_RUNLOG_TYPETIME |     1 |       |     3   (0)| 00:00:01 |
|   6 |     TABLE ACCESS BY INDEX ROWID| SYS_USER             |     1 |    97 |     1   (0)| 00:00:01 |
|*  7 |      INDEX UNIQUE SCAN         | SYS_INDEX_SYS_003    |     1 |       |     0   (0)| 00:00:01 |
|   8 |    TABLE ACCESS BY INDEX ROWID | SYS_PERSON           |     1 |    88 |     1   (0)| 00:00:01 |
|*  9 |     INDEX UNIQUE SCAN          | SYS_INDEX_SYS_002    |     1 |       |     0   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   5 - access("RUN"."OPERATETYPE"='CS????' AND TO_CHAR(INTERNAL_FUNCTION("OPERATETIME"),'yyyy-m
              m-dd')='2013-09-04')
   7 - access("U"."USERID"="RUN"."OPERATORID")
   9 - access("U"."PERSONID"="P"."PERSONID")
 
 
Statistics
----------------------------------------------------------
         31  recursive calls
          0  db block gets
          7  consistent gets
          2  physical reads
          0  redo size
        452  bytes sent via SQL*Net to client
        481  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed


--- SQL 3:
select (a.conn - b.close) num
  from (select count(*) conn
          from sde.conf_runlog d
         where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
           and d.operatetype = 'CS????') a,
       (select count(*) close
          from sde.conf_runlog d
         where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
           and d.operatetype = 'CS????') b

— 原执行计划及统计信息

SQL> select (a.conn - b.close) num
  2    from (select count(*) conn
  3            from sde.conf_runlog d
  4           where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
  5             and d.operatetype = 'CS????') a,
  6         (select count(*) close
  7            from sde.conf_runlog d
  8           where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
  9             and d.operatetype = 'CS????') b;
 
Elapsed: 00:00:00.92
 
Execution Plan
----------------------------------------------------------
Plan hash value: 4028634323
 
------------------------------------------------------------------------------------
| Id  | Operation            | Name        | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |             |     1 |    26 | 22477   (1)| 00:04:30 |
|   1 |  NESTED LOOPS        |             |     1 |    26 | 22477   (1)| 00:04:30 |
|   2 |   VIEW               |             |     1 |    13 | 11239   (1)| 00:02:15 |
|   3 |    SORT AGGREGATE    |             |     1 |    17 |            |          |
|*  4 |     TABLE ACCESS FULL| CONF_RUNLOG |     1 |    17 | 11239   (1)| 00:02:15 |
|   5 |   VIEW               |             |     1 |    13 | 11239   (1)| 00:02:15 |
|   6 |    SORT AGGREGATE    |             |     1 |    17 |            |          |
|*  7 |     TABLE ACCESS FULL| CONF_RUNLOG |     1 |    17 | 11239   (1)| 00:02:15 |
------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - filter("D"."OPERATETYPE"='CS????' AND
              TO_CHAR(INTERNAL_FUNCTION("D"."OPERATETIME"),'yyyy-MM-dd')='2013-09-04')
   7 - filter("D"."OPERATETYPE"='CS????' AND
              TO_CHAR(INTERNAL_FUNCTION("D"."OPERATETIME"),'yyyy-MM-dd')='2013-09-04')
 
 
Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
     102096  consistent gets
          0  physical reads
          0  redo size
        509  bytes sent via SQL*Net to client
        492  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

— 优化后执行计划及统计信息

SQL> select (a.conn - b.close) num
  2    from (select count(*) conn
  3            from sde.conf_runlog d
  4           where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
  5             and d.operatetype = 'CS????') a,
  6         (select count(*) close
  7            from sde.conf_runlog d
  8           where to_CHAR(d.operatetime, 'yyyy-MM-dd') = '2013-09-04'
  9             and d.operatetype = 'CS????') b   ;
 
Elapsed: 00:00:00.01
 
Execution Plan
----------------------------------------------------------
Plan hash value: 2459318296
 
-------------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name                 | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                      |     1 |    26 |     8   (0)| 00:00:01 |
|   1 |  NESTED LOOPS                  |                      |     1 |    26 |     8   (0)| 00:00:01 |
|   2 |   VIEW                         |                      |     1 |    13 |     4   (0)| 00:00:01 |
|   3 |    SORT AGGREGATE              |                      |     1 |    17 |            |          |
|*  4 |     TABLE ACCESS BY INDEX ROWID| CONF_RUNLOG          |     1 |    17 |     4   (0)| 00:00:01 |
|*  5 |      INDEX RANGE SCAN          | CONF_RUNLOG_TYPETIME |     1 |       |     3   (0)| 00:00:01 |
|   6 |   VIEW                         |                      |     1 |    13 |     4   (0)| 00:00:01 |
|   7 |    SORT AGGREGATE              |                      |     1 |    17 |            |          |
|*  8 |     TABLE ACCESS BY INDEX ROWID| CONF_RUNLOG          |     1 |    17 |     4   (0)| 00:00:01 |
|*  9 |      INDEX RANGE SCAN          | CONF_RUNLOG_TYPETIME |     1 |       |     3   (0)| 00:00:01 |
-------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
   4 - filter(TO_CHAR(INTERNAL_FUNCTION("D"."OPERATETIME"),'yyyy-MM-dd')='2013-09-04')
   5 - access("D"."OPERATETYPE"='CS????')
   8 - filter(TO_CHAR(INTERNAL_FUNCTION("D"."OPERATETIME"),'yyyy-MM-dd')='2013-09-04')
   9 - access("D"."OPERATETYPE"='CS????')
 
 
Statistics
----------------------------------------------------------
         15  recursive calls
          0  db block gets
         10  consistent gets
          0  physical reads
          0  redo size
        509  bytes sent via SQL*Net to client
        492  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed


--- SQL 4:
select s.userid, d.depid
  from sde.sys_user s,
       (select run.operatorid
          from sde.conf_runlog run, sde.conf_rundetaillog de
         where run.loggerid = de.loggerid
           and ((de.operatename = '????' and de.description = '????'))) aa,
       sde.sys_department d,
       sde.sys_person p
 where s.userid = aa.operatorid
   and s.personid = p.personid
   and p.depid = d.depid
union all
select u.userid, d.depid
  from sde.sys_user u, sde.conf_runlog r, sde.sys_department d, sde.sys_person p
 where u.userid = r.operatorid
   and u.personid = p.personid
   and p.depid = d.depid
   and r.operatetype = 'CS????'

— 原执行计划及统计信息

SQL> select s.userid, d.depid
  2    from sde.sys_user s,
  3         (select run.operatorid
  4            from sde.conf_runlog run, sde.conf_rundetaillog de
  5           where run.loggerid = de.loggerid
  6             and ((de.operatename = '????' and de.description = '????'))) aa,
  7         sde.sys_department d,
  8         sde.sys_person p
  9   where s.userid = aa.operatorid
 10     and s.personid = p.personid
 11     and p.depid = d.depid
 12  union all
 13  select u.userid, d.depid
 14    from sde.sys_user u, sde.conf_runlog r, sde.sys_department d, sde.sys_person p
 15   where u.userid = r.operatorid
 16     and u.personid = p.personid
 17     and p.depid = d.depid
 18     and r.operatetype = 'CS????';
 
no rows selected
 
Elapsed: 00:00:00.46
 
Execution Plan
----------------------------------------------------------
Plan hash value: 3274435553
 
-----------------------------------------------------------------------------------------------------------
| Id  | Operation                             | Name              | Rows  | Bytes | Cost (%CPU)| Time     |
-----------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                      |                   |     2 |   684 | 11266 (100)| 00:02:16 |
|   1 |  UNION-ALL                            |                   |       |       |            |          |
|   2 |   NESTED LOOPS                        |                   |     1 |   421 |    32   (0)| 00:00:01 |
|   3 |    NESTED LOOPS                       |                   |     1 |   377 |    32   (0)| 00:00:01 |
|   4 |     NESTED LOOPS                      |                   |     1 |   289 |    31   (0)| 00:00:01 |
|   5 |      NESTED LOOPS                     |                   |     1 |   201 |    30   (0)| 00:00:01 |
|   6 |       TABLE ACCESS BY INDEX ROWID     | CONF_RUNDETAILLOG |     1 |   134 |    27   (0)| 00:00:01 |
|   7 |        BITMAP CONVERSION TO ROWIDS    |                   |       |       |            |          |
|   8 |         BITMAP AND                    |                   |       |       |            |          |
|   9 |          BITMAP CONVERSION FROM ROWIDS|                   |       |       |            |          |
|* 10 |           INDEX RANGE SCAN            | IND_RDL_OPE       |  1452 |       |     8   (0)| 00:00:01 |
|  11 |          BITMAP CONVERSION FROM ROWIDS|                   |       |       |            |          |
|* 12 |           INDEX RANGE SCAN            | IND_RDL_DES       |  1452 |       |    19   (0)| 00:00:01 |
|  13 |       TABLE ACCESS BY INDEX ROWID     | CONF_RUNLOG       |     1 |    67 |     3   (0)| 00:00:01 |
|* 14 |        INDEX RANGE SCAN               | IND_RL_LID        |     1 |       |     2   (0)| 00:00:01 |
|  15 |      TABLE ACCESS BY INDEX ROWID      | SYS_USER          |     1 |    88 |     1   (0)| 00:00:01 |
|* 16 |       INDEX UNIQUE SCAN               | SYS_INDEX_SYS_003 |     1 |       |     0   (0)| 00:00:01 |
|  17 |     TABLE ACCESS BY INDEX ROWID       | SYS_PERSON        |     1 |    88 |     1   (0)| 00:00:01 |
|* 18 |      INDEX UNIQUE SCAN                | SYS_INDEX_SYS_002 |     1 |       |     0   (0)| 00:00:01 |
|* 19 |    INDEX UNIQUE SCAN                  | SYS_INDEX_SYS_001 |     1 |    44 |     0   (0)| 00:00:01 |
|  20 |   NESTED LOOPS                        |                   |     1 |   263 | 11234   (1)| 00:02:15 |
|  21 |    NESTED LOOPS                       |                   |     1 |   219 | 11234   (1)| 00:02:15 |
|  22 |     NESTED LOOPS                      |                   |     1 |   131 | 11233   (1)| 00:02:15 |
|* 23 |      TABLE ACCESS FULL                | CONF_RUNLOG       |     1 |    43 | 11232   (1)| 00:02:15 |
|  24 |      TABLE ACCESS BY INDEX ROWID      | SYS_USER          |     1 |    88 |     1   (0)| 00:00:01 |
|* 25 |       INDEX UNIQUE SCAN               | SYS_INDEX_SYS_003 |     1 |       |     0   (0)| 00:00:01 |
|  26 |     TABLE ACCESS BY INDEX ROWID       | SYS_PERSON        |     1 |    88 |     1   (0)| 00:00:01 |
|* 27 |      INDEX UNIQUE SCAN                | SYS_INDEX_SYS_002 |     1 |       |     0   (0)| 00:00:01 |
|* 28 |    INDEX UNIQUE SCAN                  | SYS_INDEX_SYS_001 |     1 |    44 |     0   (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
  10 - access("DE"."OPERATENAME"='????')
  12 - access("DE"."DESCRIPTION"='????')
  14 - access("RUN"."LOGGERID"="DE"."LOGGERID")
  16 - access("S"."USERID"="RUN"."OPERATORID")
  18 - access("S"."PERSONID"="P"."PERSONID")
  19 - access("P"."DEPID"="D"."DEPID")
  23 - filter("R"."OPERATETYPE"='CS????')
  25 - access("U"."USERID"="R"."OPERATORID")
  27 - access("U"."PERSONID"="P"."PERSONID")
  28 - access("P"."DEPID"="D"."DEPID")
 
 
Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
      51051  consistent gets
          0  physical reads
          0  redo size
        386  bytes sent via SQL*Net to client
        481  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed

— 优化后新执行计划及统计信息

SQL> select s.userid, d.depid
  2    from sde.sys_user s,
  3         (select run.operatorid
  4            from sde.conf_runlog run, sde.conf_rundetaillog de
  5           where run.loggerid = de.loggerid
  6             and ((de.operatename = '????' and de.description = '????'))) aa,
  7         sde.sys_department d,
  8         sde.sys_person p
  9   where s.userid = aa.operatorid
 10     and s.personid = p.personid
 11     and p.depid = d.depid
 12  union all
 13  select u.userid, d.depid
 14    from sde.sys_user u, sde.conf_runlog r, sde.sys_department d, sde.sys_person p
 15   where u.userid = r.operatorid
 16     and u.personid = p.personid
 17     and p.depid = d.depid
 18     and r.operatetype = 'CS????';
 
no rows selected
 
Elapsed: 00:00:00.02
 
Execution Plan
----------------------------------------------------------
Plan hash value: 43471384
 
--------------------------------------------------------------------------------------------------------------
| Id  | Operation                             | Name                 | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                      |                      |     2 |   686 |    40  (15)| 00:00:01 |
|   1 |  UNION-ALL                            |                      |       |       |            |          |
|   2 |   NESTED LOOPS                        |                      |     1 |   423 |    34   (0)| 00:00:01 |
|   3 |    NESTED LOOPS                       |                      |     1 |   379 |    34   (0)| 00:00:01 |
|   4 |     NESTED LOOPS                      |                      |     1 |   291 |    33   (0)| 00:00:01 |
|   5 |      NESTED LOOPS                     |                      |     1 |   203 |    32   (0)| 00:00:01 |
|   6 |       TABLE ACCESS BY INDEX ROWID     | CONF_RUNDETAILLOG    |     1 |   136 |    28   (0)| 00:00:01 |
|   7 |        BITMAP CONVERSION TO ROWIDS    |                      |       |       |            |          |
|   8 |         BITMAP AND                    |                      |       |       |            |          |
|   9 |          BITMAP CONVERSION FROM ROWIDS|                      |       |       |            |          |
|* 10 |           INDEX RANGE SCAN            | IND_RDL_OPE          |  2085 |       |    10   (0)| 00:00:01 |
|  11 |          BITMAP CONVERSION FROM ROWIDS|                      |       |       |            |          |
|* 12 |           INDEX RANGE SCAN            | IND_RDL_DES          |  2085 |       |    18   (0)| 00:00:01 |
|  13 |       TABLE ACCESS BY INDEX ROWID     | CONF_RUNLOG          |     1 |    67 |     4   (0)| 00:00:01 |
|* 14 |        INDEX RANGE SCAN               | IND_RL_LID           |     1 |       |     2   (0)| 00:00:01 |
|  15 |      TABLE ACCESS BY INDEX ROWID      | SYS_USER             |     1 |    88 |     1   (0)| 00:00:01 |
|* 16 |       INDEX UNIQUE SCAN               | SYS_INDEX_SYS_003    |     1 |       |     0   (0)| 00:00:01 |
|  17 |     TABLE ACCESS BY INDEX ROWID       | SYS_PERSON           |     1 |    88 |     1   (0)| 00:00:01 |
|* 18 |      INDEX UNIQUE SCAN                | SYS_INDEX_SYS_002    |     1 |       |     0   (0)| 00:00:01 |
|* 19 |    INDEX UNIQUE SCAN                  | SYS_INDEX_SYS_001    |     1 |    44 |     0   (0)| 00:00:01 |
|  20 |   NESTED LOOPS                        |                      |     1 |   263 |     6   (0)| 00:00:01 |
|  21 |    NESTED LOOPS                       |                      |     1 |   219 |     6   (0)| 00:00:01 |
|  22 |     NESTED LOOPS                      |                      |     1 |   131 |     5   (0)| 00:00:01 |
|  23 |      TABLE ACCESS BY INDEX ROWID      | CONF_RUNLOG          |     1 |    43 |     4   (0)| 00:00:01 |
|* 24 |       INDEX RANGE SCAN                | CONF_RUNLOG_TYPETIME |     1 |       |     3   (0)| 00:00:01 |
|  25 |      TABLE ACCESS BY INDEX ROWID      | SYS_USER             |     1 |    88 |     1   (0)| 00:00:01 |
|* 26 |       INDEX UNIQUE SCAN               | SYS_INDEX_SYS_003    |     1 |       |     0   (0)| 00:00:01 |
|  27 |     TABLE ACCESS BY INDEX ROWID       | SYS_PERSON           |     1 |    88 |     1   (0)| 00:00:01 |
|* 28 |      INDEX UNIQUE SCAN                | SYS_INDEX_SYS_002    |     1 |       |     0   (0)| 00:00:01 |
|* 29 |    INDEX UNIQUE SCAN                  | SYS_INDEX_SYS_001    |     1 |    44 |     0   (0)| 00:00:01 |
--------------------------------------------------------------------------------------------------------------
 
Predicate Information (identified by operation id):
---------------------------------------------------
 
  10 - access("DE"."OPERATENAME"='????')
  12 - access("DE"."DESCRIPTION"='????')
  14 - access("RUN"."LOGGERID"="DE"."LOGGERID")
  16 - access("S"."USERID"="RUN"."OPERATORID")
  18 - access("S"."PERSONID"="P"."PERSONID")
  19 - access("P"."DEPID"="D"."DEPID")
  24 - access("R"."OPERATETYPE"='CS????')
  26 - access("U"."USERID"="R"."OPERATORID")
  28 - access("U"."PERSONID"="P"."PERSONID")
  29 - access("P"."DEPID"="D"."DEPID")
 
 
Statistics
----------------------------------------------------------
         15  recursive calls
          0  db block gets
         10  consistent gets
          0  physical reads
          0  redo size
        386  bytes sent via SQL*Net to client
        481  bytes received via SQL*Net from client
          1  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          0  rows processed

Oracle中诊断阻塞的session

发表回复

由于锁的机制，当某一条DML或者DDL SQL语句执行被阻塞的时候，需要找出是什么原因导致这条SQL被阻塞了，下面介绍两种常用的诊断方法：
假设有这样一个表：table t(id int primary key,val int)，数据为：

id      val
1       1
2       2
[oracle@10g ~]$ sqlplus scott/tiger
SQL*Plus: Release 10.2.0.5.0 - Production on Wed Aug 28 16:48:03 2013
Copyright (c) 1982, 2010, Oracle.  All Rights Reserved.
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> create table t (id int primary key,val int); 
Table created.
SQL> insert into t values (1,1);
1 row created.
SQL> insert into t values (2,2);
1 row created.
SQL> commit;
Commit complete.
SQL> select * from t;
        ID        VAL
---------- ----------
         1          1
         2          2

1.在第一个Session，这里把它叫做Session A，做了如下的update语句，没有提交或者回滚：

SQL> update t set val = 3 where id=1;
1 row updated.

2.在另一个Session里，这里把它叫做Session B，做了如下的update语句，Session B会被阻塞：

SQL> update t set val = 4 where id=1;

方法一：
有活动事务对对象加锁的时候，在v$locked_object视图中会有记录，如object_id,session_id等，通常被阻塞session的XIDUSN,XIDSLOT,XIDSQN字段都为空，下面查询中session_id为138的是被阻塞的session：

SQL> conn / as sysdba
Connected.
SQL> select * from v$locked_object;
XIDUSN XIDSLOT XIDSQN OBJECT_ID SESSION_ID ORACLE_USERNAME OS_USER_NAME PROCESS LOCKED_MODE
------ ------- ------ --------- ---------- --------------- ------------ ------- -----------
     0       0      0     54364        138 SCOTT           oracle       25455             3
     7      24    322     54364        143 SCOTT           oracle       25338             3

通过v$locked_object和dba_objects关联查询出被阻塞session的对象：

SQL> select dbo.*
  2    from v$locked_object lo, dba_objects dbo
  3   where lo.object_id = dbo.object_id
  4     and lo.xidusn = 0;
OWNER OBJECT_NAM SUBOBJECT_NAME OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE CREATED   LAST_DDL_ TIMESTAMP           STATUS  T G S
----- ---------- -------------- --------- -------------- ----------- --------- --------- ------------------- ------- - - -
SCOTT T                             54364          54364 TABLE       28-AUG-13 28-AUG-13 2013-08-28:16:48:53 VALID   N N N

通过查询v$lock可以看到是哪一个session阻塞了哪一个session:143阻塞了138

SQL> select blkingsess.sid blockingsid, blkedsess.sid blockedsid
  2    from v$lock blkingsess,
  3         (select * from v$lock where request != 0) blkedsess
  4   where blkingsess.id1 = blkedsess.id1
  5     and blkingsess.id2 = blkedsess.id2
  6     and blkingsess.sid != blkedsess.sid;
BLOCKINGSID BLOCKEDSID
----------- ----------
        143        138

在通过v$session可以查到session相关的信息，被阻塞的status一般为ACTIVE，还可以通过sql_address关联v$sql找到被阻塞的SQL语句：

SQL> select sid, serial#, status, sql_address
  2    from v$session
  3   where sid in (143, 138);
SID SERIAL# STATUS   SQL_ADDRESS
--- ------- -------- ----------------
138    5914 ACTIVE   000000008358A478
143    7044 INACTIVE 000000007AA1DA68
SQL> select sql_id,sql_text from v$sql where address='000000008358A478';
SQL_ID        SQL_TEXT
------------- -------------------------------
cgxjac574kd3q update t set val = 4 where id=1

这时候DBA可以联系造成阻塞的session结束事务或者根据情况用命令终止session：

SQL> alter system kill session '143,7044';
System altered.

其中143为sid，7044为serial#，session 143会收到如下错误，session 138可以执行后续步骤.

ERROR:
ORA-03114: not connected to ORACLE

方法二：
查看等待事件会发现存在锁表：

SQL> select sid, event
  2    from v$session_wait
  3   where event not like 'SQL%'
  4     and event not like 'rdbms%';
       SID EVENT
---------- ----------------------------------------------------------------
       135 jobq slave wait
       138 enq: TX - row lock contention
       140 wait for unread message on broadcast channel
       149 Streams AQ: waiting for time management or cleanup tasks
       150 Streams AQ: qmn slave idle wait
       153 Streams AQ: qmn coordinator idle wait
       164 smon timer
       170 pmon timer
8 rows selected.

查看此锁的持有者与等待着：

SQL> column sess format a15
SQL> SELECT DECODE(request, 0, 'Holder: ', 'Waiter: ') || sid sess,
  2         id1,
  3         id2,
  4         lmode,
  5         request,
  6         type
  7    FROM V$LOCK
  8   WHERE (id1, id2, type) IN
  9         (SELECT id1, id2, type FROM V$LOCK WHERE request > 0)
 10   ORDER BY id1, request;
SESS           ID1 ID2 LMODE REQUEST TY
----------- ------ --- ----- ------- --
Holder: 143 458776 322     6       0 TX
Waiter: 138 458776 322     0       6 TX

查出此锁持有者session的session id，机器，程序等信息；

SQL> select s.sid,
  2         s.serial#,
  3         s.program,
  4         s.machine,
  5         s.username,
  6         s.last_call_et,
  7         s.logon_time,
  8         sw.event
  9    from v$session s, v$session_wait sw
 10   where s.sid = sw.sid
 11     and s.sid = 143;
SID SERIAL# PROGRAM                             MACHINE         USERNAME   LAST_CALL_ET LOGON_TIM EVENT
--- ------- ----------------------------------- --------------- ---------- ------------ --------- ------------------------------
143    7044 sqlplus@10g.localdomain (TNS V1-V3) 10g.localdomain SCOTT              3500 28-AUG-13 SQL*Net message from client

这时候DBA可以联系造成阻塞的session结束事务或者根据情况用命令终止session：

SQL> alter system kill session '143,7044';
System altered.

其中143为sid，7044为serial#，session 143会收到如下错误，session 138可以执行后续步骤.

ERROR:
ORA-03114: not connected to ORACLE