一條看似平常的報警郵件所做的分析
今天留意到一封報警郵件。內容如下：
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左右，但是索引大小已經遠大於資料段了，所以這部分索引需要考慮重建。
而且可以進一步和開發的同學確實，是否需要保留很早以前的索引。
在這個基礎上，其實也可以進一步分析，寫個指令碼找出這類問題資料段，索引段來。
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左右，但是索引大小已經遠大於資料段了，所以這部分索引需要考慮重建。
而且可以進一步和開發的同學確實，是否需要保留很早以前的索引。
在這個基礎上，其實也可以進一步分析，寫個指令碼找出這類問題資料段，索引段來。
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/23718752/viewspace-1988706/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- 一條關於swap爭用的報警郵件分析
- 一條關於swap爭用的報警郵件分析(一）
- 一條關於swap爭用的報警郵件分析(二）
- 備庫報警郵件的分析案例（一)
- 三封報警郵件的分析
- 一封備庫報警郵件的分析
- 備庫報警郵件的分析案例（二)
- 備庫報警郵件的分析案例(三)
- grafana的郵件報警AlertingGrafana
- zabbix郵件報警通知
- 由報警郵件分析發現的備庫oracle bugOracle
- zabbix郵件報警功能的驗證
- prometheus配置MySQL郵件報警PrometheusMySql
- 一條報警資訊的快速處理和分析
- 由一條日誌警告所做的調優分析
- zabbix 配置傳送郵件報警
- 兩條報警資訊的分析（第一篇)
- 使用Zabbix服務端本地郵箱賬號傳送報警郵件及指定報警郵件操作記錄服務端
- jenkins郵件報警機制配置Jenkins
- SQLServer郵件預警SQLServer
- pinpoint-docker開啟郵件報警和整合釘釘報警推送Docker
- 細述zabbix郵件報警常見問題
- supervisor守護程式並配置郵件報警
- zabbix監控之同時向多人郵件報警
- Linux 下如何用 mutt 設定郵件報警Linux
- UNIX系統高負載郵件報警指令碼負載指令碼
- 一條細小的報警簡訊的處理
- 基於Nginx+Keepalived的LB服務監控（郵件報警）Nginx
- 一條簡單的報警資訊發現的oracle bugOracle
- 表空間郵件預警(luckyfriends)
- oracle資料庫自動發郵件實現報警功能Oracle資料庫
- 伺服器磁碟監控指令碼分享（含報警郵件）伺服器指令碼
- 配置Jenkins構建失敗觸發郵件報警機制Jenkins
- 郵件開發：複雜郵件的一個示例
- 技術分享| 如何使用Prometheus實現系統監控報警郵件通知Prometheus
- Zabbix郵件預警-這個坑我跳了不止一次
- 網管員注意：保障郵件安全的七條措施
- linux通過cacti監控apache通過飛信郵件進行報警LinuxApache