MDEV-20574 Position of events reported by mysqlbinlog is wrong with encrypted binlogs, SHOW BINLOG EVENTS reports the correct one.bb-10.3-20574

Analysis

Mysqlbinlog output for encrypted binary log
#Q> insert into tab1 values (3,'row 003')
#190912 17:36:35 server id 10221  end_log_pos 980 CRC32 0x53bcb3d3  Table_map: `test`.`tab1` mapped to number 19
# at 940
#190912 17:36:35 server id 10221  end_log_pos 1026 CRC32 0xf2ae5136     Write_rows: table id 19 flags: STMT_END_F

Here we can see Table_map_log_event ends at 980 but Next event starts at 940.
And the reason for that is we do not send START_ENCRYPTION_EVENT to the slave

Solution:-
Send Start_encryption_log_event as Ignorable_log_event to slave(mysqlbinlog),
So that mysqlbinlog can update its log_pos.
Since Slave can request multiple FORMAT_DESCRIPTION_EVENT while master does not
have so We only update slave master pos when master actually have the
FORMAT_DESCRIPTION_EVENT. Similar logic should be applied for START_ENCRYPTION_EVENT.

Also added the test case when new server reads the data from old server which
does not send START_ENCRYPTION_EVENT to slave.

6 files changed, 80 insertions, 0 deletions

diff --git a/mysql-test/std_data/binlog_before_20574.bin b/mysql-test/std_data/binlog_before_20574.bin
new file mode 100644
index 00000000000..596a883dc71
--- /dev/null
+++ b/mysql-test/std_data/binlog_before_20574.bin
diff --git a/mysql-test/suite/binlog_encryption/binlog_row_annotate.result b/mysql-test/suite/binlog_encryption/binlog_row_annotate.result
index a6054f00ebc..b783488b07a 100644
--- a/mysql-test/suite/binlog_encryption/binlog_row_annotate.result
+++ b/mysql-test/suite/binlog_encryption/binlog_row_annotate.result
@@ -104,6 +104,9 @@ DELIMITER /*!*/;
 #010909  4:46:40 server id #  end_log_pos # 	Start: binlog v 4, server v #.##.## created 010909  4:46:40 at startup
 ROLLBACK/*!*/;
 # at #
+#010909  4:46:40 server id #  end_log_pos # 	Ignorable
+# Ignorable event type 164 (Start_encryption)
+# at #
 #010909  4:46:40 server id #  end_log_pos # 	Gtid list []
 # at #
 #010909  4:46:40 server id #  end_log_pos # 	Binlog checkpoint master-bin.000001
@@ -342,6 +345,9 @@ DELIMITER /*!*/;
 #010909  4:46:40 server id #  end_log_pos # 	Start: binlog v 4, server v #.##.## created 010909  4:46:40 at startup
 ROLLBACK/*!*/;
 # at #
+#010909  4:46:40 server id #  end_log_pos # 	Ignorable
+# Ignorable event type 164 (Start_encryption)
+# at #
 #010909  4:46:40 server id #  end_log_pos # 	Gtid list []
 # at #
 #010909  4:46:40 server id #  end_log_pos # 	Binlog checkpoint master-bin.000001
@@ -502,6 +508,9 @@ DELIMITER /*!*/;
 #010909  4:46:40 server id #  end_log_pos # 	Start: binlog v 4, server v #.##.## created 010909  4:46:40 at startup
 ROLLBACK/*!*/;
 # at #
+#010909  4:46:40 server id #  end_log_pos # 	Ignorable
+# Ignorable event type 164 (Start_encryption)
+# at #
 #010909  4:46:40 server id #  end_log_pos # 	Gtid list []
 # at #
 #010909  4:46:40 server id #  end_log_pos # 	Binlog checkpoint master-bin.000001
