诊断与分析itpub坛友提出关于为何awr cpu usage非常高

个人简介：

    8年oracle从业经验，具备丰富的oracle技能，目前在国内北京某专业oracle服务公司从事高级技术顾问。

   

   服务过的客户：

          中国电信

          中国移动

          中国联通

          中国电通

          国家电网

          四川达州商业银行

          湖南老百姓大药房

          山西省公安厅

          中国邮政

          北京302医院     

          河北廊坊新奥集团公司

  

 项目经验:

           中国电信3G项目AAA系统数据库部署及优化

           中国联通CRM数据库性能优化

           中国移动10086电商平台数据库部署及优化

           湖南老百姓大药房ERR数据库sql优化项目

           四川达州商业银行TCBS核心业务系统数据库模型设计和RAC部署及优化

           四川达州商业银行TCBS核心业务系统后端批处理存储过程功能模块编写及优化

           北京高铁信号监控系统RAC数据库部署及优化

           河南宇通客车数据库性能优化

           中国电信电商平台核心采购模块表模型设计及优化

           中国邮政储蓄系统数据库性能优化及sql优化

           北京302医院数据库迁移实施

           河北廊坊新奥data guard部署及优化

           山西公安厅身份证审计数据库系统故障评估

           

  

 联系方式：

           手机：18201115468

           qq   :   305076427

           qq微博: wisdomone1

           

           新浪微博：wisdomone9

          

           qq群：275813900    

          

           itpub博客名称：wisdomone1     http://blog.itpub.net/9240380/

前言：

   itpub坛友提出的问题，详细链接见下：

分析：

DB Name DB Id Instance Inst num Startup Time Release RAC HDDB 729144632 hddb1 1 19-6月 -14 03:06 11.2.0.4.0 YES

Host Name Platform CPUs Cores Sockets Memory (GB) dbserver1 AIX-Based Systems (64-bit) 32 8   62.00

Snap Id Snap Time Sessions Cursors/Session Instances Begin Snap 32367 13-8月 -14 10:02:33 587 4.8 2 End Snap: 32368 13-8月 -14 10:31:08 592 4.9 2 Elapsed:   28.60 (mins)       DB Time:   1,036.10 (mins)      

数据库版本11.2.0.4.0,rac架构

数据采样间隔28分钟

配置32个cpu,db time为1036分钟，db time/elapsed为37,表明数据库非常繁忙

32个物理CPU已满负荷运行

另外，表明会存在等待5个cpu时间=5*28.6分钟=143分钟*60=8580s 

Top 10 Foreground Events by Total Wait Time

Event Waits Total Wait Time (sec) Wait Avg(ms) % DB time Wait Class DB CPU   9239.6   14.9   reliable message 1,175,583 3924.9 3 6.3 Other db file sequential read 429,967 1844.8 4 3.0 User I/O SQL*Net more data to client 8,947,769 838.2 0 1.3 Network log file sync 195,677 436.8 2 .7 Commit gc current block 2-way 433,667 331.9 1 .5 Cluster db file parallel read 40,693 260.8 6 .4 User I/O gc cr block 2-way 137,863 125.1 1 .2 Cluster SQL*Net message to client 32,641,422 99.9 0 .2 Network gc current block busy 28,184 80.6 3 .1 Cluster 

上述TOP 10等待事件累计不到30%的 db time,数据库这么繁忙，还有70%的cpu的的资源消耗到哪儿去了

即db time*0.7=1036分钟*0.7=725分钟 

Wait Classes by Total Wait Time

Wait Class Waits Total Wait Time (sec) Avg Wait (ms) % DB time Avg Active Sessions DB CPU   9,240   14.9 5.4 Other 6,603,229 4,114 1 6.6 2.4 User I/O 481,780 2,119 4 3.4 1.2 Network 42,069,399 1,190 0 1.9 0.7 Cluster 832,954 793 1 1.3 0.5 Commit 195,677 437 2 .7 0.3 System I/O 571,383 418 1 .7 0.2 Concurrency 2,157,806 100 0 .2 0.1 Configuration 512 3 5 .0 0.0 Application 714 1 1 .0 0.0 

这是各个等待事件类型的占比分布情况，由此图可知哪些等待类型最严重，尔后进行针对性分析与诊断 

Host CPU

CPUs Cores Sockets Load Average Begin Load Average End %User %System %WIO %Idle 32 8   51.97 78.14 77.7 19.1 0.4 3.2

从主机层面来看，CPU空闲只有3.2%，表明目前cpu基本满负荷运转了

Instance CPU

%Total CPU %Busy CPU %DB time waiting for CPU (Resource Manager) 17.6 18.1 0.0

从数据库占用CPU资源来看，数据库只消耗了主机cpu资源的17.6%,说明大量的cpu资源是由非oracle应用程序消耗了

