MySQL Bugs: #77729: Cleanup procedure for Memory engine tables breaks GITD replica

Bug #77729	Cleanup procedure for Memory engine tables breaks GITD replica
Submitted:	15 Jul 2015 8:41	Modified:	13 May 2020 12:23
Reporter:	Rumen Palov	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S2 (Serious)
Version:	Distrib 5.6.16, for FreeBSD,5.6.35	OS:	FreeBSD (tested only on freebsd)
Assigned to:		CPU Architecture:	Any

Description:
When you have table with Engine MEMORY working on replication master, mysqld injects "DELETE" statement in binary logs on first access query to this table. This insures consistent of data on replicating slaves. ( https://dev.mysql.com/doc/refman/5.6/en/memory-storage-engine.html / #MEMORY Tables and Replication  ) 

If replication is GTID ROW based, this inserted "DELETE" breaks replication.  Logged event is in STATEMENT format and do not generate correct SET GTID_NEXT statements in binary log.  

Binary Log snapshtop:
-------------------------------------------------------------------------------
SET @@SESSION.GTID_NEXT= '18c65f0b-1dae-11e4-89ba-00259087d9a8:6809'/*!*/;
# at 164462833
#150714 17:17:02 server id 663  end_log_pos 164462977 CRC32 0x7d3fbc90  Query   thread_id=183308        exec_time=3     error_code=0
use `information_schema`/*!*/;
SET TIMESTAMP=1436883422/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=3, @@session.auto_increment_offset=3/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
DELETE FROM `schema_name`.`table_name`
/*!*/;
# at 164462977
#150714 17:17:02 server id 663  end_log_pos 164463113 CRC32 0x4b5397a3  Query   thread_id=183308        exec_time=4     error_code=0
SET TIMESTAMP=1436883422/*!*/;
DELETE FROM `schema_name`.`table_name`
/*!*/;
# at 164463113
-------------------------------------------------------------------------------

Error message in mysql log is as follow: 
-------------------------------------------------------------------------------
ERROR] Slave SQL: Error 'When @@SESSION.GTID_NEXT is set to a GTID, you must explicitly set it to a different value after a COMMIT or ROLLBACK. Please check GTID_NEXT variable manual page for detailed explanation. Current @@SESSION.GTID_NEXT is '18c65f0b-1dae-11e4-89ba-00259087d9a8:6809'.' on query. Default database: 'information_schema'. Query: 'DELETE FROM `nl_website_tickets`.`test_last_month`', Error_code: 1837
2015-07-14 17:17:08 91890 [Warning] Slave: When @@SESSION.GTID_NEXT is set to a GTID, you must explicitly set it to a different value after a COMMIT or ROLLBACK. Please check GTID_NEXT variable manual page for detailed explanation. Current @@SESSION.GTID_NEXT is '18c65f0b-1dae-11e4-89ba-00259087d9a8:6809'. Error_code: 1837
-------------------------------------------------------------------------------

Quick workaround - Inject empty gtid event, with GTID from error in mysql error log. 

How to repeat:
1) Setup replication with GTID enabled, ROW based.
2) Create memory table
3) Insert few rows
4) Restart Master mysqld
5) log in mysql console on master 
6) SELECT * from memory_table 
7) log in mysql console slave - replication is broken with messages from "Description" Section of this bug report

Suggested fix:
When mysql injects cleanup "DELETE"-S in binary log, they have to be in the same format as is binary log itself and configured replication type.

Hello Rumen,

Thank you for the report.
I'm not seeing this issue on 5.6.25/5.6.27, I see you are using 5.6.16 which is very old and many bugs fixed since then. Please try GA version 5.6.25 and let us know if you are still having this issue along with conf files used and error log for further investigations.

If you can provide more information, feel free to add it to this bug and change the status back to 'Open'.

Thank you for your interest in MySQL.

Thanks,
Umesh

5.6.25/27 test results

Attachment: 77729_5.6.25.results (application/octet-stream, text), 54.99 KiB.

I am still getting this issue in 5.6.25 as well as 5.6.26.
5.6.27 is still not released according to Mysql5.6 release-notes page.

Any updates...

Was this issue fixed as part of bug # 68525?

Thank you for the feedback, and steps.

test results

Attachment: 77729_5.6.35.results (application/octet-stream, text), 10.32 KiB.

Posted by developer:
 
Changelog entry added for MySQL 5.6.49, 5.7.31, and 8.0.21:

When a master server shuts down and restarts, its MEMORY tables become empty. To replicate this effect to slaves, the first time that the master uses a given MEMORY table after startup, it notifies slaves that the table must be emptied by writing a DELETE statement for that table to the binary log. Previously, the generated DELETE statement was written to the binary log statement cache for the current session, which could result in it being logged together with other statements under the same GTID, or logged without BEGIN and COMMIT statements. Also, in some situations, the generated DELETE statement could consume the GTID intended for the transaction that triggered it. The generated DELETE statement is now logged with accompanying BEGIN and COMMIT statements, and the resulting transaction is flushed to the binary log immediately after it is written to the statement cache, so that it always receives its own GTID and is kept separate from other transactions.