MySQL Bugs: #98665: replication broken on blackhole node if binlog_rows_query_log

Bug #98665	replication broken on blackhole node if binlog_rows_query_log_events on master
Submitted:	19 Feb 2020 12:27	Modified:	27 Feb 2020 12:28
Reporter:	Zhenghu Wen (OCA)	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	8.0.19, 5.7.29	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
suppose we have a db instance with one master and slave node, we use blackhole as slave's default storage engine, if we set binlog_rows_query_log_events=on in master node, then replication(with RBR) broken on dml(update or delete) event

How to repeat:
use node1 as master, node3 as slave.

1. setup master-slave async replication with node1.cnf and node3.cnf.

2. node3: set global default_storage_engine=BLACKHOLE;

3. node1: create backhole_rpl database, and test table:
create database blackhole_rpl;
use blackhole_rpl;
 CREATE TABLE `test` (
  `a` int NOT NULL,
  PRIMARY KEY (`a`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_0900_ai_ci;

4. node1: insert one record and update it:
insert into test values (1);
update test set a=11 where a=1;

5. node3: found replication error log:
2020-02-19T20:21:56.584014+08:00 13 [ERROR] [MY-010584] [Repl] Slave SQL for channel '': Worker 1 failed executing transaction 'fbf34394-5311-11ea-8bac-246e963b3e60:6' at master log mysql-bin.000002, end_log_pos 1690; Could not execute Update_rows event on table blackhole_rpl.test; Can't find record in 'test', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; the event's master log mysql-bin.000002, end_log_pos 1690, Error_code: MY-001032

Suggested fix:
null

master config file

Attachment: node1.cnf (application/octet-stream, text), 2.34 KiB.

slave config file

Attachment: node3.cnf (application/octet-stream, text), 2.34 KiB.

the same as 5.7.20+

a. if binlog_rows_query_log_events is on the master, the dml query will write into binlog as rows_query_log_event; 

b. when the slave apply this event ,it will set thd query:
int Rows_query_log_event::do_apply_event(Relay_log_info const *rli)
{
  ...
  /* Set query for writing Rows_query log event into binlog later.*/
  thd->set_query(m_rows_query, strlen(m_rows_query));
  ...
}

c. it is conflict with blackhole engine: 
int ha_blackhole::update_row(const uchar *, uchar *) {
  DBUG_TRACE;
  THD *thd = ha_thd();
  if (is_slave_applier(thd) && thd->query().str == NULL) return 0;
  return HA_ERR_WRONG_COMMAND;
}

int ha_blackhole::delete_row(const uchar *) {
  DBUG_TRACE;
  THD *thd = ha_thd();
  if (is_slave_applier(thd) && thd->query().str == NULL) return 0;
  return HA_ERR_WRONG_COMMAND;
}
we can see in ha_blackhole::update_row and ha_blackhole::delete_row that only if thd->query().str is NULL, it will return 0 (means everything is fine)

Hello Zhenghu,

Thank you for the report.
Verified as described with 8.0.19 build.

Thanks,
Umesh

Test results - 8.0.19

Attachment: 98665_8.0.19.results (application/octet-stream, text), 11.84 KiB.

I'll add 5.7 test results later on.

Test results - 5.7.29

Attachment: 98665_5.7.29.results (application/octet-stream, text), 9.90 KiB.