Time Model Statistics 

Statistic Name Time (s) % of DB Time sql execute elapsed time 52,477.58 84.42 DB CPU 9,239.60 14.86 parse time elapsed 422.57 0.68 PL/SQL execution elapsed time 41.28 0.07 hard parse elapsed time 18.58 0.03 sequence load elapsed time 17.49 0.03 hard parse (sharing criteria) elapsed time  15.02 0.02 connection management call elapsed time  12.12 0.02 hard parse (bind mismatch) elapsed time 3.45 0.01 repeated bind elapsed time 0.65 0.00 PL/SQL compilation elapsed time 0.38 0.00 failed parse elapsed time 0.05 0.00 DB time 62,166.08   background elapsed time 2,233.68   background cpu time 404.84

上述awr信息源于如下视图 

V$SYS_TIME_MODEL

V$SYS_TIME_MODEL displays the system-wide accumulated times for various operations. The time reported is the total elapsed or CPU time (in microseconds). Any timed operation will buffer at most 5 seconds of time data. Specifically, this means that if a timed operation (such as SQL execution) takes a long period of time to perform, the data published to this view is at most missing 5 seconds of the time accumulated for the operation.

The time values are 8-byte integers and can therefore hold approximately 580,000 years worth of time before wrapping. Background process time is not included in a statistic value unless the statistic is specifically for background processes.

Column Datatype Description STAT_ID NUMBER Statistic identifier for the time statistic STAT_NAME VARCHAR2(64) Name of the statistic (see ) VALUE NUMBER Amount of time (in microseconds) that the system has spent in this operation 

小结：显示是一个指标的累计值

         如果指标和时间有关，其单位为microsecond,即一百万分之一秒

         所有定时的操作至多在此视图存储5秒，也就是说，如果这个定时操作超过5秒，就把把超过5秒的数据清除出去

         此时间值有8个比特长，因此可以存储接近580000年，才会重新开始初始化或截断

         注意后面进程时间不会存储在此，除非这个统计指标比较特别

      

  如下是上述统计相关的具体指标

Table 9-1 V$SESS_TIME_MODEL and V$SYS_TIME_MODEL Statistics

Statistic Name Description

DB Time

Amount of elapsed time (in microseconds) spent performing Database user-level calls. This does not include the elapsed time spent on instance background processes such as PMON.

DB CPU

Amount of CPU time (in microseconds) spent on database user-level calls. This does not include the CPU time spent on instance background processes such as PMON.

background elapsed time

Amount of elapsed time (in microseconds) consumed by database background processes.

background CPU time

Amount of CPU time (in microseconds) consumed by database background processes.

sequence load elapsed time

Amount of elapsed time spent getting the next sequence number from the data dictionary. If a sequence is cached, then this is the amount of time spent replenishing the cache when it runs out. No time is charged when a sequence number is found in the cache. For non-cached sequences, some time will be charged for every nextval call.

parse time elapsed

Amount of elapsed time spent parsing SQL statements. It includes both soft and hard parse time.

hard parse elapsed time

Amount of elapsed time spent hard parsing SQL statements.

SQL execute elapsed time

Amount of elapsed time SQL statements are executing. Note that for select statements this also includes the amount of time spent performing fetches of query results.

connection management call elapsed time

Amount of elapsed time spent performing session connect and disconnect calls.

failed parse elapsed time

Amount of time spent performing SQL parses which ultimately fail with some parse error.

failed parse (out of shared memory) elapsed time

Amount of time spent performing SQL parses which ultimately fail with error ORA-04031.

hard parse (sharing criteria) elapsed time

Amount of elapsed time spent performing SQL hard parses when the hard parse resulted from not being able to share an existing cursor in the SQL cache.

hard parse (bind mismatch) elapsed time

Amount of elapsed time spent performing SQL hard parses when the hard parse resulted from bind type or bind size mismatch with an existing cursor in the SQL cache.

PL/SQL execution elapsed time

Amount of elapsed time spent running the PL/SQL interpreter. This does not include time spent recursively executing/parsing SQL statements or time spent recursively executing the Java VM.

PL/SQL compilation elapsed time

Amount of elapsed time spent running the PL/SQL compiler.

inbound PL/SQL rpc elapsed time

Time inbound PL/SQL remote procedure calls have spent executing. It includes all time spent recursively executing SQL and JAVA, and therefore is not easily related to "PL/SQL execution elapsed time".

Java execution elapsed time

Amount of elapsed time spent running the Java VM. This does not include time spent recursively executing/parsing SQL statements or time spent recursively executing PL/SQL.

RMAN cpu time (backup/restore)

Amount of CPU time (in microseconds) spent in RMAN backup and restore operations.

repeated bind elapsed time

Amount of elapsed time spent giving new values to bind variables (rebinding).

