Hiveserver2 OOM 問題排查記錄

問題現(xiàn)象

生產(chǎn)環(huán)境hiveserver2使用過程中占用大量?jī)?nèi)存,甚至將內(nèi)存上限增大到32G左右后hiveserver2仍會(huì)達(dá)到內(nèi)存上限慷嗜。使用G1GC碉输,單次full GC耗時(shí)很長(zhǎng)秫筏,且絕大部分內(nèi)存無法被回收(只能回收幾百M(fèi)內(nèi)存)隘冲,然后發(fā)生OOM退出。懷疑存在內(nèi)存泄漏問題欺劳。本文圍繞hiveserver2內(nèi)存泄漏問題展開分析唧取。

生產(chǎn)環(huán)境Hive版本為3.1.0。

Heap dump 分析

在生產(chǎn)服務(wù)器獲取到hiveserver2 OOM時(shí)候的heap dump之后划提,使用MAT工具分析枫弟。獲取它的leak suspect報(bào)告。具體分析步驟參見Java Heap Dump 分析步驟鹏往。

我們使用瀏覽器打開leak suspect報(bào)告淡诗。發(fā)現(xiàn)里面有一個(gè)內(nèi)存泄漏懷疑點(diǎn)。打開詳情掸犬,內(nèi)容如下圖所示:

Leak suspect報(bào)告

上圖中可以很明顯的看出operationManager中有一個(gè)叫做queryIdOperationConcurrentHashMap袜漩,占用了大量的內(nèi)存绪爸。這個(gè)報(bào)告給出了問題分析的方向湾碎。下面的分析圍繞著queryIdOpereation展開。

原因分析

我們查看源代碼奠货,發(fā)現(xiàn)OperationManager類中的queryIdOperation為私有變量介褥。因此queryIdOperation只可能在OperationManager中操作。繼續(xù)尋找操作queryIdOperation的方法递惋,發(fā)現(xiàn)有如下三個(gè):

  • addOperation
  • removeOperation
  • getOperationByQueryId

其中前兩個(gè)方法分別為向集合中添加和移除元素柔滔。我們接下來分析這兩個(gè)方法。

OperationManageraddOperation方法代碼如下:

private void addOperation(Operation operation) {
    LOG.info("Adding operation: " + operation.getHandle());
    // 通過getQueryId方法從operation中獲取queryId萍虽,然后將queryId作為key睛廊,存放入queryIdOperation
    queryIdOperation.put(getQueryId(operation), operation);
    handleToOperation.put(operation.getHandle(), operation);
    if (operation instanceof SQLOperation) {
        synchronized (webuiLock) {
            liveQueryInfos.put(operation.getHandle().getHandleIdentifier().toString(),
                               ((SQLOperation) operation).getQueryInfo());
        }
    }
}

getQueryId方法內(nèi)容如下:

private String getQueryId(Operation operation) {
    // 獲取parent session的HiveConf對(duì)象
    // queryId在這個(gè)HiveConf對(duì)象當(dāng)中存放
    return operation.getParentSession().getHiveConf().getVar(ConfVars.HIVEQUERYID);
}

這個(gè)方法是重點(diǎn),此處先埋個(gè)伏筆杉编,后面還會(huì)再次分析這個(gè)方法超全。

removeOperation方法邏輯如下:

private Operation removeOperation(OperationHandle opHandle) {
    Operation operation = handleToOperation.remove(opHandle);
    // 通過上面的邏輯咆霜,獲取queryId
    String queryId = getQueryId(operation);
    // 從queryIdOperation集合中remove掉
    queryIdOperation.remove(queryId);
    LOG.info("Removed queryId: {} corresponding to operation: {}", queryId, opHandle);
    if (operation instanceof SQLOperation) {
        removeSafeQueryInfo(opHandle);
    }
    return operation;
}

接下來我們需要順著向上層找,分別追蹤addOperationremoveOperation方法的調(diào)用鏈嘶朱。

addOperation方法在OperationManagernewExecuteStatementOperation方法中調(diào)用蛾坯,內(nèi)容如下:

public ExecuteStatementOperation newExecuteStatementOperation(HiveSession parentSession,
                                                              String statement, Map<String, String> confOverlay, boolean runAsync, long queryTimeout)
    throws HiveSQLException {
    // 創(chuàng)建一個(gè)ExecuteStatementOperation
    ExecuteStatementOperation executeStatementOperation =
        ExecuteStatementOperation.newExecuteStatementOperation(parentSession, statement,
                                                               confOverlay, runAsync, queryTimeout);
    // 調(diào)用addOperation
    addOperation(executeStatementOperation);
    return executeStatementOperation;
}

