通过案例学调优之--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.Copy after login
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;" src="http://www.68idc.cn/help/uploads/allimg/151111/121634EE-5.jpg" style="max-width:90%" title="tm6.png" alt="wKiom1Sb29nRx0GhAAOP_74XJR0966.jpg" />
可以看出系统存在大量的hard parse，占用了大量的cpu time
![]()
650) this.width=650;" src="http://www.68idc.cn/help/uploads/allimg/151111/1216345118-6.jpg" style="max-width:90%" title="tm7.png" alt="wKiom1Sb29nQ-jVfAAFRf4AnTh0312.jpg" />
![]()
650) this.width=650;" src="http://www.68idc.cn/help/uploads/allimg/151111/12163420A-7.jpg" style="max-width:90%" title="tm9.png" alt="wKioL1Sb3IiBUfDCAAOBX1cK0n8438.jpg" />
Top Wait Events
![]()
650) this.width=650;" src="http://www.68idc.cn/help/uploads/allimg/151111/1216341222-8.jpg" title="tm8.png" alt="wKioL1Sb3IaTpOY0AALBr5ZdqLU611.jpg" style="max-width:90%" />
![]()
650) this.width=650;" src="http://www.68idc.cn/help/uploads/allimg/151111/121634MG-9.jpg" 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.
Copy after login
查看系统等待事件（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.Copy after login
案例分析：
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
Copy after login
2、SYS的总的PARSE情况
select name, value from v$sysstat where name like 'parse count%';
Copy after login
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
Copy after login
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)Copy after login
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;Copy after login
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.Copy after login
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;Copy after login
11:56:00 SYS@ test1 >select username,sid from v$session where username is not null;
USERNAME
Copy after login
![[Web front-end] Node.js quick start](https://img.php.cn/upload/course/000/000/067/662b5d34ba7c0227.png)
