备库报警邮件的分析案例(二) (r7笔记第15天)

时间:2022-05-04
本文章向大家介绍备库报警邮件的分析案例(二) (r7笔记第15天),主要内容包括其使用实例、应用技巧、基本知识点总结和需要注意事项,具有一定的参考价值,需要的朋友可以参考一下。

备库报警邮件的分析案例(一) (r7笔记第14天)

在第一篇中分享了关于备库报警邮件的分析,发现很多问题都是一环扣一环. 起初是通过监控主库中的v$dataguard_status发现备库中可能存在一些问题,结果逐步分析,发现是由备库的crontab触发了备库的定时 read-only和online状态,(即只读和应用日志,10gR2的环境),而这些关键信息都是从数据库的alert日志中发现的,但是问题还没有 完,才刚刚开始,因为发现备库中竟然有ORA-1652: unable to extend temp segment by 128 in tablespace的错误,这在备库中着实是很奇怪的,备库在read-only状态时会有什么样的sql语句对于temp消耗如此之大?通过对比主备 库发现,主库仅仅为32G,而备库却有近98G大小,而且从历史记录来看,这个错误一致存在,也算是一个历史遗留问题吧。 通过分析temp的空间占用情况,发现系统级的磁盘空间确实也不够了。目前只保留了20G左右,如果系统出现了大的业务抖动,这备库的空间使用是岌岌可危的。 在暂时没有办法去换取硬件的情况下,就可以考虑删除两个临时数据文件,但是这个时候就需要明白为什么备库要3个临时数据文件,这种使用是否合理,是不是哪里出了问题。 对于这个问题,自己也走了一点弯路,那就是通过ash的思路来分析。 在备库中抓取了问题时间段里的ash报告,发现下面两条sql貌似占有了一定的比例。 Top SQL Statements

SQL ID

Planhash

% Activity

Event

% Event

SQL Text

57j9uu7c9681a

672161835

34.48

db file sequential read

27.59

SELECT * FROM TEST_CN_BIND WHERE CN...

CPU + Wait for CPU

6.90

2w4d3aa19719s

935831560

17.24

db file sequential read

15.52

SELECT CN_MASTER, PASSWD, BIND...

top1的语句为 SELECT * FROM TEST_CN_BIND WHERE CN=:1 AND CN_TYPE IN(1, 2, 3) AND ENAABLED='Y' ORDER BY CN_TYPE 执行计划为: Execution Plan ----------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ----------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 3 (100)| | | 1 | SORT ORDER BY | | 1 | 43 | 3 (34)| 00:00:01 | | 2 | TABLE ACCESS BY INDEX ROWID| TEST_CN_BIN | 1 | 43 | 2 (0)| 00:00:01 | | 3 | INDEX RANGE SCAN | IDX_CN_BIND_CN | 1 | | 1 (0)| 00:00:01 | ----------------------------------------------------------------------------------------------- 通过这个也着实看不出有什么问题了,top 2的语句也是类似的情况。 这个时候就有些迷茫了,到底是什么原因导致了temp的过度使用。 这个问题回过头来看,首先要明白什么操作可能会消耗大量的temp,使用temp的场景有下面几种 - 索引创建或重创建. - ORDER BY or GROUP BY - DISTINCT 操作. - UNION & INTERSECT & MINUS 等集合运算 - Sort-Merge joins. - Analyze 操作 --其它异常 那么到底可能是什么原因呢,查看了所有的top sql发现只有top1的语句含有order by的字样,但是通过执行计划来分析,却实在分析不出来更多的数据,因为确实走了索引,这个索引列重复值极低,所以order by的代价非常小,尽管执行频率极高,有大概百万的调用次数 Stat Name Statement Per Execution % Snap ------------------------------------ -------------- ------- Elapsed Time (ms) 760,955 0.8 40.6 CPU Time (ms) 80,327 0.1 11.7 Executions 1,007,536 N/A N/A Buffer Gets 4,223,066 4.2 52.4 Disk Reads 110,754 0.1 45.3 Parse Calls 1,007,396 1.0 40.0 Rows 185,860 0.2 N/A User I/O Wait Time (ms) 684,686 N/A N/A Cluster Wait Time (ms) 0 N/A N/A Application Wait Time (ms) 0 N/A N/A Concurrency Wait Time (ms) 0 N/A N/A Invalidations 0 N/A N/A Version Count 8 N/A N/A Sharable Mem(KB) 127 N/A N/A 所以看着这个报告,让人着实摸不着头脑,这个时候也不能风风火火开始调优,既然自己都说不通自己,那么到底是怎么消耗的temp,这些还是需要找到靠谱的理由来。 而temp的使用情况是一个动态的过程,所以直接通过历史视图等等是无从知晓的。 我们可以使用手工监控的方式来做。 第一个脚本为: 语句为check_temp.sh ##check_temp.sh function get_temp_usage { sqlplus -s / as sysdba < set time on set pages 100 set linesize 200 col sysdate format a10 col username format a15 col sid format 9999 col serial# format 99999 col blocks format 99999999 col sql_text format a70 set feedback off select systimestamp from dual; set feedback on SELECT sysdate,a.username, a.sid, a.serial#, a.osuser, b.blocks, c.sql_text FROM v$session a, v$sort_usage b, v$sqlarea c WHERE b.tablespace = 'TEMP' and a.saddr = b.session_addr AND c.address= a.sql_address AND c.hash_value = a.sql_hash_value AND b.blocks*8192 > 0 ORDER BY b.tablespace, b.blocks; EOF } get_temp_usage 第二个就是个种子程序来调用,给定10秒的轮询。 $ cat tmp.sh for i in {1..36000} do sh check_temp.sh >> check_temp.log sleep 10 done 这种守株待兔的方式看起来不是很灵活,但是着实有效。 昨晚写好之后来看,早上收网就发现有收获了。发现在早晨的特定时间段里,有两个session在运行同样的sql语句,语句的temp使用起初不大。都是4000多个block,大概是31M


