备库报警邮件的分析案例(二)

在第一篇中分享了关于备库报警邮件的分析,发现很多问题都是一环扣一环.
起初是通过监控主库中的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 <<EOF
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;
当然这个时候在备库中还是可以考虑使用并行资源的。
可能到这个时候问题的分析就到此为止了,就可以质问开发的同学,为什么写出这么消耗资源的语句来,然后把他们痛批一顿,其实还真不是这样,而且这样也没有找到根本的原因,为什么需要这个查询,这是基于什么样的需求等等,其实还有很多需要改进的东西,比如在10g版本中备库的ash其实就是主库的这些信息,在11g以后就可以独立查看备库的ash了。在下一个章节继续再说这个问题的由来和改进。

时间: 2024-04-19 05:37:08

备库报警邮件的分析案例(二)的相关文章

备库报警邮件的分析案例(一)

今天早上到了公司后,收到了这样一封报警邮件,发现收到备库的报警案例也比较多,着实颠覆了我对备库基本不需要关注管理的观点.后面可以把几个案例做成一个主题来说说. 报警邮件的内容如下:  ZABBIX-监控系统: ------------------------------------ 报警内容: DG_issue ------------------------------------ 报警级别: PROBLEM ------------------------------------ 监控项目:

备库报警邮件的分析案例(三)

继前两篇分析了一个看似非常普通的报警邮件,结果在分析问题的时候八面玲珑,相关因素都给分析了一下,没想到还真是有不小的收获. 前两篇地址: http://blog.itpub.net/23718752/viewspace-1827685/ http://blog.itpub.net/23718752/viewspace-1829630/ 最后通过手工定位监控的方式终于把罪魁祸首揪了出来,为什么在备库使用ash无果,因为还是10g的库,还没有这个特性,在11g中才可以.这个也算是在10g中的一个监控

一封备库报警邮件的分析

对于orabbix报出的警报,自己都是心怀敬畏,因为这些表面的现象如果深入分析没准就能有所收获,当然目的还是解决问题,不是一味追求指标. 今天收到的报警邮件如下,然后在两分钟后问题自动恢复. ### ZABBIX-监控系统: ------------------------------------ 报警内容: DG_issue ------------------------------------ 报警级别: PROBLEM ----------------------------------

三封报警邮件的分析

今天收到3封报警邮件,从邮件内容中的报警情况来看,还是比较反常的.需要引起关注,找到原因处理. 这个库是一个历史库,库中的数据非常庞大,几十亿数据的表还是有好几个.但是访问频率很低,一般到历史库中所做的历史数据分析查询需求还是要少很多. 报警邮件如下,可以看到DB time的阀值还是很高的. #邮件1 [DB监控系统]_testdb2_hist_p@10.12.6.18_报警 ZABBIX-监控系统: ------------------------------------ 报警内容: DB t

PostgreSQL 备库apply延迟原理分析与诊断

标签 PostgreSQL , 物理流复制 , IO不对称 背景 开车的同学都喜欢一马平川,最好是车道很多,车很少,开起来爽. 大家想象一下,同样的车速,6车道每秒可以通过6辆车,而1车道每秒就只能通过1辆车. 好了,我们回到IO层面,我们在使用fio测试块设备的IO能力时,可以选择多少个线程进行压测,实际可以理解为开多少车道的意思. 只要没到通道或者设备本身的极限,当然开的车道(并发)越多,测出来的IO数据越好看.比如单线程可以做到每秒处理1万次请求,而开8个并发,可能处理能达到8万次请求.

一则备库CPU报警的思考

今天收到一封报警邮件,这引起了我的注意.当然过了一会,有收到了CPU使用率恢复的邮件. 报警邮件内容如下: ZABBIX-监控系统: ------------------------------------报警内容: Disk I/O is overloaded on ora_statdb2_s_xxx@xxxxx ------------------------------------报警级别: PROBLEM ------------------------------------监控项目:

数据库内核月报 - 2015 / 08-PgSQL · 答疑解惑 · RDS中的PostgreSQL备库延迟原因分析

背景 在RDS环境中,多租户使用同一台主机是很常见的事情,为了隔离用户资源,有很多手段,例如使用虚拟机,或者CGROUP技术.以CGROUP为例,可以控制进程的CPU使用.内存使用.块设备的IOPS或者吞吐速率等资源使用.限制资源的好处是可以在共用的硬件层面为多个用户提供承诺的性能指标.当然这种方法也有一定的弊端,例如当用户需要运行消耗较多资源的SQL的时候,无法利用机器的空闲资源,因为它被限制住了.还有一些弊端可能导致RDS的不稳定,本文将展开讨论其中的弊端之一,资源限制是如何导致备库延迟的.

由报警邮件分析发现的备库oracle bug

昨天到公司之后,收到两份封报警邮件,可以看到在早晨6:30左右主库的v$dataguard_status检查时发现了一个错误.然后再2分钟后就自动恢复了. 一般这种问题很自然想到可能是网络出现了一些问题.因为自动恢复了,所以也不同太着急处理,于是细细看了下.报警邮件如下: ZABBIX-监控系统: ------------------------------------ 报警内容: DG_issue ------------------------------------ 报警级别: PROBL

一条关于swap争用的报警邮件分析(一)

最近这些天有一台服务器总是会收到剩余swap过低的告警. 邮件内容大体如下: ############ ZABBIX-监控系统: ------------------------------------ 报警内容: Lack of free swap space on ora_test_s2_yangjr@10.127.2.xxxx ------------------------------------ 报警级别: PROBLEM -------------------------------