binlog_summary分析MySQL Binlog

Binlog中，除了具体的SQL，其实，还包含了很多有价值的信息，如，

1. 事务的开始时间。
2. 事务的结束时间。
3. 事务的开始位置点。
4. 事务的结束位置点。
5. 操作的开始时间（一个事务通常会包含多个操作）。
6. 表的操作信息，如哪些表执行了哪些操作。

拿到上面这些信息，我们可以做哪些事情呢？

1. 基于事务的开始位置点和结束位置点，我们可以得到事务的大小。知道了事务的大小，可用来判断它是否为大事务，是否是导致主从延迟的原因。
2. 基于事务的开始时间和结束时间，我们可以得到事务的持续时间。
3. 通过分析表的操作信息，可间接定位出线上的热点表。

开发了一个简单的Binlog分析工具-binlog_summary.py，可提取上面这些信息，并在此基础上，进行一些常见分析。

下载地址：

https://github.com/slowtech/dba-toolkit/blob/master/MySQL/binlog_summary.py  

参数解析：

[root@db-test-tools-02-hankyoon ]# python binlog_summary.py --help

usage: binlog_summary.py [-h] [-f BINLOG_TEXT_FILE] [--new]
                         [-c {tps,opr,transaction}] [--start START_DATETIME]
                         [--stop STOP_DATETIME] [--sort SORT_CONDITION] [-e]
                         [--limit LIMIT]

optional arguments:
  -h, --help            show this help message and exit
  -f BINLOG_TEXT_FILE, --file BINLOG_TEXT_FILE
                        Binlog text file, not the Raw binary file
  --new                 Make a fresh start
  -c {tps,opr,transaction}, --command {tps,opr,transaction}
                        Command type: [tps, opr, transaction],tps: transaction
                        per second, opr: dml per table, transaction: show
                        transaction info
  --start START_DATETIME
                        Start datetime, for example: 2004-12-25 11:25:56
  --stop STOP_DATETIME  Stop datetime, for example: 2004-12-25 11:25:56
  --sort SORT_CONDITION
                        Sort condition: time or size, you can use it when
                        command type is transaction
  -e, --extend          Show transaction info in detail,you can use it when
                        command type is transaction
  --limit LIMIT         Limit the number of rows to display

其中，

• -f：Binlog通过mysqlbinlog解析后的文本文件。

• 注意，是文本文件，不是Binlog原始文件。使用mysqlbinlog解析时，建议指定-v（显示Pseudo SQL，即伪SQL）和--base64-output=decode-rows（不会显示Base64的编码结果）这两个参数，这样，生成的文本文件才是最小的，相应地，binlog_summary.py解析起来也是最快的。具体命令如下：

# mysqlbinlog --base64-output=decode-rows -v mysql-bin.000001 > /tmp/mysql-bin.000001.txt

• --new：工具的分析结果默认是存储在sqlite3数据库中。如果指定了--new，会删除之前创建的sqlite3数据库。在对一个新的Binlog进行分析时需指定该参数。

• -c：指定命令的类型。支持的命令类型有：

  • tps：分析实例的TPS信息。
  • opr：分析表的操作情况。
  • transaction：分析事务信息。

• --start：开始时间。分析指定时间段的日志。

• --stop：结束时间。

• --sort：排序条件。当命令类型是transaction时，默认是按照事务的执行顺序输出的，可指定size，按事务大小排序，也可指定time，按事务的持续时间排序。

• -e：当命令类型是transaction时，指定该参数会输出每个事务的详细操作信息。

• --limit：限制输出的行数。

常用命令

1. 分析实例的TPS信息：

# python binlog_summary.py -f /tmp/mysql-bin.000001.txt -c tps --limit 5

COMMIT_TIME        TPS                
2021-04-17 08:12:14 1                  
2021-04-17 08:12:15 7                  
2021-04-17 08:12:16 12                 
2021-04-17 08:12:17 12                 
2021-04-17 08:12:18 9                 

