MongoDB Kill Hang問題排查記錄

aliclouddb mongodb在開發過程中遇到一個無法正常退出的bug，由于是release版本的編譯（-o3），debuginfo已經不能很好的展現出堆棧的情況。這時又該如何确定問題所在呢？本篇文章完整的記錄了整個排查過程。

kill指令正常執行，但程序遲遲沒有退出。非必現場景，在批量回收資源時比較容易出現，平時開發測試時沒有遇到。從場景上看出現的機率并不高，可能是在某種極端條件下才能觸發，由于第一次收到報告後沒有保留現場，先到官方jira平台上去搜相關的bug，無果，又盲目的嘗試了幾個場景後隻能先hold住，等待下次出現。

很幸運，第二天bug再次出現，僵屍程序？死循環？死鎖？沒有收到kill信号？無數想法蹦出來，迅速登陸機器，檢視現場，先從最簡單的可能性開始開始排查。

<code>ps</code>`top`第一套組合拳，排除了僵屍程序可能性，并且top顯示cpu使用率為0并不高；strace繼續跟進檢視，也沒有發現有系統調用，最後在補一個pstack列印堆棧資訊，全部線程都在wait。bug的排查方向大緻确定：線程間資源同步的問題（當然也不能排除是其他的可能性）。

詳細分析pstack内容，從堆棧資訊中看一個長相特别的（其他大部分的線程堆棧都是雷同的）：

從函數名上看起來是mongodb退出的關鍵路徑，就從這裡入手，人肉翻下源碼：

這麼多的join，到底是哪個呢。上gdb，我們來看看thread 46到底在等誰。先加載symbol-file，失敗，加載後堆棧變得更亂了，換<code>disassemble</code>指令，顯示彙編資訊：

檢視<code>0x0000000000c8eeb7</code>位址的上下文，通過前後指令的函數符号名确定了目前代碼是在<code>_applierthread-&gt;join()</code>，這裡可以思考下是否還有的其他方法獲得代碼行。

<code>_applierthread</code>同樣也是個線程，如果shutdown在等它，那它又在等誰呢，回頭繼續查pstack輸出，找到相關的堆棧：

注意這裡與shutdown的等待是不同的，shutdown是在等待線程退出，而這裡是在等待某個條件變量，再次上gdb，檢視thread 34 &amp; backtrace 1, <code>info locals</code>：

看看代碼怎麼寫的吧：

<code>_pause</code>變量一直都是0，是以會hang在這裡。繼續檢視代碼，跟蹤<code>_pausedcondition</code>的調用，有兩個函數會去喚醒，一個是stop，另一個是shutdown，但shutdown的調用應該線上程退後調用，以便釋放資源。

同時，再次回過來在pstack中檢視<code>backgroundsync</code>的堆棧資訊，想看看到底卡在了哪裡。結果找不到<code>backgroundsync</code>線程，問題更清晰了，所有<code>_pausedcondition</code>條件變量的喚醒，都是在該線程中完成的，如果<code>backgroundsync</code>已經不存在了，一定會hang住。

再反複閱讀代碼，<code>backgroundsync</code>在判斷到<code>inshutdown()</code>時會自動結束生命周期，但結束後并沒有更改<code>_pause</code>狀态。

解決辦法是線程最後退出前執行stop函數，修改<code>_pause</code>狀态，（shutdown會提前釋放資源），檢視官方最最新代碼，确認有同樣的修改，反向追蹤送出，找到相關jira，抱怨jira的搜尋弱爆了。

為何該bug出現的頻率會非常低呢，主要在判斷是否等待的條件上：

也就是說剛剛赢得了選舉後會産生<code>_iswaitingfordraintocomplete == true</code>狀态，恰巧這個時間視窗内程序接受到退出信号。複現的辦法就是在<code>kactionwinelection</code>的後面加上sleep，以此來延長時間視窗，當然也可以通過gdb block的方式來複現。