From feac078f15c0be6c0592d74d20cb65b8f5ad2f85 Mon Sep 17 00:00:00 2001 From: Andrei Elkin Date: Tue, 11 Aug 2020 21:45:09 +0300 Subject: MDEV-16372 ER_BASE64_DECODE_ERROR upon replaying binary log via mysqlbinlog --verbose (This commit is exclusively for 10.1 branch, do not merge it to upper ones) In case of a pattern of non-STMT_END-marked Rows-log-event (A) followed by a STMT_END marked one (B) mysqlbinlog mixes up the base64 encoded rows events with their pseudo sql representation produced by the verbose option: BINLOG ' base64 encoded data for A ### verbose section for A base64 encoded data for B ### verbose section for B '/*!*/; In effect the produced BINLOG '...' query is not valid and is rejected with the error. Examples of this way malformed BINLOG could have been found in binlog_row_annotate.result that gets corrected with the patch. The issue is fixed with introduction an auxiliary IO_CACHE to hold on the verbose comments until the terminal STMT_END event is found. The new cache is emptied out after two pre-existing ones are done at that time. The correctly produced output now for the above case is as the following: BINLOG ' base64 encoded data for A base64 encoded data for B '/*!*/; ### verbose section for A ### verbose section for B Thanks to Alexey Midenkov for the problem recognition and attempt to tackle, Venkatesh Duggirala who produced a patch for the upstream whose idea is exploited here, as well as to MDEV-23077 reporter LukeXwang who also contributed a piece of a patch aiming at this issue. Extra: mysqlbinlog_row_minimal refined to not produce mutable numeric values into the result file. --- mysql-test/r/mysqlbinlog_row_minimal.result | 40 ++++++++++++++++++++--------- 1 file changed, 28 insertions(+), 12 deletions(-) (limited to 'mysql-test/r') diff --git a/mysql-test/r/mysqlbinlog_row_minimal.result b/mysql-test/r/mysqlbinlog_row_minimal.result index 2e34b2885ca..a7fecc7e4bc 100644 --- a/mysql-test/r/mysqlbinlog_row_minimal.result +++ b/mysql-test/r/mysqlbinlog_row_minimal.result @@ -295,6 +295,24 @@ ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/; DROP TABLE t1,t2; +# +# MDEV-16372 ER_BASE64_DECODE_ERROR upon replaying binary log with system table +# +FLUSH BINARY LOGS; +CREATE TABLE t1 (pk INT PRIMARY KEY); +INSERT INTO t1 VALUES (1); +INSERT INTO t1 VALUES (1), (2) ON DUPLICATE KEY UPDATE pk= pk + 10; +FLUSH BINARY LOGS; +Proof: two subsequent patterns must be found +FOUND /### UPDATE `test`.`t1`/ in mysqlbinlog.sql +FOUND /### INSERT INTO `test`.`t1`/ in mysqlbinlog.sql +DROP TABLE t1; +SELECT * FROM t1; +pk +2 +11 +# Cleanup +DROP TABLE t1; CREATE TABLE `t1` ( `id` BIGINT(20) UNSIGNED NOT NULL AUTO_INCREMENT, `is_deleted` BIT(1) DEFAULT b'0', @@ -319,28 +337,28 @@ FLUSH BINARY LOGS; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; -# at 368 -# server id 1 end_log_pos 406 GTID 0-1-16 +# at POS +# server id 1 end_log_pos END_LOG_POS GTID D-S-N /*!100101 SET @@session.skip_parallel_replication=0*//*!*/; /*!100001 SET @@session.gtid_domain_id=0*//*!*/; /*!100001 SET @@session.server_id=1*//*!*/; -/*!100001 SET @@session.gtid_seq_no=16*//*!*/; +/*!100001 SET @@session.gtid_seq_no=21*//*!*/; BEGIN /*!*/; -# at 406 -# server id 1 end_log_pos 453 Table_map: `test`.`t1` mapped to number 34 -# at 453 -# server id 1 end_log_pos 498 Update_rows: table id 34 flags: STMT_END_F +# at POS +# server id 1 end_log_pos END_LOG_POS Table_map: `test`.`t1` mapped to number TID +# at POS +# server id 1 end_log_pos END_LOG_POS Update_rows: table id TID flags: STMT_END_F ### UPDATE `test`.`t1` ### WHERE ### @1=1 /* LONGINT meta=0 nullable=0 is_null=0 */ ### SET ### @2=b'1' /* BIT(1) meta=1 nullable=1 is_null=0 */ ### @3=X /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */ -# at 498 -# server id 1 end_log_pos 576 Query thread_id=4 exec_time=x error_code=0 +# at POS +# server id 1 end_log_pos END_LOG_POS Query thread_id=TID exec_time=x error_code=0 SET TIMESTAMP=X/*!*/; -SET @@session.pseudo_thread_id=4/*!*/; +SET @@session.pseudo_thread_id=TID/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1342177280/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; @@ -350,8 +368,6 @@ SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; COMMIT /*!*/; -# at 576 -# server id 1 end_log_pos 620 Rotate to master-bin.000004 pos: 4 DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; -- cgit v1.2.1