【Maclean技术分享】开Oracle调优鹰眼,深入理解AWR性能报告 第二讲

Oracle调优鹰眼系列只有2讲,对AWR感兴趣的同学更多指标可以参考 【性能调优】Oracle AWR报告指标全解析 https://www.askmaclean.com/archives/performance-tuning-oracle-awr.html

 

 

【技术分享】开Oracle调优鹰眼,深入理解AWR性能报告 第二讲

涉及性能优化教学知识:Host CPU、Instance CPU、Wait Class、SQL Statistics、AWR FOR RAC集群特定调优 https://zcdn.askmaclean.com/oracle%20awr%20hawk%202.mp4

适合的学员: 对性能优化有兴趣,或给予提升自己Oracle调优技能的同学

预计时长: 2个小时左右

本次公开教学的视频地址:

 

 

正式版文档材料已上传:

 

【Maclean Liu技术分享】开Oracle调优鹰眼,深入理解AWR性能报告 第二讲 正式版 20130.pdf (2.27 MB, 下载次数: 30699)

 

 

【技术分享】开Oracle调优鹰眼,深入理解AWR性能报告 第一讲  https://zcdn.askmaclean.com/%E3%80%90Maclean%20Liu%E6%8A%80%E6%9C%AF%E5%88%86%E4%BA%AB%E3%80%91%E5%BC%80Oracle%E8%B0%83%E4%BC%98%E9%B9%B0%E7%9C%BC%EF%BC%8C%E6%B7%B1%E5%85%A5%E7%90%86%E8%A7%A3AWR%E6%80%A7%E8%83%BD%E6%8A%A5%E5%91%8A.mp4

适合参与成员: 对性能优化有兴趣或急于提升自己oracle技术水平的学员

 

 

 

 

讲座材料presentation 当前版本下载:

【Maclean Liu技术分享】开Oracle调优鹰眼,深入理解AWR性能报告_20130303版.pdf.pdf (1.79 MB, 下载次数: 32641)

Script:查找表或索引增长的历史信息

有同学在Oracle ALL STARS群中提问 如何通过AWR来查找一段时间内,数据库段对象(堆表、索引)等的空间增长信息。

 

在Oracle 10g开始awr自动负载仓库引入了dba_hist_seg_stat视图,该视图记录了快照时间内segment-level段级的历史统计信息:DBA_HIST_SEG_STAT displays historical information about segment-level statistics. This view captures the top segments based on a set of criteria and captures information from V$SEGSTAT. The total value is the value of the statistics since instance startup. The delta value is the value of the statistics from the BEGIN_INTERVAL_TIME to the END_INTERVAL_TIME in the DBA_HIST_SNAPSHOT view.

 

我们可以通过以下SQL脚本来列出相关段对象在 快照时间内的使用空间的历史变化信息:

 

 

column owner format a16
column object_name format a36
column start_day format a11
column block_increase format 9999999999

select   obj.owner, obj.object_name,
         to_char(sn.BEGIN_INTERVAL_TIME,'RRRR-MON-DD') start_day,
         sum(a.db_block_changes_delta) block_increase
from     dba_hist_seg_stat a,
         dba_hist_snapshot sn,
         dba_objects obj
where    sn.snap_id = a.snap_id
and      obj.object_id = a.obj#
and      obj.owner not in ('SYS','SYSTEM')
and      end_interval_time between to_timestamp('01-JAN-2000','DD-MON-RRRR')
         and to_timestamp('02-FEB-2013','DD-MON-RRRR')
group by obj.owner, obj.object_name,
         to_char(sn.BEGIN_INTERVAL_TIME,'RRRR-MON-DD')
order by obj.owner, obj.object_name
/

 

 

使用示例:

 

Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

SQL> conn maclean/maclean
Connected.
SQL>
SQL>
SQL>
SQL> create table check_size tablespace users as select  * from dba_objects where rownum=0;

Table created.

SQL> exec dbms_workload_repository.create_snapshot;

