480
由重啟引起的Oracle RAC節點宕機分析及追根溯源
作者介紹
裴征峰，現就職於北京海天起點，二線專家成員，南京辦事處負責人，OCP 10g、OCP 11g、OCM11g。超八年Oracle服務經驗，擅長數據庫故障診斷和性能調優。目前主要從事客戶的現場維護、重大問題的解決、數據庫性能分析、二線服務質量保證等工作。
1 背景說明
某省份的電信業務係統由於業務量較大，按地市劃分部署在4套配置相同的RAC上，相同主機版本，相同的CRS和數據庫版本。該係統已正常運行3年多，其間也有重啟主機等正常維護操作。從4月24日 開始，這個係統的4套RAC的節點，一個接一個地宕機重啟，但每次都不是同一個節點。整理的宕機情況列表如下：
係統 宕機時間
-----------------
xx1db01 04-24
xx1db02
xx2db01 07-30
xx2db02 07-23
xx3db01 08-19
xx3db02 07-27
xx4db01
xx4db02
這4套RAC是3年前安裝的，平時運行非常穩定，基本沒有問題，從4月份開始有節點宕機，並且在7，8月份宕機頻率非常高。但有點比較奇怪，每次宕機都是不同的節點，沒有相同的節點發生宕機。由於配置了業務隔離，所以RAC宕一個節點，對業務影響不大，但是如此大規模的節點宕機，肯定有一些共性的問題。
每次宕機基本為ocssd.bin進程出錯，直接重啟節點。ocssd.bin報錯的日誌基本為：
clssscExit: CSSD signal 11 in thread GMClientListener
這4套RAC的配置如下：
-
主機版本：HP-UX B.11.31 U ia64
-
數據庫CRS版本為：10.2.0.5.0（未打PSU）
-
數據庫版本為：10.2.0.5.8（PSU號：13923855）
-
安裝了Veritas Storage Foundataion，使用VCS集群文件係統。
2 4月24日宕機分析過程
4月24日，xx1db01節點宕機，這是這套業務係統的第一次節點宕機。由於沒有安裝OSWatch工具，無法得知宕機時操作係統資源情況。
檢查操作係統日誌，沒有發現報錯信息。這可能是係統直接重啟時，還沒有來得及把內存中的信息刷到磁盤。檢查數據庫的alert日誌，宕機重啟時數據庫實例沒有異常信息。
檢查ocssd.log，發現如下報錯：
clssscExit：CSSD signal 11 in thread這個報錯以前沒有碰見過。
對這個報錯的相關解釋：當RAC GM client監聽線程在處理"clsc_disc_orphans"時，CSSD.LOG中會出現"clsc_disc_orphans"的信息，該函數在處理clsc_disc嚐試斷開連接時，負責獲得和持有線程信息。存在BUG(Bug 9132429: LNX64-10205-CRS:NODE CRASH AFTER 5 MINUTES OF HANG/RESUME OCSSD.BIN。)可能導致多個session形成死鎖，最終導致節點HANG住或被驅逐宕機。
MOS上的這個Bug 9132429是在Linux平台上，當前主機是HP-UX。請網絡組檢查心跳交換機，沒有發現閃斷或者其它異常。由於沒有檢查到有用的信息，認為這可能是ocssd.bin進程的偶然報錯現象，暫時沒法解釋這個問題。
3 7月23日宕機分析過程
07月23日，xx2db02發生宕機，檢查結果和4月23日一樣，其它全部沒有信息，隻有ocssd.log日誌信息如下：
經過確認，主機重啟是由於ocssd的GMClientListener問題導致。由於未在主機上安裝係統資源監控工具，沒有有效的主機資源使用情況。在MOS上了開SR，SR回複可能是主機資源使用存在問題，但沒有OSW的信息，他們給不出解釋。
4 7月27日宕機分析過程
7月27日，xx3db02宕機，Oracle Support認為在ocssd.log中存在Authentication OSD error信息，可能是認證失敗導致GMClientListener發生問題，進而cssd.bin進程宕掉。相關日誌信息如下：
認證信息失敗的原因，可能有以下幾點：
1、節點間有防火牆 【沒有配置】
2、節點間有authentication tools 【未配置】
3、$ORA_CRS_HOME/crs/css目錄權限發生改變 【未發生】
4、/oracle文件係統滿 【未滿】
5、/tmp目錄下的.oracle目錄被刪除 【未刪除】
6、節點間認證信息網絡包發生問題 【無證據】
而前兩次宕機，沒有Authentication OSD error的信息，所以沒有直接證據表明Authentication OSD error造成了CSSD signal 11 in thread GMClientListener，Authentication OSD error錯誤信息也可能是結果，不是根本原因。
監控係統上主機資源使用情況如下，CPU使用率：
IO使用率：
SR認為監控粒度太粗。給這4套RAC、8個節點全部安裝了OSWatch，下次如果有其它節點宕機就有詳細的操作係統資源使用信息。
5 7月30日宕機分析過程
7月30日，xx2db01宕機，日誌信息如下：
發生“clsc_event_hndlr: (6000000000ae51b0) answer error, rc 15”，Oracle認為是操作係統發生了問題。
檢查ulimit信息：
root@xx2db01:/#ulimit -a
time(seconds) unlimited
file(blocks) unlimited
data(kbytes) 4194300
stack(kbytes) 392192
memory(kbytes) unlimited
coredump(blocks) 4194303
nofiles(descriptors) 20480
root@xx2db01:/#su - oracle
oracle@xx2db01:/oracle#ulimit -a
time(seconds) unlimited
file(blocks) unlimited
data(kbytes) 4194300
stack(kbytes) 392192
memory(kbytes) unlimited
coredump(blocks) 4194303
nofiles(descriptors) 20480
檢查file相關的內核參數：
oracle@xx2db01:/oracle#/usr/sbin/kctune |grep file
fcache_seqlimit_file 100 Default Immed
filecache_max 130470211584 Default Auto
filecache_min 13047017472 Default Auto
max_acct_file_size 2560000 Default Immed
maxfiles 20480 20480
maxfiles_lim 20480 20480 Immed
檢查nproc內核參數：
oracle@xx2db01:/oracle#/usr/sbin/kctune |grep nproc
nproc 30000 30000 Immed
oracle@xx2db01:/oracle#/usr/sbin/kctune nfile
Tunable Value Expression Changes
nfile 0 Default Immed
SR認為這些參數都正常。上次故障時，在所有節點上都安裝了OSW工具，這次有了相關主機資源信息。經過檢查，vmstat中顯示：從7月30號的08:42到宕機時的09:34，一直存在pi的情況，而空閑內存為11g左右。xx2db01主機是256G內存，sga_max_size=100g，pga_aggregate_target=40g。
宕機時vmstat信息如下，空閑內存為11g，有一些內存頁交換。
而正常情況下xx2db01主機的空閑內存是100g，pi基本為0。
經過檢查，內核參數filecache_max 130470211584 Default Auto這個參數表明主機允許文件緩存最大為130g左右，該參數設置較高，有可能占用大部分內存，但是OSWatch沒有監控這個參數，所以宕機時無文件係統緩存的相關信息。當前使用了Veritas ODM，基本用不到操作係統緩存，建議把該參數調整到10g。
在宕機時的ps輸出文件中存在大量的sendmail和rmail進程，但具體不清楚是什麼作用。
這次故障的原因，猜測是主機swap造成，但從vmstat中監控到主機空閑內存還有11g左右（主機內存是256g），不怎麼確認一定是主機內存耗盡導致ocssd.bin出現故障。
暫時建議：
filecache_max調整到10g左右，減小文件係統占用內存導致宕機的概率。
調整CSSD的日誌級別為4，讓cssd出故障時，輸出更多的日誌信息。
crsctl debug log css CSSD:4
6 8月19日宕機分析過程
8月19日，xx3db01節點也是因為“CSSD signal 11 in thread GMClientListener”發生宕機重啟。vmstat查看宕機時內存使用情況，發現宕機時空閑內存有將近80g，這又排除了內存緊張，主機swap導致的問題。
通過詳細檢查OSWatch日誌，發現了宕機時ocssd.bin內存占用達到8g。
跟SR交流，SR建議以下ulimit設置為unlimited，如下：
data(kbytes) unlimited
stack(kbytes) unlimited
我檢查了7月30日宕機時，ocssd.bin的大小，發現也是8g左右。
懷疑是不是進程所使用的內存達到限製導致，這時侯我谘詢了主機工程師，是否有內核參數，限製一個進程能夠使用的內存大小，查到如下參數：
root@xx3db01:/ # kctune | grep maxdsiz
maxdsiz 4294963200 4294963200 Immed
maxdsiz_64bit 8589934592 8589934592 Immed
這兩個參數解釋如下：
maxdsiz、maxdsiz_64bit，是指任何用戶進程的數據段的最大大小（以字節為單位）。HP-UX 係統上的用戶程序由五個不連續的虛擬內存段組成：文本（或代碼）、數據、堆棧、共享的和 I/O。每個段都占用一段已設定大小上限的結構化定義的虛擬地址空間範圍，但由於 maxtsiz、maxdsiz 和 maxssiz 可調參數的強製約束，文本、數據段和堆棧段的最大值可能會略小。此可調參數定義了 32 位和 64 位進程的靜態數據存儲段的最大大小。數據存儲段包含了固定的數據存儲，例如使用 sbrk() 和 malloc() 在main()、字符串和空間中分配的全局變量、數組變量、靜態變量和局部變量。
檢查其它HP-UX上的10g庫，發現10.2.0.4的RAC，ocssd.bin內存占用正常，而所有10.2.0.5版本的ocssd.bin內存占用在緩慢增加。
檢查未發生過宕機的xx4db02節點上ocssd.bin進程一段時間的內存使用情況，確認存在內存泄露問題。
猜想可能是內存泄露導致了ocssd.bin內存占用過高，達到操作係統限製，造成ocssd.bin出現問題，進而宕機重啟。經過到MOS上檢查，發現如下Bug：
Memory usage of crsd.bin and ocssd.bin keeps growing after upgrade to 10.2.0.5 (文檔 ID 1633236.1)
Bug 11704113 - OVER TIME THE MEMORY USAGE OF THE CRSD.BIN PROCESS GROWS TO VERY LARGE VALUES
SR也確認是由於crsd.bin的nsdo()函數發生內存泄露，導致ocssd.bin受影響。當前情況與MOS文檔上描述一致。
7 總結
問題的根本原因是，由於存在如下Bug：
Memory usage of crsd.bin and ocssd.bin keeps growing after upgrade to 10.2.0.5 (文檔 ID 1633236.1)
Bug 11704113 - OVER TIME THE MEMORY USAGE OF THE CRSD.BIN PROCESS GROWS TO VERY LARGE VALUES
導致ocssd.bin進程的內存使用率持續上升，達到了maxdsiz_64bit內核參數的限製，進而造成ocssd.bin進程故障，ocssd.log日誌中的“clssscExit: CSSD signal 11 in thread GMClientListener”信息，signal 11代表內存申請失敗。
解決辦法有兩個：
-
打CRS補丁11704113
-
由於內存泄露緩慢，可能要半年到一年左右，ocssd.bin的內存使用才能達到限製，並且隻有在特定的版本和平台上存在這個問題，可以監控一下ocssd.bin進程的內存使用率，在快達到限製前，手工重啟下CRS。
這個問題非常之隱蔽，會被很多因素遮蓋掉，因為在1年時間之內，主機很可能因為維護、硬件故障等造成了主機重啟，而重啟主機後CRS的ocssd.bin進程的內存就釋放了，又要經過長時間的內存泄露才會觸發。如果沒有多套RAC的長時間穩定運行，宕機後操作係統資源使用數據的相互交叉比對，很難診斷出根本原因。
原文發布時間為：2016-12-26
本文來自雲棲社區合作夥伴DBAplus
最後更新：2017-05-13 08:42:25