MySQL Bugs: #68607: REPLACE statement not properly logged in binary log in RBR

Bug #68607	REPLACE statement not properly logged in binary log in RBR
Submitted:	7 Mar 2013 22:11	Modified:	5 Jun 2015 6:34
Reporter:	Justin Swanhart	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Errors	Severity:	S3 (Non-critical)
Version:	5.5.30, 5.7.2	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	binary logging

Description:
mysql> select * from test.t1;
+----+
| c1 |
+----+
|  1 |
|  2 |
|  3 |
+----+
3 rows in set (0.00 sec)

mysql> reset master;
Query OK, 0 rows affected (0.01 sec)

mysql> replace into test.t1 values (1);
Query OK, 1 row affected (0.00 sec)

mysql> set binlog_format=row;
Query OK, 0 rows affected (0.00 sec)

mysql> replace into test.t1 values (1);
Query OK, 1 row affected (0.00 sec)

mysql> show binlog events;
+----------+-----+-------------+-----------+-------------+---------------------------------------+
| Log_name | Pos | Event_type  | Server_id | End_log_pos | Info                                  |
+----------+-----+-------------+-----------+-------------+---------------------------------------+
| a.000001 |   4 | Format_desc |         1 |         107 | Server ver: 5.5.30-log, Binlog ver: 4 |
| a.000001 | 107 | Query       |         1 |         171 | BEGIN                                 |
| a.000001 | 171 | Query       |         1 |         261 | replace into test.t1 values (1)       |
| a.000001 | 261 | Xid         |         1 |         288 | COMMIT /* xid=86 */                   |
+----------+-----+-------------+-----------+-------------+---------------------------------------+
4 rows in set (0.00 sec)

How to repeat:
Set up a 5.5.30 server with all defaults except binary logging should be turned on.  I used:

[mysqld]
datadir=/usr/local/mysql55/data
basedir=/usr/local/mysql55
log_bin=a

Simplified test case:
mysql -e 'reset master'
mysql -e 'drop table if exists test.t1;'
mysql -e 'create table test.t1(c1 int primary key) engine=innodb';
mysql -e 'insert into test.t1 values (1)'
mysql -e 'set binlog_format=row; replace into test.t1 values (1)';

It appears to only be a problem for REPLACE statements that actually replace rows.  

Replacing the value 4 into the table is properly logged as a write_rows event.

I guess technically the row image doesn't change in this case, so from a logging standpoint this is technically correct.  The slave sees no effective change.  If the replace had caused triggers to fire, or cascade deletes, these would be captured by RBR.

I still think it should be logged though, because a row really was replaced, even if just logically.  I've decreased the severity accordingly.

Also, strangely the affected_row_count is 1 for the REPLACE INTO t1 VALUES (1) statement, even though the value of one is replaced (not inserted):

From the manual:
The affected-rows count makes it easy to determine whether REPLACE only added a row or whether it also replaced any rows: Check whether the count is 1 (added) or greater (replaced).

This can actually be interpreted as a side-effect of statement based replication. Another similar case is when REPLACE is used to update a row on the master but the row does not exist on the slave. If SBR is used, the row is inserted, while if RBR is used, replication breaks (a Update_rows event fails to apply).

Thank you for the report.

Verified as described in version 5.7.2 and not repeatable with 5.5 and 5.6 for me.

Lack of row-based event in the log is not a bug, but wrong number of affected rows is since it contradicts with that written at http://dev.mysql.com/doc/refman/5.6/en/replace.html:

The REPLACE statement returns a count to indicate the number of rows affected. This is the sum of the rows deleted and inserted. If the count is 1 for a single-row REPLACE, a row was inserted and no rows were deleted. If the count is greater than 1, one or more old rows were deleted before the new row was inserted. It is possible for a single row to replace more than one old row if the table contains multiple unique indexes and the new row duplicates values for different old rows in different unique indexes.

Maybe I was too fast about row event, because versions where this works fine fills records:

=====bug68607=====
create table t1(c1 int not null primary key);
affected rows: 0
insert into t1 values(1),(2),(3);
affected rows: 3
info: Records: 3  Duplicates: 0  Warnings: 0
reset master;
affected rows: 0
replace into test.t1 values (1);
affected rows: 2
set binlog_format=row;
affected rows: 0
replace into test.t1 values (1);
affected rows: 2
show binlog events;
Log_name	Pos	Event_type	Server_id	End_log_pos	Info
master-bin.000001	4	Format_desc	1	120	Server ver: 5.6.12-debug-log, Binlog ver: 4
master-bin.000001	120	Query	1	199	BEGIN
master-bin.000001	199	Query	1	304	use `test`; replace into test.t1 values (1)
master-bin.000001	304	Query	1	384	COMMIT
master-bin.000001	384	Query	1	456	BEGIN
master-bin.000001	456	Table_map	1	501	table_id: 81 (test.t1)
master-bin.000001	501	Update_rows	1	547	table_id: 81 flags: STMT_END_F
master-bin.000001	547	Query	1	620	COMMIT
affected rows: 8

But anyway main issue here is affected rows count.

I'm setting this to status Duplicate (an equivalent of closed) because the corresponding bug 16523197 in the master bugs system is marked as a duplicate of another bug in that system, 13904273 that was found via a test case. That other bug is closed but there is no corresponding public bug to refer to so it wasn't visible in public in this system.

The decision on the other bug was to adjust the documentation and not change the way the server works. Two documentation pages were updated:

https://dev.mysql.com/doc/refman/5.6/en/information-functions.html#function_row-count

1. Mention the key duplicate case of the INSERT ... ON DUPLICATE KEY UPDATE
statement there as a special case of the true UPDATE statement:

"For UPDATE statements, the affected-rows value by default is the number of
rows actually changed. If you specify the CLIENT_FOUND_ROWS flag to
mysql_real_connect() when connecting to mysqld, the affected-rows value is
the number of rows ???found???; that is, matched by the WHERE clause."

https://dev.mysql.com/doc/refman/5.6/en/insert-on-duplicate.html

2. Add a special case for the update with a same values there:

"With ON DUPLICATE KEY UPDATE, the affected-rows value per row is 1 if the
row is inserted as a new row, and 2 if an existing row is updated." (
http://dev.mysql.com/doc/refman/5.6/en/insert-on-duplicate.html ).

I.e. in the case of a key duplicate, if the ON DUPLICATE KEY UPDATE clause
has to update the record with the same values, then the record stays
untouched and the affected-rows value is 0 per such a row.

So, server acting as designed but the documentation wasn't as clear as it could have been about what to expect.

James Day, MySQL Senior Principal Support Engineer, Oracle