注意：这里的TPS是基于事务的提交时间来统计的。

如此细粒度的TPS信息，只能通过Binlog来获取。一般的监控很难做到这一点。

如果要对TPS进行排序，可通过管道 + sort，如：

# python binlog_summary.py -f /tmp/mysql-bin.000001.txt -c tps | sort -k 3 -n 

其中，-k 3是对第三列进行排序，-n是按照数值（默认是字符）的大小进行排序，也可指定-r参数，反向排序。

2. 分析表的操作情况：

# python binlog_summary.py -f /tmp/mysql-bin.000001.txt -c opr --limit 5

TABLE_NAME         DML_TYPE           NUMS               
sbtest.sbtest4     INSERT             609526             
sbtest.sbtest6     INSERT             543658             
sbtest.sbtest2     INSERT             309701             
sbtest.sbtest7     INSERT             309651             
sbtest.sbtest5     INSERT             309606           

这里的NUMS是执行次数。

3. 分析Binlog中最大的5个事务：

# python binlog_summary.py -f /tmp/mysql-bin.000001.txt -c transaction --sort size --limit 5

TRANS_NAME BEGIN_TIME          COMMIT_TIME         BEGIN_LOG_POS  COMMIT_LOG_POS DURATION_TIME  SIZE           
t62562     2021-04-17 08:30:01 2021-04-17 08:32:31 734265229      867878401      150            133613172      
t62561     2021-04-17 08:29:19 2021-04-17 08:29:19 677048698      734265148      0              57216450       
t62563     2021-04-17 08:33:26 2021-04-17 08:33:50 867878482      925094932      24             57216450       
t62564     2021-04-17 08:34:21 2021-04-17 08:34:21 925095013      971504525      0              46409512       
t62565     2021-04-17 08:34:58 2021-04-17 08:34:58 971504606      1016178117     0              44673511       

其中，

• TRANS_NAME：事务编号。
• BEGIN_TIME：事务开始时间。
• COMMIT_TIME：事务提交时间。
• BEGIN_LOG_POS：事务的开始位置点。
• COMMIT_LOG_POS：事务的结束位置点。
• DURATION_TIME：事务的持续时间，单位秒。其中，DURATION_TIME = COMMIT_TIME - BEGIN_TIME。
• SIZE：事务的大小，单位字节，其中，SIZE = COMMIT_LOG_POS - BEGIN_LOG_POS。

拿到事务的大小，我们可以粗略地判断这个Binlog中是否存在大事务。如果要进一步分析事务中包含哪些操作，需加上--extend，如：

# python binlog_summary.py -f /tmp/mysql-bin.000001.txt -c transaction --sort size --extend --limit 5

TRANS_NAME BEGIN_TIME           COMMIT_TIME          BEGIN_LOG_POS  COMMIT_LOG_POS  DURATION_TIME SIZE
t62562     2021-04-17 08:30:01  2021-04-17 08:32:31  734265229      867878401       150           133613172
├──        sbtest.sbtest2                            DELETE         200000
├──        sbtest.sbtest3                            UPDATE         100000
├──        sbtest.sbtest4                            INSERT         300000
t62561     2021-04-17 08:29:19  2021-04-17 08:29:19  677048698      734265148       0             57216450
├──        sbtest.sbtest1                            DELETE         300000
t62563     2021-04-17 08:33:26  2021-04-17 08:33:50  867878482      925094932       24            57216450
├──        sbtest.sbtest6                            DELETE         300000
t62564     2021-04-17 08:34:21  2021-04-17 08:34:21  925095013      971504525       0             46409512
├──        sbtest.sbtest5                            UPDATE         121324
t62565     2021-04-17 08:34:58  2021-04-17 08:34:58  971504606      1016178117      0             44673511
├──        sbtest.sbtest6                            INSERT         234234