追溯這個(gè)方法調(diào)用,我們來到HiveSessionImplexecuteStatementInternal方法疏遏,內(nèi)容如下:

private OperationHandle executeStatementInternal(String statement,
                                                 Map<String, String> confOverlay, boolean runAsync, long queryTimeout) throws HiveSQLException {
    acquire(true, true);

    ExecuteStatementOperation operation = null;
    OperationHandle opHandle = null;
    try {
        // 此處調(diào)用了newExecuteStatementOperation
        operation = getOperationManager().newExecuteStatementOperation(getSession(), statement,
                                                                       confOverlay, runAsync, queryTimeout);
        opHandle = operation.getHandle();
        addOpHandle(opHandle);
        operation.run();
        return opHandle;
    } catch (HiveSQLException e) {
        // Refering to SQLOperation.java, there is no chance that a HiveSQLException throws and the
        // async background operation submits to thread pool successfully at the same time. So, Cleanup
        // opHandle directly when got HiveSQLException
        if (opHandle != null) {
            removeOpHandle(opHandle);
            getOperationManager().closeOperation(opHandle);
        }
        throw e;
    } finally {
        if (operation == null || operation.getBackgroundHandle() == null) {
            release(true, true); // Not async, or wasn't submitted for some reason (failure, etc.)
        } else {
            releaseBeforeOpLock(true); // Release, but keep the lock (if present).
        }
    }
}

再繼續(xù)向上追蹤脉课,發(fā)現(xiàn)上面的方法在HiveSessionImplexecuteStatementexecuteStatementAsync方法中調(diào)用(忽略了重載方法)。這兩個(gè)方法分別為阻塞方式執(zhí)行SQL statement和異步執(zhí)行SQL statement财异。如果繼續(xù)向上追蹤調(diào)用倘零,我們能夠找到CLIService類。ThriftCLIService類又再次包裝了CLIService類戳寸,它擁有ExecuteStatement方法视事。這個(gè)方法是thrift RPC調(diào)用的endpoint,通過TExecuteStatementReq類傳遞調(diào)用參數(shù)庆揩。繼續(xù)追蹤調(diào)用端的話我們陸續(xù)跟蹤到HiveStatementrunAsyncOnServer方法->execute方法(具體邏輯不再分析俐东,只分析調(diào)用鏈)。HiveStatementjava.sql.Statement的子類订晌,因此再往上分析就是JDBC使用的范疇了虏辫。調(diào)用鏈分析到這里為止。我們得到的結(jié)論是Hive JDBC調(diào)用statementexecute方法锈拨,會(huì)在執(zhí)行SQL前創(chuàng)建一個(gè)operation砌庄。一條SQL的執(zhí)行對(duì)應(yīng)著一個(gè)operation。

接下來我們轉(zhuǎn)到RemoveOperation的分析奕枢。它的調(diào)用位于HiveSessionImplclose方法娄昆。close方法會(huì)關(guān)閉所有的operation。代碼如下所示缝彬,其他不相關(guān)的邏輯此處不分析萌焰。

@Override
public void close() throws HiveSQLException {
    try {
        acquire(true, false);
        // Iterate through the opHandles and close their operations
        List<OperationHandle> ops = null;
        synchronized (opHandleSet) {
            ops = new ArrayList<>(opHandleSet);
            opHandleSet.clear();
        }
        // 遍歷各個(gè)operationHandle,一個(gè)operationHandle對(duì)應(yīng)著一個(gè)operation
        // 然后關(guān)閉他們
        for (OperationHandle opHandle : ops) {
            operationManager.closeOperation(opHandle);
        }
        // Cleanup session log directory.
        cleanupSessionLogDir();
        HiveHistory hiveHist = sessionState.getHiveHistory();
        if (null != hiveHist) {
            hiveHist.closeStream();
        }
        try {
            sessionState.resetThreadName();
            sessionState.close();
        } finally {
            sessionState = null;
        }
    } catch (IOException ioe) {
        throw new HiveSQLException("Failure to close", ioe);
    } finally {
        if (sessionState != null) {
            try {
                sessionState.resetThreadName();
                sessionState.close();
            } catch (Throwable t) {
                LOG.warn("Error closing session", t);
            }
            sessionState = null;
        }
        if (sessionHive != null) {
            try {
                Hive.closeCurrent();
            } catch (Throwable t) {
                LOG.warn("Error closing sessionHive", t);
            }
            sessionHive = null;
        }
        release(true, false);
    }
}

除此之外還有一處調(diào)用位于closeOperation方法谷浅,內(nèi)容如下扒俯。