PL/SQL procedure successfully completed.

SQL> insert into check_size select * from dba_objects;

75536 rows created.

SQL> insert into check_size select * from check_size;

75536 rows created.

SQL> /

151072 rows created.

SQL> commit;

Commit complete.

SQL> insert into check_size select * from check_size;

302144 rows created.

SQL> insert into check_size select * from check_size;

604288 rows created.

SQL> commit;

Commit complete.

SQL> alter system checkpoint;

System altered.

SQL> exec dbms_workload_repository.create_snapshot;

PL/SQL procedure successfully completed.

SQL> @seg_hist

OWNER            OBJECT_NAME                          START_DAY   BLOCK_INCREASE
---------------- ------------------------------------ ----------- --------------
DBSNMP           BSLN_STATISTICS                      2012-MAR-18            224
DBSNMP           BSLN_STATISTICS_PK1                  2012-MAR-18            192
MACLEAN          CHECK_SIZE                           2012-MAR-22          96176
SH               CUSTOMERS                            2012-MAR-17              0

SQL> select data_object_id from dba_objects where object_name='CHECK_SIZE';

DATA_OBJECT_ID
--------------
         78062

SQL> select seg.snap_id,
  2         seg.ts#,
  3         seg.space_used_total,
       seg.space_allocated_total,
       seg.SPACE_ALLOCATED_DELTA
  from dba_hist_seg_stat seg
 where seg.DATAOBJ#=78062
   /  4    5    6    7    8  

   SNAP_ID        TS# SPACE_USED_TOTAL SPACE_ALLOCATED_TOTAL SPACE_ALLOCATED_DELTA
---------- ---------- ---------------- --------------------- ---------------------
       354          4         30909079              36700160              36700160
       355          4        123645655             149946368             113246208

SPACE_USED_DELTA  	Delta value for space used
SPACE_ALLOCATED_DELTA   Delta value for space allocated

Know more about AWR Parse Statistics

Parse CPU to Parse Elapsed%是一个我们在分析AWR报告时常会看到的解析性能指标,该指标反映了 快照内解析CPU时间和总的解析时间的比值(Parse CPU Time/ Parse Elapsed Time); 若该指标水平很低,那么说明在整个解析过程中 实际在CPU上运算的时间是很短的,而主要的解析时间都耗费在各种其他非空闲的等待事件上了(如latch:shared pool,row cache lock之类等), 通过该指标我们可以了解是否有必要来调优Oracle的优化器Optimizer的解析(parse)工作, 调优的对象包括软、硬解析(soft and hard parse),理论上我们的目标是有极少的硬解析,少量的软解析,以及Parse CPU to Parse Elapsed% 接近于100% 相当于解析时都是在CPU上运算 而不等待, 所以Parse CPU to Parse Elapsed%也同时给我们以调优方向的启示。

 

Soft Parse %是AWR中另一个重要的解析指标,该指标反应了快照时间内 软解析次数 和 总解析次数 (soft+hard 软解析次数+硬解析次数)的比值,若该指标很低,那么说明了可能存在剧烈的hard parse硬解析,大量的硬解析会消耗更多的CPU时间片并产生解析争用(此时可以考虑使用cursor_sharing=FORCE); 理论上我们总是希望 Soft Parse % 接近于100%, 但并不是说100%的软解析就是最理想的解析状态,通过设置 session_cached_cursors参数和反复重用游标我们可以让解析来的更轻量级,即通俗所说的利用会话缓存游标实现的软软解析(soft soft parse)。

 

其他一些对于tuning SQL parse调优SQL解析有帮助的指标信息:

 

Reloads:

 

Library Cache Activity -> SQL Area reloads 信息,该指标反映了 游标被重新加载到shared pool共享池中的次数,引起reload重新装载的原因可能是共享游标失效Invalidation (失效可能由DDL等操作引起),也可能由shared pool共享池Free memory空闲内存过少导致sql reloads;reloads往往意味着本来可能已经被解析好的SQL语句,需要再次经历硬解析才能使用。

 

