## 背景 官方 5.6 最新版本 5.6.24 有這樣一個bugfix，當使用 GTID 協議進行復制，并且備庫的 slave_net_timeout 值設置太小的話，備庫的 slave io 線程會卡住，同時主庫上的 binlog dump 線程數一直在漲，[官方的bug地址](http://bugs.mysql.com/bug.php?id=74607 "slave io_thread may get stuck when using GTID and low slave_net_timeouts")?。 ## bug分析 首先說明下幾個概念： 1\. slave_net_timeout，這個變量控制備庫 IO 線程的連接超時，如果IO線程在指定時間內沒有從主庫收到數據的話，就斷開重連，默認值是3600秒； 2\. heartbeat 事件，主庫在dump線程空閑的時候（dump線程已經把所有binlog都發給備庫了，主庫還沒有更新操作），就隔斷時間發一個 heartbeat 給備庫，以免備庫超時斷開，這個時間間隔是備庫在 change master 時傳過來的，在 rpl_slave.cc 中可以看到，默認取?`min<float>(SLAVE_MAX_HEARTBEAT_PERIOD, (slave_net_timeout/2.0))`； 3\. GTID 的 auto_position 協議，正是因為有了 GTID，才可以在 chang master 時不指定binlog坐標（filename, pos），但是主庫dump線程在發給備庫event的時候，還是需要從某個坐標開始的，只是這個過程通過 GTID 能自動搜出來罷了，關于如何找到要發送的第一個 binlog 可以看下[之前的月報](http://mysql.taobao.org/index.php?title=MySQL%E5%86%85%E6%A0%B8%E6%9C%88%E6%8A%A5_2014.11#MySQL.C2.B7.E3.80.80.E6.8D.89.E8.99.AB.E5.8A.A8.E6.80.81.C2.B7SIGHUP_.E5.AF.BC.E8.87.B4_binlog_.E5.86.99.E9.94.99 "內核月報2014.11 捉蟲動態·SIGHUP 導致 binlog 寫錯")，找到后就需要從這個 binlog 開頭開始掃描，找到第一個備庫沒有 GTID，然后開始發送。 問題的源頭就出在 binlog 文件掃描上，官方 bug 的復現步驟中有這樣一個條件，use 1GB binlog file size. stop slave at high binlog position (>800MB)，就是說主庫的 binlog 要比較大，并且備庫 IO 線程要停在這個 binlog 比較靠后的位置。這樣備庫 start slave 連上的時候，主庫的 dump 線程就要從這個 binlog 開頭往后掃，找到開始發送 binlog 的位置，如果文件比較大的話，這個掃描時間就會比較長。heartbeat 事件是在主庫空閑的時候才會發送的，在掃描過種中是不會檢查要不要發 heartbeat 的，如果備庫的 slave_net_timeout 設置比較小的話，超過時間還沒收到一個事件，這時備庫 IO 就會停下，然后重連。 IO 線程重連會導致另外一個問題，我們知道一個主庫是可以拖多個備庫的，但是對每個備庫只能有一個連接，如果已經連上來的備庫再發一個 dump 請求的話，主庫就會把當前備庫老的 IO 連接置為 killed，具體函數是 sql/rpl_master.cc 中的?`kill_zombie_dump_threads`，但這個 kill 只是置了標志位，還需要老的 dump 線程自己判斷，然后退出。dump 線程 killed 狀態檢測只在切換 binlog 和空閑的時候，如果這個時候老的 dump 線程還在掃 binlog，即使已經是killed了也不會退出。而同時新的 dump 線程依然要從頭掃 binlog，重復上面的過程，導致備庫 IO 又超時重連，因此在主庫上show processlist的話，會看到 dump 線程慢慢堆積起來。 下面的結果就是備庫 slave_net_timeout 設置為10s的測試結果，可以看到相鄰 dump 線程差不多間隔10s。 ~~~ | 9 | root | localhost:46882 | NULL | Binlog Dump GTID | 159 | init | NULL | | 10 | root | localhost:46929 | NULL | Binlog Dump GTID | 149 | init | NULL | | 11 | root | localhost:46975 | NULL | Binlog Dump GTID | 138 | init | NULL | | 12 | root | localhost:47023 | NULL | Binlog Dump GTID | 127 | init | NULL | | 13 | root | localhost:47074 | NULL | Binlog Dump GTID | 115 | init | NULL | | 14 | root | localhost:47143 | NULL | Binlog Dump GTID | 104 | init | NULL | | 15 | root | localhost:47206 | NULL | Binlog Dump GTID | 93 | init | NULL | | 16 | root | localhost:47255 | NULL | Binlog Dump GTID | 82 | init | NULL | | 17 | root | localhost:47311 | NULL | Binlog Dump GTID | 71 | init | NULL | | 18 | root | localhost:47362 | NULL | Binlog Dump GTID | 60 | init | NULL | | 19 | root | localhost:47427 | NULL | Binlog Dump GTID | 49 | init | NULL | ~~~ 如果在備庫上 show slave status 的的話，會看到 IO 線程接收的 binlog 位點一直不更新，就像 hang 住了一樣。 ## bug修復 出現這個問題是因為主庫 dump 線程檢測 heartbeat_period 和 thd->killed 的粒度太大，都是 binlog 文件級別的，因此官方的改法就是把兩者的檢測粒度降為event級別，dump 線程每 read 一個 event，都會檢測是否該發送 heartbeat 了，同時 thd 的 killed 標志是否被置上，是的話就退出。 具體的patch可以看[官方github](https://github.com/mysql/mysql-server/commit/9ab03d0d41b25b86978b7a0aaf12f4a77c96dc27 "github patch commit")。 有了這個 patch 后，主庫 dump 線程還是需要時間掃描binlog，備庫的 IO 線程看起來依然像 hang 住一樣，但是已經不會超時重連，主庫的dump 線程也不會堆積。