通过案例学调优之--OracleTimeModel（时间模型）

通过案例学调优之--Oracle Time Model（时间模型） 650) this.width=650;" src="http://www.68idc.cn/help/uploads/allimg/151111/12163450Z-0.jpg" style="float:none;" title="tm1.png" alt="wKioL1Sb1KyxlqMXAAEQiWTzD4I228.jpg" /> 数据库时间 优化不仅

通过案例学调优之--Oracle Time Model（时间模型）

数据库时间 

      优化不仅仅是缩短等待时间。优化旨在缩短最终用户响应时间和（或）尽可能减少每个请求占用的平均资源。有时这些目标可同时实现，而有时则需要进行折衷（如在并行查询时）。通常可以认为，优化就是避免以浪费的方式占用或保留资源。  

      对数据库发出的任何请求都由两个不同的段组成：等待时间（数据库等待时间）和服务时间（数据库 CPU 时间）。等待时间是各种数据库实例资源的所有等待时间的总和。CPU 时间是实际处理请求时消耗的时间的总和。这些时间不一定由一个等待时间和一个 CPU 时间块组成。通常，进程会等待数据库资源较短时间，然后在 CPU 上短暂运行，并重复执行这一系列过程。 

优化包括缩短或消除等待时间以及缩短 CPU 时间。此定义适用于任何应用程序类型、联机事务处理 (OLTP) 或数据仓库 (DW)。  

注：非常繁忙的系统的数据库 CPU 时间较长，这会增大其它时间。 

CPU 时间和等待时间优化思维 

     优化系统时，应将 CPU 时间与系统的等待时间进行比较，这一点很重要。通过将 CPU 时间与等待时间进行比较，可以确定用于有效工作的响应时间，以及用于等待可能由其它进程占用的资源的时间。通常情况下，与等待时间占主导地位的系统相比，CPU 时间占主导地位的系统需要的优化较少。但是，SQL 语句编写不佳也可能导致高 CPU 使用率。 

虽然随着系统负载的增加，等待时间与 CPU 时间的比值会不断增大，但等待时间的迅速增加是争用的迹象，必须解决这一问题才能获得良好的可扩展性。 

     增加的等待时间表明发生争用时，在节点中增加 CPU 或在集群中增加节点的作用将非常有限。相反，CPU 时间的分配比例不会随着负载增大而明显减小的系统，可扩展性会更好，并且最有可能通过添加 CPU 或 Real Application Clusters (RAC) 实例受益。 

注： 自动工作量资料档案库 (AWR) 和 Statspack 报表在“Top 5 Event（前 5 个事件）”部分显示 CPU 时间排前 5 位的事件的 CPU 时间和等待时间。

时间模型：概览 

       许多组件参与 Oracle DB 系统的优化，每个组件拥有自己的统计信息集。如何评估优化措施预计为总体系统带来的好处？例如，如果将内存从缓冲区高速缓存移至共享池，是否可以提高总体性能？整体查看系统时，时间是比较各个组件的唯一常用标尺。在 Oracle DB 服务器中，大多数建议统计信息都会以时间为单位报告其结果。还有称为“时间模型统计信息”的统计信息，显示为 V$SYS_TIME_MODEL 和 V$SESS_TIME_MODEL 性能视图。此工具帮助 Oracle DB 服务器确定对数据库操作的定量影响。 

      时间模型统计信息中最重要的是数据库时间。此统计信息代表数据库调用花费的总时间，并指示总的实例工作量，它是未等待“空闲等待事件”的所有会话（非空闲用户会话）的 CPU 时间和等待时间的总和。 

     优化 Oracle 数据库系统的目标可以表述为：缩短用户在数据库上执行某项操作花费的时间；或简单地表述为缩短数据库时间。 

其它时间模型统计信息会提供对特定操作（如登录操作、硬分析和软分析、PL/SQL 执行和 Java 执行）的量化影响（以时间为单位）。

时间模型统计信息的层次结构 

      本幻灯片列出了时间模型统计信息之间的关系。这些关系组成两个结构树：后台所用时间和数据库时间。结构树中的子项所报告的时间均包含在结构树中的相应父项内。 

      数据库时间：执行数据库用户级调用的所用时间量（微秒）。此时间不包括用于实例后台进程（如 PMON）的时间。数据库时间从实例启动时开始累计。因为数据库时间的计算方法是将所有非空闲用户会话的时间组合在一起，所以，数据库时间可能会超过从实例启动算起的实际已用时间。例如，已运行 30 分钟的实例可能有四个活动用户会话，累计的数据库时间大约为 120 分钟。 

      数据库 CPU：数据库用户级调用的 CPU 时间量（微秒）。 

      序列装入所用时间：从数据字典获取下一个序号的所用时间量。如果将序列缓存起来，则此时间是用于在高速缓存用尽时补充高速缓存的时间量。在高速缓存中能找到序号时，不会记入任何时间。对于非缓存序列，将为每个 NEXTVAL 调用记入一定时间。

