如何通過 binlog 定位大事務？你學會了嗎？
1序
大事務想必大家都遇到過，既然要對大事務進行拆分，第一步就是要找到它。那么如何通過 binlog 來定位到大事務呢？
首先，可通過 binlog 文件的大小來判斷是否存在大事務，當一個 binlog 文件快被寫完時，突然出現大事務，會突破 max_binlog_size 的大小繼續寫入。
官方文檔[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.
根據這個特點，只要進入 binlog 的存放目錄，觀察到文件大小異常的 binlog，那么你就可以去解析這個 binlog 獲取大事務了。當然，需要注意的是，這只是一部分，文件大小正常的 binlog 中也藏著大事務。
2實踐
既然要定位大事務的 SQL，針對已開啟 GTID 的實例，只要定位到對應的 GTID 即可，下面我們開始對一個 binlog 進行解析:
環境 | 測試環境 |
binlog 格式 | row |
binlog 版本 | v4 |
GTID | 已開啟 |
已驗證的 MySQL 版本 | MySQL 5.7.30、MySQL 8.0.28 |
首先，我們解析出一個 binlog 中按照事務大小排名前 N 的事務。
# 為了方便保存為腳本，這里定義幾個基本的變量
BINLOG_FILE_NAME=$1 # binlog文件名
TRANS_NUM=$2 # 想要獲取的事務數量
MYSQL_BIN_DIR='/data/mysql/3306/base/bin' # basedir
# 獲取前TRANS_NUM個大事務
${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經過第一步對 binlog 的基本解析后，我們已經拿到了對應事務的大小和可供定位 GTID 的 POS 信息，接下來對上述輸出的臨時文件進行逐行解析，針對每一個事務獲取到相應的信息。
while read line
do
# 事務大小這里取近似值，因為不是通過(TRANS_END_POS-TRANS_START_POS)計算出的
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}')
# 通過GTID解析出事務的詳細信息
${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}"
# 統計對應的DML語句數量
logWrite "該事務的DML語句及相關表統計:"
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至此，我們已經基本實現了通過解析一個 binlog 文件，從而拿到對應的 GTID、事務開始和結束時間、事務開始和結束的 POS、對應的 DML 語句數量統計。為了不重復執行解析命令，我們可以將其封裝為腳本，作為日常運維工具使用。
最終效果展示
[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] 開始解析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] 該事務的DML語句及相關表統計:
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] 該事務的DML語句及相關表統計:
1 ### INSERT INTO `sbtest`.`sbtest100`
1 ### DELETE FROM `sbtest`.`sbtest100`
1 ### UPDATE `sbtest`.`sbtest100`
1 ### UPDATE `sbtest`.`sbtest87`通過上述結果可以看到，這種解析方式是基于事務的大小進行排序的，有時我們還可能需要從時間維度進行排序，通過大致相同的思路寫腳本也可以實現，這里提供一個開源的工具 my2sql[2]。
my2sql 可指定 rows 和 time 進行過濾，在 mode 為 file 且 work-type 為 stats 時，連接任意一個 MySQL 實例（無需原庫）均可對 binlog 中的事務進行解析。
# 統計指定 binlog 中各個表的 DML 操作數量(不加 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
# 按照事務的行數倒序排序
[root@localhost ~]$ less tmpdir/biglong_trx.txt | sort -nr -k 6 | less
# 按照事務的執行時間倒序排序
[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
作者：李彬，愛可生 DBA 團隊成員，負責項目日常問題處理及公司平臺問題排查。愛好有億點點多，吉他、旅行、打游戲…
