yarn ResourceManager Active頻繁易主問題排查

也可以看我CSDN的博客
https://blog.csdn.net/u013332124/article/details/88758290

本周三公司的yarn集群出現(xiàn)故障尽纽,導(dǎo)致兩臺(tái)ResourceManger頻繁易主幌缝,并且許多提交到集群的任務(wù)狀態(tài)為NEW_SAVING衰絮,無法執(zhí)行缴淋。這里對(duì)此次的故障排查進(jìn)行一個(gè)總結(jié)。

一敦腔、故障現(xiàn)象

  1. 兩個(gè)節(jié)點(diǎn)的ResourceManger頻繁在active和standby角色中切換缆八。不斷有active易主的告警發(fā)出
  2. 許多任務(wù)的狀態(tài)沒能成功更新,導(dǎo)致一些任務(wù)狀態(tài)卡在NEW_SAVING無法進(jìn)入調(diào)度(還有許多資源空閑)

看了下ResourceManger的日志蛔琅,發(fā)現(xiàn)大量以下錯(cuò)誤:

org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss

在這里插入圖片描述

在這里插入圖片描述

從日志可以看出是在操作zk時(shí)出現(xiàn)了錯(cuò)誤胎许,并且會(huì)進(jìn)行重試。RM在重試1000次后才會(huì)放棄嘗試。并且從日志可以看出辜窑,這是在更新任務(wù)appattempt_1535616282827_1432747_000002的狀態(tài)時(shí)發(fā)生的異常钩述。

緊接著后面還發(fā)現(xiàn)另外一條日志,表示此時(shí)RM的狀態(tài)進(jìn)入了standby:

2019-03-20 14:37:48,914 INFO org.apache.hadoop.yarn.server.resourcemanager.ResourceManager: Transitioning to standby state

RM進(jìn)入standby狀態(tài)前會(huì)將對(duì)應(yīng)的ZK節(jié)點(diǎn)/yarn/ActiveStandbyElectorLock刪除穆碎,然后再轉(zhuǎn)到standby狀態(tài)牙勘。這時(shí)兩臺(tái)RM同時(shí)開始競(jìng)爭嘗試新建/yarn/ActiveStandbyElectorLock節(jié)點(diǎn),誰競(jìng)爭到誰就是active所禀。

成為active的節(jié)點(diǎn)又收到appattempt_1535616282827_1432747_000002的狀態(tài)更新方面,就嘗試更新zk節(jié)點(diǎn)的數(shù)據(jù),然后又發(fā)生上面的錯(cuò)誤色徘,重試1000次后轉(zhuǎn)為standby葡幸。如此一直重復(fù)下去,直到人為介入kill了該任務(wù)贺氓,集群才恢復(fù)正常蔚叨。

因?yàn)槭莦k操作的問題,所以看了下zk的日志辙培,也發(fā)現(xiàn)了異常:

2019-03-20 14:37:40,141 [myid:1] - WARN  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@362] - Exception causing close of session 0x16324e8243d0003 due to java.io.IOException: Len error 2186401
2019-03-20 14:37:40,142 [myid:1] - INFO  [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:2181:NIOServerCnxn@1007] - Closed socket connection for client /192.168.142.10:23412 which had sessionid 0x16324e8243d0003

從日志上看蔑水,只有appattempt_1535616282827_1432747_000002這個(gè)任務(wù)狀態(tài)會(huì)更新失敗,其他任務(wù)的狀態(tài)都可以正常更新扬蕊,有一些任務(wù)會(huì)因?yàn)閦k連接被關(guān)閉而更新失敗搀别,這個(gè)后面解釋原因。

二尾抑、問題分析

RM的HA機(jī)制分析

之前一直以為RM只有在和zk失聯(lián)歇父,/yarn/ActiveStandbyElectorLock節(jié)點(diǎn)斷開后才會(huì)進(jìn)行易主。但是這次的異常卻顛覆了我的認(rèn)知再愈。于是去跟了下yarn的源碼榜苫。發(fā)現(xiàn)還有一種情況可能導(dǎo)致RM從active狀態(tài)切換到standby狀態(tài)。