@Override
public void closeOperation(OperationHandle opHandle) throws HiveSQLException {
    acquire(true, false);
    try {
        operationManager.closeOperation(opHandle);
        synchronized (opHandleSet) {
            opHandleSet.remove(opHandle);
        }
    } finally {
        release(true, false);
    }
}

繼續(xù)追蹤調(diào)用,我們發(fā)現(xiàn)它的調(diào)用端也在CLIServicecloseOperation方法一疯。繼續(xù)跟蹤到ThriftCLIServiceCloseOperation方法撼玄,它也是thrift RPC endpoint。通過TCloseOperationReq傳遞RPC調(diào)用參數(shù)墩邀。追蹤到RPC調(diào)用端掌猛,我們跟蹤到HiveStatementcloseStatementIfNeeded方法。在往上追蹤眉睹,調(diào)用鏈為closeClientOperation -> close方法荔茬。其中close方法重寫了java.sql.Statement的同名方法只盹。到這里我們得到結(jié)論,close Hive的statement的時(shí)候兔院,會(huì)調(diào)用removeOperation殖卑,從而將operation從queryIdOperation中移除。

按照J(rèn)DBC標(biāo)準(zhǔn)使用方式坊萝,statement使用完畢之后是必須要close的孵稽。也就是說正常情況下addOperationremoveOperation必然是成對(duì)出現(xiàn)。我們先假設(shè)用戶使用問題十偶,沒有及時(shí)close掉statement菩鲜。

接著繼續(xù)分析還有哪些時(shí)機(jī)會(huì)調(diào)用removeOperation方法。我們找到HiveSessionImplclose方法 -> SessionManagercloseSession方法惦积。除了正常關(guān)閉session外接校,SessionManager中還有一個(gè)startTimeoutChecker。這個(gè)方法周期運(yùn)行狮崩,當(dāng)session超時(shí)的時(shí)候會(huì)自動(dòng)關(guān)閉session蛛勉。從而關(guān)閉所有的statement。這些措施確保了removeOperation是一定會(huì)被調(diào)用到的睦柴。就算是用戶使用問題诽凌,沒有close掉statement,這些operation也是可以被清理掉的坦敌。

造成OOM的原因是某些operation始終不能夠被remove掉侣诵。查看日志我們的確發(fā)現(xiàn)部分query id的確沒有被remove掉(removeOperationLOG.info("Removed queryId: {} corresponding to operation: {}", queryId, opHandle);這一行代碼會(huì)打印日志,存在一些query id沒有這一行日志)狱窘。問題可能在于OperationManagergetQueryId方法杜顺。無法通過operation獲取到它對(duì)應(yīng)的query id。

我們回到OperationManagergetQueryId方法蘸炸。發(fā)現(xiàn)query id并沒有存儲(chǔ)在operation中躬络,而是存儲(chǔ)在HiveConf中层亿。

private String getQueryId(Operation operation) {
    return operation.getParentSession().getHiveConf().getVar(ConfVars.HIVEQUERYID);
}

一路跟蹤operation的parentSession是什么時(shí)候賦值進(jìn)去的吮螺。最終找到了HiveSessionImplexecuteStatementInternal方法。下面只貼出關(guān)鍵的一行,其他無關(guān)部分省略仗嗦。

operation = getOperationManager().newExecuteStatementOperation(getSession(), statement,
          confOverlay, runAsync, queryTimeout);

getSession方法返回的是this。說明這些operation共用同一個(gè)Hive Session(同一個(gè)JDBC連接下所有操作公用session)甘凭。自然HiveConf也是公用的稀拐。到這里為止分析的重點(diǎn)來到了這個(gè)HiveConf保存的內(nèi)容上。

Hive的query id存儲(chǔ)在HiveConf中丹弱,key為ConfVars.HIVEQUERYID德撬。猜測(cè)這個(gè)key一定有某個(gè)地方被set铲咨。跟蹤HiveConf的set這個(gè)key的調(diào)用,我們發(fā)現(xiàn)QueryStatebuild方法蜓洪。

QueryStatebuild方法中分配新的queryId纤勒。方法內(nèi)容如下:

