一條看似平常的報警郵件所做的分析

今天留意到一封報警郵件。內容如下：
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左右，但是索引大小已經遠大於資料段了，所以這部分索引需要考慮重建。
而且可以進一步和開發的同學確實，是否需要保留很早以前的索引。
在這個基礎上，其實也可以進一步分析，寫個指令碼找出這類問題資料段，索引段來。