共計 1660 個字符,預計需要花費 5 分鐘才能閱讀完成。
本篇內容主要講解“如何理解 MySQL 數據延遲跳動的問題”,感興趣的朋友不妨來看看。本文介紹的方法操作簡單快捷,實用性強。下面就讓丸趣 TV 小編來帶大家學習“如何理解 MySQL 數據延遲跳動的問題”吧!
首先在高可用檢測中,有一套環境的檢測時斷時續,經過排查發現是數據庫產生了延遲,在登錄到從庫 show slave status 查看,會發現 Seconds_behind_master 的值是不斷跳動的,即從 0~39~0~39 這樣的頻率不斷跳動,讓人很搓火。
查看數據庫的相關日志發現竟然沒有任何可以參考的日志記錄,怎么分析這個問題呢,我們先來復現,于是我按照節奏抓取了 3 次問題出現的日志,即通過 show slave status 連續監測,抓取 show slave status 輸出的結果保存下來,這樣我們就得到了一個問題發生過程中的偏移量變化,而這個變化則是在 SQLThread 在回放過程中產生的問題。
比如下面的一段輸出,我截取的是 Slave 端的 relay log 進行分析,相應的字段為 Relay_Log_Pos
Slave_IO_State: Waiting for master to send event Master_Host: xxxx Master_User: dba_repl Master_Port: 4306 Connect_Retry: 60 Master_Log_File: mysqlbin.000044 Read_Master_Log_Pos: 386125369 Relay_Log_File: slave-relay-bin.000066 Relay_Log_Pos: 386125580 Relay_Master_Log_File: mysqlbin.000044
所以很快得到了偏移量的變化情況:385983806,386062813,386125580
接著我使用 mysqlbinlog 開始分析這些日志過程中的明細,根據如下的命令可以很快得到轉儲的日志中相關的表有 3 張。
# grep INSERT relaylog_xxxx.dump |awk {print $3 $4} |sed s/INTO//g |sort|uniq act_action_exec_info act_join_desc dic_subsidy_marketing_querylog_202008
我逐步分析了每張表的數據操作情況,得到的信息還是比較有限,繼續做更進一步的分析,比如我們分析一下整個日志中的事務量大小:
# mysqlbinlog slave-relay-bin.000066 | grep GTID$(printf \t)last_committed -B 1 \ | grep -E ^# at | awk {print $3} \ | awk NR==1 {tmp=$1} NR 1 {print ($1-tmp);tmp=$1} \ | sort -n -r | head -n 100 mysqlbinlog: [Warning] unknown variable loose-default-character-set=utf8 5278 5268 5268 5268 5253 5253 5253 5253 5253
可以看到是 5K 左右,算是比較大了,而這些額外的信息從哪里獲得呢,我在主庫開啟了 general_log,這樣就能夠得到更細粒度的操作日志了。
進一步分析發現,整個業務使用了顯示事務的方式:SET autocommit=0,整個事務中包含了幾個大 SQL, 里面存儲了很多操作日志明細,而且在事務操作過程中還基于 Mybatis 框架調用了多次 select count(1) from xxx 的操作。
經過和業務溝通也基本明確了以上問題。
到此,相信大家對“如何理解 MySQL 數據延遲跳動的問題”有了更深的了解,不妨來實際操作一番吧!這里是丸趣 TV 網站,更多相關內容可以進入相關頻道進行查詢,關注我們,繼續學習!