Bug #80053 Assertion in binlog coordinator on slave with 2 2pc handler log_slave_updates=0
Submitted: 19 Jan 2016 16:57 Modified: 10 Nov 2016 6:09
Reporter: George Lorch (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.7.10 OS:Any
Assigned to: CPU Architecture:Any
Tags: Contribution

[19 Jan 2016 16:57] George Lorch
Description:
5.7 assertion mysqld: ./sql/binlog.cc:7987: virtual int MYSQL_BIN_LOG::prepare(THD*, bool): Assertion `thd->slave_thread ? opt_log_slave_updates : thd->variables.sql_log_bin' failed.

1) Slave is started with binlog enabled, but with slave updates not being logged, thus, it has chosen binlog not mmap as the transaction coordinator.
1) Use two different transactional engines within one transaction
3) A mixed engine transaction comes from the master. It should not be binlogged, but binlog acts as the transaction coordinator and asserts.

How to repeat:
Setup basic master-slave w/ binlog replication.

Master options:
server-id=1
log-bin=mysql-bin
max_connections=1000
plugin-load=TokuDB=ha_tokudb.so;TokuDB_trx=ha_tokudb.so;TokuDB_locks=ha_tokudb.so;TokuDB_lock_waits=ha_tokudb.so;TokuDB_file_map=ha_tokudb.so;TokuDB_fractal_tree_info=ha_tokudb.so;TokuDB_fractal_tree_block_map=ha_tokudb.so;TokuDB_background_job_status=ha_tokudb.so

Slave options:
server-id=2
log-bin=mysql-bin
log-slave-updates=0 ### Note, this is critical to reproducing the bug ###
max_connections=1000
plugin-load=TokuDB=ha_tokudb.so;TokuDB_trx=ha_tokudb.so;TokuDB_locks=ha_tokudb.so;TokuDB_lock_waits=ha_tokudb.so;TokuDB_file_map=ha_tokudb.so;TokuDB_fractal_tree_info=ha_tokudb.so;TokuDB_fractal_tree_block_map=ha_tokudb.so;TokuDB_background_job_status=ha_tokudb.so

On the master:
CREATE TABLE t1(`a` INT) ENGINE=TokuDB;
CREATE TABLE t2(`a` INT) ENGINE=InnoDB;
begin;
insert into t1 values (1);
insert into t2 values (1);
commit;

The slave will crash as it processes the commit.

Suggested fix:
diff --git a/sql/binlog.cc b/sql/binlog.cc
index 64680a1..390074c 100644
--- a/sql/binlog.cc
+++ b/sql/binlog.cc
@@ -7995,9 +7995,13 @@ int MYSQL_BIN_LOG::prepare(THD *thd, bool all)
   /*
     The applier thread explicitly overrides the value of sql_log_bin
     with the value of log_slave_updates.
+    We may also end up here in some cases if we have a transaction with two
+    active transactional storage engines, such as is the case if this is a
+    replication applier and log_slave_updates=0.
   */
-  DBUG_ASSERT(thd->slave_thread ?
-              opt_log_slave_updates : thd->variables.sql_log_bin);
+  DBUG_ASSERT((thd->slave_thread ?
+              opt_log_slave_updates : thd->variables.sql_log_bin) ||
+              total_ha_2pc > 1);
 
   /*
     Set HA_IGNORE_DURABILITY to not flush the prepared record of the
[21 Jan 2016 21:20] George Lorch
sql/binlog.cc diff

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: 80053.diff (text/x-patch), 758 bytes.

[10 Nov 2016 6:09] MySQL Verification Team
Hello George,

Thank you for the report and contribution.

Thanks,
Umesh