时间模型示例 

      所示的示例来自 AWR 报表。Statspack 报表也提供时间模型信息。统计信息按照占数据库时间值的百分比排序，因此占用时间最多的区域及其子项排在列表的第一个。本例中“sql execute elapsed time（sql 执行所用时间）”排在顶部。“Parse time elapsed（分析所用时间）”紧随其后，而“hard parse elapsed time（硬分析所用时间）”为“parse time elapsed（分析所用时间）”的子项。您马上可以看到，硬分析占用了几乎所有分析时间，而分析时间占用了数据库时间的绝大部分。 

注：各个统计信息的数据库时间百分比总和大于 100%。尽管没有将“parse time elapsed（分析所用时间）”作为“sql execute elapsed time（sql 执行所用时间）”的子项，但两者重复计入了部分元素。 

案例分析：

1、建立AWR snapshot

15:50:10 SYS@ test1 >exec dbms_workload_repository.create_snapshot();

PL/SQL procedure successfully completed.

2、进行事务操作

15:51:21 SCOTT@ test1 >conn scott/tiger
Connected.
15:51:28 SCOTT@ test1 >begin
15:51:33   2  for i in 1..100000 loop
15:51:37   3  execute immediate 'insert into t1(id) values ('||i||')';
15:51:43   4  end loop;
15:51:48   5  end;
15:51:50   6  /
PL/SQL procedure successfully completed.

2、建立AWR snapshot

15:52:31 SYS@ test1 >exec dbms_workload_repository.create_snapshot();

PL/SQL procedure successfully completed.

通过AWR Report分析如下：

650) this.width=650;" style="max-width:90%" title="tm6.png" alt="wKiom1Sb29nRx0GhAAOP_74XJR0966.jpg" />

可以看出系统存在大量的hard parse，占用了大量的cpu time

650) this.width=650;" style="max-width:90%" title="tm7.png" alt="wKiom1Sb29nQ-jVfAAFRf4AnTh0312.jpg" />

650) this.width=650;" style="max-width:90%" title="tm9.png" alt="wKioL1Sb3IiBUfDCAAOBX1cK0n8438.jpg" />

Top Wait Events

650) this.width=650;" title="tm8.png" alt="wKioL1Sb3IaTpOY0AALBr5ZdqLU611.jpg" style="max-width:90%" />

650) this.width=650;" style="max-width:90%" title="tm10.png" alt="wKiom1Sb29uz4-7mAATm3X70_xk326.jpg" />

查看用户session占用的CPU TIME:

16:12:40 SYS@ test1 >select
16:13:11   2     ss.username,
16:13:11   3     se.SID,
16:13:11   4     VALUE/100 cpu_usage_seconds
16:13:11   5  from
16:13:11   6     v$session ss,
16:13:11   7     v$sesstat se,
16:13:11   8     v$statname sn
16:13:11   9  where
16:13:11  10     se.STATISTIC# = sn.STATISTIC#
16:13:11  11  and
16:13:11  12     NAME like '%CPU used by this session%'
16:13:11  13  and
16:13:11  14     se.SID = ss.SID
16:13:11  15  and
16:13:11  16     ss.status='ACTIVE'
16:13:11  17  and
16:13:11  18     ss.username is not null
16:13:11  19  order by VALUE desc;
USERNAME                              SID CPU_USAGE_SECONDS
------------------------------ ---------- -----------------
SCOTT                                  37            128.08
SYS                                    39               .48
SCOTT                                  37                 0
SYS                                    39                 0
SCOTT                                  37                 0
SYS                                    39                 0
SCOTT                                  37                 0
SYS                                    39                 0
8 rows selected.

查看系统等待事件（Wait Events）：

16:12:29 SYS@ test1 >SELECT
  2     wait_class,
  3     NAME,
  4     ROUND (time_secs, 2) time_secs,
  5     ROUND (time_secs * 100 / SUM (time_secs) OVER (), 2) pct
  6  FROM
  7     (SELECT
  8        n.wait_class,
  9        e.event NAME,
 10        e.time_waited / 100 time_secs
 11      FROM
 12        v$system_event e,
 13        v$event_name n
 14      WHERE
 15         n.NAME = e.event AND n.wait_class <> 'Idle'
 16      AND
 17         time_waited > 0
 18      UNION
 19      SELECT
 20        'CPU',
 21        'server CPU',
 22        SUM (VALUE / 1000000) time_secs
 23      FROM
 24        v$sys_time_model
 25      WHERE
 26        stat_name IN ('background cpu time', 'DB CPU'))
 27  ORDER BY
 28*    time_secs DESC；
 
