MySQL Bugs: #76974: Mixed based replication looses events when relay_log_info

Bug #76974	Mixed based replication looses events when relay_log_info_repository=TABLE
Submitted:	7 May 2015 14:45	Modified:	19 Nov 2015 17:40
Reporter:	Vaclav Bilek	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S1 (Critical)
Version:	5.6.25	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	binlog, mixed based replication, relay_log_info_repository

Description:
2 level replication M1 -> S1 ->S2 ( S1 is slave of M1; S2 is slave of S1)

when set relay_log_info_repository=TABLE; and bin log rotation ocures in the midle of statement that was translated to multiple rows, then you loos part of that events.

When bilog rotation ocures, on S1 not all rows are writen to it's binlog, therefore S2 seemlesly looses part of rows that were translated from one statement to several rows;

How to repeat:
M1->S1->S2

relay_log_info_repository=TABLE
binlog_format= MIXED
max_binlog_size=4096

M1:
use test;
CREATE TABLE `t1` ( `c1` int(10)  AUTO_INCREMENT, PRIMARY KEY (`c1`) ) ENGINE=InnoDB;
delimiter //
create procedure populate (in num int) 
begin 
declare i int default 0;
while i < num do
insert into t1 values (); 
set i = i + 1; 
end while; 
end//
delimiter ;

call populate (10000);

delete from t1 limit 10000;
select count(*) from t1 ;

S1:
use test;
select count(*) from t1 ;

S2:
use test;
select count(*) from t1 ;

my results:
M1:
[test]> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|        0 |
+----------+

S1:
[test]> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|        0 |
+----------+

S2:
[test]> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|     8364 |
+----------+

Suggested fix:
repare bug that causes event loos

Hello Vaclav Bilek,

Thank you for the bug report and test case.
Observed similar behavior with 5.6.24.

Thanks,
Umesh

// Setup m1->s1->s2
// Conf used
# m1
[mysqld]
basedir=/export/umesh/server/binaries/mysql-5.6.24
datadir=/export/umesh/server/binaries/mysql-5.6.24/m1
port = 15000
pid-file = /export/umesh/server/binaries/mysql-5.6.24/run/m1.pid
socket = /export/umesh/server/binaries/mysql-5.6.24/run/m1.sock
log-error=/export/umesh/server/binaries/mysql-5.6.24/log/m1.log
server-id=1
log-bin=master1-bin
binlog_format= MIXED
max_binlog_size=4096

# s1
[mysqld]
basedir=/export/umesh/server/binaries/mysql-5.6.24
datadir=/export/umesh/server/binaries/mysql-5.6.24/s1
port = 15001
server-id=2
log-bin=master2-bin
binlog_format= MIXED
max_binlog_size=4096
log-slave-updates
skip-slave-start
pid-file = /export/umesh/server/binaries/mysql-5.6.24/run/s1.pid
socket = /export/umesh/server/binaries/mysql-5.6.24/run/s1.sock
log-error=/export/umesh/server/binaries/mysql-5.6.24/log/s1.log
master_info_repository=TABLE
relay_log_info_repository=TABLE

# s2
[mysqld]
basedir=/export/umesh/server/binaries/mysql-5.6.24
datadir=/export/umesh/server/binaries/mysql-5.6.24/s2
port = 15002
server-id=3
pid-file = /export/umesh/server/binaries/mysql-5.6.24/run/s2.pid
socket = /export/umesh/server/binaries/mysql-5.6.24/run/s2.sock
log-error=/export/umesh/server/binaries/mysql-5.6.24/log/s2.log
master_info_repository=TABLE
relay_log_info_repository=TABLE

## Use provided test case to create schema, and populate data
## m1 ( call sp 2-3 times instead of 1 to trigger this issue)

m1>  call populate (10000);
Query OK, 1 row affected (3.37 sec)

m1>  call populate (10000);
Query OK, 1 row affected (3.43 sec)

mysql> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    20000 |
+----------+
1 row in set (0.00 sec)

## s1 - confirmed that data is populated

s1> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    20000 |
+----------+
1 row in set (0.00 sec)

## s2 - confirmed that data is populated

s2> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    20000 |
+----------+
1 row in set (0.00 sec)

# m1 - trying to delete 10K data, confirming that 10K rows deleted

m1> delete from t1 limit 10000;
Query OK, 10000 rows affected (0.04 sec)

m1> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    10000 |   <------- expected
+----------+
1 row in set (0.00 sec)

# s1

s1> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    10000 |  <------- expected
+----------+
1 row in set (0.00 sec)

# s2

s2> select count(*) from t1 ;
+----------+
| count(*) |
+----------+
|    18364 | <-------------- 8364 extra rows
+----------+
1 row in set (0.00 sec)

Bug #76587 marked duplicate of this

version 5.6.25 ... the bug is still there

I found workaround.
S1 max_relay_log_size > max_binlog_size avoid this bug.

Thanks for your feedback. This has been fixed as part of Bug #68525.