1. 程式人生 > >一個ceph-osd異常DOWN掉的原因分析

一個ceph-osd異常DOWN掉的原因分析

今天早上,運維的兄弟報告說,ceph分散式儲存叢集同時有3個OSD異常DOWN掉。因為CEPH叢集是三份資料儲存的,所以對業務沒有什麼太大的影響,所以等有空再查根本原因。

同時報告了有一臺物理機當機了,做了重啟恢復的操作。

有空的時候對問題進行了分析,同事進行了預查,發現如下:

1、在osd down掉的一段時間,所有的CEPH節點的網路流量都高上去了。

2、3個OSD down掉的時候可以看到日誌是大概是說,本OSD斷言心跳斷掉了,所以由斷言觸發了關閉。

3、上面物理機當機的時時間與osd當機的時間基本上是同時。

由於物理機(KVM HOST)的問題比較嚴重,所以先查它的問題,檢視系統日誌發現是之前已經知道的一個原因導致的。這個原因是:由於這一批物理機部署的比較久,當時是安裝的centos7.0,kernel是3.10-123,由於我們使用了openvswitch,而這個版本的Kernel有一個openvswitch的Bug,在某些極端的狀況下,會出現Soft lockup的問題。由於升級kernel會影響客戶的VM,所以一直沒有升級。

再分析ceph osd down掉的問題

一開始懷疑是由於網路流量高導致的心跳不正常,最後發現在那個時間段,使用該儲存叢集的物理機的流量在那個時間段內都沒有流量異常,初步排除由於Guest OS導致的問題。

檢視監控流量圖,發現流量高的時間是在OSD down掉之後才發生的,所以更確定是因為ceph進行資料恢復導致的流量攀升,所以確定流量異常和OSD異常的關係是:OSD異常是因,流量異常是果。

再分析OSD異常的原因,首先發現monitor有以下日誌:

2015-09-11 05:50:50.941975 7fc7f0985700  1 [email protected](leader).osd e59081 prepare_failure osd.13 192.168.20.22:6806/23132 from osd.56 192.168.20.25:6828/4297 is reporting failure:1
2015-09-11 05:50:50.941995 7fc7f0985700  0 log_channel(cluster) log [DBG] : osd.13 192.168.20.22:6806/23132 reported failed by osd.56 192.168.20.25:6828/4297
2015-09-11 05:50:51.494959 7fc7f33be700  0 log_channel(cluster) log [INF] : pgmap v35579953: 2688 pgs: 2688 active+clean; 13309 GB data, 40498 GB used, 34722 GB / 75220 GB avail; 101082 B/s rd, 3726 kB/s wr, 883 op/s
2015-09-11 05:50:51.839815 7fc7f0985700  1

[email protected](leader).osd e59081 prepare_failure osd.13 192.168.20.22:6806/23132 from osd.12 192.168.20.22:6800/45218 is reporting failure:1
2015-09-11 05:50:51.839834 7fc7f0985700  0 log_channel(cluster) log [DBG] : osd.13 192.168.20.22:6806/23132 reported failed by osd.12 192.168.20.22:6800/45218
2015-09-11 05:50:52.551379 7fc7f33be700  0 log_channel(cluster) log [INF] : pgmap v35579954: 2688 pgs: 2688 active+clean; 13309 GB data, 40498 GB used, 34722 GB / 75220 GB avail; 159 kB/s rd, 4259 kB/s wr, 804 op/s
2015-09-11 05:50:52.822059 7fc7f0985700  1
[email protected]
(leader).osd e59081 prepare_failure osd.13 192.168.20.22:6806/23132 from osd.14 192.168.20.22:6820/4240 is reporting failure:1
2015-09-11 05:50:52.822077 7fc7f0985700  0 log_channel(cluster) log [DBG] : osd.13 192.168.20.22:6806/23132 reported failed by osd.14 192.168.20.22:6820/4240
2015-09-11 05:50:53.304056 7fc7f0985700  1 [email protected](leader).osd e59081 prepare_failure osd.13 192.168.20.22:6806/23132 from osd.97 192.168.20.29:6833/42329 is reporting failure:1
2015-09-11 05:50:53.304074 7fc7f0985700  0 log_channel(cluster) log [DBG] : osd.13 192.168.20.22:6806/23132 reported failed by osd.97 192.168.20.29:6833/42329
2015-09-11 05:50:53.304280 7fc7f0985700  1 [email protected](leader).osd e59081  we have enough reports/reporters to mark osd.13 down