Library Cache Activity

  • “Pct Misses” should be very low
Namespace Get Requests Pct Miss Pin Requests Pct Miss Reloads Invali- dations
BODY 245 0.41 1,835 0.05 0 0
CLUSTER 665 0.00 155 0.00 0 0
DBLINK 1,020 0.00 0 0 0
EDITION 34 0.00 52 0.00 0 0
INDEX 308 3.90 244 10.66 14 0
OBJECT ID 273 100.00 0 0 0
QUEUE 5 0.00 762 0.00 0 0
RULESET 2 0.00 2 0.00 0 0
SCHEMA 1,077 0.00 0 0 0
SQL AREA 3,224 29.44 30,256 2.92 119 89
SUBSCRIPTION 1 0.00 1 0.00 0 0
TABLE/PROCEDURE 6,210 0.55 8,069 2.12 40 0
TRIGGER 182 0.00 188 0.00 0 0

 

 

High version Count:

 

在Oracle中同样的SQL语句可能被硬解析成不同的子游标(child cursor),一句SQL statement拥有过多的child cursor(例如超过50个子游标)往往说明游标无法被共享,若游标无法被共享使用那么只好每一次都再次硬解析和生成更多的子游标了,可以通过v$sql_shared_cursor来了解具体无法共享游标的原因。 实际引起SQL High Version Count的原因可能有很多,这里不再一一列举,特别需要注意的是以下2个Note涉及到的问题:

 

Note 296377.1 Handling and resolving unshared cursors/large version_counts Troubleshooting: High Version Count Issues
Note 261020.1 High Version Count with CURSOR_SHARING = SIMILAR or FORCE
Note 438755.1 High SQL Version Counts – Script to determine reason(s)
Note 377847.1 Unsafe Literals or Peeked Bind Variables

 

AWR中提供了SQL ordered by Version Count信息方便用户了解该指标

 

SQL ordered by Version Count

  • Only Statements with Version Count greater than 20 are displayed
