MYSQL BINLOG文件解析

MySQL
499
0
0
2023-04-07
标签   MySQL日志

写在前面

本文有点长, 不耐心的可以直接看总结.

说明

也可以使用gdb查看生成binlog过程的, 但是太复杂了... 还是看源码注释方便点.

本文主要介绍的binlog 4的格式,下面使用的均是binlog4的情况, 然后使用python解析该格式与mysqlbinlog做对比.

解析binlog的工具有: mysqlbinlog, binlog2sql, pymysqlreplication等.

下面的int类型未特殊说明均使用小端(little), 均为无符号

我的环境:

mysql 5.7.38-log

binlog_format = ROW

binlog_row_image = FULL

binlog_checksum = None #不影响,反正是最后4字节

可变长度计算方法:

本文例子均只考虑第一种情况. 主要是演示

第一个字段值

占用大小 取值范围

0-250

1字节 0-250

252

2字节 251-0xffff

253

3字节 0xffff-0xffffff

254

8字节 0xffffff-0xfffffffffffffff

BINLOG文件格式

官网介绍binlog文件 由开头的 4字节(0xFE 'bin’) 加上一些列的 event 组成.

第一个event是START_EVENT_V3或者FORMAT_DESCRIPTION_EVENT.

最后一个event是STOP_EVENT或者rROTATE_EVENT

所以我们着重看event组成即可.

img

BINLOG EVENT

binlog event组成

binlog event是 由 event_header(固定19字节) 加上 event_body(由各事件决定大小)组成

|   event header(19字节)   |      event body           |

event_header

从左到右的字节为如下表内容

数据类型

名字

描述

int<4>

timestamp

时间戳

int<1>

event_type

event类型(5.7.38就有43种...)

int<4>

server-id

server_id

int<4>

event-size

event大小(含event_header的19字节)

int<4>

log-pos

下个event的起始地址(本event的结束地址)

int<2>

flags

flag

event_body

event_body由 post_header body crc32(可选,由变量binlog_checksum决定)组成

|   post_header  |     body      | crc32 |

不同的event的内容不一样, 下面讲下常用的event格式

binlog event分类

只列举部分.

管理类:

主要是控制识别binlog file的

  • START_EVENT_V3 第一个event
  • FORMAT_DESCRIPTION_EVENT 第一个event,替代start_event_v3的, 格式同start_event_v3
  • STOP_EVENT 最后一个event, 表示服务器已经停止运行(下次启动自动轮转)
  • ROTATE_EVENT 最有一个event, 服务器还在运行(自动轮转或者flush log)
  • SLAVE_EVENT
  • INCIDENT_EVENT
  • HEARTBEAT_EVENT

语句类:

  • QUERY_EVENT 存SQL的, 比如DDL
  • INTVAR_EVENT
  • RAND_EVENT
  • USER_VAR_EVENT
  • XID_EVENT 2pc提交的时候会写入这个event. 当作事务结束的标志

ROW格式类:

下面会讲这个的详细结构

  • TABLE_MAP_EVENT 每个row event前面都有个table_map_event记录表名和字段数据类型
  • DELETE_ROWS_EVENT 记录delete的
  • UPDATE_ROWS_EVENT 记录update的
  • WRITE_ROWS_EVENT 记录insert的

常见binlog event结构

FORMAT_DESCRIPTION_EVENT

每个Binlog文件的第一个event, 这个event记录如下数据

名字

大小(字节)

描述

binlog_version

int<2>

记录binlog版本的, 均为4

mysql_server_version

char<50>

记录mysql版本的, 不足的填充0

create_timestamp

int<4>

创建时间

event_header_length

int<1>

每个event的event_header的大小,固定值19

event_type_header_length

header的event_size减去上面的大小(19), 为数组类型, 每个记录值为1字节

每个event的event body的post header的大小




event_type_header_length 记录值参考(5.7.38-log) [56, 13, 0, 8, 0, 18, 0, 4, 4, 4, 4, 18, 0, 0, 95, 0, 4, 26, 8, 0, 0, 0, 8, 8, 8, 2, 0, 0, 0, 10, 10, 10, 42, 42, 0, 18, 52, 0, 1, 20, 121, 129, 83]

TABLE_MAP_EVENT

这个是row格式独有的, 记录下个row_event的表名,各字段类型.

除了开头8字节外(post_header)外, 均为可变长度....

名字

大小(字节)

描述

table_id

int<6>

表打开的id, 不是数据库里面的table_id

flags

2

保留字段

database_name_length

可变长度

数据库名长度

database_name

取决于database_name_length

数据库名(以0x00结尾, 这个字节不计算在database_name_length中)

table_name_length

可变长度

表名长度

table_name

取决于table_name_length

表名(以额外的0x00结尾, 就是不在table_name_length的计算中)

column_count

可变长度

多少个字段

column_type_list

取决于column_count

list类型, 每个字段的数据类型,用1字节表示(比如3表示int<4> 详情)

.....

.....

暂时用不上其它的

ROWS_EVENT

row_event 包含Delete_rows_log_event 和 Write_rows_log_event 和 Update_rows_log_event

继承关系如下图

img

Delete_rows_log_event 和 Write_rows_log_event 和 Update_rows_log_event 基本上一样, 都是继承自row_log_event

区别在于 Write_rows_log_event(insert) 没得Cols_before_image delete_rows_log_event没得Cols_after_image

         +-------------------------------------------------------+
         | Event Type | Cols_before_image | Cols_after_image     |
         +-------------------------------------------------------+
         |  DELETE    |   Deleted row     |    NULL              |
         |  INSERT    |   NULL            |    Inserted row      |
         |  UPDATE    |   Old     row     |    Updated row       |
         +-------------------------------------------------------+

结构如下

也是只有开头的8字节(post header)固定

名字

大小(字节)

描述

table_id

6


flags

2


width

可变长度

表有多少列

cols

INT((width + 7) / 8)

是否使用该列, 每列对于一个bit位, 对字节向上取整(数据读写只能按字节读写)

extra_row_info

Extra_row_info

暂不考虑, 以1字节算

columns_before_image

INT((width + 7) / 8)

仅update和delete有. 与binlog_row_image有关

columns_after_image

INT((width + 7) / 8)

仅update和insert有

Null_bit_mask

INT((width + 7) / 8)

某列是否为空, 每列对应一个比特位

row

table_map_event记录了大小

具体的数据(before_image + after_image), 如果还剩4字节的话, 就是CRC32校验. 每个image数据前面都有null_bit_mask

验证

生成测试数据

另起一个binlog 方便观察

(root@127.0.0.1) [(none)]> flush logs;
Query OK, 0 rows affected (0.01 sec)

(root@127.0.0.1) [(none)]> create table db1.t20230310(id int primary key, name varchar(20));
Query OK, 0 rows affected (0.01 sec)

(root@127.0.0.1) [(none)]> begin;
Query OK, 0 rows affected (0.00 sec)

(root@127.0.0.1) [(none)]> insert into db1.t20230310 values(1,'first'),(2,'ddcw');
Query OK, 2 rows affected (0.00 sec)
Records: 2  Duplicates: 0  Warnings: 0

(root@127.0.0.1) [(none)]> delete from db1.t20230310 where id=1;
Query OK, 1 row affected (0.00 sec)

(root@127.0.0.1) [(none)]> update db1.t20230310 set name = 'ddcw update' where id=2;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0

(root@127.0.0.1) [(none)]> commit;
Query OK, 0 rows affected (0.01 sec)

(root@127.0.0.1) [(none)]> show master status\G
*************************** 1. row ***************************
             File: m3308.001008
         Position: 1027
     Binlog_Do_DB: 
 Binlog_Ignore_DB: 
Executed_Gtid_Set: 6d650f1f-ba4e-11ed-99ab-000c2980c11e:1-29253,
7ab066ef-c1be-11ec-92dd-000c2980c11e:2579-2584:2700,
90bdfbb7-cbe2-11ec-a870-000c2980c112:25178542,
90bdfbb7-cbe2-11ec-a870-000c2980c11e:1-14138280:25178542,
aaaaaaaa-aaaa-aaaa-aaaa-aaaaaaaaaaaa:1-283382
1 row in set (0.00 sec)

hexdump解析

这个就是人工解析了, 只解析一部分. 重复的工作应该机器做

只解析第一个event吧...

12:23:55 [root@ddcw21 ~]#hexdump -C /data/mysql_3308/mysqllog/binlog/m3308.001008 
00000000  fe 62 69 6e 35 b0 0a 64  0f 6c 30 ad 18 77 00 00  |.bin5..d.l0..w..|
00000010  00 7b 00 00 00 01 00 04  00 35 2e 37 2e 33 38 2d  |.{.......5.7.38-|
00000020  6c 6f 67 00 00 00 00 00  00 00 00 00 00 00 00 00  |log.............|
00000030  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
00000040  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 13  |................|
00000050  38 0d 00 08 00 12 00 04  04 04 04 12 00 00 5f 00  |8............._.|

前4个字节 fe 62 69 6e 查询ascii表得 '\xfebin' 和上面官方说的一致

img

再来看看第一个event, 前19字节是header, 不看了, 太多了. 从 4 + 19 字节看起走

注意是使用的小端

img

名字

二进制数据

ascii编码后

binlog_version

b'\x04\x00'

4

mysql_server_version

b'5.7.38-log\x00\x00' 为方便观察,去掉了后面的填充字段

5.7.38-log (去掉了填充字段)

create_timestamp

b'\x00\x00\x00\x00'

0

event_header_length

b'\x13'

19

event_type_header_length

b'8\r\x00\x08\x00 .... \x00m/Lp' 为方便观察省略了中间的数据

[56, 13, 0, 8, 0, 18, 0, 4, 4, 4, 4, 18, 0, 0, 95, 0, 4, 26, 8, 0, 0, 0, 8, 8, 8, 2, 0, 0, 0, 10, 10, 10, 42, 42, 0, 18, 52, 0, 1, 20, 121, 129, 83]

Python解析

人工解析确实太费劲了, 我们使用python来解析

脚本见文末. 此脚本未解析 row(需要TABLE_MAP_EVENT) 和 crc32

import row_event
aa = row_event.parse_event('/data/mysql_3308/mysqllog/binlog/m3308.001008',1000)
for x in aa:
	print(x)

img每个row_event上面都有个TABLE_MAP_EVENT

我们人工解析下最后个update的row

数据 b'\xfc\x02\x00\x00\x00\x04ddcw\xfc\x02\x00\x00\x00\x0bddcw update'

类型 [3, 15] 查表 得 3对应 int<4> 15对应varchar

未使用binlog crc32校验(mgr), 有的话, row的最后4字节就是crc32校验

>>> def btoint(bdata,t='little'):
...         return int.from_bytes(bdata,t)
... 
>>> aa = b'\xfc\x02\x00\x00\x00\x04ddcw\xfc\x02\x00\x00\x00\x0bddcw update'
>>> aa[0:1] #befor image null_bit_map
b'\xfc'
>>> btoint(aa[1:1+4]) #before image first column
2
>>> btoint(aa[5:6]) #查看varchar记录的长度, 仅考虑0-250(1字节的情况)
4
>>> aa[6:6+4] #before image seccond column
b'ddcw'
>>> 
>>> aa[10:11] #after image的 null_bit_map
b'\xfc'
>>> btoint(aa[11:15]) #after image的第一列 
2
>>> btoint(aa[15:16]) #after image的 第二列的长度
11
>>> aa[16:27]
b'ddcw update'
>>> 

得到 Update前数据 (2,'ddcw') update后数据为(2,'ddcw update')

然后使用mysqlbinlog 解析对比一下, 发现对的上, 说明没有解析错

img

总结

1. binlog文件由开头固定4字节和 各个event组成 (relay log也是)

2. 每个event由 header(固定19字节) 和 body组成, body又由post header 和 data组成(若剩余4字节就是crc32校验码)

3. 每个row_event前面都有个table_map_event记录表名,字段类型等信息.

4. 最后一个event如果是stop_event, 那就说明服务器停止了(下次启动字段切换), 如果是rota_event就说明文件切换了.

5. Delete_rows_log_event 和 Write_rows_log_event 和 Update_rows_log_event 都是继承自row_log_event, 区别在于 Write_rows_log_event(insert) 没得Cols_before_image

delete_rows_log_event没得Cols_after_image

附python代码

row_event.py

import binlog_event_type
import struct
def btoint(bdata,t='little'):
	return int.from_bytes(bdata,t)

def event_header(bdata):
	timestamp, event_type, server_id, event_size, log_pos, flags = struct.unpack("<LBLLLh",bdata[0:19])
	return {"timestamp":timestamp,'event_type':event_type,'server_id':server_id,'event_size':event_size,'log_pos':log_pos,'flags':flags,}


def first_event(bdata):
	#FORMAT_DESCRIPTION_EVENT
	ethl = len(bdata) - 57 #2 50 4 1 var
	ff = f'<h50sLB{ethl}s'
	binlog_version, mysql_server_version, create_timestamp, event_header_length, event_type_header_length = struct.unpack(ff,bdata)
	mysql_server_version = mysql_server_version.decode('ascii').replace('\x00','') #美化一下
	event_type_header_length = [ int(x) for x in event_type_header_length ] #event specific header length. 比如TABLE_MAP_EVENT = 8 (table_id:6 + flag:2) #记录其它event的post header的长度
	return {'binlog_version':binlog_version, 'mysql_server_version':mysql_server_version, 'create_timestamp':create_timestamp, 'event_header_length':event_header_length, 'event_type_header_length':event_type_header_length,}

def table_map_event(bdata):
	post_header = {'table_id':btoint(bdata[0:6]), 'flags':btoint(bdata[6:8])} #flags保留字段
	offset = 8
	database_length = btoint(bdata[offset:offset+1])
	offset +=1
	database_name = bdata[offset:offset+database_length].decode() #0x00 结尾
	offset += database_length + 1
	table_length = btoint(bdata[offset:offset+1])
	offset +=1
	table_name = bdata[offset:offset+table_length].decode() #0x00 结尾, 但是我不读,计数的时候别忘了就行
	offset += table_length + 1
	column_count = btoint(bdata[offset:offset+1]) #Packed Integer 我只考虑0-250个字段. 也就是占用1字节 计算方式https://dev.mysql.com/doc/dev/mysql-server/latest/classbinary__log_1_1Binary__log__event.html#packed_integer
	offset += 1
	column_type_list = []
	for x in range(column_count):
		column_type_list.append(btoint(bdata[offset:offset+1])) #先不做转换了.具体类型参考https://dev.mysql.com/doc/dev/mysql-server/latest/classbinary__log_1_1Table__map__event.html
		offset += 1

	#metadata_length和column_count一样, 但是我不想写了
	#省略 metadata_length metadata null_bits optional metadata fields
	return {
		'post_header':post_header,
		'body':{
			'database_name':database_name,
			'table_name':table_name,
			'column_type_list':column_type_list,
		}
		}
	


def row_event(bdata,imaget):
	#不解析具体的字段, 因为需要table_map才知道对应的字段类型
	#columns_before_image delete,update
	#columns_after_image  insert,update
	data = {}
	post_header = {'table_id':btoint(bdata[0:6]), 'flags':btoint(bdata[6:8])} #flags保留字段
	data['post_header'] = post_header
	data['body'] = {}
	offset = 8
	width = btoint(bdata[offset:offset+1])
	offset += 1
	_toff = int((width+7)/8)
	cols = btoint(bdata[offset:offset+_toff])
	offset += _toff
	extra_row_info = btoint(bdata[offset:offset+1])
	offset += 1
	if imaget == 30 or imaget == 31: #30 write   31 update   32 delete
		columns_after_image = btoint(bdata[offset:offset+_toff])
		offset += _toff
		data['body']['columns_after_image'] = columns_after_image
	if imaget == 32 or imaget == 31:
		columns_before_image = btoint(bdata[offset:offset+_toff])
		offset += _toff
		data['body']['columns_before_image'] = columns_before_image
	data['body']['row'] = bdata[offset:]
	data['body']['width'] = width
	data['body']['cols'] = cols
	data['body']['extra_row_info'] = extra_row_info
	return data
		



def parse_event(filename,n=10): #默认只解析前面10个event 
	data = []
	with open(filename,'rb') as f:
		magic = f.read(4)
		if magic != b'\xfebin':
			return False
		for x in range(n):
			event_data = None
			try:
				common_header = event_header(f.read(19))
			except:
				break
			event_bdata = f.read(common_header['event_size']-19)
			if common_header['event_type'] == binlog_event_type.FORMAT_DESCRIPTION_EVENT:
				event_data = first_event(event_bdata)
				common_header['event_type'] = 'FORMAT_DESCRIPTION_EVENT'
			elif common_header['event_type'] == binlog_event_type.WRITE_ROWS_EVENT:
				event_data = row_event(event_bdata,common_header['event_type'])
				common_header['event_type'] = 'WRITE_ROWS_EVENT'
			elif common_header['event_type'] == binlog_event_type.UPDATE_ROWS_EVENT:
				event_data = row_event(event_bdata,common_header['event_type'])
				common_header['event_type'] = 'UPDATE_ROWS_EVENT'
			elif common_header['event_type'] == binlog_event_type.DELETE_ROWS_EVENT:
				event_data = row_event(event_bdata,common_header['event_type'])
				common_header['event_type'] = 'DELETE_ROWS_EVENT'
			elif common_header['event_type'] == binlog_event_type.TABLE_MAP_EVENT:
				event_data = table_map_event(event_bdata)
				common_header['event_type'] = 'TABLE_MAP_EVENT'
			elif common_header['event_type'] == binlog_event_type.GTID_LOG_EVENT:
				common_header['event_type'] = 'GTID_LOG_EVENT'
			elif common_header['event_type'] == binlog_event_type.XID_EVENT:
				common_header['event_type'] = 'XID_EVENT'
			elif common_header['event_type'] == binlog_event_type.QUERY_EVENT:
				common_header['event_type'] = 'QUERY_EVENT'
				event_data = event_bdata
			elif common_header['event_type'] == binlog_event_type.STOP_EVENT:
				common_header['event_type'] = 'STOP_EVENT'
			elif common_header['event_type'] == binlog_event_type.PREVIOUS_GTIDS_LOG_EVENT:
				common_header['event_type'] = 'PREVIOUS_GTIDS_LOG_EVENT'
			elif common_header['event_type'] == binlog_event_type.ROTATE_EVENT:
				common_header['event_type'] = 'ROTATE_EVENT'
			data.append({'event_header':common_header,'event_body':event_data})
	return data

binlog_event_type.py

从源码 libbinlogevents/include/binlog_event.h 里面复制出来的

# -*- coding: utf-8 -*-
# libbinlogevents/include/binlog_event.h
UNKNOWN_EVENT= 0
START_EVENT_V3= 1
QUERY_EVENT= 2
STOP_EVENT= 3
ROTATE_EVENT= 4
INTVAR_EVENT= 5
LOAD_EVENT= 6
SLAVE_EVENT= 7
CREATE_FILE_EVENT= 8
APPEND_BLOCK_EVENT= 9
EXEC_LOAD_EVENT= 10
DELETE_FILE_EVENT= 11
NEW_LOAD_EVENT= 12
RAND_EVENT= 13
USER_VAR_EVENT= 14
FORMAT_DESCRIPTION_EVENT= 15
XID_EVENT= 16
BEGIN_LOAD_QUERY_EVENT= 17
EXECUTE_LOAD_QUERY_EVENT= 18

TABLE_MAP_EVENT = 19

PRE_GA_WRITE_ROWS_EVENT = 20
PRE_GA_UPDATE_ROWS_EVENT = 21
PRE_GA_DELETE_ROWS_EVENT = 22

WRITE_ROWS_EVENT_V1 = 23
UPDATE_ROWS_EVENT_V1 = 24
DELETE_ROWS_EVENT_V1 = 25

INCIDENT_EVENT= 26

HEARTBEAT_LOG_EVENT= 27

IGNORABLE_LOG_EVENT= 28
ROWS_QUERY_LOG_EVENT= 29

WRITE_ROWS_EVENT = 30
UPDATE_ROWS_EVENT = 31
DELETE_ROWS_EVENT = 32

GTID_LOG_EVENT= 33
ANONYMOUS_GTID_LOG_EVENT= 34

PREVIOUS_GTIDS_LOG_EVENT= 35 #描述之前的gtid信息(不需要扫描之前的binlog文件)

TRANSACTION_CONTEXT_EVENT= 36

VIEW_CHANGE_EVENT= 37

XA_PREPARE_LOG_EVENT= 38