Bug #93423 binlog_row_image=full not always honoured for binrow_format=MIXED
Submitted: 30 Nov 2018 10:55 Modified: 16 Dec 2018 7:05
Reporter: James Lawrie Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:5.7.24,5.6.28,8.0.12 OS:Linux
Assigned to: CPU Architecture:Any

[30 Nov 2018 10:55] James Lawrie
Description:
With:
binlog_row_image='FULL'
binlog_format='MIXED'
set tx_isolation='READ-COMMITTED'

An INSERT INTO table SELECT * FROM anothertable; will be written in row format but it will not write NULL columns to the binary log

How to repeat:
set binlog_format='MIXED';
set binlog-row-image="full";
set tx_isolation='READ-COMMITTED'; 
create database a; 
create database b; 
create table a.test (id int primary key, name varchar(50) default null, age bigint); 
create table b.test (id int primary key, name varchar(50) default null, age bigint); 
insert into a.test(id, age) values (1,5), (2,10); /* This insert event is written with full row image in binary log */ 
insert into b.test(id,age) select id , age from a.test ; /* name column information is not present in row image */

BINLOG '
Trr/WxMBAAAAMAAAAMEMAAAAAOAAAAAAAAEAAWEABHRlc3QAAwMPCAIyAAbYzi1r
Trr/Wx4BAAAAPQAAAP4MAAAAAOAAAAAAAAEAAgAD//oBAAAABQAAAAAAAAD6AgAAAAoAAAAAAAAA
o50iBQ==
'/*!*/;
### INSERT INTO `a`.`test`
### SET
###   @1=1
###   @2=NULL
###   @3=5
### INSERT INTO `a`.`test`
### SET
###   @1=2
###   @2=NULL
###   @3=10
# at 3326
#181129  5:07:10 server id 1  end_log_pos 3357 CRC32 0xc21cc3ba  Xid = 43
COMMIT/*!*/;
# at 3357
#181129  5:07:21 server id 1  end_log_pos 3422 CRC32 0xa82c7878  Anonymous_GTID    last_committed=15    sequence_number=16    rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 3422
#181129  5:07:21 server id 1  end_log_pos 3490 CRC32 0x5efd2acf  Query    thread_id=4    exec_time=0    error_code=0
SET TIMESTAMP=1543486041/*!*/;
BEGIN
/*!*/;
# at 3490
#181129  5:07:21 server id 1  end_log_pos 3538 CRC32 0x3f909882  Table_map: `b`.`test` mapped to number 225
# at 3538
#181129  5:07:21 server id 1  end_log_pos 3599 CRC32 0xa6559a3a  Write_rows: table id 225 flags: STMT_END_F

BINLOG '
Wbr/WxMBAAAAMAAAANINAAAAAOEAAAAAAAEAAWIABHRlc3QAAwMPCAIyAAaCmJA/
Wbr/Wx4BAAAAPQAAAA8OAAAAAOEAAAAAAAEAAgADBfwBAAAABQAAAAAAAAD8AgAAAAoAAAAAAAAA
OppVpg==
'/*!*/;
### INSERT INTO `b`.`test`
### SET
###   @1=1
###   @3=5
### INSERT INTO `b`.`test`
### SET
###   @1=2
###   @3=10
# at 3599

If you try again:
TRUNCATE TABLE a.test;
TRUNCATE TABLE b.test;
SET binlog_format="ROW";
insert into a.test(id, age) values (1,5), (2,10); /* This insert event is written with full row image in binary log */ 
insert into b.test(id,age) select id , age from a.test ; /* name column information is not present in row image */

This time it works as expected:
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#181129  9:18:02 server id 1  end_log_pos 123 CRC32 0x9df266b8 	Start: binlog v 4, server v 5.7.18-log created 181129  9:18:02 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
GvX/Ww8BAAAAdwAAAHsAAAABAAQANS43LjE4LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAa9f9bEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
Abhm8p0=
'/*!*/;
# at 123
#181129  9:18:02 server id 1  end_log_pos 154 CRC32 0x804378b2 	Previous-GTIDs
# [empty]
# at 154
#181129 10:08:22 server id 1  end_log_pos 219 CRC32 0x774ecdfe 	Anonymous_GTID	last_committed=0	sequence_number=1	rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#181129 10:08:22 server id 1  end_log_pos 287 CRC32 0x2cc3d729 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1543504102/*!*/;
SET @@session.pseudo_thread_id=3/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 287
#181129 10:08:22 server id 1  end_log_pos 335 CRC32 0x45948473 	Table_map: `b`.`test` mapped to number 109
# at 335
#181129 10:08:22 server id 1  end_log_pos 397 CRC32 0x97acd9f1 	Update_rows: table id 109 flags: STMT_END_F

BINLOG '
5gAAXBMBAAAAMAAAAE8BAAAAAG0AAAAAAAEAAWIABHRlc3QAAwMPCAIyAAZzhJRF
5gAAXB8BAAAAPgAAAI0BAAAAAG0AAAAAAAEAAgAD///6AgAAAAoAAAAAAAAA+gIAAAAPAAAAAAAA
APHZrJc=
'/*!*/;
### UPDATE `b`.`test`
### WHERE
###   @1=2
###   @2=NULL
###   @3=10
### SET
###   @1=2
###   @2=NULL
###   @3=15
# at 397
#181129 10:08:22 server id 1  end_log_pos 428 CRC32 0x8d8f76f1 	Xid = 18
COMMIT/*!*/;
# at 428
#181129 10:09:07 server id 1  end_log_pos 493 CRC32 0xb76ab4c3 	Anonymous_GTID	last_committed=1	sequence_number=2	rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 493
#181129 10:09:07 server id 1  end_log_pos 561 CRC32 0xad2bd698 	Query	thread_id=3	exec_time=0	error_code=0
SET TIMESTAMP=1543504147/*!*/;
BEGIN
/*!*/;
# at 561
#181129 10:09:07 server id 1  end_log_pos 609 CRC32 0xd0df56be 	Table_map: `a`.`test` mapped to number 108
# at 609
#181129 10:09:07 server id 1  end_log_pos 657 CRC32 0x8c95af6d 	Delete_rows: table id 108 flags: STMT_END_F

BINLOG '
EwEAXBMBAAAAMAAAAGECAAAAAGwAAAAAAAEAAWEABHRlc3QAAwMPCAIyAAa+Vt/Q
EwEAXCABAAAAMAAAAJECAAAAAGwAAAAAAAEAAgAD//oBAAAABQAAAAAAAABtr5WM
'/*!*/;
### DELETE FROM `a`.`test`
### WHERE
###   @1=1
###   @2=NULL
###   @3=5
# at 657
#181129 10:09:07 server id 1  end_log_pos 688 CRC32 0x867067f2 	Xid = 19
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

Tested against several versions of 5.6, 5.7 and 8 (with SET TRANSACTION ISOLATION LEVEL READ COMMITTED;).

It doesn't seem to have the same problem with DELETE FROM or a normal INSERT.
[16 Dec 2018 7:05] Umesh Shastry
Hello James Lawrie,

Thank you for the report!

regards,
Umesh