Version Count Executions SQL Id SQL Module SQL Text
37 4 1nhkkuq1y13vm python.exe select * from www.askmaclean.com
32 0 6mvfay19q3v4n SELECT COUNT(CLIENT_INFO) FROM…
30 0 dqbhc9r7gz0a5 SELECT DECODE(COUNT(CLIENT_INF…
27 24 2nk2p4h18rbwf MMON_SLAVE select tablespace_id, rfno, al…
26 24 a1xgxtssv5rrp MMON_SLAVE select * from www.askmaclean.com
24 4 5s34t44u10q4g SELECT a.name task_name, nvl(e…
24 8 69k5bhm12sz98 SELECT dbin.instance_number, d…
24 4 c8gnrhxma4tas SELECT owner#, property FROM s…
24 4 gdn3ysuyssf82 SELECT advisor_id FROM sys.wri…
22 4 23nad9x295gkf SELECT (m.current_size / 10485…

 

具体的high version count诊断步骤:

 

1 select sql_text, hash_value,address from v$sqlarea where sql_id ='{sql id
from AWR>}'

2 select * from v$sql_shared_cursor where address = <address returned above>

3 SELECT sql_text,version_count,address FROM V$SQLAREA order by version_count desc;

4 From step 3 , take the sql with highest version count and put in below 

SELECT * FROM V$SQL_SHARED_CURSOR WHERE address = 'HERE';

5. 检查 参数 NLS_LENGTH_SEMANTICS  What is the value of NLS_LENGTH_SEMANTICS ?

流言终结者: AWR的保留天数和SYSAUX表空间的使用率有关吗?

今天在QQ群的技术讨论中有人提及AWR实际保留的天数并非10g的 7天 或 11g 的 8天 ,而是视乎SYSAUX表空间的使用率而定,当SYSAUX表空间空闲空间较多时会将AWR数据保留地更久。

虽然不知道以上这番理论出自那部书籍,但是至少是说的有模有样的,而且网友还告诉我这是他测试过的结果。

实际是这样吗?

我相信这位网友并没有吹牛,他很可能查询dba_hist_snapshot等AWR视图且看到了的确有7天之前的快照仍被保留着,而没有被清理掉。我们来重演他所看到的现场:

测试使用版本11.2.0.2 , 11g中默认AWR保留8天:

 

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

SQL> select * from global_name;

GLOBAL_NAME
----------------------------------------------------------
www.askmaclean.com & www.askmaclean.com

SQL> col SNAP_INTERVAL for a20
SQL> col RETENTION for a20
SQL> select snap_interval,retention from dba_hist_wr_control;

SNAP_INTERVAL        RETENTION
-------------------- --------------------
+00000 01:00:00.0    +00008 00:00:00.0

以上确认了默认的快照间隔为1小时 ,且保留时间为8天

检查当前SYSAUX表空间的使用率

REM tablespace report

set linesize 200

select a.tablespace_name,
       round(a.bytes_alloc / 1024 / 1024) megs_alloc,
       round(nvl(b.bytes_free, 0) / 1024 / 1024) megs_free,
       round((a.bytes_alloc - nvl(b.bytes_free, 0)) / 1024 / 1024) megs_used,
       round((nvl(b.bytes_free, 0) / a.bytes_alloc) * 100) Pct_Free,
       100 - round((nvl(b.bytes_free, 0) / a.bytes_alloc) * 100) Pct_used,
       round(maxbytes / 1048576) Max
  from (select f.tablespace_name,
               sum(f.bytes) bytes_alloc,
               sum(decode(f.autoextensible, 'YES', f.maxbytes, 'NO', f.bytes)) maxbytes
          from dba_data_files f
         group by tablespace_name) a,
       (select f.tablespace_name, sum(f.bytes) bytes_free
          from dba_free_space f
         group by tablespace_name) b
 where a.tablespace_name = b.tablespace_name(+)
union all
select h.tablespace_name,
       round(sum(h.bytes_free + h.bytes_used) / 1048576) megs_alloc,
       round(sum((h.bytes_free + h.bytes_used) - nvl(p.bytes_used, 0)) /
             1048576) megs_free,
       round(sum(nvl(p.bytes_used, 0)) / 1048576) megs_used,
       round((sum((h.bytes_free + h.bytes_used) - nvl(p.bytes_used, 0)) /
             sum(h.bytes_used + h.bytes_free)) * 100) Pct_Free,
       100 -
       round((sum((h.bytes_free + h.bytes_used) - nvl(p.bytes_used, 0)) /
             sum(h.bytes_used + h.bytes_free)) * 100) pct_used,
       round(sum(f.maxbytes) / 1048576) max
  from sys.v_$TEMP_SPACE_HEADER h,
       sys.v_$Temp_extent_pool  p,
       dba_temp_files           f
 where p.file_id(+) = h.file_id
   and p.tablespace_name(+) = h.tablespace_name
   and f.file_id = h.file_id
   and f.tablespace_name = h.tablespace_name
 group by h.tablespace_name
 ORDER BY 1
/

TABLESPACE_NAME                MEGS_ALLOC  MEGS_FREE  MEGS_USED   PCT_FREE   PCT_USED        MAX
------------------------------ ---------- ---------- ---------- ---------- ---------- ----------
MGMT_AD4J_TS                          200        199          1         99          1      32768
MGMT_ECM_DEPOT_TS                      40         13         27         32         68      32768
MGMT_TABLESPACE                      1350         86       1265          6         94      32768
SYSAUX                                600        295        305         49         51      32768
SYSTEM                                700        231        469         33         67      32768
TEMP                                   21         21          0        100          0      32768
UNDOTBS1                              495        358        137         72         28      32768
USERS                                1950       1243        707         64         36      32768

SYSAUX表空间剩余295MB空间,空闲率较高

 

因为这套数据库在2011-10-17之后就一直没有打开过,所以Automatic Workload Repository中最早保留的快照信息是在2011-10-10,通过查询dba_hist_snapshot视图可以反映这一点:

 

select snap_id,
       to_char(begin_interval_time, 'YYYY-MM-DD'),
       to_char(end_interval_time, 'YYYY-MM-DD')
  from dba_hist_snapshot
 order by snap_id;
   SNAP_ID TO_CHAR(BE TO_CHAR(EN
---------- ---------- ----------
        96 2011-10-10 2011-10-10
        97 2011-10-10 2011-10-10
        98 2011-10-10 2011-10-10
        99 2011-10-10 2011-10-10
       100 2011-10-10 2011-10-10
       101 2011-10-10 2011-10-11
       102 2011-10-11 2011-10-11
       103 2011-10-11 2011-10-11
...................
       221 2011-10-17 2011-10-17
       222 2011-10-24 2011-10-24

SQL> select sysdate from dual;

SYSDATE
---------
24-OCT-11

 

当前的日期是24-OCT-11,而最早的快照信息是在2011-10-10,这样就达成了网友所说的AWR的保留时间并非7或8天,”awr保留天数根据sysaux大小决定。” 或 “默认7天,sysaux足够大这个7天没有意义” 的说法。

 

事实是这样吗?

不是的!

那么为什么能看到早于7天的快照呢?

回答: 不要被所看到的信息所蒙蔽,虽然我们常说事实胜于雄辩或实践是检验真知的唯一 , 但事情的表象往往会欺骗我们。

以上这个问题的关键点并非在于是否能看到早于7天的snapshot快照信息,而在于当MMON后台进程(该进程负责收集和清理AWR数据)在执行对过期快照清理工作时是否会清除7 或 8 天之前的snapshot,以及MMON后台进程多久才Purge一次AWR Snapshot。

以上这些问题 , 我们可以通过_swrf_test_action参数和10046 trace搞清楚:

 

SQL> SELECT x.ksppinm NAME, y.ksppstvl VALUE, x.ksppdesc describ
  2   FROM SYS.x$ksppi x, SYS.x$ksppcv y
  3   WHERE x.inst_id = USERENV ('Instance')
  4   AND y.inst_id = USERENV ('Instance')
  5   AND x.indx = y.indx
  6  AND x.ksppinm LIKE '%_swrf%';

NAME                 VALUE      DESCRIB
-------------------- ---------- --------------------------------------------------
_swrf_test_action    0          test action parameter for SWRF
_swrf_mmon_flush     TRUE       Enable/disable SWRF MMON FLushing
_swrf_mmon_metrics   TRUE       Enable/disable SWRF MMON Metrics Collection
_swrf_metric_frequen FALSE      Enable/disable SWRF Metric Frequent Mode Collectio
t_mode                          n

_swrf_on_disk_enable TRUE       Parameter to enable/disable SWRF
d

_swrf_mmon_dbfus     TRUE       Enable/disable SWRF MMON DB Feature Usage
_swrf_test_dbfus     FALSE      Enable/disable DB Feature Usage Testing

 

_swrf_test_action 隐藏参数用以调试MMON的行为,设置该参数并10046事件:

 

SQL> alter session set "_swrf_test_action" = 28; 

Session altered.

SQL> alter session set "_swrf_test_action" = 10; 

Session altered.

[oracle@vrh4 ContentsXML]$ ps -ef|grep mmon
oracle    2872     1  0 18:28 ?        00:00:00 ora_mmon_SBDB
oracle    3446  3289  0 18:44 pts/1    00:00:00 tail -f SBDB_mmon_2872.trc
oracle    3997  3407  0 19:17 pts/2    00:00:00 grep mmon

SQL> oradebug setospid 2872;
Oracle pid: 15, Unix process pid: 2872, image: oracle@vrh4.oracle.com (MMON)

SQL> oradebug event 10046 trace name context forever,level 12;
Statement processed.

 

完成以上操作后等待一段时间,MMON进程的trace文件会陆续写出一些信息,如:

 

*** 2011-10-24 18:45:24.795
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.

*** 2011-10-24 18:46:24.874
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.

*** 2011-10-24 18:47:24.952
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.

*** 2011-10-24 18:48:25.053
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.

说明MMON每分钟都会自动刷新一定的数据到磁盘上。

 

此外还可以看到MMON清理过期快照的信息:

 

*** 2011-10-24 18:58:25.290
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.
KEWRAPM: Beginning one MMON Auto-Purge cycle ...
  KEWRAPM: Finished one MMON Auto-Purge cycle.
KEWRAPC: Auto Purge Action Completed.

*** 2011-10-24 19:28:26.091
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.
KEWRAPM: Beginning one MMON Auto-Purge cycle ..
  KEWRAPM: Finished one MMON Auto-Purge cycle

*** 2011-10-24 19:58:27.041
KEWRAFM: Beginning one MMON Auto-Flush cycle ...
  Finished one MMON Auto-Flush cycle.
KEWRAPM: Beginning one MMON Auto-Purge cycle ...
  KEWRAPM: Finished one MMON Auto-Purge cycle.

 

可以看到在默认情况下MMON每30分钟会自动去清理一次Automatic Workload Repository自动负载仓库中的过期快照信息,当18:58:25.290的第一次清理工作完成后查询dba_hist_snapshot可以发现过期快照消失了:

 

SQL> select snap_id,
  2         to_char(begin_interval_time, 'YYYY-MM-DD'),
  3         to_char(end_interval_time, 'YYYY-MM-DD')
  4    from dba_hist_snapshot
  5   order by snap_id;

   SNAP_ID TO_CHAR(BE TO_CHAR(EN
---------- ---------- ----------
       194 2011-10-16 2011-10-16
       195 2011-10-16 2011-10-16
       196 2011-10-16 2011-10-16
       197 2011-10-16 2011-10-16
.................
       222 2011-10-24 2011-10-24

 

通过以上演示我们可知AWR快照的保留天数与SYSAUX的使用率并无关系,实际控制AWR保留天数的最主要因素是MMON何时、如何地清理过期快照? MMON的清理操作直接受到dba_hist_wr_control.retention设置值的影响,默认情况10g 为保留7天,而11g为保留8天,MMON只已清理过期的快照。

同时KEWRAPM的trace信息也说明了,默认情况下MMON每30分钟做一次”MMON Auto-Purge cycle”清理工作。

Extract SQL Plan from AWR

之前有用户在AWR中定位到问题SQL语句后想要了解该SQL statement的具体执行计划,于是就用AWR报告中得到的SQL ID去V$SQL等几个动态性能视图中查询,但发现V$SQL或V$SQL_PLAN视图都已经找不到对应SQL ID的记录,一般来说这些语句已经从shared pool共享池中被替换出去了。

这个时候我们可以尝试使用DBMS_XPLAN.DISPLAY_AWR存储过程来将Oracle Automatic Workload Repository自动负载仓库中记录的SQL语句相关信息抽取出来,如:

SQL> set linesize 200 pagesize 2000;

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
askmaclean.com

SQL> select /* extract_me */ count(*) from maclean;

  COUNT(*)
----------
      9564

SQL> select sql_id from v$sql where sql_text like '%extract_me%' and sql_text not like '%like%';

SQL_ID
-------------
8vff23q8qp9fj

SQL> exec dbms_workload_repository.create_snapshot;
PL/SQL procedure successfully completed.

QL> select * from table(dbms_xplan.display_cursor('8vff23q8qp9fj',0));

PLAN_TABLE_OUTPUT
-------------------------------------
SQL_ID  8vff23q8qp9fj, child number 0
-------------------------------------
select /* extract_me */ count(*) from maclean

Plan hash value: 1679547536

----------------------------------------------------------------------
| Id  | Operation          | Name    | Rows  | Cost (%CPU)| Time     |
----------------------------------------------------------------------
|   0 | SELECT STATEMENT   |         |       |    34 (100)|          |
|   1 |  SORT AGGREGATE    |         |     1 |            |          |
|   2 |   TABLE ACCESS FULL| MACLEAN | 10438 |    34   (0)| 00:00:01 |
----------------------------------------------------------------------

Note
-----
   - dynamic sampling used for this statement

18 rows selected.

/* 冲刷共享池后v$SQL/V$SQL_PLAN等动态视图内的记录会消失,
     需要注意的是如果在AWR快照自动生成之前冲刷了共享池,那么可能丢失SQL的执行统计信息
 */

SQL> alter system flush shared_pool;
System altered.

SQL> select * from table(dbms_xplan.display_cursor('8vff23q8qp9fj',0));

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------
SQL_ID: 8vff23q8qp9fj, child number: 0 cannot be found

/* 此时就可以利用dbms_xplan.display_awr存储过程来抓取该SQL_ID对应的执行计划 */

SQL>  select * from table(dbms_xplan.display_awr('8vff23q8qp9fj'));

PLAN_TABLE_OUTPUT
--------------------------------------------------
SQL_ID 8vff23q8qp9fj
--------------------
select /* extract_me */ count(*) from maclean

Plan hash value: 1679547536

----------------------------------------------------------------------
| Id  | Operation          | Name    | Rows  | Cost (%CPU)| Time     |
----------------------------------------------------------------------
|   0 | SELECT STATEMENT   |         |       |    34 (100)|          |
|   1 |  SORT AGGREGATE    |         |     1 |            |          |
|   2 |   TABLE ACCESS FULL| MACLEAN | 10438 |    34   (0)| 00:00:01 |
----------------------------------------------------------------------

Note
-----
   - dynamic sampling used for this statement

18 rows selected.

/* 这里可以代入'all'选项获取更细致的计划信息 */

SQL> select * from table(dbms_xplan.display_awr('8vff23q8qp9fj',null,null,'all'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------
SQL_ID 8vff23q8qp9fj
--------------------
select /* extract_me */ count(*) from maclean

Plan hash value: 1679547536

----------------------------------------------------------------------
| Id  | Operation          | Name    | Rows  | Cost (%CPU)| Time     |
----------------------------------------------------------------------
|   0 | SELECT STATEMENT   |         |       |    34 (100)|          |
|   1 |  SORT AGGREGATE    |         |     1 |            |          |
|   2 |   TABLE ACCESS FULL| MACLEAN | 10438 |    34   (0)| 00:00:01 |
----------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SEL$1
   2 - SEL$1 / MACLEAN@SEL$1

Note
-----
   - dynamic sampling used for this statement

24 rows selected.

/* 也可以从 dba_hist_sql_plan/dba_hist_sqltext等awr历史视图中直接观察该SQL ID对应的语句 */

SQL> select OPERATION,OPTIONS,OBJECT_NAME from dba_hist_sql_plan where sql_id='8vff23q8qp9fj';

OPERATION                      OPTIONS                        OBJECT_NAME
------------------------------ ------------------------------ -------------------------------
SELECT STATEMENT
SORT                           AGGREGATE
TABLE ACCESS                   FULL                           MACLEAN

应用长短链接变更对于Oracle数据库性能的影响

Question:某客户的应用做过变更(短链变长链),现cpu利用率较之前有明显改善,参见附件中的awr报告。想咨询一下sql语句的执行时间,cpu Time等指标,是否会受到短链变长链影响,因为从awr报告看,性能有明显改善。

Load Profile
变更前:

Per Second Per Transaction
Redo size: 244,606.59 13,269.94
Logical reads: 5,964.59 323.58
Block changes: 1,278.41 69.35
Physical reads: 339.03 18.39
Physical writes: 35.30 1.92
User calls: 693.44 37.62
Parses: 241.46 13.10
Hard parses: 0.16 0.01
Sorts: 97.93 5.31
Logons: 16.05 0.87
Executes: 617.55 33.50
Transactions: 18.43

变更后:

Per Second Per Transaction
Redo size: 314,037.68 4,249.08
Logical reads: 7,939.19 107.42
Block changes: 1,629.35 22.05
Physical reads: 221.23 2.99
Physical writes: 41.85 0.57
User calls: 1,005.17 13.60
Parses: 76.15 1.03
Hard parses: 0.16 0.00
Sorts: 37.36 0.51
Logons: 0.36 0.00
Executes: 810.16 10.96
Transactions: 73.91

Top 5 Timed Events
变更前:

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
CPU time 2,430 68.6
db file sequential read 84,286 416 5 11.7 User I/O
log file sync 63,773 266 4 7.5 Commit
db file scattered read 74,972 235 3 6.6 User I/O
enq: TX – row lock contention 463 229 494 6.5 Application

变更后:

Event Waits Time(s) Avg Wait(ms) % Total Call Time Wait Class
CPU time 1,661 74.0
log file sync 167,658 473 3 21.1 Commit
db file sequential read 91,101 411 5 18.3 User I/O
wait for scn ack 145,796 142 1 6.3 Other
log file parallel write 166,143 121 1 5.4 System I/O

Time Model Statistics

变更前:

Statistic Name Time (s) % of DB Time
sql execute elapsed time 2,603.73 73.47
DB CPU 2,430.37 68.58
connection management call elapsed time 511.90 14.45
parse time elapsed 163.60 4.62
PL/SQL execution elapsed time 84.88 2.40
hard parse elapsed time 27.08 0.76
sequence load elapsed time 17.88 0.50
hard parse (sharing criteria) elapsed time 0.01 0.00
repeated bind elapsed time 0.00 0.00
DB time 3,543.74
background elapsed time 513.68
background cpu time 351.72

变更后:

Statistic Name Time (s) % of DB Time
DB CPU 1,661.42 74.02
sql execute elapsed time 1,558.64 69.44
PL/SQL execution elapsed time 66.66 2.97
parse time elapsed 37.24 1.66
hard parse elapsed time 15.09 0.67
connection management call elapsed time 8.37 0.37
sequence load elapsed time 3.53 0.16
PL/SQL compilation elapsed time 0.49 0.02
hard parse (sharing criteria) elapsed time 0.08 0.00
failed parse elapsed time 0.08 0.00
repeated bind elapsed time 0.00 0.00
DB time 2,244.66
background elapsed time 669.28
background cpu time 382.82

性能分析:

从这2个awr报告对比来看修改为长连接后单位小时的CPU TIME与DB TIME均有所下降,CPU TIME从原来的2430s下降到1661s,降幅为769s。但分析2个报告中的每秒逻辑读可以发现修改为长连接后的逻辑读反而增加了。CPU TIME主要可以分为parse cpu,execute cpu和fetch cpu。短连接时一小时的parse time即解析时间为163s;另外因为短连接时每秒登录数达到16个,Oracle为建立连接(connection management call)耗时511s。

总结以下几点:
1.短连接情况下因为新建立的会话没有缓存游标信息,进而导致无法避免大量的软解析,解析消耗了163s的DB TIME。修改为长连接后解析数量明显减少,解析仅消耗37s的DB TIME。
2.短连接情况下每秒登录数达到16次,建立连接(connection)同样会消耗大量的CPU TIME,这里connection management call消耗了约500s的CPU TIME。修改为长连接后每秒Logons数为0.36,节约了大量无谓的CPU浪费。
3.改为长连接后Top SQL的平均每次逻辑读并未下降,部分Top SQL的执行次数还有所增加;可见通过减少不必要的解析和反复建立连接,系统的性能得到了释放
4.原短连接的AWR报告中显示该时段内出现行锁等待(row lock contention)共463次,总耗时为229s,该等待事件也是造成2个报告中DB TIME差异的一个因素。而长连接报告中则没有该等待出现,这可能是出于偶然,也可能是程序修改导致的。

沪ICP备14014813号-2

沪公网安备 31010802001379号