今天分析了另外一個關于數據庫延遲跳動的問題，也算是比較典型，這個過程中也有一些分析問題的方法和技巧工參考。
首先在高可用檢測中，有一套環境的檢測時斷時續，經過排查發現是數據庫產生了延遲，在登錄到從庫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數據延遲跳動的問題解決的詳細內容，更多關于MySQL數據延遲跳動的資料請關注腳本之家其它相關文章！
您可能感興趣的文章:- 如何解決mysql insert亂碼的問題
- 如何解決mysql無法關閉的問題
- 解決MySQL數據庫意外崩潰導致表數據文件損壞無法啟動的問題
- 一文解決django 2.2與mysql兼容性問題
- 淺談mysql導出表數據到excel關于datetime的格式問題
- 快速解決mysql導數據時,格式不對、導入慢、丟數據的問題
- 快速解決mysql導出scv文件亂碼、躥行的問題
- Docker的MySQL容器時區問題修改
- pyMySQL SQL語句傳參問題,單個參數或多個參數說明
- MySQL 5.7.30 安裝與升級問題詳細教程
