通过案例学调优之--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（时间模型）
650) this.width=650; src=http://www.68idc.cn/help/uploads/allimg/151111/12163450z-0.jpg style=max-width:90% title=tm1.png alt=wkiol1sb1kyxlqmxaaeqiwtzd4i228.jpg>
数据库时间 
      优化不仅仅是缩短等待时间。优化旨在缩短最终用户响应时间和（或）尽可能减少每个请求占用的平均资源。有时这些目标可同时实现，而有时则需要进行折衷（如在并行查询时）。通常可以认为，优化就是避免以浪费的方式占用或保留资源。  
      对数据库发出的任何请求都由两个不同的段组成：等待时间（数据库等待时间）和服务时间（数据库 cpu 时间）。等待时间是各种数据库实例资源的所有等待时间的总和。cpu 时间是实际处理请求时消耗的时间的总和。这些时间不一定由一个等待时间和一个 cpu 时间块组成。通常，进程会等待数据库资源较短时间，然后在 cpu 上短暂运行，并重复执行这一系列过程。 
优化包括缩短或消除等待时间以及缩短 cpu 时间。此定义适用于任何应用程序类型、联机事务处理 (oltp) 或数据仓库 (dw)。  
注：非常繁忙的系统的数据库 cpu 时间较长，这会增大其它时间。 
650) this.width=650; src=http://www.68idc.cn/help/uploads/allimg/151111/121634f18-1.jpg title=tm2.png alt=wkiol1sb4wbbtihuaagyqc4p0_i330.jpg>
cpu 时间和等待时间优化思维 
     优化系统时，应将 cpu 时间与系统的等待时间进行比较，这一点很重要。通过将 cpu 时间与等待时间进行比较，可以确定用于有效工作的响应时间，以及用于等待可能由其它进程占用的资源的时间。通常情况下，与等待时间占主导地位的系统相比，cpu 时间占主导地位的系统需要的优化较少。但是，sql 语句编写不佳也可能导致高 cpu 使用率。 
虽然随着系统负载的增加，等待时间与 cpu 时间的比值会不断增大，但等待时间的迅速增加是争用的迹象，必须解决这一问题才能获得良好的可扩展性。 
     增加的等待时间表明发生争用时，在节点中增加 cpu 或在集群中增加节点的作用将非常有限。相反，cpu 时间的分配比例不会随着负载增大而明显减小的系统，可扩展性会更好，并且最有可能通过添加 cpu 或 real application clusters (rac) 实例受益。 
注： 自动工作量资料档案库 (awr) 和 statspack 报表在“top 5 event（前 5 个事件）”部分显示 cpu 时间排前 5 位的事件的 cpu 时间和等待时间。
650) this.width=650; src=http://www.68idc.cn/help/uploads/allimg/151111/12163455a-2.jpg style=max-width:90% title=tm3.png alt=wkiol1sb1k3tsny7aah-63cegvo147.jpg>
时间模型：概览 
       许多组件参与 oracle db 系统的优化，每个组件拥有自己的统计信息集。如何评估优化措施预计为总体系统带来的好处？例如，如果将内存从缓冲区高速缓存移至共享池，是否可以提高总体性能？整体查看系统时，时间是比较各个组件的唯一常用标尺。在 oracle db 服务器中，大多数建议统计信息都会以时间为单位报告其结果。还有称为“时间模型统计信息”的统计信息，显示为 v$sys_time_model 和 v$sess_time_model 性能视图。此工具帮助 oracle db 服务器确定对数据库操作的定量影响。 
      时间模型统计信息中最重要的是数据库时间。此统计信息代表数据库调用花费的总时间，并指示总的实例工作量，它是未等待“空闲等待事件”的所有会话（非空闲用户会话）的 cpu 时间和等待时间的总和。 
     优化 oracle 数据库系统的目标可以表述为：缩短用户在数据库上执行某项操作花费的时间；或简单地表述为缩短数据库时间。 
其它时间模型统计信息会提供对特定操作（如登录操作、硬分析和软分析、pl/sql 执行和 java 执行）的量化影响（以时间为单位）。
650) this.width=650; src=http://www.68idc.cn/help/uploads/allimg/151111/121634a07-3.jpg style=max-width:90% title=tm4.png alt=wkiom1sb1acixjp_aahvwgdab48821.jpg>
时间模型统计信息的层次结构 
      本幻灯片列出了时间模型统计信息之间的关系。这些关系组成两个结构树：后台所用时间和数据库时间。结构树中的子项所报告的时间均包含在结构树中的相应父项内。 
      数据库时间：执行数据库用户级调用的所用时间量（微秒）。此时间不包括用于实例后台进程（如 pmon）的时间。数据库时间从实例启动时开始累计。因为数据库时间的计算方法是将所有非空闲用户会话的时间组合在一起，所以，数据库时间可能会超过从实例启动算起的实际已用时间。例如，已运行 30 分钟的实例可能有四个活动用户会话，累计的数据库时间大约为 120 分钟。 
      数据库 cpu：数据库用户级调用的 cpu 时间量（微秒）。 
      序列装入所用时间：从数据字典获取下一个序号的所用时间量。如果将序列缓存起来，则此时间是用于在高速缓存用尽时补充高速缓存的时间量。在高速缓存中能找到序号时，不会记入任何时间。对于非缓存序列，将为每个 nextval 调用记入一定时间。
