1.基本信息
主库：
IP：10.16.24.107 port:3376
server-id = 1073377
data_dir:/data/MySQL/mysql3376/data/
base_dir:/usr/local/mysql
版本：mysql 5.6.29-log
binlog_format:ROW
从库：
IP：10.16.24.108 port:3376
server-id = 1083376
data_dir:/data/mysql/mysql3376/data/
base_dir:/usr/local/mysql
版本：mysql 5.6.29-log
binlog_format:ROW
2.场景一:从库有设置log_slave_updates参数
从库上查看：
(product)root@localhost [lots]> show variables like 'log_slave_updates';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| log_slave_updates | ON |
+-------------------+-------+
1 row in set (0.01 sec)
主库上操作：
insert into test values (4,'zeng4'),(5,'zeng5'),(6,'zeng6');
从库查看：
product)root@localhost [(none)]> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 10.16.24.107
Master_User: repl
Master_Port: 3376
Connect_Retry: 60
Master_Log_File: mysql-bin.000064
Read_Master_Log_Pos: 761
Relay_Log_File: relay-bin.000007
Relay_Log_Pos: 504
Relay_Master_Log_File: mysql-bin.000064
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 761
Relay_Log_Space: 1254
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1073376
Master_UUID: 36af7e42-f4fc-11e5-8b08-0050568a0bcb
Master_Info_File: /data/mysql/mysql3376/data/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
Auto_Position: 0
1 row in set (0.00 sec)
主库上分析日志：
mysqlbinlog -vv mysql-bin.000064 --stop-position=761 --base64-output=DECODE-ROWS
#160429 14:50:39 server id 1073376 end_log_pos 730 CRC32 0xab87e600 Write_rows: table id 70 flags: STMT_END_F
### INSERT INTO `lots`.`test`
### SET
### @1=4 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng4' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=5 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng5' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=6 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng6' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
# at 730
确认主库的insert操作位置是mysql-bin.000064的730。
我们再在从库上分析中继日志：
mysqlbinlog -vv relay-bin.000007 --stop-position=504 --base64-output=DECODE-ROWS
#160429 14:50:39 server id 1073376 end_log_pos 730 CRC32 0xab87e600 Write_rows: table id 70 flags: STMT_END_F
### INSERT INTO `lots`.`test`
### SET
### @1=4 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng4' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=5 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng5' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=6 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng6' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
# at 473
上面查看到insert操作位置有两个position：730和473，其中730是从master读取binlog记录insert操作位置，473是insert操作在relay log中位置。
然后分析下从库的binlog:
mysqlbinlog -vv --base64-output=DECODE-ROWS mysql-bin.000011 --start-datetime='2016-04-29 14:50:00'
#160429 14:50:39 server id 1073376 end_log_pos 927 CRC32 0x2c41c940 Write_rows: table id 70 flags: STMT_END_F
### INSERT INTO `lots`.`test`
### SET
### @1=4 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng4' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=5 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng5' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
### INSERT INTO `lots`.`test`
### SET
### @1=6 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng6' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
# at 927
在设置log_slave_updates参数后，从库中的binlog有记录了insert操作，position为927。
场景二：从库没有设置log_slave_updates参数
(product)root@localhost [(none)]> show variables like 'log_slave_updates';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| log_slave_updates | OFF |
+-------------------+-------+
1 row in set (0.00 sec)
主库执行：delete from test where id=6;
查看从库状态：
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 10.16.24.107
Master_User: repl
Master_Port: 3376
Connect_Retry: 60
Master_Log_File: mysql-bin.000064
Read_Master_Log_Pos: 960
Relay_Log_File: relay-bin.000009
Relay_Log_Pos: 482
Relay_Master_Log_File: mysql-bin.000064
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 960
Relay_Log_Space: 649
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 0
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 1073376
Master_UUID: 36af7e42-f4fc-11e5-8b08-0050568a0bcb
Master_Info_File: /data/mysql/mysql3376/data/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
Auto_Position: 0
1 row in set (0.00 sec)
主库上分析日志：
mysqlbinlog -vv mysql-bin.000064 --stop-position=960 --base64-output=DECODE-ROWS
#160429 17:24:25 server id 1073376 end_log_pos 929 CRC32 0x15e16d68 Delete_rows: table id 70 flags: STMT_END_F
### DELETE FROM `lots`.`test`
### WHERE
### @1=6 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng6' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
# at 929
#160429 17:24:25 server id 1073376 end_log_pos 960 CRC32 0x489880cc Xid = 54
COMMIT/*!*/;
确认主库的delete操作位置是mysql-bin.000064的929。
我们再在从库上分析中继日志：
mysqlbinlog -vv --base64-output=DECODE-ROWS relay-bin.000009 --start-datetime='2016-04-29 17:24:00'
#160429 17:24:25 server id 1073376 end_log_pos 929 CRC32 0x15e16d68 Delete_rows: table id 70 flags: STMT_END_F
### DELETE FROM `lots`.`test`
### WHERE
### @1=6 /* INT meta=0 nullable=1 is_null=0 */
### @2='zeng6' /* VARSTRING(60) meta=60 nullable=1 is_null=0 */
# at 451
#160429 17:24:25 server id 1073376 end_log_pos 960 CRC32 0x489880cc Xid = 54
COMMIT/*!*/;
上面查看到insert操作位置有两个position：929和451，其中929是从master读取binlog记录insert操作位置，451是insert操作在relay log中位置。
然后分析下从库的binlog:
mysqlbinlog -vv --base64-output=DECODE-ROWS mysql-bin.000012 --start-datetime='2016-04-29 17:24:00'
[mysql@mvxl0783 logs]$ mysqlbinlog -vv --base64-output=DECODE-ROWS mysql-bin.000012
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#160429 17:21:05 server id 1083376 end_log_pos 120 CRC32 0xa8d9d152 Start: binlog v 4, server v 5.6.29-log created 160429 17:21:05 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
从上面分析查看，当从库log_slave_updates参数没有开启时，从库的binlog不会记录来源于主库的操作记录。只有开启log_slave_updates，从库binlog才会记录主库同步的操作日志。