RM在進(jìn)行任務(wù)狀態(tài)更新時(shí)翎冲,會(huì)進(jìn)行對(duì)應(yīng)的zk操作垂睬,也就是將任務(wù)的相關(guān)信息存儲(chǔ)到zk。如果這個(gè)失敗抗悍,RM會(huì)進(jìn)行重試驹饺,這個(gè)重試的次數(shù)可以通過yarn.resourcemanager.zk-num-retries配置,默認(rèn)是1000次缴渊。當(dāng)對(duì)應(yīng)的zk操作失敗重試達(dá)到1000次赏壹,RM就會(huì)將狀態(tài)切換到standby

具體可能導(dǎo)致active切換成standby的操作有以下這些:

  1. storeApplicationStateInternal
  2. updateApplicationStateInternal
  3. removeApplicationStateInternal
  4. storeApplicationAttemptStateInternal
  5. updateApplicationAttemptStateInternal
  6. storeRMDelegationTokenState
  7. removeRMDelegationTokenState
  8. updateRMDelegationTokenState
  9. storeRMDTMasterKeyState
  10. removeRMDTMasterKeyState
  11. storeOrUpdateAMRMTokenSecretManagerState

所以我們上面的故障很明顯就是在某個(gè)任務(wù)的updateApplicationAttemptStateInternal操作出現(xiàn)異常后衔沼,才導(dǎo)致active在兩個(gè)RM節(jié)點(diǎn)間不斷切換的蝌借。

如果配置了多個(gè)RM田柔,客戶端根據(jù)yarn-site.xml的配置會(huì)采用round-robin的方式逐個(gè)去連接RM,直到找到active 節(jié)點(diǎn)位置骨望。所以即使active節(jié)點(diǎn)切換硬爆,在運(yùn)行中的客戶端也能通過這種方式重新找到新的Active RM進(jìn)行連接。

ZK問題分析

上面的故障其實(shí)歸根結(jié)底還是zk的問題擎鸠。zk的這條日志Exception causing close of session 0x16324e8243d0003 due to java.io.IOException: Len error 2186401也很明確的表明是由于客戶端發(fā)來的請(qǐng)求包太大缀磕,zk主動(dòng)關(guān)閉了連接。

上網(wǎng)搜了下zk的Len error的問題劣光,發(fā)現(xiàn)也有一些人碰到過袜蚕。甚至找到兩個(gè)相關(guān)的issue,一個(gè)是yarn的绢涡,一個(gè)是zookeeper的:

https://issues.apache.org/jira/browse/YARN-3469

https://issues.apache.org/jira/browse/ZOOKEEPER-706

其中zk的issue是說如果一個(gè)請(qǐng)求要注冊(cè)的watcher太多牲剃,會(huì)導(dǎo)致Len error的問題。因此這個(gè)issue的patch是將這些watcher分成多個(gè)請(qǐng)求發(fā)送雄可,這樣就不會(huì)導(dǎo)致請(qǐng)求過大的問題了凿傅。剛好修復(fù)版本是3.4.7,而我們集群用的zk版本是3.4.6数苫。

yarn的issue是說之前的版本設(shè)置了過多無用的watcher聪舒,導(dǎo)致某個(gè)請(qǐng)求太大,出現(xiàn)Len error的問題虐急。因此yarn這邊做的修復(fù)是不在注冊(cè)無用的watcher箱残。修復(fù)版本是2.6.0,我們集群用的版本是2.7.4止吁,因此我們集群應(yīng)該不會(huì)有這個(gè)問題被辑。

因?yàn)榕挪闀r(shí)已經(jīng)無法找到那個(gè)請(qǐng)求包的具體內(nèi)容,這兩個(gè)issue看上去又很有說服力敬惦。雖然yarn已經(jīng)修復(fù)了注冊(cè)過多無用watcher的盼理,但是可能還有一些地方還有類似的問題呢。

本來以為問題大概就是這樣了仁热,我們已經(jīng)準(zhǔn)備升級(jí)zk版本了榜揖。突然又想到失敗的zk操作是updateApplicationAttemptStateInternal勾哩,它底層的zk操作是setData抗蠢,而setData是不會(huì)注冊(cè)任何watcher的。因此這個(gè)問題和watcher沒有任何關(guān)系思劳。

