背景

前段時間用戶反饋某生產環境 TiDB 集群 drainer 頻繁發生故障，要么服務崩潰無法啟動，要么數據跑著跑著就丟失了，很是折磨人。該集群跑的是離線分析業務，數據量20T ，v4版本，有多個 drainer 往下游同步數據，目標端包括kafka、file、tidb多種形態。

兩天前剛恢復過一次，這會又故障重現，不得不來一次根因排查。

故障現象

接業務端反饋，某下游kafka幾個小時沒收到 TiDB 數據了，但是 pump 和 drainer 節點狀態都顯示正常，同樣在幾天前也收到類似的反饋，當時是因為 binlog 發生未知異常導致 TiDB server 停止寫入，需要通過以下 API 驗證 binlog 狀態：

curl http://{tidb-server ip}:{status_port}/info/all

該 API 會返回所有 TiDB server 的元信息，其中就包括每個實例 binlog 的寫入狀態（binlog_status字段），如果 TiDB server設置了ignore-error，那么在 binlog 故障時通常是 skipping，正常情況下是 on。

經確認7個 TiDB server 的 binlog_status 均為 skipping狀態，和此前是一樣的問題。

處理方法比較簡單，重啟 TiDB server 即可，但是避免后續重復出現需要搞清楚原因后再重啟。

分析過程

數據不同步了相信大家都會第一時間懷疑是 drainer 的問題， 最常見的原因就是大事務導致 drainer 崩潰panic，但是登錄到 drainer 所在的機器上分析日志，并沒有發現異常現象，日志顯示 savepoint 正常寫入，checkpoint 正常推進，實例狀態up，說明并不是 drainer的問題。

根據 binlog skip 狀態，轉頭去分析 TiDB server監控，在 TiDB->Server->Skip Binlog Count面板可以看到被跳過的 binlog 數量：

從監控看到，在8月18號下午6點左右 Skip Count 突然從高位掉到0，正是因為上一次重啟 TiDB server 修復了故障。往后到21號早上左右，Skip Count 又開始出現，那么就要重點分析這個時間點的日志。

進一步分析監控，發現 Skip Count 上升趨勢和 Critical Error 相吻合，說明在21號早上07:06左右開始出現大量的 binlog 寫入異常，接下來根據這個時間點去排查 pump 的日志。

根據精確的時間點，很快就在 pump 日志中定位到了panic的位置，在panic之后日志發現了一個非常有用的信息：

日志顯示，binlog 確實停止寫入了，同時指出停止寫入的原因是磁盤空間不夠，這里有個關鍵信息StopWriteAtAvailableSpace，也就是說 pump 所在的磁盤可用空間小于這個參數時就會停止寫入。我們用edit-config看一下 pump 的配置參數：

  pump:
 ?  gc: 2
 ?  heartbeat-interval: 2
 ?  security:
 ? ?  ssl-ca: ""
 ? ?  ssl-cert: ""
 ? ?  ssl-key: ""
 ?  storage:
 ? ?  stop-write-at-available-space: 1 gib

發現日志和配置參數可以對應上，確實是磁盤不夠了。反手就是一個df -h看看什么情況：

意外的是，上圖顯示 pump 的數據盤只用了1%，還有大把的空間沒被使用，貌似和日志報錯原因不符。

到這里我忽略了一個重要的時間因素，就是介入排查的時候離 pump 故障已經過去了3天（從前面第一章監控圖可以看到），而 pump gc時間設置的是2天，那么意味著在排查的時候 pump 之前記錄的binlog 已經被 gc 掉了，至于這些 binlog 有沒有被 drainer正常消費還不得而知。好在 Grafana 監控里面有一個面板記錄了 pump storage 的變化情況，路徑是：Binlog->pump->Storage Size。

從上面這個曲線聯想最近兩次的故障，貌似問題一下子清楚了：18號下午6點左右重啟 TiDB Server 恢復 binlog 寫入，pump 可用空間開始變少，到21號早上7點左右幾乎被使用完畢，觸發StopWriteAtAvailableSpace異常，binlog 停止寫入變成 skipping狀態，但與此同時 pump gc 還在工作，且沒有新的 binlog 進來，兩天后存量數據被 gc 完畢在23號早上7點左右恢復到空盤水平，持續到現在。

半途接手的集群，各種背景信息也不是很了解，經常奇奇怪怪問題一查就是查半天，這就是oncall人的日常。。??

解決方案

到這里問題已經很明確了，是磁盤空間不夠導致的，那么只有兩條路擺在面前：要么開源、要么節流。

經過和用戶溝通，加盤是不可能加的，直接就把 pump gc 縮短到1天。不過縮短 gc 也是存在風險的，如果哪次 drainer 故障超過1天那就要丟數據了。最終在24號下午6點左右把 gc 調整和 TiDB server 重啟剛好一起做了，binlog 同步恢復正常。

觀察幾天后發現，pump 磁盤使用率穩定在一半左右，評估不會再出現類似問題，可以睡個安穩覺了。

好在下游 kafka 對丟數據不敏感，可以接受隨時從當前時間重新同步，省了好多事，要不然得崩潰。

吐槽時間

不得不說要重啟 TiDB server 才能恢復 binlog 真的太難受了，生產環境不是想重啟就能重啟的，好在后面發現了還有個 API 能恢復 binlog，下次碰到了試一下。

curl http://{tidb-server ip}:{status_port}/binlog/recover

文檔隱蔽工作做的太好了，這些走后門的方法不知道 TiDB 還隱藏了多少。??

再就是在文檔上看到的 binlog 主從故障恢復方法，真是瑟瑟發抖，誰用誰996。↓↓↓

根據使用經驗來看，設置了ignore-error后發生 critical error的可能性非常高，binlog 同步真的是太脆了，一言不合就罷工。每次都要全備+ 恢復+重啟 TiDB server，對于動輒幾十T的集群那絕對是災難，時間成本不說，這么大數據量出錯的概率也高，想想都后背發涼。

被折磨的人應該不少。

總結

從這個案例中我總結到，在參數設置上要留有一些buffer，給后續出問題時有緩沖時間來處理。比如在本案中可以把stop-write-at-available-space設大一點，在出現磁盤空間不足時可以快速把值調小，這樣 binlog 還能恢復繼續同步，也能留出時間去做磁盤擴容，或者制定其他方案。

另外一點要注意 pump gc 的影響，它不會管 drainer 有沒有正常消費，gc 設置上也要給 drainer 故障處理留出一些時間。

最后，沒事多研究下監控指標，在排查問題時能少走很多彎路。

不好意思，標題讓 drainer 背鍋了。??

作者介紹：hey-hoho，來自神州數碼鈦合金戰隊，是一支致力于為企業提供分布式數據庫TiDB整體解決方案的專業技術團隊。團隊成員擁有豐富的數據庫從業背景，全部擁有TiDB高級資格證書，并活躍于TiDB開源社區，是官方認證合作伙伴。目前已為10+客戶提供了專業的TiDB交付服務，涵蓋金融、證券、物流、電力、*、零售等重點行業。

總結

以上是生活随笔為你收集整理的TiDB binlog故障处理之drainer周期性罢工的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。