三封报警邮件的分析

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

##邮件2
ZABBIX-监控系统:
------------------------------------
报警内容: DB time is too high
------------------------------------
报警级别: PROBLEM
------------------------------------
监控项目: DBtime：1403 %
------------------------------------
报警时间:2015.10.21-05:19:35

#邮件3
ZABBIX-监控系统:
-------------------------------
监控项目: DBtime_447 %
------------------------------------
主机名称：testdb2_hist_p@10.12.6.18
------------------------------------
恢复时间:2015.10.21-05:29:38

通过这三封邮件可以看到，问题持续了有近20分钟，然后恢复正常。
那么这种抖动通过快照级的数据情况来看，还是可以体现出明显的浮动。
Current Instance
~~~~~~~~~~~~~~~~
      DBID DB_NAME     INST_NUM INST_NAME
---------- --------- ---------- ----------------
2534640677 testdb2            1 testdb2
DB_NAME   BEGIN_SNAP   END_SNAP SNAPDATE                    LVL DURATION_MINS     DBTIME
--------- ---------- ---------- -------------------- ---------- ------------- ----------
testdb2    45336      45337 21 Oct 2015 00:00             1            30          0
               45337      45338 21 Oct 2015 00:30             1            30          0
               45338      45339 21 Oct 2015 01:00             1            30          0
               45339      45340 21 Oct 2015 01:30             1            30          4
               45340      45341 21 Oct 2015 02:00             1            30         40
               45341      45342 21 Oct 2015 02:31             1            30         30
               45342      45343 21 Oct 2015 03:00             1            29         31
               45343      45344 21 Oct 2015 03:30             1            30         31
               45344      45345 21 Oct 2015 04:00             1            30         31
               45345      45346 21 Oct 2015 04:30             1            30         31
               45346      45347 21 Oct 2015 05:00             1            30        131
               45347      45348 21 Oct 2015 05:30             1            30          0
               45348      45349 21 Oct 2015 06:00             1            30          3
这个时候自己就对自己提出一个问题，为什么平时不会报出这个问题？
下面的图是两天内的DB time情况，通过下面的图可以看到DB time前一天是到了临界阀值，但是还没有越界，所以没有报警，而昨天却又很大的抖动。

通过下面的图可以看到，在凌晨的时候，不只报警的时间点存在大量的等待时间，主要等待时间为multiblock read，而且持续时间还是几个小时。

可见还是存在着大量的读操作，相对来说还是比较高的。
鉴于此，基本可以推断可以是sql级的原因导致的，先抓取一个报告，看看在问题时间段里，哪些sql占用了大量的DB time
ksh showsnapsql.sh 45347
   SNAP_ID SQL_ID        EXECUTIONS_DELTA ELAPSED_TI PER_TOTAL
---------- ------------- ---------------- ---------- ----------
     45347 b6usrg82hwsa3                1 391s       47%
     45347 3rz14z1006jbk               18 290s       35%
     45347 53yakkh4cbmp9                3 98s        12%
     45347 4yf9vjwa2yg5j                6 9s         1%
     45347 04m0jsy80udjp                6 0s         0%
从这个图可以看出，问题还是比较明显的，sql_id为b6usrg82hwsa3的语句占用了大量的DB time.
那么来看看是怎么样的一条sql语句，抓取下来看到竟然是一个后台job.
SQL_FULLTEXT
----------------------------------------------------------------------------------------------------
call dbms_stats.gather_database_stats_job_proc (  )
对于这个问题，同样有一些疑点，首先为什么今天的负载就格外高，平时也在运行这些自动任务。还有为什么job会持续很长的时间，每天都在消耗大量的资源。
查看数据库日志内容如下：
Wed Oct 21 02:00:15 2015
DBMS_STATS: GATHER_STATS_JOB encountered errors.  Check the trace file.
Errors in file /U02/app/oracle/diag/rdbms/testdb2/testdb2/trace/testdb2_j000_3799.trc:
ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.
Wed Oct 21 02:01:44 2015
End automatic SQL Tuning Advisor run for special tuning task  "SYS_AUTO_SQL_TUNING_TASK"
Wed Oct 21 06:01:28 2015
DBMS_STATS: GATHER_STATS_JOB encountered errors.  Check the trace file.
Errors in file /U02/app/oracle/diag/rdbms/testdb2/testdb2/trace/testdb2_j000_16901.trc:
ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.
Wed Oct 21 06:20:33 2015
Thread 1 advanced to log sequence 99940 (LGWR switch)
  Current log# 22 seq# 99940 mem# 0: +DATA/testdb2/onlinelog/group_22.863.811354265
Wed Oct 21 06:20:38 2015
Archived Log entry 215736 added for thread 1 sequence 99939 ID 0x9bd5d836 dest 1:
Wed Oct 21 08:00:00 2015
Closing scheduler window
Closing Resource Manager plan via scheduler window
Clearing Resource Manager plan via parameter     
create tablespace DETAIL_DATA_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
Completed: create tablespace TLDETAIL_DATA_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
create tablespace DETAIL_INDEX_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
Completed: create tablespace TLDETAIL_INDEX_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
create tablespace SERLOG_DATA_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
Completed: create tablespace TLSERLOG_DATA_20160110 datafile '+data' size 50m autoextend on next 10m maxsize 34359721984
通过这个日志可以看出还是存在两个问题，一个是因为尝试去收集统计信息的job失败了。还有一个是表在昨天创建了大量的表空间。
问题可以初步分解。报错的trace文件内容如下，发现是一个datapump的临时表导致的。
$ less /U02/app/oracle/diag/rdbms/testdb2/testdb2/trace/testdb2_j000_3799.trc
*** 2015-10-21 02:00:15.184
*** SESSION ID:(5090.5085) 2015-10-21 02:00:15.184
*** CLIENT ID:() 2015-10-21 02:00:15.184
*** SERVICE NAME:(SYS$USERS) 2015-10-21 02:00:15.184
*** MODULE NAME:(DBMS_SCHEDULER) 2015-10-21 02:00:15.184
*** ACTION NAME:(ORA$AT_OS_OPT_SY_5869) 2015-10-21 02:00:15.184
 
ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.