WAIT_CLASS           NAME                                     TIME_SECS    PCT
-------------------- ------------------------------ ------------------- ------
CPU                  server CPU                                  113.80  31.36
System I/O           control file parallel write                  96.43  26.57
System I/O           db file async I/O submit                     31.03   8.55
Other                enq: CF - contention                         20.43   5.63
System I/O           log file parallel write                      19.78   5.45
System I/O           flashback log file write                     14.93   4.11
Other                wait for stopper event to be i               10.11   2.79
                     ncreased
Other                rdbms ipc reply                               8.97   2.47
Configuration        free buffer waits                             7.99   2.20
User I/O             db file sequential read                       5.55   1.53
Configuration        log buffer space                              4.98   1.37
User I/O             Parameter File I/O                            4.43   1.22
Configuration        flashback buf free by RVWR                    4.06   1.12
Other                control file heartbeat                        4.00   1.10
Other                ARCH wait for process start 3                 2.00    .55
WAIT_CLASS           NAME                                     TIME_SECS    PCT
-------------------- ------------------------------ ------------------- ------
User I/O             flashback log file sync                       1.89    .52
Other                change tracking file synchrono                1.75    .48
                     us write
Concurrency          os thread startup                             1.69    .47
User I/O             db file single write                          1.62    .45
Other                buffer exterminate                            1.41    .39
User I/O             db file scattered read                        1.15    .32
Configuration        checkpoint completed                           .84    .23
System I/O           log file sequential read                       .80    .22
Other                ADR block file read                            .61    .17
Commit               log file sync                                  .49    .14
System I/O           log file single write                          .35    .10
System I/O           flashback log file read                        .33    .09
User I/O             Disk file operations I/O                       .27    .07
System I/O           db file parallel write                         .21    .06
Other                SGA: allocation forcing compon                 .18    .05
WAIT_CLASS           NAME                                     TIME_SECS    PCT
-------------------- ------------------------------ ------------------- ------
                     ent growth
Other                ADR block file write                           .18    .05
User I/O             direct path sync                               .17    .05
Other                enq: PR - contention                           .07    .02
User I/O             direct path read                               .06    .02
Concurrency          latch: shared pool                             .06    .02
Concurrency          buffer busy waits                              .05    .01
System I/O           control file sequential read                   .04    .01
System I/O           Log archive I/O                                .03    .01
Other                PX Deq: Signal ACK EXT                         .03    .01
Concurrency          latch: row cache objects                       .03    .01
User I/O             Disk file Mirror/Media Repair                  .02    .01
                     Write
Concurrency          library cache: mutex X                         .01    .00
User I/O             db file parallel read                          .01    .00
WAIT_CLASS           NAME                                     TIME_SECS    PCT
-------------------- ------------------------------ ------------------- ------
Other                latch: cache buffers lru chain                 .01    .00
Other                reliable message                               .01    .00
Concurrency          latch: cache buffers chains                    .01    .00
Other                latch: redo allocation                         .01    .00
Other                cr request retry                               .01    .00
48 rows selected.

案例分析：

CPU使用信息统计：

1、发现那些SQL运行了大量的PARSE

select sql_text, parse_calls, executions from v$sqlarea where rownu <4 order by parse_calls desc;

11:52:47 SYS@ test1 >select sql_text, parse_calls, executions from v$sqlarea where rownum <4 order by 2
SQL_TEXT                                                               PARSE_CALLS EXECUTIONS
---------------------------------------------------------------------- ----------- ----------
insert into t1 (id) values (55135)                                               1         1
insert into t1 (id) values (55443)                                               1          1
insert into t1 (id) values (55243)                                               1          1

2、SYS的总的PARSE情况

select name, value from v$sysstat where name like 'parse count%';

11:53:05 SYS@ test1 >select name, value from v$sysstat where name like 'parse count%'
NAME                                                                  VALUE
---------------------------------------------------------------- ----------
parse count (total)                                                   88502
parse count (hard)                                                    86643
parse count (failures)                                                    0
parse count (describe)                                                    0

3、CPU空间及繁忙情况

select * from v$osstat;
STAT_NAME                                               VALUE  OSSTAT_ID COMMENTS                                 CUM
-------------------------------------------------- ---------- ---------- ---------------------------------------- ---
NUM_CPUS                                                    1          0 Number of active CPUs                    NO
IDLE_TIME                                               35790          1 Time (centi-secs) that CPUs have been in YES
                                                                          the idle state
BUSY_TIME                                                5632          2 Time (centi-secs) that CPUs have been in YES
                                                                          the busy state
