背景

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

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

故障現(xiàn)象

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

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

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

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

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

分析過程

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

根據 binlog skip 狀態(tài)，轉頭去分析 TiDB server監(jiān)控，在 TiDB->Server->Skip Binlog Count面板可以看到被跳過的 binlog 數(shù)量：

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

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

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

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

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

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

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

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

從上面這個曲線聯(lián)想最近兩次的故障，貌似問題一下子清楚了：18號下午6點左右重啟 TiDB Server 恢復 binlog 寫入，pump 可用空間開始變少，到21號早上7點左右?guī)缀醣皇褂猛戤叄|發(fā)StopWriteAtAvailableSpace異常，binlog 停止寫入變成 skipping狀態(tài)，但與此同時 pump gc 還在工作，且沒有新的 binlog 進來，兩天后存量數(shù)據被 gc 完畢在23號早上7點左右恢復到空盤水平，持續(xù)到現(xiàn)在。

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

解決方案

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

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

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

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

吐槽時間

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

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

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

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

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

被折磨的人應該不少。

總結

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

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

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

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

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

總結

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

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