大體意思就是說,有好幾個OSD都報告說osd.13DOWN掉了,既然大家都這麼說,那就認為它死了吧。

再看這個osd的日誌:

 -3722> 2015-09-11 05:50:34.371402 7f91c3e0f700  1 -- 192.168.20.22:6809/23132 <== osd.45 192.168.20.24:0/45829 1146487 ==== osd_ping(ping e59081 stamp 2015-09-11 05:50:34.557436) v2 ==== 47+0+0 (3343728556 0 0) 0x148d0200 con 0xab37220
 -3721> 2015-09-11 05:50:34.371436 7f91c260c700  1 -- 192.168.20.22:6808/23132 <== osd.45 192.168.20.24:0/45829 1146487 ==== osd_ping(ping e59081 stamp 2015-09-11 05:50:34.557436) v2 ==== 47+0+0 (3343728556 0 0) 0x6e2e800 con 0xab32c00
 -3720> 2015-09-11 05:50:34.371459 7f91c3e0f700  1 -- 192.168.20.22:6809/23132 --> 192.168.20.24:0/45829 -- osd_ping(ping_reply e59081 stamp 2015-09-11 05:50:34.557436) v2 -- ?+0 0x127f1400 con 0xab37220
 -3719> 2015-09-11 05:50:34.371547 7f91c260c700  1 -- 192.168.20.22:6808/23132 --> 192.168.20.24:0/45829 -- osd_ping(ping_reply e59081 stamp 2015-09-11 05:50:34.557436) v2 -- ?+0 0x1055e000 con 0xab32c00
 -3718> 2015-09-11 05:50:34.518138 7f91c260c700  1 -- 192.168.20.22:6808/23132 <== osd.90 192.168.20.28:0/13937 1146080 ==== osd_ping(ping e59081 stamp 2015-09-11 05:50:34.918851) v2 ==== 47+0+0 (2786616502 0 0) 0x15bfb800 con 0xadb44c0
 -3717> 2015-09-11 05:50:34.518181 7f91c260c700  1 -- 192.168.20.22:6808/23132 --> 192.168.20.28:0/13937 -- osd_ping(ping_reply e59081 stamp 2015-09-11 05:50:34.918851) v2 -- ?+0 0x6e2e800 con 0xadb44c0
 -3716> 2015-09-11 05:50:34.518227 7f91c3e0f700  1 -- 192.168.20.22:6809/23132 <== osd.90 192.168.20.28:0/13937 1146080 ==== osd_ping(ping e59081 stamp 2015-09-11 05:50:34.918851) v2 ==== 47+0+0 (2786616502 0 0) 0xff8fe00 con 0x11ce1600
 -3715> 2015-09-11 05:50:34.518307 7f91c3e0f700  1 -- 192.168.20.22:6809/23132 --> 192.168.20.28:0/13937 -- osd_ping(ping_reply e59081 stamp 2015-09-11 05:50:34.918851) v2 -- ?+0 0x148d0200 con 0x11ce1600
 -3714> 2015-09-11 05:50:34.686020 7f91af0da700  1 -- 192.168.20.22:6807/23132 <== osd.73 192.168.20.27:6825/23657 1691650 ==== osd_repop(client.2449020.0:3342441 3.13e e056913e/rbd_data.255e726b8b4567.0000000000000e46/head//3 v 59081'19449146) v1 ==== 929+0+8971 (805582020 0 3664754197) 0xdfa3c00 con 0xb401760
 -3713> 2015-09-11 05:50:34.686433 7f91af0da700  5 -- op tracker -- seq: 39473910, time: 2015-09-11 05:50:34.685145, event: header_read, op: osd_repop(client.2449020.0:3342441 3.13e e056913e/rbd_data.255e726b8b4567.0000000000000e46/head//3 v 59081'19449146)
 -3712> 2015-09-11 05:50:34.686618 7f91af0da700  5 -- op tracker -- seq: 39473910, time: 2015-09-11 05:50:34.685147, event: throttled, op: osd_repop(client.2449020.0:3342441 3.13e e056913e/rbd_data.255e726b8b4567.0000000000000e46/head//3 v 59081'19449146)
 -3711> 2015-09-11 05:50:34.686658 7f91af0da700  5 -- op tracker -- seq: 39473910, time: 2015-09-11 05:50:34.685897, event: all_read, op: osd_repop(client.2449020.0:3342441 3.13e e056913e/rbd_data.255e726b8b4567.0000000000000e46/head//3 v 59081'19449146)
 -3710> 2015-09-11 05:50:34.686712 7f91af0da700  5 -- op tracker -- seq: 39473910, time: 0.000000, event: dispatched, op: osd_repop(client.2449020.0:3342441 3.13e e056913e/rbd_data.255e726b8b4567.0000000000000e46/head//3 v 59081'19449146)

結合最後死掉的日誌,分析就是這個OSD和其它的OSD都不太能傳送和接受心跳包了,問題是,為什麼???

經過一系列的分析,結果是無果,但是也看到了另外一個線索即:計算節點物理機的crash時間正好在這三個OSD出現故障之前。

最終,因為正好大膽地做了一個假設:rbd的客戶端(kvm)因為kernel出現了異常,所以無法完成分散式儲存的某些操作,進而導致相關物件所在的塊的OSD有了鎖之類的東西,進而導致這個OSD無法正常反饋心跳,進而導致了OSD被自己斷言死亡。

這是一個猜測,但是是一個非常合理的猜測。

有知道的同學,也請告知,回頭把這個問題報告到社群中問一下。

相關推薦

一個ceph-osd異常DOWN原因分析

今天早上,運維的兄弟報告說,ceph分散式儲存叢集同時有3個OSD異常DOWN掉。因為CEPH叢集是三份資料儲存的,所以對業務沒有什麼太大的影響,所以等有空再查根本原因。 同時報告了有一臺物理機當機了,做了重啟恢復的操作。 有空的時候對問題進行了分析,同事進行了預查,發現

OpenStack中down異常dhcp port 處理

端口 style device family Opens oot status fixed -- 在OpenStack中,隨著網絡環境費復雜增長,有時候會遇到dhcp agent port bonding failed,導致agent無法正常提供服務,我們可以簡單的用下面的

Jupyter notebook 轉pdf時出現的一個錯誤(只出現前4頁)及原因分析

文章目錄 問題描述 原因分析 解決方案 問題描述 最近迷上了利用Jupyter notebook 為工具學習有關Python語言方面的知識。遇到該錯誤純粹是個偶然,這應該算是Jupyter notebook的一個bug。 問題的

關於QT在開啟子視窗時程式崩潰的其中一個原因分析

其實這個問題當時是糾結了我很長的一段時間,這段時間裡面,我一直在網上面找相關的資料但是卻沒有有用的資訊。 但是在後面的一個機緣巧合之下,我通過函式執行順序來Debug,慢慢的發現問題出現在什麼地方了。現在來總結一下這個問題吧。 其實我現在的經驗覺得,對於QT裡面(由於QT是基於C++的),不

Cron連線正常工作5次後異常原因分析

目錄 目錄 1 問題描述 1 分析定位 1 解決方法 2 附1:Cron工作流 3 附2:SIGPIPE發生的位置 3   如果一個shell命令的“$?”值為141,則它是收到了SIGPIPE訊號。一些shell指令碼中的sleep或ps、wc等命令無效,

簡單利用Apache Logs Viewer工具分析錯誤日誌和頻繁掛原因

最近網站換成了騰訊雲的伺服器, 不知道為什麼dmz社群 apache老是掉線,更無語的是前幾天好不容易有點時間回下老家休息中途被使用者告知dmz社群無法訪問,大中午的個騎著個小毛驢重大山裡出來(大山沒訊號,收到使用者資訊純屬偶然),心中對於騰訊雲更是一萬個草泥馬奔騰著,不過分析日誌之後才發現我冤枉騰訊雲了!日

一個Java程序直接死的問題分析

一個專案24小時不停的下載檔案,並呼叫本地安卓工具包,aapt命令分析apk的包名等應用名資訊,偶發性出現該問題,導致Java程序直接死掉 硬體環境:雲主機 軟體環境:Linux(CentOS 6.5 final) + Java8(Oracle JDK)+ Tomcat7.

在Activity的onCreate方法中顯示PopupWindow導致異常原因分析及解決方案

一、前言        在某些情況下,我們需要一進入Activity就顯示PopupWindow,比如常見的選擇介面。但由於PopupWindow是依附於Activity的,如果Activity沒有建立完成,Activity還沒完全顯示出來就顯示PopupWindow的話,

STL string 析構異常原因分析

class __declspec(dllexport) smart_string { public: smart_string(); ~smart_string(); constchar*get_data() const; void set_data(constchar*data); void clear()

C# 外部元件發生異常原因分析 [分析]

在專案中,用From2 啟動 Report 正常,用From1 啟動 Report 失敗,日誌: 2007-05-12 13:11:06 StartGenerateReportTask: System.Runtime.InteropServices.SEHException

ADSL上網速度慢經常原因分析

1.  ADSL接入Internet的方式有虛擬撥號和專線接入兩種,現在個人使用者的ADSL大都是虛擬撥號。而PPPOE(Point-to- Point Protocol over Ethernet乙太網上的點對點協議)虛擬撥號軟體都有各自的優缺點。經過多方在不同作業系統的測

www.beishuo.net 網站打開異常慢的原因

科來數據包分析現象:客戶投訴http://www.beishuo.net/ 網站在移動線路下打不開或者打開異常緩慢(墨綠色是服務器向客戶端發送數據的時間,顯得非常耗時)分析:這個CASE比較有意思,我在用科來分析數據包的時候發現服務器的重傳率非常高,普遍達到12%以上,如下圖,一個450K的內容,花了整整1分

epoll驚群原因分析

all lec 水平 next log lag 到來 delayed eas 考慮如下情況(實際一般不會做,這裏只是舉個例子): 在主線程中創建一個socket、綁定到本地端口並監聽 在主線程中創建一個epoll實例(epoll_create(2)) 將監聽socket添

公司網絡很慢很卡的原因分析與處理

網絡問題分析與解決方案一、電腦網速突然變的很慢、很卡,怎麽辦1. 如果你是用的無線路由器,不管你有沒有設置無線密碼,都有可能被別人盜用你的網絡,可以關掉無線功能,自已用有線連接上網 2. 如果還不行,那麽啟路由器,有貓的話也要重啟,再試試 3. 如果你的路由器用的時間超過一年,質量不好的話可能內部的部件已經老

修改hosts不立即生效原因分析

real 專註 開始 image 下載 when 顯示 方法 做了 我們經常也遇到修改hosts不生效的情況,而且有時生效,有時不生效的情況也有發生,這到底是為什麽呢? 起:DNS緩存機制 關於DNS緩存的機制,有一篇非常詳細的文章What really happens w

SQL Server 磁盤請求超時的833錯誤原因分析以及解決

ger ssa sage blog htm 好的 發生 如何 tle 本文出處:http://www.cnblogs.com/wy123/p/6984885.html 最近遇到一個SQL Server服務器響應極度緩慢,並且出現客戶端請求報錯的情況,在數

記一次OGG數據寫入HBase的丟失數據原因分析

hat xdg column 安裝 tint b- 主鍵 取余 bst 一、現象二、原因排查2.1 SparkStreaming程序排查2.2 Kafka數據驗證2.3 查看OGG源碼2.3.1 生成Kafka消息類2.3.2 Kafka配置類2.3.3 Kafka 消息發

AppStore IPv6-only審核被拒原因分析及解決方案

穩定 eip ios 穩定性 only 應用服務器 http 一個 搭建 AppStore IPv6-only審核被拒原因分析及解決方案 http://www.jianshu.com/p/8edfdfa20b29 自2016年6月1日起,蘋果要求所有提交App St

SDK環境變量配置及adb不是內部或外部命令原因分析

form 如何 環境變量配置 無法 設置 添加 and 是否 排除 一、 1、SDK下載:http://tools.android-studio.org/index.php/sdk/ 建議下載zip格式文件,下載解壓即可 2、在解壓的SDK文件,找到“platform-to

C 語言的一個錯誤,沒找出原因

amp n) string getc bsp can 什麽 數據 能夠 #include <stdio.h>#include <stdlib.h>#include <string.h> intmain(void){ char str[51