USER_TIME                                                3867          3 Time (centi-secs) spent in user code     YES
SYS_TIME                                                 1673          4 Time (centi-secs) spent in the kernel    YES
IOWAIT_TIME                                              4248          5 Time (centi-secs) spent waiting for IO   YES
NICE_TIME                                                   0          6 Time (centi-secs) spend in low-priority  YES
                                                                         user code
RSRC_MGR_CPU_WAIT_TIME                                      0         14 Time (centi-secs) processes spent in the YES
                                                                          runnable state waiting
LOAD                                               .659179688         15 Number of processes running or waiting o NO
STAT_NAME                                               VALUE  OSSTAT_ID COMMENTS                                 CUM
-------------------------------------------------- ---------- ---------- ---------------------------------------- ---
                                                                         n the run queue
PHYSICAL_MEMORY_BYTES                              1236480000       1008 Physical memory size in bytes            NO
TCP_SEND_SIZE_MIN                                        4096       2000 TCP Send Buffer Min Size                 NO
TCP_SEND_SIZE_DEFAULT                                   16384       2001 TCP Send Buffer Default Size             NO
TCP_SEND_SIZE_MAX                                     3489792       2002 TCP Send Buffer Max Size                 NO
TCP_RECEIVE_SIZE_MIN                                     4096       2003 TCP Receive Buffer Min Size              NO
TCP_RECEIVE_SIZE_DEFAULT                                87380       2004 TCP Receive Buffer Default Size          NO
TCP_RECEIVE_SIZE_MAX                                  3489792       2005 TCP Receive Buffer Max Size              NO
GLOBAL_SEND_SIZE_MAX                                  1048586       2006 Global send size max (net.core.wmem_max) NO
GLOBAL_RECEIVE_SIZE_MAX                               4194304       2007 Global receive size max (net.core.rmem_m NO
                                                                         ax)

4、查看每个Session的CPU利用情况：

select ss.sid,se.command,ss.value CPU ,se.username,se.program  
      from v$sesstat ss, v$session se  where ss.statistic# in  
     (select statistic#  from v$statname  
     where name = 'CPU used by this session')  
     and se.sid=ss.sid  
     and ss.sid>6 order by CPU desc;

11:55:19 SYS@ test1 >select ss.sid,se.command,ss.value CPU ,se.username,se.program
11:55:55   2  from v$sesstat ss, v$session se
11:55:55   3  where ss.statistic# in
11:55:55   4  (select statistic#
11:55:55   5  from v$statname
11:55:55   6  where name = 'CPU used by this session')
11:55:55   7  and se.sid=ss.sid
11:55:55   8  and ss.sid>6 order by CPU desc;
       SID    COMMAND        CPU USERNAME                       PROGRAM
---------- ---------- ---------- ------------------------------ ------------------------------------------------
        34          2       8963 SCOTT                          sqlplus@RH6.cuug.net (TNS V1-V3)
        40          0         59                                oracle@RH6.cuug.net (CJQ0)
        15          3         34                                oracle@RH6.cuug.net (MMON)
        13          0          2                                oracle@RH6.cuug.net (SMON)
         9          0          0                                oracle@RH6.cuug.net (MMAN)
        12          0          0                                oracle@RH6.cuug.net (CKPT)
        14          0          0                                oracle@RH6.cuug.net (RECO)
         8          0          0                                oracle@RH6.cuug.net (DIA0)
        16          0          0                                oracle@RH6.cuug.net (MMNL)
        18          0          0                                oracle@RH6.cuug.net (RVWR)
        20          0          0                                oracle@RH6.cuug.net (ARC0)
        21          0          0                                oracle@RH6.cuug.net (ARC1)
        22          0          0                                oracle@RH6.cuug.net (ARC2)
        23          0          0                                oracle@RH6.cuug.net (ARC3)
        28          0          0                                oracle@RH6.cuug.net (CTWR)
         7          0          0                                oracle@RH6.cuug.net (PSP0)
        10          0          0                                oracle@RH6.cuug.net (DBW0)
       SID    COMMAND        CPU USERNAME                       PROGRAM
---------- ---------- ---------- ------------------------------ ------------------------------------------------
        11          0          0                                oracle@RH6.cuug.net (LGWR)
18 rows selected.

5、比较一下哪个session的CPU使用时间最多，然后查看该Session的具体情况：

select s.sid, s.event, s.MACHINE,s.OSUSER,s.wait_time, w.seq#, q.sql_text  
from v$session_wait w, v$session s, v$process p, v$sqlarea q  
where s.paddr=p.addr and  s.sid=&p 
       and  s.sql_address=q.address;

11:56:00 SYS@ test1 >select username,sid from v$session where username is not null;
USERNAME