SYSTIMESTAMP
-----------------------------------------------------
11-NOV-15 06.00.21.907858 AM +08:00
 
SYSDATE    USERNAME     SID SERIAL# OSUSER      BLOCKS SQL_TEXT
---------- ---------- ----- ------- ------------------ ----------------------------------------------------------------------
2015-11-11 TEST_SHINK  6553   47693 webadmin      4352 select c.cn as  cn, c.uin as uin from (select cn from test_cn_bind where ena
 06:00:21                                              bled='Y' group by cn having count(cn)>1) t, cn_bind c where t.cn = c.c
                                                       n and c.enabled='Y' order by cn

2015-11-11 TEST_SHINK  6533   60000 webadmin      4480 select c.cn as  cn, c.uin as uin from (select cn from test_cn_bind where ena
 06:00:21                                                   bled='Y'  group by cn having count(cn)>1) t, cn_bind c where t.cn = c.c
                                                            n and c.enabled='Y' order by cn

但是继续往下看,就发现这个问题就开始突出了。
SYSDATE    USERNAME          SID SERIAL# OSUSER    BLOCKS SQL_TEXT
---------- --------------- ----- ------- -------- ------- ----------------------------------------------------------------------
2015-11-11 TEST_SHINK       6553   47693 webadmin 3302400 select c.cn as  cn, c.uin as uin from (select cn from test_cn_bind where ena
 06:57:37                                                 bled='Y' group  by cn having count(cn)>1) t, test_cn_bind c where t.cn = c.c
                                                          n and c.enabled='Y' order by cn
 
2015-11-11 TEST_SHINK       6533   60000 webadmin 3302400 select c.cn as  cn, c.uin as uin from (select cn from test_cn_bind where ena
 06:57:37                                                 bled='Y' group  by cn having count(cn)>1) t, test_cn_bind c where t.cn = c.c
                                                          n and c.enabled='Y' order by cn
按照这个量级和使用情况,一条语句需要消耗的temp大小为近26G,两条sql占用的就是52G
SQL> select 3302400*8192/1024/1024 size_MB from dual;
   SIZE_MB
----------
     25800
听起来似乎还是有余地,不是配置了98G的temp空间吗,应该还够用,但是继续往下看就发现后面还会有其它的session进来。最多的时候差不多8个,这样计算的话,98G的空间也是不够的。
来看看这个语句的资源消耗,预估是近18G的temp使用。
----------------------------------------------------------------------------------
| Id  | Operation              | Name       | Rows  | Bytes |TempSpc| Cost (%CPU)|
----------------------------------------------------------------------------------
|   0 | SELECT STATEMENT       |            |    29M|  1654M|       |  5361K  (4)|
|   1 |  SORT ORDER BY         |            |    29M|  1654M|  2032M|  5361K  (4)|
|*  2 |   HASH JOIN            |            |    29M|  1654M|  1037M|  4941K  (4)|
|   3 |    VIEW                |            |    29M|   700M|       |  2696K  (5)|
|*  4 |     FILTER             |            |       |       |       |            |
|   5 |      HASH GROUP BY     |            |    29M|   756M|    19G|  2696K  (5)|
|*  6 |       TABLE ACCESS FULL|TEST_CN_BIND|   587M|    14G|       |   898K  (5)|
|*  7 |    TABLE ACCESS FULL   |TEST_CN_BIND|   587M|    18G|       |   898K  (5)|
----------------------------------------------------------------------------------   
Predicate Information (identified by operation id):                               
---------------------------------------------------                                                
   2 - access("T"."CN"="C"."CN")                                                  
   4 - filter(COUNT(*)>1)                                                         
   6 - filter("ENABLED"='Y')                                                      
   7 - filter("C"."ENABLED"='Y')                                                  
有同事提问是否这个语句存在并行的可能性,显然是不会的,一来从执行计划中没有任何痕迹,二来如果是并行,session应该同时被监控出来,而不是后面逐步多起来。
这条语句如果细看还是存在一定的问题,这么大的表引用了两次同一个大表,其实完全可以改写为更简单的形式
select c.cn as cn,c.uin from test_cn_bind c where enabled='Y' group by c.cn,c.uin having count(c.cn) >1;
当然这个时候在备库中还是可以考虑使用并行资源的。