public QueryState build() {
    HiveConf queryConf;

    if (isolated) {
        // isolate query conf
        if (hiveConf == null) {
            queryConf = new HiveConf();
        } else {
            queryConf = new HiveConf(hiveConf);
        }
    } else {
        queryConf = hiveConf;
    }

    // Set the specific parameters if needed
    if (confOverlay != null && !confOverlay.isEmpty()) {
        // apply overlay query specific settings, if any
        for (Map.Entry<String, String> confEntry : confOverlay.entrySet()) {
            try {
                queryConf.verifyAndSet(confEntry.getKey(), confEntry.getValue());
            } catch (IllegalArgumentException e) {
                throw new RuntimeException("Error applying statement specific settings", e);
            }
        }
    }

    // Generate the new queryId if needed
    // 如果需要生成新的query id
    if (generateNewQueryId) {
        // 分配新的query id
        String queryId = QueryPlan.makeQueryId();
        queryConf.setVar(HiveConf.ConfVars.HIVEQUERYID, queryId);
        // FIXME: druid storage handler relies on query.id to maintain some staging directories
        // expose queryid to session level
        // 將query id存放到hive session中
        if (hiveConf != null) {
            hiveConf.setVar(HiveConf.ConfVars.HIVEQUERYID, queryId);
        }
    }

    QueryState queryState = new QueryState(queryConf);
    if (lineageState != null) {
        queryState.setLineageState(lineageState);
    }
    return queryState;
}

下面我們要確認(rèn)下這個(gè)build方法是否在執(zhí)行SQL查詢的過程中調(diào)用。跟蹤調(diào)用我們發(fā)現(xiàn)Operation類的構(gòu)造函數(shù)隆檀。內(nèi)容如下:

protected Operation(HiveSession parentSession,
                    Map<String, String> confOverlay, OperationType opType) {
    this.parentSession = parentSession;
    this.opHandle = new OperationHandle(opType, parentSession.getProtocolVersion());
    beginTime = System.currentTimeMillis();
    lastAccessTime = beginTime;
    operationTimeout = HiveConf.getTimeVar(parentSession.getHiveConf(),
                                           HiveConf.ConfVars.HIVE_SERVER2_IDLE_OPERATION_TIMEOUT, TimeUnit.MILLISECONDS);
    scheduledExecutorService = Executors.newScheduledThreadPool(1);

    currentStateScope = updateOperationStateMetrics(null, MetricsConstant.OPERATION_PREFIX,
                                                    MetricsConstant.COMPLETED_OPERATION_PREFIX, state);
    // 這里創(chuàng)建出了queryState
    // 這個(gè)queryState被operation持有
    queryState = new QueryState.Builder()
        .withConfOverlay(confOverlay)
        // 指定需要生成query id
        .withGenerateNewQueryId(true)
        .withHiveConf(parentSession.getHiveConf())
        .build();
}

跟蹤這個(gè)構(gòu)造函數(shù)摇天,不難發(fā)現(xiàn)ExecuteStatementOperationOperation的子類。創(chuàng)建ExecuteStatementOperation的時(shí)候調(diào)用了這個(gè)方法恐仑。

public ExecuteStatementOperation(HiveSession parentSession, String statement,
                                 Map<String, String> confOverlay, boolean runInBackground) {
    super(parentSession, confOverlay, OperationType.EXECUTE_STATEMENT);
    this.statement = statement;
}

ExecuteStatementOperationHiveCommandOperation的父類泉坐。HiveCommandOperation的構(gòu)造函數(shù)中自然需要調(diào)用上面的方法。

ExecuteStatementOperation還有一個(gè)方法newExecuteStatementOperation裳仆。這個(gè)方法我們上面已經(jīng)分析過了腕让,它最后創(chuàng)建了一個(gè)HiveCommandOperation對(duì)象并返回。經(jīng)過這段分析我們驗(yàn)證了Hive每次執(zhí)行SQL statement的時(shí)候都會(huì)設(shè)置一個(gè)新的query id歧斟。那么問題來了纯丸,如果上一個(gè)query id還被來得及被remove就設(shè)置了新的query id,上一個(gè)query id就再也沒有機(jī)會(huì)被remove静袖,造成OOM的問題液南。同一個(gè)session只會(huì)保存最后一個(gè)query id。到此問題的根源已經(jīng)找到勾徽。

問題解決

跟蹤社區(qū)我們發(fā)現(xiàn)在Hive項(xiàng)目的branch-3.1分支中有一個(gè)HIVE-26530patch滑凉。這個(gè)patch合并的時(shí)間明顯晚于Hive 3.1.0發(fā)布的時(shí)間,是一個(gè)hotfix喘帚。它對(duì)應(yīng)的正是OperationManagergetQueryId方法的修改畅姊。這個(gè)patch將OperationManagergetQueryId方法從:

private String getQueryId(Operation operation) {
    return operation.getParentSession().getHiveConf().getVar(ConfVars.HIVEQUERYID);
}

修改為:

private String getQueryId(Operation operation) {
    return operation.getQueryId();
}

Operation類增加如下代碼:

public String getQueryId() {
    return queryState.getQueryId();
}

