主从协议分析

模拟从库，连接主库，获取binlog事件

获取binlog

连接成功后，发送binlogdump指令给主库，并附带要访问的binlog文件和偏移（可以事先从show master status获取到）。客户端开始被动等待，主库开始发送

out|2017-10-11 12:36:40|[read packet]    [file: mysql-bin.000005]    [curPos: 14161]    [curTypeEvent: 4 ROTATE_EVENT]    [nextPosValid: 14161]    [nextPos: 14161]
out|2017-10-11 12:36:40|[read packet]    [file: mysql-bin.000005]    [curPos: 14161]    [curTypeEvent: 15 FORMAT_DESCRIPTION_EVENT]    [nextPosValid: 14161]    [nextPos: 0]

注：rotate event并不真正存在主库的binlog文件中，format event是真实binlog文件的第一个事件。每次建立起连接，客户端发送了dump指令后，master总是会先发送这两个event，再从client要求的偏移开始发送数据。

注：format event在binlog文件中只会存在一次（第一个）。但每次连接后，都会被发送。

Ref:sql/rpl_master.cc:1081

一个更新操作产生的事件

out|2017-10-11 12:36:47|[read packet]    [file: mysql-bin.000005]    [curPos: 14161]    [curTypeEvent: 34 ANONYMOUS_GTID_LOG_EVENT]    [nextPosValid: 14226]    [nextPos: 14226]
out|2017-10-11 12:36:47|[read packet]    [file: mysql-bin.000005]    [curPos: 14226]    [curTypeEvent: 2 QUERY_EVENT]    [nextPosValid: 14298]    [nextPos: 14298]
out|2017-10-11 12:36:47|[read packet]    [file: mysql-bin.000005]    [curPos: 14298]    [curTypeEvent: 19 TABLE_MAP_EVENT]    [nextPosValid: 14298]    [nextPos: 14366]
out|2017-10-11 12:36:47|[read packet]    [file: mysql-bin.000005]    [curPos: 14298]    [curTypeEvent: 31 UPDATE_ROWS_EVENT_V2]    [nextPosValid: 14420]    [nextPos: 14420]
out|2017-10-11 12:36:48|[read packet]    [file: mysql-bin.000005]    [curPos: 14420]    [curTypeEvent: 16 XID_EVENT]    [nextPosValid: 14451]    [nextPos: 14451]

对应主库binlog

# at 14161
#171011 12:36:47 server id 1  end_log_pos 14226 CRC32 0x47f9b05f     Anonymous_GTID    last_committed=48    sequence_number=49    rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 14226
#171011 12:36:47 server id 1  end_log_pos 14298 CRC32 0xc4417fb3     Query    thread_id=3186    exec_time=0    error_code=0
SET TIMESTAMP=1507696607/*!*/;
BEGIN
/*!*/;
# at 14298
#171011 12:36:47 server id 1  end_log_pos 14366 CRC32 0xbb39a921     Table_map: `test`.`test_binlog_tmp` mapped to number 299
# at 14366
#171011 12:36:47 server id 1  end_log_pos 14420 CRC32 0xfc509e2d     Update_rows: table id 299 flags: STMT_END_F

BINLOG '
35/dWRMBAAAARAAAAB44AAAAACsBAAAAAAEABHRlc3QAD3Rlc3RfYmlubG9nX3RtcAAFAw/+//wG
LAH4AQQCHiGpObs=
35/dWR8BAAAANgAAAFQ4AAAAACsBAAAAAAEAAgAF///4CQAAAAEAMwP4CQAAAAEANAMtnlD8
'/*!*/;
# at 14420
#171011 12:36:47 server id 1  end_log_pos 14451 CRC32 0x3b7ca383     Xid = 13151
COMMIT/*!*/;

一个插入操作产生的事件

out|2017-10-11 12:39:55|[read packet]    [file: mysql-bin.000005]    [curPos: 15601]    [curTypeEvent: 34 ANONYMOUS_GTID_LOG_EVENT]    [nextPosValid: 15666]    [nextPos: 15666]
out|2017-10-11 12:39:55|[read packet]    [file: mysql-bin.000005]    [curPos: 15666]    [curTypeEvent: 2 QUERY_EVENT]    [nextPosValid: 15738]    [nextPos: 15738]
out|2017-10-11 12:39:55|[read packet]    [file: mysql-bin.000005]    [curPos: 15738]    [curTypeEvent: 19 TABLE_MAP_EVENT]    [nextPosValid: 15738]    [nextPos: 15806]
out|2017-10-11 12:39:55|[read packet]    [file: mysql-bin.000005]    [curPos: 15738]    [curTypeEvent: 30 WRITE_ROWS_EVENT_V2]    [nextPosValid: 15850]    [nextPos: 15850]
out|2017-10-11 12:39:55|[read packet]    [file: mysql-bin.000005]    [curPos: 15850]    [curTypeEvent: 16 XID_EVENT]    [nextPosValid: 15881]    [nextPos: 15881]

对应主库binlog

# at 15601
#171011 12:39:55 server id 1  end_log_pos 15666 CRC32 0x4b300a96     Anonymous_GTID    last_committed=53    sequence_number=54    rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 15666
#171011 12:39:55 server id 1  end_log_pos 15738 CRC32 0x8868e4b7     Query    thread_id=3186    exec_time=0    error_code=0
SET TIMESTAMP=1507696795/*!*/;
BEGIN
/*!*/;
# at 15738
#171011 12:39:55 server id 1  end_log_pos 15806 CRC32 0x1ebf3ba6     Table_map: `test`.`test_binlog_tmp` mapped to number 299
# at 15806
#171011 12:39:55 server id 1  end_log_pos 15850 CRC32 0x225b1d59     Write_rows: table id 299 flags: STMT_END_F

BINLOG '
m6DdWRMBAAAARAAAAL49AAAAACsBAAAAAAEABHRlc3QAD3Rlc3RfYmlubG9nX3RtcAAFAw/+//wG
LAH4AQQCHqY7vx4=
m6DdWR4BAAAALAAAAOo9AAAAACsBAAAAAAEAAgAF//hsAAAAAQA0A1kdWyI=
'/*!*/;
# at 15850
#171011 12:39:55 server id 1  end_log_pos 15881 CRC32 0xb2e82fb4     Xid = 13215
COMMIT/*!*/;

一个删除操作产生的事件

out|2017-10-11 12:39:38|[read packet]    [file: mysql-bin.000005]    [curPos: 15321]    [curTypeEvent: 34 ANONYMOUS_GTID_LOG_EVENT]    [nextPosValid: 15386]    [nextPos: 15386]
out|2017-10-11 12:39:38|[read packet]    [file: mysql-bin.000005]    [curPos: 15386]    [curTypeEvent: 2 QUERY_EVENT]    [nextPosValid: 15458]    [nextPos: 15458]
out|2017-10-11 12:39:38|[read packet]    [file: mysql-bin.000005]    [curPos: 15458]    [curTypeEvent: 19 TABLE_MAP_EVENT]    [nextPosValid: 15458]    [nextPos: 15526]
out|2017-10-11 12:39:39|[read packet]    [file: mysql-bin.000005]    [curPos: 15458]    [curTypeEvent: 32 DELETE_ROWS_EVENT_V2]    [nextPosValid: 15570]    [nextPos: 15570]
out|2017-10-11 12:39:39|[read packet]    [file: mysql-bin.000005]    [curPos: 15570]    [curTypeEvent: 16 XID_EVENT]    [nextPosValid: 15601]    [nextPos: 15601]