650) this.width=650; src=http://www.68idc.cn/help/uploads/allimg/151111/121634n39-4.jpg style=max-width:90% title=tm5.png alt=wkiol1sb1k-xmtrlaaj8trgf2xi034.jpg>
时间模型示例 
      所示的示例来自 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/tigerconnected.15:51:28 scott@ test1 >begin15:51:33 2 for i in 1..100000 loop15: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; 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 >select16:13:11 2 ss.username,16:13:11 3 se.sid,16:13:11 4 value/100 cpu_usage_seconds16:13:11 5 from16:13:11 6 v$session ss,16:13:11 7 v$sesstat se,16:13:11 8 v$statname sn16:13:11 9 where16:13:11 10 se.statistic# = sn.statistic#16:13:11 11 and16:13:11 12 name like '%cpu used by this session%'16:13:11 13 and16:13:11 14 se.sid = ss.sid16:13:11 15 and16:13:11 16 ss.status='active'16:13:11 17 and16:13:11 18 ss.username is not null16:13:11 19 order by value desc;username sid cpu_usage_seconds------------------------------ ---------- -----------------scott 37 128.08sys 39 .48scott 37 0sys 39 0scott 37 0sys 39 0scott 37 0sys 39 08 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.36system i/o control file parallel write 96.43 26.57system i/o db file async i/o submit 31.03 8.55other enq: cf - contention 20.43 5.63system i/o log file parallel write 19.78 5.45system i/o flashback log file write 14.93 4.11other wait for stopper event to be i 10.11 2.79 ncreasedother rdbms ipc reply 8.97 2.47configuration free buffer waits 7.99 2.20user i/o db file sequential read 5.55 1.53configuration log buffer space 4.98 1.37user i/o parameter file i/o 4.43 1.22configuration flashback buf free by rvwr 4.06 1.12other control file heartbeat 4.00 1.10other arch wait for process start 3 2.00 .55wait_class name time_secs pct-------------------- ------------------------------ ------------------- ------user i/o flashback log file sync 1.89 .52other change tracking file synchrono 1.75 .48 us writeconcurrency os thread startup 1.69 .47user i/o db file single write 1.62 .45other buffer exterminate 1.41 .39user i/o db file scattered read 1.15 .32configuration checkpoint completed .84 .23system i/o log file sequential read .80 .22other adr block file read .61 .17commit log file sync .49 .14system i/o log file single write .35 .10system i/o flashback log file read .33 .09user i/o disk file operations i/o .27 .07system i/o db file parallel write .21 .06other sga: allocation forcing compon .18 .05wait_class name time_secs pct-------------------- ------------------------------ ------------------- ------ ent growthother adr block file write .18 .05user i/o direct path sync .17 .05other enq: pr - contention .07 .02user i/o direct path read .06 .02concurrency latch: shared pool .06 .02concurrency buffer busy waits .05 .01system i/o control file sequential read .04 .01system i/o log archive i/o .03 .01other px deq: signal ack ext .03 .01concurrency latch: row cache objects .03 .01user i/o disk file mirror/media repair .02 .01 writeconcurrency library cache: mutex x .01 .00user i/o db file parallel read .01 .00wait_class name time_secs pct-------------------- ------------------------------ ------------------- ------other latch: cache buffers lru chain .01 .00other reliable message .01 .00concurrency latch: cache buffers chains .01 .00other latch: redo allocation .01 .00other cr request retry .01 .0048 rows selected.
案例分析：
cpu使用信息统计：
1、发现那些sql运行了大量的parse
select sql_text, parse_calls, executions from v$sqlarea where rownu select sql_text, parse_calls, executions from v$sqlarea where rownum select name, value from v$sysstat where name like 'parse count%'name value---------------------------------------------------------------- ----------parse count (total) 88502parse count (hard) 86643parse count (failures) 0parse count (describe) 0
3、cpu空间及繁忙情况
select * from v$osstat;stat_name value osstat_id comments cum-------------------------------------------------- ---------- ---------- ---------------------------------------- ---num_cpus 1 0 number of active cpus noidle_time 35790 1 time (centi-secs) that cpus have been in yes the idle statebusy_time 5632 2 time (centi-secs) that cpus have been in yes the busy stateuser_time 3867 3 time (centi-secs) spent in user code yessys_time 1673 4 time (centi-secs) spent in the kernel yesiowait_time 4248 5 time (centi-secs) spent waiting for io yesnice_time 0 6 time (centi-secs) spend in low-priority yes user codersrc_mgr_cpu_wait_time 0 14 time (centi-secs) processes spent in the yes runnable state waitingload .659179688 15 number of processes running or waiting o nostat_name value osstat_id comments cum-------------------------------------------------- ---------- ---------- ---------------------------------------- --- n the run queuephysical_memory_bytes 1236480000 1008 physical memory size in bytes notcp_send_size_min 4096 2000 tcp send buffer min size notcp_send_size_default 16384 2001 tcp send buffer default size notcp_send_size_max 3489792 2002 tcp send buffer max size notcp_receive_size_min 4096 2003 tcp receive buffer min size notcp_receive_size_default 87380 2004 tcp receive buffer default size notcp_receive_size_max 3489792 2005 tcp receive buffer max size noglobal_send_size_max 1048586 2006 global send size max (net.core.wmem_max) noglobal_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.program11:55:55 2 from v$sesstat ss, v$session se11:55:55 3 where ss.statistic# in11:55:55 4 (select statistic#11:55:55 5 from v$statname11:55:55 6 where name = 'cpu used by this session')11:55:55 7 and se.sid=ss.sid11: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