如何通過(guò) binlog 定位大事務(wù)？你學(xué)會(huì)了嗎？
1序
大事務(wù)想必大家都遇到過(guò)，既然要對(duì)大事務(wù)進(jìn)行拆分，第一步就是要找到它。那么如何通過(guò) binlog 來(lái)定位到大事務(wù)呢？
首先，可通過(guò) binlog 文件的大小來(lái)判斷是否存在大事務(wù)，當(dāng)一個(gè) binlog 文件快被寫(xiě)完時(shí)，突然出現(xiàn)大事務(wù)，會(huì)突破 max_binlog_size 的大小繼續(xù)寫(xiě)入。
官方文檔[1] 中是這樣描述的：
A transaction is written in one chunk to the binary log, so it is never split between several binary logs. Therefore, if you have big transactions, you might see binary log files larger than max_binlog_size.
根據(jù)這個(gè)特點(diǎn)，只要進(jìn)入 binlog 的存放目錄，觀察到文件大小異常的 binlog，那么你就可以去解析這個(gè) binlog 獲取大事務(wù)了。當(dāng)然，需要注意的是，這只是一部分，文件大小正常的 binlog 中也藏著大事務(wù)。
2實(shí)踐
既然要定位大事務(wù)的 SQL，針對(duì)已開(kāi)啟 GTID 的實(shí)例，只要定位到對(duì)應(yīng)的 GTID 即可，下面我們開(kāi)始對(duì)一個(gè) binlog 進(jìn)行解析:
環(huán)境 | 測(cè)試環(huán)境 |
binlog 格式 | row |
binlog 版本 | v4 |
GTID | 已開(kāi)啟 |
已驗(yàn)證的 MySQL 版本 | MySQL 5.7.30、MySQL 8.0.28 |
首先，我們解析出一個(gè) binlog 中按照事務(wù)大小排名前 N 的事務(wù)。
# 為了方便保存為腳本，這里定義幾個(gè)基本的變量
BINLOG_FILE_NAME=$1 # binlog文件名
TRANS_NUM=$2 # 想要獲取的事務(wù)數(shù)量
MYSQL_BIN_DIR='/data/mysql/3306/base/bin' # basedir
# 獲取前TRANS_NUM個(gè)大事務(wù)
${MYSQL_BIN_DIR}/mysqlbinlog ${BINLOG_FILE_NAME} | 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);tmp=$1}' | sort -n -r -k 1 | head -n ${TRANS_NUM} > binlog_init.tmp經(jīng)過(guò)第一步對(duì) binlog 的基本解析后，我們已經(jīng)拿到了對(duì)應(yīng)事務(wù)的大小和可供定位 GTID 的 POS 信息，接下來(lái)對(duì)上述輸出的臨時(shí)文件進(jìn)行逐行解析，針對(duì)每一個(gè)事務(wù)獲取到相應(yīng)的信息。
while read line
do
# 事務(wù)大小這里取近似值，因?yàn)椴皇峭ㄟ^(guò)(TRANS_END_POS-TRANS_START_POS)計(jì)算出的
TRANS_SIZE=$(echo ${line} | awk '{print $1}')
logWriteWarning "TRANS_SIZE: $(echo | awk -v TRANS_SIZE=${TRANS_SIZE} '{ print (TRANS_SIZE/1024/1024) }')MB"
FLAG_POS=$(echo ${line} | awk '{print $2}')
# 獲取GTID
${MYSQL_BIN_DIR}/mysqlbinlog -vvv --base64-output=decode-rows ${BINLOG_FILE_NAME} | grep -m 1 -A3 -Ei "^# at ${FLAG_POS}" > binlog_parse.tmp
GTID=$(cat binlog_parse.tmp | grep -i 'SESSION.GTID_NEXT' | awk -F "'" '{print $2}')
# 通過(guò)GTID解析出事務(wù)的詳細(xì)信息
${MYSQL_BIN_DIR}/mysqlbinlog --base64-output=decode-rows -vvv --include-gtids="${GTID}" ${BINLOG_FILE_NAME} > binlog_gtid.tmp
START_TIME=$(grep -Ei '^BEGIN' -m 1 -A 3 binlog_gtid.tmp | grep -i 'server id' | awk '{print $1,$2}' | sed 's/#//g')
END_TIME=$(grep -Ei '^COMMIT' -m 1 -B 1 binlog_gtid.tmp | head -1 | awk '{print $1,$2}' | sed 's/#//g')
TRANS_START_POS=$(grep -Ei 'SESSION.GTID_NEXT' -m 1 -A 1 binlog_gtid.tmp | tail -1 | awk '{print $3}')
TRANS_END_POS=$(grep -Ei '^COMMIT' -m 1 -B 1 binlog_gtid.tmp | head -1 | awk '{print $7}')
# 輸出
logWrite "GTID: ${GTID}"
logWrite "START_TIME: $(date -d "${START_TIME}" '+%F %T')"
logWrite "END_TIME: $(date -d "${END_TIME}" '+%F %T')"
logWrite "TRANS_START_POS: ${TRANS_START_POS}"
logWrite "TRANS_END_POS: ${TRANS_END_POS}"
# 統(tǒng)計(jì)對(duì)應(yīng)的DML語(yǔ)句數(shù)量
logWrite "該事務(wù)的DML語(yǔ)句及相關(guān)表統(tǒng)計(jì):"
grep -Ei '^### insert' binlog_gtid.tmp | sort | uniq -c
grep -Ei '^### delete' binlog_gtid.tmp | sort | uniq -c
grep -Ei '^### update' binlog_gtid.tmp | sort | uniq -c
done < binlog_init.tmp至此，我們已經(jīng)基本實(shí)現(xiàn)了通過(guò)解析一個(gè) binlog 文件，從而拿到對(duì)應(yīng)的 GTID、事務(wù)開(kāi)始和結(jié)束時(shí)間、事務(wù)開(kāi)始和結(jié)束的 POS、對(duì)應(yīng)的 DML 語(yǔ)句數(shù)量統(tǒng)計(jì)。為了不重復(fù)執(zhí)行解析命令，我們可以將其封裝為腳本，作為日常運(yùn)維工具使用。
最終效果展示
[root@localhost ~]$ sh parse_binlog.sh /opt/sandboxes/rsandbox_5_7_35/master/data/mysql-bin.000003 2
2023-12-12 15:15:40 [WARNING] 開(kāi)始解析BINLOG: /opt/sandboxes/rsandbox_5_7_35/master/data/mysql-bin.000003
2023-12-12 15:15:53 [WARNING] TRANS_SIZE: 0.00161743MB
2023-12-12 15:16:06 [INFO] GTID: 00020236-1111-1111-1111-111111111111:362779
2023-12-12 15:16:06 [INFO] START_TIME: 2023-12-12 15:14:35
2023-12-12 15:16:06 [INFO] END_TIME: 2023-12-12 15:14:35
2023-12-12 15:16:06 [INFO] TRANS_START_POS: 362096066
2023-12-12 15:16:06 [INFO] TRANS_END_POS: 362097697
2023-12-12 15:16:06 [INFO] 該事務(wù)的DML語(yǔ)句及相關(guān)表統(tǒng)計(jì):
1 ### INSERT INTO `sbtest`.`sbtest100`
1 ### DELETE FROM `sbtest`.`sbtest100`
2 ### UPDATE `sbtest`.`sbtest100`
2023-12-12 15:16:06 [WARNING] TRANS_SIZE: 0.00161648MB
2023-12-12 15:16:25 [INFO] GTID: 00020236-1111-1111-1111-111111111111:505503
2023-12-12 15:16:25 [INFO] START_TIME: 2023-12-12 15:15:36
2023-12-12 15:16:25 [INFO] END_TIME: 2023-12-12 15:15:36
2023-12-12 15:16:25 [INFO] TRANS_START_POS: 603539112
2023-12-12 15:16:25 [INFO] TRANS_END_POS: 603540742
2023-12-12 15:16:25 [INFO] 該事務(wù)的DML語(yǔ)句及相關(guān)表統(tǒng)計(jì):
1 ### INSERT INTO `sbtest`.`sbtest100`
1 ### DELETE FROM `sbtest`.`sbtest100`
1 ### UPDATE `sbtest`.`sbtest100`
1 ### UPDATE `sbtest`.`sbtest87`通過(guò)上述結(jié)果可以看到，這種解析方式是基于事務(wù)的大小進(jìn)行排序的，有時(shí)我們還可能需要從時(shí)間維度進(jìn)行排序，通過(guò)大致相同的思路寫(xiě)腳本也可以實(shí)現(xiàn)，這里提供一個(gè)開(kāi)源的工具 my2sql[2]。
my2sql 可指定 rows 和 time 進(jìn)行過(guò)濾，在 mode 為 file 且 work-type 為 stats 時(shí)，連接任意一個(gè) MySQL 實(shí)例（無(wú)需原庫(kù)）均可對(duì) binlog 中的事務(wù)進(jìn)行解析。
# 統(tǒng)計(jì)指定 binlog 中各個(gè)表的 DML 操作數(shù)量(不加 row 和 time 限制)
[root@localhost ~]$ mkdir tmpdir
[root@localhost ~]$ ./my2sql -user root -password xxx -host 127.0.0.1 -port 3306 -mode file -local-binlog-file ./mysql-bin.005375 -work-type stats -start-file mysql-bin.005375 -output-dir ./tmpdir
# 按照事務(wù)的行數(shù)倒序排序
[root@localhost ~]$ less tmpdir/biglong_trx.txt | sort -nr -k 6 | less
# 按照事務(wù)的執(zhí)行時(shí)間倒序排序
[root@localhost ~]$ less tmpdir/biglong_trx.txt | sort -nr -k 7 | less
# 輸出示例(binlog starttime stoptime startpos stoppos rows duration tables)
mysql-bin.005375 2023-12-12_16:04:06 2023-12-12_16:16:59 493014756 582840954 123336 53 [test.t1(inserts=61668, updates=0, deletes=0) test.t2(inserts=61668, updates=0, deletes=0)]參考資料
[1]sysvar_max_binlog_size: https://dev.mysql.com/doc/refman/5.7/en/replication-options-binary-log.html#sysvar_max_binlog_size
[2]my2sql: https://github.com/liuhr/my2sql
作者：李彬，愛(ài)可生 DBA 團(tuán)隊(duì)成員，負(fù)責(zé)項(xiàng)目日常問(wèn)題處理及公司平臺(tái)問(wèn)題排查。愛(ài)好有億點(diǎn)點(diǎn)多，吉他、旅行、打游戲…
