MySQL Bugs: #107956: log_slave_updates not respecting binlog_row

Bug #107956	log_slave_updates not respecting binlog_row_image
Submitted:	25 Jul 2022 7:11	Modified:	12 Aug 2022 8:09
Reporter:	Martin Vobruba	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Row Based Replication ( RBR )	Severity:	S3 (Non-critical)
Version:	5.7.35	OS:	Ubuntu
Assigned to:		CPU Architecture:	Any

Description:
Hi,

I have 3 master servers and all of them have binlog_row_image = MINIMAL. In binary logs I still see UPDATE_ROWS_EVENTs in FULL row image format if they originate from another master.

This is how UPDATE_ROWS_EVENTs look like in binary logs (same table, PK present):

On master A:
UPDATE from master A → MINIMAL row image format
UPDATE from master B → FULL row image format
UPDATE from master C → FULL row image format

On master B:
UPDATE from master A → FULL row image format
UPDATE from master B → MINIMAL row image format
UPDATE from master C → FULL row image format

On master C:
UPDATE from master A → FULL row image format
UPDATE from master B → FULL row image format
UPDATE from master C → MINIMAL row image format

How to repeat:
Start replica with:
binlog_row_image = MINIMAL
log_slave_updates = ON

Generate some UPDATE_ROWS_EVENTs on master. You will see those events in FULL image row format in replica's binary log.

Hi,

Can you give us more data about your configuration. This is ring replication (A->B->C->A) or this is InnoDB Cluster configuration (Group replication)? 

Thanks

Hi,

my setup is multi-master star replication A<->B<->C.

Hi,

Thank you for the report

all best

Hi,

Are there some virtual generated columns in your table?

Posted by developer:
 
I can't reproduce this. Can you please share your test case that reproduces it?

Here is mine:

-------- begin .test file --------
--source include/have_grep.inc
--source include/have_binlog_format_row.inc
--let $rpl_topology=1->2->3->1
--source include/rpl_init.inc

CREATE TABLE t (a INT PRIMARY KEY AUTO_INCREMENT, b INT);
INSERT INTO t VALUES (1, 2);
UPDATE t SET b = 3;
--sleep 2
--source include/rpl_sync.inc

--connection server_1
SELECT * FROM t;
--source include/save_binlog_position.inc
--let $binlog_fullpath = `SELECT @@datadir`
--let $binlog_fullpath = $binlog_fullpath/$binlog_file
--exec $MYSQL_BINLOG -v $binlog_fullpath | grep '^###'

--connection server_2
SELECT * FROM t;
--source include/save_binlog_position.inc
--let $binlog_fullpath = `SELECT @@datadir`
--let $binlog_fullpath = $binlog_fullpath/$binlog_file
--exec $MYSQL_BINLOG -v $binlog_fullpath | grep '^###'

--connection server_3
SELECT * FROM t;
--source include/save_binlog_position.inc
--let $binlog_fullpath = `SELECT @@datadir`
--let $binlog_fullpath = $binlog_fullpath/$binlog_file
--exec $MYSQL_BINLOG -v $binlog_fullpath | grep '^###'

DROP TABLE t;

--source include/rpl_end.inc
-------- end .test file --------
-------- begin .cnf file --------
!include ../my.cnf

[mysqld.1]
binlog-row-image=MINIMAL

[mysqld.2]
binlog-row-image=MINIMAL

[mysqld.3]
binlog-row-image=MINIMAL
loose-innodb_write_io_threads=    2
loose-innodb_read_io_threads=     2
log-slave-updates

[ENV]
SERVER_MYPORT_3=		@mysqld.3.port
SERVER_MYSOCK_3=		@mysqld.3.socket
-------- end .cnf file --------

It shows that the update is logged with row images equivalent to:
  UPDATE `test`.`t` WHERE @1=1 SET @2=3
I.e., it has just the first column in the before-image
and just the second column in the after-image.
Both in 5.7 in 8.0.

If there is such a bug, it is unlikely related to circular replication: please see if you can reproduce also with just a single replica.

I have reproduced this issue with simple master-slave setup. Problem is when binlog-row-image is set at runtime.

On master:
1) Start server with binlog-row-image = FULL
2) Open client and set binlog-row-image to MINIMAL:
SET @@GLOBAL.binlog_row_image="MINIMAL";
3) Events will be logged in FULL format until you use the current connection.

On slave:
1) Start server with binlog-row-image = FULL
2) Open client and set binlog-row-image to MINIMAL:
SET @@GLOBAL.binlog_row_image="MINIMAL";
3) Events will be logged in FULL format until you restart the slave.

With your testcase I see this:

mysqlbinlog --base64-output decode-rows -v path_to_latest_binlog
...
### UPDATE `test`.`t`
### WHERE
###   @1=1
###   @2=2
### SET
###   @1=1
###   @2=3
...

Posted by developer:
 
The behavior you describe is the expected one. For any variables that exist in @@global and @@session scope, client connections inherit the global value when the session starts. Subsequent changes of the global value do not affect existing session values (only subsequently started sessions). The same rule applies to replication threads. So it is correct that you need to restart the replica threads (STOP REPLICA + START REPLICA) in order for the changes to take effect.

Did you remember to copy the .cnf file when using my test? It needs to have the same base name as the .test file, but with a .cnf extension, and both should live in mysql-test/suite/rpl/t

Closing this as "not a bug". If I misunderstood the scenario, please provide more precise steps.

Ah, I get it now. Thank you for the explanation!