后面繼續(xù)排查迅矛,發(fā)現(xiàn)下面這篇博客:

https://www.jishuwen.com/d/2BBc/zh-hk#tuit

和我們的故障現(xiàn)象很像,于是追到了博客提到的yarn的issue:

https://issues.apache.org/jira/browse/YARN-2368

ResourceManager failed when ZKRMStateStore tries to update znode data larger than 1MB潜叛。也就是我們遇到的問題秽褒。就是要更新的任務(wù)信息過大導(dǎo)致的壶硅,和watcher沒有關(guān)系

這issue并沒有修復(fù)的版本销斟,看了下它的patch庐椒,就是加了一個(gè)配置,用來指定jute.maxbuffer蚂踊,也就是通過調(diào)大zk的閥值來避免出現(xiàn)該問題约谈。

部分任務(wù)狀態(tài)更新失敗問題分析

從日志看,只有appattempt_1535616282827_1432747_000002這個(gè)任務(wù)因?yàn)楦聝?nèi)容過大導(dǎo)致zk操作失敗犁钟。但是故障時(shí)看到的現(xiàn)象確實(shí)許多任務(wù)狀態(tài)都卡在NEW_SAVING無法更新棱诱。這是為什么呢?

通過分析日志涝动,可以很容易得出結(jié)論迈勋。RM在更新appattempt_1535616282827_1432747_000002狀態(tài)失敗時(shí),zk服務(wù)端主動(dòng)斷掉了連接醋粟,RM在下次重試時(shí)就會(huì)再次嘗試建立連接靡菇。

因?yàn)槿蝿?wù)狀態(tài)更新用的zk連接可能是同一個(gè),如果要更新時(shí)剛好連接被關(guān)閉了米愿,任務(wù)肯定無法成功更新镰官。因此才會(huì)有部分任務(wù)狀態(tài)可以更新,部分任務(wù)狀態(tài)無法更新的現(xiàn)象吗货。

在RM的日志中我們也可以看到許多下面的Broken pipe異常:

在這里插入圖片描述

三泳唠、解決和優(yōu)化方案

1. 調(diào)大 jute.maxbuffer 參數(shù)

通過調(diào)大jute.maxbuffer來讓zk可以接受更大的請(qǐng)求包而不會(huì)拋出IOException。這個(gè)參數(shù)的默認(rèn)值是1M宙搬。

注意笨腥,這個(gè)不是在zk的配置文件中設(shè)置。而是作為java參數(shù)在啟動(dòng)zk時(shí)設(shè)置勇垛,也就是-Djute.maxbuffer=xxxx的方式脖母。

另外,根據(jù)zk的文檔闲孤,這個(gè)參數(shù)在所有的客戶端和zk服務(wù)端都要設(shè)置谆级,否則會(huì)有更多的問題產(chǎn)生。也就是說讼积,我們需要在yarn這邊也設(shè)置這個(gè)參數(shù)肥照。

這種方式有點(diǎn)治標(biāo)不治本,因?yàn)槲覀儫o法知道任務(wù)信息最大可能到多少勤众。設(shè)置過大的值也不是個(gè)好主意舆绎。最重要的是這個(gè)方案要同時(shí)對(duì)yarn和zk進(jìn)行重啟,風(fēng)險(xiǎn)略高们颜。

2. 修改yarn的源碼

雖然知道了問題的原因所在吕朵,但是我們還不知道為什么那個(gè)任務(wù)會(huì)產(chǎn)生那么大的任務(wù)信息猎醇。所以我們對(duì)zk的端口進(jìn)行抓包查看正常的任務(wù)信息的請(qǐng)求都有多大:

在這里插入圖片描述

通過抓包的結(jié)果,我們發(fā)現(xiàn)正常任務(wù)包的大小其實(shí)都只有幾K努溃,最高不會(huì)超過5K硫嘶。所以我們打算修改yarn的源碼過濾掉那些大小超過1M的任務(wù)更新請(qǐng)求,同時(shí)把這些大于1M的請(qǐng)求內(nèi)容打印出來梧税。