該patch做出的改動(dòng)將query id保存在每個(gè)operation專有的queryState中,從而杜絕了query id被覆蓋的情況吹由。將本地Hive3.1.0代碼合入這個(gè)patch后重新編譯若未。替換集群中的hive-service-xxx.jar為新編譯輸出的jar后重啟集群,問題解決倾鲫。目前使用Hive 3.x版本的環(huán)境都存在此隱患粗合,建議緊急修復(fù)此問題。

本博客為作者原創(chuàng)乌昔,歡迎大家參與討論和批評(píng)指正隙疚。如需轉(zhuǎn)載請(qǐng)注明出處。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末磕道,一起剝皮案震驚了整個(gè)濱河市供屉,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌,老刑警劉巖伶丐,帶你破解...
    沈念sama閱讀 222,807評(píng)論 6 518
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件悼做,死亡現(xiàn)場(chǎng)離奇詭異,居然都是意外死亡哗魂,警方通過查閱死者的電腦和手機(jī)肛走,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 95,284評(píng)論 3 399
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來录别,“玉大人羹与,你說我怎么就攤上這事∈樱” “怎么了纵搁?”我有些...
    開封第一講書人閱讀 169,589評(píng)論 0 363
  • 文/不壞的土叔 我叫張陵,是天一觀的道長(zhǎng)往踢。 經(jīng)常有香客問我腾誉,道長(zhǎng),這世上最難降的妖魔是什么峻呕? 我笑而不...
    開封第一講書人閱讀 60,188評(píng)論 1 300
  • 正文 為了忘掉前任利职,我火速辦了婚禮,結(jié)果婚禮上瘦癌,老公的妹妹穿的比我還像新娘猪贪。我一直安慰自己,他們只是感情好讯私,可當(dāng)我...
    茶點(diǎn)故事閱讀 69,185評(píng)論 6 398
  • 文/花漫 我一把揭開白布热押。 她就那樣靜靜地躺著,像睡著了一般斤寇。 火紅的嫁衣襯著肌膚如雪桶癣。 梳的紋絲不亂的頭發(fā)上,一...
    開封第一講書人閱讀 52,785評(píng)論 1 314
  • 那天娘锁,我揣著相機(jī)與錄音牙寞,去河邊找鬼。 笑死莫秆,一個(gè)胖子當(dāng)著我的面吹牛间雀,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播镊屎,決...
    沈念sama閱讀 41,220評(píng)論 3 423
  • 文/蒼蘭香墨 我猛地睜開眼惹挟,長(zhǎng)吁一口氣:“原來是場(chǎng)噩夢(mèng)啊……” “哼!你這毒婦竟也來了杯道?” 一聲冷哼從身側(cè)響起匪煌,我...
    開封第一講書人閱讀 40,167評(píng)論 0 277
  • 序言:老撾萬榮一對(duì)情侶失蹤责蝠,失蹤者是張志新(化名)和其女友劉穎党巾,沒想到半個(gè)月后萎庭,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經(jīng)...
    沈念sama閱讀 46,698評(píng)論 1 320
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡齿拂,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,767評(píng)論 3 343
  • 正文 我和宋清朗相戀三年驳规,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片署海。...
    茶點(diǎn)故事閱讀 40,912評(píng)論 1 353
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡吗购,死狀恐怖,靈堂內(nèi)的尸體忽然破棺而出砸狞,到底是詐尸還是另有隱情捻勉,我是刑警寧澤,帶...
    沈念sama閱讀 36,572評(píng)論 5 351
  • 正文 年R本政府宣布刀森,位于F島的核電站踱启,受9級(jí)特大地震影響,放射性物質(zhì)發(fā)生泄漏研底。R本人自食惡果不足惜埠偿,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 42,254評(píng)論 3 336
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望榜晦。 院中可真熱鬧冠蒋,春花似錦、人聲如沸乾胶。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,746評(píng)論 0 25
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽识窿。三九已至牙躺,卻和暖如春,著一層夾襖步出監(jiān)牢的瞬間腕扶,已是汗流浹背孽拷。 一陣腳步聲響...
    開封第一講書人閱讀 33,859評(píng)論 1 274
  • 我被黑心中介騙來泰國(guó)打工, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留半抱,地道東北人脓恕。 一個(gè)月前我還...
    沈念sama閱讀 49,359評(píng)論 3 379
  • 正文 我出身青樓,卻偏偏與公主長(zhǎng)得像窿侈,于是被迫代替她去往敵國(guó)和親炼幔。 傳聞我的和親對(duì)象是個(gè)殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,922評(píng)論 2 361

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