diff --git a/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.result b/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.result
new file mode 100644
index 00000000000..52029b6342e
--- /dev/null
+++ b/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.result
@@ -0,0 +1,27 @@
+include/master-slave.inc
+[connection master]
+connection slave;
+include/stop_slave.inc
+connection master;
+include/rpl_stop_server.inc [server_number=1]
+# Data in binlog
+# CREATE TABLE t1 (a INT);
+# INSERT INTO t1 VALUES (1),(2),(3);
+# REPLACE INTO t1 VALUES (4);
+include/rpl_start_server.inc [server_number=1]
+connection slave;
+reset slave;
+reset master;
+CHANGE MASTER TO master_host='127.0.0.1', master_port=16000, master_user='root', master_log_file='master-bin.000001', master_log_pos=4;
+include/start_slave.inc
+desc t1;
+Field	Type	Null	Key	Default	Extra
+a	int(11)	YES		NULL	
+select * from t1 order by a;
+a
+1
+2
+3
+4
+drop table t1;
+include/rpl_end.inc
diff --git a/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.test b/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.test
new file mode 100644
index 00000000000..183697ab9c3
--- /dev/null
+++ b/mysql-test/suite/binlog_encryption/mdev_20574_old_binlog.test
@@ -0,0 +1,40 @@
+# Test replicating off old master.
+# We simulate old master by copying in pre-generated binlog files from earlier
+# server versions.
+source include/have_binlog_format_row.inc;
+source include/master-slave.inc;
+--source include/have_innodb.inc
+
+--connection slave
+--source include/stop_slave.inc
+
+--connection master
+--let $datadir= `SELECT @@datadir`
+
+--let $rpl_server_number= 1
+--source include/rpl_stop_server.inc
+
+--remove_file $datadir/master-bin.000001
+--remove_file $datadir/master-bin.state
+--echo # Data in binlog
+--echo # CREATE TABLE t1 (a INT);
+--echo # INSERT INTO t1 VALUES (1),(2),(3);
+--echo # REPLACE INTO t1 VALUES (4);
+
+--copy_file $MYSQL_TEST_DIR/std_data/binlog_before_20574.bin $datadir/master-bin.000001
+
+--let $rpl_server_number= 1
+--source include/rpl_start_server.inc
+
+--source include/wait_until_connected_again.inc
+
+--connection slave
+#--replace_result $SERVER_MYPORT_1 SERVER_MYPORT_1
+reset slave;
+reset master;
+eval CHANGE MASTER TO master_host='127.0.0.1', master_port=$SERVER_MYPORT_1, master_user='root', master_log_file='master-bin.000001', master_log_pos=4;
+--source include/start_slave.inc
+desc t1;
+select * from t1 order by a;
+drop table t1;
+source include/rpl_end.inc;
diff --git a/mysql-test/suite/binlog_encryption/mysqlbinlog.result b/mysql-test/suite/binlog_encryption/mysqlbinlog.result
index 71758f7d6e7..e97e0569571 100644
--- a/mysql-test/suite/binlog_encryption/mysqlbinlog.result
+++ b/mysql-test/suite/binlog_encryption/mysqlbinlog.result
@@ -4,3 +4,4 @@ INSERT INTO t1 VALUES (1),(2),(3);
 REPLACE INTO t1 VALUES (4);
 DROP TABLE t1;
 FLUSH LOGS;
+FOUND 1 /Ignorable event type 164.*/ in binlog_enc.sql
diff --git a/mysql-test/suite/binlog_encryption/mysqlbinlog.test b/mysql-test/suite/binlog_encryption/mysqlbinlog.test
index b80388aaa45..108dbd8782f 100644
--- a/mysql-test/suite/binlog_encryption/mysqlbinlog.test
+++ b/mysql-test/suite/binlog_encryption/mysqlbinlog.test
@@ -17,5 +17,8 @@ let outfile=$MYSQLTEST_VARDIR/tmp/binlog_enc.sql;
 exec $MYSQL_BINLOG $local > $outfile;
 exec $MYSQL_BINLOG $local --force-read >> $outfile;
 exec $MYSQL_BINLOG $remote >> $outfile;
+--let SEARCH_FILE= $outfile
+--let SEARCH_PATTERN= Ignorable event type 164.*
+--source include/search_pattern_in_file.inc
 remove_file $outfile;