這樣做一方面是為了避免后面因?yàn)槟硞€(gè)任務(wù)的更新失敗又導(dǎo)致集群出現(xiàn)問題音半,另一方面也可以觀察到為什么有的任務(wù)會(huì)產(chǎn)生那么大的信息。

附上更新的代碼,ZKRMStateStore#updateApplicationAttemptStateInternal()

    byte[] attemptStateData = attemptStateDataPB.getProto().toByteArray();
 //測(cè)試環(huán)境可以加上下面這個(gè)日志贡蓖,實(shí)時(shí)觀察各個(gè)任務(wù)信息的大小
LOG.info(String.format("attempId:%s,len:%s",attemptStateDataPB.getAttemptId(),attemptStateData.length));
    //如果任務(wù)信息超過了950K曹鸠,就打出error日志,輸出任務(wù)信息斥铺,同時(shí)直接返回彻桃,不再往zk發(fā)送請(qǐng)求
    if(attemptStateData.length > 972800){
      LOG.error(String.format("attemptStateData len larger than 1M.len:%s,nodeUpdatePath:%s,data:%s,attemptId:%s,Diagnostics:%s,traceUrl:%s,container%s",
              attemptStateData.length,nodeUpdatePath,String.valueOf(attemptStateData),attemptStateDataPB.getAttemptId(),attemptStateDataPB.getDiagnostics(),
              attemptStateDataPB.getFinalTrackingUrl(),attemptStateDataPB.getMasterContainer()));
      return;
    }
    //往zk發(fā)送請(qǐng)求更新任務(wù)信息
    if (existsWithRetries(nodeUpdatePath, false) != null) {
      setDataWithRetries(nodeUpdatePath, attemptStateData, -1);
    } else {
      createWithRetries(nodeUpdatePath, attemptStateData, zkAcl,
        CreateMode.PERSISTENT);
      LOG.debug(appAttemptId + " znode didn't exist. Created a new znode to"
          + " update the application attempt state.");
    }

3. 快速讓集群恢復(fù)穩(wěn)定的方法

如果集群又發(fā)生了類似的問題,可以找到任務(wù)的ApplicationMaster所在的Container晾蜘,然后上目標(biāo)服務(wù)器將對(duì)應(yīng)的Container進(jìn)程kill掉邻眷,后面RM就不會(huì)再更新該任務(wù)的信息,而是將任務(wù)直接轉(zhuǎn)為Kill狀態(tài)剔交。

四肆饶、總結(jié)

此次故障大概持續(xù)了2個(gè)半小時(shí)才恢復(fù),還是剛好業(yè)務(wù)同學(xué)手動(dòng)kill了那個(gè)任務(wù)的container進(jìn)程岖常,最終才沒有一直切換下去驯镊。

因?yàn)橹皩?duì)yarn只有原理上的認(rèn)知,并沒有看過yarn的代碼竭鞍,對(duì)yarn狀態(tài)機(jī)的相關(guān)知識(shí)也了解不多板惑。所以在故障發(fā)生時(shí)有點(diǎn)手足無措,不知道從何下手排查偎快。

此刻回想起來真的很僥幸冯乘,因?yàn)檫@個(gè)故障不是重啟一下RM就能恢復(fù)的。如果業(yè)務(wù)同學(xué)沒有剛好kill那個(gè)container進(jìn)程晒夹,可能我們要一直排查到分析出問題的根本原因?yàn)橹柜陕辽僖喟胩斓臅r(shí)間。