如下是上述各个指标的图谱关系

The relationships between the statistics listed in  form two trees in which all the time reported by a child in the tree is contained within the parent in the tree. The following are the relationship trees; the number is the level in the given tree.

1) background elapsed time
    2) background cpu time
          3) RMAN cpu time (backup/restore)
1) DB time
    2) DB CPU
    2) connection management call elapsed time
    2) sequence load elapsed time
    2) sql execute elapsed time
    2) parse time elapsed
          3) hard parse elapsed time
                4) hard parse (sharing criteria) elapsed time
                    5) hard parse (bind mismatch) elapsed time
          3) failed parse elapsed time
                4) failed parse (out of shared memory) elapsed time
    2) PL/SQL execution elapsed time
    2) inbound PL/SQL rpc elapsed time
    2) PL/SQL compilation elapsed time
    2) Java execution elapsed time
    2) repeated bind elapsed time

上述统计指标的一些指导原则（非常重要）

The relationship between a parent and a child in the tree indicates containment only. Keep the following in mind with regard to the tree:

Children do not necessarily add up to the parent.（子项不一定会累加到父项）

Children are not necessarily exclusive (that is, it is possible that they overlap).（子项之间不是互斥的，即可能子项之间有重叠计算部分）

The union of children does not necessarily cover the whole of the parent.（子项合集并不一定会包括或覆盖整个父项，即父项还可能包括其它的未列出来的子项）

从上图可知:

 

sql execute elapsed time/db time=84.42%

db cpu/db time=14.86%

表明sql execute elapsed time是db time的最大凶手，

把sql execute elapse time搞下去，就可以大大提升数据库性能，

所以说只要优化sql,就可以把db time降下来，达到提升数据库性能

沿着上述的分析逻辑，

我们查看sql统计部分，主要查看sql order by elapsed time即可

SQL Statistics

SQL ordered by Elapsed Time

Resources reported for PL/SQL code includes the resources used by all SQL statements called by the code. % Total DB Time is the Elapsed Time of the SQL statement divided into the Total Database Time multiplied by 100 %Total - Elapsed Time as a percentage of Total DB time %CPU - CPU Time as a percentage of Elapsed Time %IO - User I/O Time as a percentage of Elapsed Time Captured SQL account for 82.7% of Total DB Time (s): 62,166 Captured PL/SQL account for 0.0% of Total DB Time (s): 62,166 Elapsed Time (s) Executions Elapsed Time per Exec (s) %Total %CPU %IO SQL Id SQL Module SQL Text 15,434.99 10,719 1.44 24.83 15.49 0.00   select , aa.title, aa.con... 12,280.97 10,704 1.15 19.76 14.26 0.00   select * from ( select , ... 7,623.18 5,587 1.36 12.26 16.01 0.00   select , aa.title, aa.con... 6,119.31 5,578 1.10 9.84 14.74 0.00   select * from ( select , ... 1,237.11 170 7.28 1.99 17.53 0.00   select count(t.business_id) nu...  1,161.12 3,589 0.32 1.87 19.46 0.00   select  as id0_... 912.41 119,289 0.01 1.47 2.46 84.38   select  as id4_... 616.80 1,435,837 0.00 0.99 17.73 0.00   select  as id12... 601.76 473 1.27 0.97 17.96 0.00   select , aa.title, aa.con... 581.22 4,662 0.12 0.93 24.05 0.00   select  as id12... 

大家注意看，上述是根据物理消耗时间排名的top 10 sql，我们仅分析top 1 sql ,

sql_id为bbjh8y6nbzrvx,

其执行时间为15434.99s,%total列表明这个sql执行时间占据db time的比例，这个比值达到15.49，其它sql

同理，不再复述，只要把类似这种sql优化，就可以大大提升数据库性能

结论：
      数据库非常繁忙，但占用物理CPU比例不高，且主机CPU使用很高，可以从主机导面进行诊断

          

          比如使用nmon,oswatcher或者vmstat看看cpu到底被哪些非ORACLE程序占用了

         

          db time=db cpu+sql execute elapsed time+parse time elapsed +pl/sql execution elapsed time(compilation)

          

          上述公式可以分析出来db time到底是被哪些组件消耗最多，然后可针对性进行优化工作

 

          查看sql statistics的

          70%的db time被sql所消耗

扩展阅读：

          Bug 5213488  Column value in AWR (TEXT) report overflows and only shows ########

            "No data exists for this section of the report" in Segment Statistics Section of AWR Report (文档 ID 1570007.1)

            How to Interpret the OS stats section of an AWR report (文档 ID 762526.1)

           AWR Report Shows Huge Numbers For Av/Rd (文档 ID 465106.1)

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/9240380/viewspace-1252817/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/9240380/viewspace-1252817/