今天留意到一封报警邮件。内容如下:
代码语言:javascript复制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左右,但是索引大小已经远大于数据段了,所以这部分索引需要考虑重建。
而且可以进一步和开发的同学确实,是否需要保留很早以前的索引。
在这个基础上,其实也可以进一步分析,写个脚本找出这类问题数据段,索引段来。