后面還是要多看看集群各個(gè)組件的源碼丐怯,深入了解他們的架構(gòu)喷好,爭取出現(xiàn)問題時(shí)能更快的定位到問題并修復(fù)。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末响逢,一起剝皮案震驚了整個(gè)濱河市绒窑,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌舔亭,老刑警劉巖些膨,帶你破解...
    沈念sama閱讀 222,729評(píng)論 6 517
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場(chǎng)離奇詭異钦铺,居然都是意外死亡订雾,警方通過查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 95,226評(píng)論 3 399
  • 文/潘曉璐 我一進(jìn)店門矛洞,熙熙樓的掌柜王于貴愁眉苦臉地迎上來洼哎,“玉大人,你說我怎么就攤上這事沼本∝停” “怎么了?”我有些...
    開封第一講書人閱讀 169,461評(píng)論 0 362
  • 文/不壞的土叔 我叫張陵抽兆,是天一觀的道長识补。 經(jīng)常有香客問我,道長辫红,這世上最難降的妖魔是什么凭涂? 我笑而不...
    開封第一講書人閱讀 60,135評(píng)論 1 300
  • 正文 為了忘掉前任,我火速辦了婚禮贴妻,結(jié)果婚禮上切油,老公的妹妹穿的比我還像新娘。我一直安慰自己名惩,他們只是感情好澎胡,可當(dāng)我...
    茶點(diǎn)故事閱讀 69,130評(píng)論 6 398
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著娩鹉,像睡著了一般滤馍。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上底循,一...
    開封第一講書人閱讀 52,736評(píng)論 1 312
  • 那天巢株,我揣著相機(jī)與錄音,去河邊找鬼熙涤。 笑死阁苞,一個(gè)胖子當(dāng)著我的面吹牛,可吹牛的內(nèi)容都是我干的祠挫。 我是一名探鬼主播那槽,決...
    沈念sama閱讀 41,179評(píng)論 3 422
  • 文/蒼蘭香墨 我猛地睜開眼,長吁一口氣:“原來是場(chǎng)噩夢(mèng)啊……” “哼等舔!你這毒婦竟也來了骚灸?” 一聲冷哼從身側(cè)響起,我...
    開封第一講書人閱讀 40,124評(píng)論 0 277
  • 序言:老撾萬榮一對(duì)情侶失蹤慌植,失蹤者是張志新(化名)和其女友劉穎甚牲,沒想到半個(gè)月后义郑,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 46,657評(píng)論 1 320
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡丈钙,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,723評(píng)論 3 342
  • 正文 我和宋清朗相戀三年非驮,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片雏赦。...
    茶點(diǎn)故事閱讀 40,872評(píng)論 1 353
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡劫笙,死狀恐怖,靈堂內(nèi)的尸體忽然破棺而出星岗,到底是詐尸還是另有隱情填大,我是刑警寧澤,帶...
    沈念sama閱讀 36,533評(píng)論 5 351
  • 正文 年R本政府宣布俏橘,位于F島的核電站允华,受9級(jí)特大地震影響,放射性物質(zhì)發(fā)生泄漏敷矫。R本人自食惡果不足惜例获,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 42,213評(píng)論 3 336
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望曹仗。 院中可真熱鬧榨汤,春花似錦、人聲如沸怎茫。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,700評(píng)論 0 25
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽轨蛤。三九已至蜜宪,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間祥山,已是汗流浹背圃验。 一陣腳步聲響...
    開封第一講書人閱讀 33,819評(píng)論 1 274
  • 我被黑心中介騙來泰國打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留缝呕,地道東北人澳窑。 一個(gè)月前我還...
    沈念sama閱讀 49,304評(píng)論 3 379
  • 正文 我出身青樓,卻偏偏與公主長得像供常,于是被迫代替她去往敵國和親摊聋。 傳聞我的和親對(duì)象是個(gè)殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,876評(píng)論 2 361

推薦閱讀更多精彩內(nèi)容

  • 文章觀點(diǎn)選自叢非從的文章( 非常推薦 ) 研究明白三個(gè)問題...
    大琬閱讀 427評(píng)論 0 0
  • 焦點(diǎn)網(wǎng)絡(luò)九期中級(jí)紫分享第270天 外化技術(shù) 和來訪者聊她想要解決的問題栈暇。聊的盡可能細(xì)化麻裁。 找一個(gè)物品代替你想解決的...
    紫smile閱讀 128評(píng)論 0 0
  • 在他窗前 你擺了一盆盆栽 象征別扭的你 開始反省 他端岀一盒火柴 一根長長的燭 插進(jìn)盆里 想這樣才更暖心 盆栽尚未...
    楊茗月閱讀 191評(píng)論 0 0
  • 第十六章成年人缺乏對(duì)孩子的理解 一、主要內(nèi)容 心靈通過聽和看獲得感知。不讓孩子運(yùn)動(dòng)煎源,就相當(dāng)于剝奪了孩子的聽覺和視覺...
    瀟兒麻麻閱讀 8,448評(píng)論 0 2