一条看似平常的报警邮件所做的分析(r8笔记第9天)

今天留意到一封报警邮件。内容如下：

ZABBIX-监控系统: 
------------------------------------
报警内容: CPU utilization is too high
------------------------------------
报警级别: PROBLEM
------------------------------------
监控项目: CPU idle time：45.92 % 
------------------------------------ 
报警时间:2016.02.14-15:45:10

这个问题发生的时间很短，持续没多长时间就自动恢复了，但是还是引起了我的注意。 登录到环境之后，查看系统的整体负载情况。发现在问题时间段里，确实CPU使用率较高。 03:20:01 PM CPU %user %nice %system %iowait %steal %idle 03:30:01 PM all 0.37 0.00 0.22 0.17 0.00 99.25 03:40:01 PM all 18.03 0.00 0.19 0.18 0.00 81.60 03:50:01 PM all 50.94 0.00 0.13 0.17 0.00 48.75 04:00:01 PM all 75.45 0.00 0.15 0.15 0.00 24.24 04:10:01 PM all 64.55 0.00 2.23 0.25 0.00 32.97 04:20:01 PM all 57.27 0.00 0.91 0.28 0.00 41.54 对于这种情况，首先通过crontab排除了例行的维护任务,从而可以初步推断系统级没有特定的任务。 这个负载很可能来自于数据库层面，那么对于数据库层面的分析如下。 这个数据库实例的DB time，抖动不够明显。 BEGIN_SNAP END_SNAP SNAPDATE DURATION_MINS DBTIME ---------- ---------- -------------------- ------------- ---------- 18981 18982 14 Feb 2016 11:00 60 4 18982 18983 14 Feb 2016 12:00 60 4 18983 18984 14 Feb 2016 13:00 60 4 18984 18985 14 Feb 2016 14:00 60 14 18985 18986 14 Feb 2016 15:00 60 8 18986 18987 14 Feb 2016 16:00 60 32 18987 18988 14 Feb 2016 17:00 59 6 18988 18988 14 Feb 2016 18:00 60 0 但是逻辑读在下午的时间段里，确实出现了一个较大的抖动。

所以可以基本断定这个问题来自数据库层面，而且很可能来自sql语句。 当然了我也确实比较懒，对于这种问题，懒得生成awr了，直接用一个脚本来挖掘问题时间段内的快照数据。 $ sh showsnapsql.sh 18987 Current Instance ~~~~~~~~~~~~~~~~ DBID DB_NAME INST_NUM INST_NAME ---------- --------------------------- ---------- ------------------------------------------------ 1825607545 TESTDB 1 testdb SNAP_ID SQL_ID EXECUTIONS_DELTA ELAPSED_TI PER_TOTAL ---------- --------------------------------------- ---------------- ---------- ---------- 18987 c1mddahtwj7y1 1051 1388s 83% 18987 cr32qwhysqkn9 65364 112s 6% 18987 fgwt4xab7fhgt 138553 40s 2% 18987 7kt7x4s5ps0hu 836 38s 2% 18987 520mkxqpf15q8 410907 16s 1% 第一条语句毫无疑问是值得注意的部分。语句情况如下： SQL_FULLTEXT ---------------------------------------------------------------------------------------------------- UPDATE TEST_DEAL_INFO SET FLAG='0',SMS_SEND_TIME=SYSDATE WHERE ID=:1 但是查看执行计划，发现走了全表扫描。 --------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | --------------------------------------------------------------------------------------- | 0 | UPDATE STATEMENT | | | | 70961 (100)| | | 1 | UPDATE | TEST_DEAL_INFO | | | | | |* 2 | TABLE ACCESS FULL| TEST_DEAL_INFO | 1 | 10 | 70961 (1)| 00:14:12 | --------------------------------------------------------------------------------------- 那么这个问题就很明显了。需要一个相关的索引，在简单分析相关的语句之后，发现根据表的字段情况和使用的sql情况，目前只需要在id列添加索引即可。 当然简单添加之后，问题就会引刃而解。 不过在解决之后简单看了下这个环境还是不经意发现了一些问题，既然添加了索引，对应的表空间情况如下： Tablespace Total MB Free MB Used MB ----------------------- ---------- ----------- - MEG_DATA 100 98 2 MEG_INDEX 100 98 2 RECALL_DATA 77,774 28,928 48,846 RECALL_INDEX 98,444 28,889 69,555 SYSAUX 1,120 75 1,045 SYSTEM 770 2 768 TEMP 15,187 15,187 0 UNDOTBS1 3,810 3,770 40 USERS 154 8 145 有没有发现什么问题？ 问题之一就是这个表空间的使用率有些奇怪，怎么索引所在的表空间使用率比数据还高了。如果是按照这种情况下，会有大量的索引存在，过多的索引，本身对于表 的数据维护代价就比较高，而且这种索引比较多的情况很可能都是单键值索引，是否可以考虑复合索引。 带着疑问查看了一下索引的使用情况，奇怪的是没有发现什么问题，但是数据有一部分对不上，最后使用下面的语句来定位，发现了另外一个问题。 SQL> select owner,segment_type,sum(bytes/1024/1024) size_MB from dba_segments where tablespace_name='RECALL_INDEX' group by owner,segment_type; OWNER SEGMENT_TYPE SIZE_MB -------------------- -------------------- ---------- SYS INDEX 48021.4375 TEST INDEX 21528.3125 这个索引表空间是由SYS和TEST两个用户共同使用，SYS竟然使用了近48G的空间，这个确实有些奇怪。为什么呢？ 进一步分析发现，有一个表存在两个索引。每个索引大概是24G左右，表里本身就含有大量的历史数据。 INDEX_NAME TABLE_NAME ----------------------------- ------------------------- RFR_CN_MASTER_INDEX TEST_TIMELY_FOX FRF_LOGIN_TIME_INDEX TEST_TIMELY_FOX 而且表的段大小是15G左右，但是索引大小已经远大于数据段了，所以这部分索引需要考虑重建。 而且可以进一步和开发的同学确实，是否需要保留很早以前的索引。 在这个基础上，其实也可以进一步分析，写个脚本找出这类问题数据段，索引段来。