*** 2015-10-21 02:00:15.184
DBMS_STATS: GATHER_STATS_JOB: GATHER_TABLE_STATS('"SYS"','"ET$136C02550001"','""', ...)
DBMS_STATS: ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.

至于这个临时表为什么没有清除，还是历史原因，早已经存在很久了。所以还是可以验证后直接drop.
当然为了彻底解决问题还是抓取问题的本质，所以先删除这个有问题的临时表。
SQL> select owner,table_name from dba_tables where table_name like 'ET%';
OWNER                          TABLE_NAME
------------------------------ ------------------------------
SYS                            ET$136C02550001
SQL> DROP TABLE ET$136C02550001;
Table dropped.                          
这个时候还是先保留后台job enable,然后对比一下在同样的情况下，今天的负载情况。但是单纯来分析alert日志，发现每天的几个时段都都会存在ORA的问题。
$ grep -B5 "ORA-20011" alert*.log|grep 2015

Thu Oct 15 02:00:13 2015
Thu Oct 15 06:03:14 2015
Fri Oct 16 02:00:13 2015
Fri Oct 16 02:00:24 2015
Fri Oct 16 06:04:35 2015
Sat Oct 17 06:00:12 2015
Sat Oct 17 10:06:10 2015
Sat Oct 17 14:06:27 2015
Sat Oct 17 18:06:37 2015
Sat Oct 17 22:06:51 2015
Sun Oct 18 06:00:01 2015
Sun Oct 18 06:00:12 2015
Sun Oct 18 06:16:25 2015
Sun Oct 18 10:07:31 2015
Sun Oct 18 14:07:45 2015
Sun Oct 18 18:08:02 2015
Sun Oct 18 22:08:13 2015
Mon Oct 19 02:00:10 2015
Mon Oct 19 06:08:44 2015
Tue Oct 20 02:00:16 2015
Wed Oct 21 02:00:02 2015
Wed Oct 21 02:00:15 2015
Wed Oct 21 02:01:44 2015
Wed Oct 21 06:01:28 2015
所以这个问题看来还是影响很大，也算遗留历史问题。
至于为什么负载突然升高那么多，一般来说后台的自动任务的消耗还是相对较高，但是也高不了多少。为什么统计信息，统计信息收集的阀值，可以参考mos的文章。
Automatic Optimizer Statistics Collection on Partitioned Table (Doc ID 1592404.1)

时间： 2024-04-06 15:44:15

三封报警邮件的分析的相关文章

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

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

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

在第一篇中分享了关于备库报警邮件的分析,发现很多问题都是一环扣一环. 起初是通过监控主库中的v$dataguard_status发现备库中可能存在一些问题,结果逐步分析,发现是由备库的crontab触发了备库的定时read-only和online状态,(即只读和应用日志,10gR2的环境),而这些关键信息都是从数据库的alert日志中发现的,但是问题还没有完,才刚刚开始,因为发现备库中竟然有ORA-1652: unable to extend temp segment by 128 in tab

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

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

一封备库报警邮件的分析

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

对三封短邮件的答复

[来信1] 贺老师,您好!我现在大二了,也是梦想成为一位IT人,但是总感觉与别人有差距!我现在c++已经学了大部分了,自己买了c++primer中文板(第四版),但与教材差距很大,我现在感觉有点迷茫,该怎么办? [我的回答] 我很感兴趣你的"C++已经学了大部分"是什么意思:看某本书看了一大部分,看明白了或者只看了还是没有看明白,学了和学会不同:学过的内容是否有能力完成该做的实践,学会和做会不同.要学会,更要会做,这是活知识.如果不是建立在实践的基础上,你的差距恐怕不仅是与教材差距大.

一条看似平常的报警邮件所做的分析

今天留意到一封报警邮件.内容如下: ZABBIX-监控系统: ------------------------------------ 报警内容: CPU utilization is too high ------------------------------------ 报警级别: PROBLEM ------------------------------------ 监控项目: CPU idle time:45.92 % --------------------------------

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

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

两条报警信息的分析（第一篇)

任何规则都是固定的,但是人是活的,很多时候把一些细节之处结合起来,还是能够发现一些潜在的问题. 早上收到zabbix的报警,是两条看似很平常的短信. 一封邮件内容如下,这是一封报警邮件 报警内容: Free disk space is less than 20% on volume /U01 ------------------------------------ 报警级别: PROBLEM ------------------------------------ 监控项目: Free disk

Python监控主机是否存活,并发报警邮件

 利用python写了简单测试主机是否存活脚本,此脚本不适于线上使用,因为网络延迟.丢包现象会造成误报邮件,那么后续会更新判断三次ping不通后再发报警邮件,并启用多线程处理. 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 #!/usr/bin/env python # coding:UTF-8 import tim