Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC

Blackhole engine tables apparently replicated in transactions with Innodb when other unsupported types are not

  1. Series 5.6
  2. Bug #1296792
Bug #1296792 reported by Jay Janssen
8
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL patches by Codership
Won't Fix
Undecided
Seppo Jaakola
Percona XtraDB Cluster moved to https://jira.percona.com/projects/PXC
Status tracked in 5.6
5.5
Won't Fix
High
Unassigned
5.6
Confirmed
High
Unassigned

Bug Description

TLDR;

If I have a transaction with:

begin; insert innodb; insert memory; insert blackhole; commit

I find that all nodes in my cluster with log-bin enabled will get the Innodb replication (expected) AND the blackhole insert (unexpected).

the MEMORY engine (and others I've tested: MyISAM and CSV) do not exhibit this behavior -- instead their statements appear first in the binlog and do not propagate to the other nodes in the cluster.

Details:

node1 mysql> show create table inno\G
*************************** 1. row ***************************
       Table: inno
Create Table: CREATE TABLE `inno` (
  `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `j` varchar(32) NOT NULL,
  PRIMARY KEY (`i`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

node1 mysql> show create table mem\G
*************************** 1. row ***************************
       Table: mem
Create Table: CREATE TABLE `mem` (
  `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `j` varchar(32) NOT NULL,
  PRIMARY KEY (`i`)
) ENGINE=MEMORY DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

node1 mysql> show create table black\G
*************************** 1. row ***************************
       Table: black
Create Table: CREATE TABLE `black` (
  `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `j` varchar(32) NOT NULL,
  PRIMARY KEY (`i`)
) ENGINE=BLACKHOLE DEFAULT CHARSET=latin1
1 row in set (0.00 sec)

node1 mysql> begin;
Query OK, 0 rows affected (0.00 sec)

node1 mysql> insert into inno (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

node1 mysql> insert into mem (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

node1 mysql> insert into black (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

node1 mysql> commit;
Query OK, 0 rows affected (0.00 sec)

node1 mysql> select * from inno;
+---+----------+
| i | j |
+---+----------+
| 1 | aaaaaaaa |
+---+----------+
1 row in set (0.00 sec)

node1 mysql> select * from mem;
+---+----------+
| i | j |
+---+----------+
| 1 | aaaaaaaa |
+---+----------+
1 row in set (0.00 sec)

node2 mysql> select * from inno;
+---+----------+
| i | j |
+---+----------+
| 1 | aaaaaaaa |
+---+----------+
1 row in set (0.00 sec)

node2 mysql> select * from mem;
Empty set (0.00 sec)

node1 mysql> show master status;
+------------------+----------+--------------+------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| node1-bin.000007 | 621 | | |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

node2 mysql> show master status;
+------------------+----------+--------------+------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
+------------------+----------+--------------+------------------+
| node2-bin.000007 | 372 | | |
+------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

[root@node1 ~]# mysqlbinlog --base64-output=DECODE-ROWS --verbose /var/lib/mysql/node1-bin.000007
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140324 15:14:31 server id 1 end_log_pos 107 Start: binlog v 4, server v 5.5.34-55-log created 140324 15:14:31
# Warning: this binlog is either in use or was not closed properly.
# at 107
#140324 15:15:50 server id 1 end_log_pos 180 Query thread_id=41 exec_time=0 error_code=0
SET TIMESTAMP=1395674150/*!*/;
SET @@session.pseudo_thread_id=41/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=2, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 180
# at 225
#140324 15:15:50 server id 1 end_log_pos 225 Table_map: `test`.`mem` mapped to number 50
#140324 15:15:50 server id 1 end_log_pos 268 Write_rows: table id 50 flags: STMT_END_F
### INSERT INTO test.mem
### SET
### @1=1
### @2='aaaaaaaa'
# at 268
#140324 15:15:50 server id 1 end_log_pos 342 Query thread_id=41 exec_time=0 error_code=0
SET TIMESTAMP=1395674150/*!*/;
COMMIT
/*!*/;
# at 342
#140324 15:16:39 server id 1 end_log_pos 415 Query thread_id=41 exec_time=0 error_code=0
SET TIMESTAMP=1395674199/*!*/;
BEGIN
/*!*/;
# at 415
# at 461
#140324 15:15:45 server id 1 end_log_pos 461 Table_map: `test`.`inno` mapped to number 48
#140324 15:15:45 server id 1 end_log_pos 504 Write_rows: table id 48 flags: STMT_END_F
### INSERT INTO test.inno
### SET
### @1=1
### @2='aaaaaaaa'
# at 504
# at 551
#140324 15:16:34 server id 1 end_log_pos 551 Table_map: `test`.`black` mapped to number 49
#140324 15:16:34 server id 1 end_log_pos 594 Write_rows: table id 49 flags: STMT_END_F
### INSERT INTO test.black
### SET
### @1=1
### @2='aaaaaaaa'
# at 594
#140324 15:16:39 server id 1 end_log_pos 621 Xid = 31
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

[root@node2 ~]# mysqlbinlog --base64-output=DECODE-ROWS --verbose /var/lib/mysql/node2-bin.000007
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140324 15:14:31 server id 1 end_log_pos 107 Start: binlog v 4, server v 5.5.34-55-log created 140324 15:14:31
# Warning: this binlog is either in use or was not closed properly.
# at 107
#140324 15:16:34 server id 1 end_log_pos 166 Query thread_id=37 exec_time=5 error_code=0
SET TIMESTAMP=1395674194/*!*/;
SET @@session.pseudo_thread_id=37/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 166
# at 212
#140324 15:15:45 server id 1 end_log_pos 212 Table_map: `test`.`inno` mapped to number 48
#140324 15:15:45 server id 1 end_log_pos 255 Write_rows: table id 48 flags: STMT_END_F
### INSERT INTO test.inno
### SET
### @1=1
### @2='aaaaaaaa'
# at 255
# at 302
#140324 15:16:34 server id 1 end_log_pos 302 Table_map: `test`.`black` mapped to number 49
#140324 15:16:34 server id 1 end_log_pos 345 Write_rows: table id 49 flags: STMT_END_F
### INSERT INTO test.black
### SET
### @1=1
### @2='aaaaaaaa'
# at 345
#140324 15:16:34 server id 1 end_log_pos 372 Xid = 31
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

Seppo Jaakola (seppo-jaakola)
Changed in codership-mysql:
assignee: nobody → Seppo Jaakola (seppo-jaakola)
status: New → In Progress
Seppo Jaakola (seppo-jaakola)
Changed in codership-mysql:
status: In Progress → Won't Fix
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (6.9 KiB)

Verified above the same thing with PXC 5.6

On Node1:

mysql> CREATE TABLE `inno` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.18 sec)

mysql> CREATE TABLE `mem` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=MEMORY DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.05 sec)

mysql> CREATE TABLE `black` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=BLACKHOLE DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql>
mysql>
mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into inno (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> insert into mem (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> insert into black (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.03 sec)

mysql>
mysql> select * from inno;
+---+----------+
| i | j |
 +---+----------+
| 1 | aaaaaaaa |
 +---+----------+
1 row in set (0.00 sec)

mysql> select * from mem;
+---+----------+
| i | j |
 +---+----------+
| 1 | aaaaaaaa |
 +---+----------+
1 row in set (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
 +------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000001 | 1800 | | | |
 +------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

mysql> quit
Bye
root@debian:/var/log/mysql# ll
-bash: ll: command not found
root@debian:/var/log/mysql# ls -al
total 16
drwxr-s--- 2 mysql adm 4096 Aug 6 15:44 .
drwxr-xr-x 15 root root 4096 Jul 23 13:30 ..
-rw-rw---- 1 mysql adm 1800 Aug 6 15:47 mysql-bin.000001
-rw-rw---- 1 mysql adm 32 Aug 6 15:44 mysql-bin.index
root@debian:/var/log/mysql#
root@debian:/var/log/mysql#
root@debian:/var/log/mysql# mysqlbinlog --base64-output=DECODE-ROWS --verbose mysql-bin.000001
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#140806 15:44:48 server id 1 end_log_pos 120 CRC32 0x1206506c Start: binlog v 4, server v 5.6.19-67.0-56-log created 140806 15:44:48 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
# at 120
#140806 15:45:56 server id 1 end_log_pos 214 CRC32 0xd5f0c018 Query thread_id=4 exec_time=0 error_code=0
use `nil`/*!*/;
SET TIMESTAMP=1407320156/*!*/;
SET @@session.pseudo_thread_id=4/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_...

Read more...

Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (7.1 KiB)

Verified the same thing with PXC 5.5

On Node1:

[root@percona-pxc55-1 mysql]# mysql -uroot -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 3
Server version: 5.5.37-35.0-55-log Percona XtraDB Cluster (GPL), Release rel35.0, Revision 756, WSREP version 25.10, wsrep_25.10.r3985

Copyright (c) 2009-2014 Percona LLC and/or its affiliates
Copyright (c) 2000, 2014, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.

mysql>
mysql>
mysql> use test
Database changed
mysql>
mysql> CREATE TABLE `inno` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.09 sec)

mysql> CREATE TABLE `mem` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=MEMORY DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql> CREATE TABLE `black` (
    -> `i` int(10) unsigned NOT NULL AUTO_INCREMENT,
    -> `j` varchar(32) NOT NULL,
    -> PRIMARY KEY (`i`)
    -> ) ENGINE=BLACKHOLE DEFAULT CHARSET=latin1;
Query OK, 0 rows affected (0.03 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into inno (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> insert into mem (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> insert into black (j) values ('aaaaaaaa' );
Query OK, 1 row affected (0.00 sec)

mysql> commit;
Query OK, 0 rows affected (0.03 sec)

mysql> select * from inno;
+---+----------+
| i | j |
 +---+----------+
| 1 | aaaaaaaa |
 +---+----------+
1 row in set (0.00 sec)

mysql> select * from mem;
+---+----------+
| i | j |
 +---+----------+
| 1 | aaaaaaaa |
 +---+----------+
1 row in set (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+
| File | Position | Binlog_Do_DB | Binlog_Ignore_DB |
 +------------------+----------+--------------+------------------+
| mysql-bin.000001 | 1281 | | |
 +------------------+----------+--------------+------------------+
1 row in set (0.00 sec)

mysql>
mysql> quit
Bye
[root@percona-pxc55-1 mysql]# ls -al
total 280652
drwxr-xr-x. 5 mysql mysql 4096 Aug 11 13:13 .
drwxr-xr-x. 17 root root 4096 Mar 3 16:18 ..
-rw-rw---- 1 mysql mysql 27572 Aug 11 13:13 error.log
-rw------- 1 mysql mysql 134219048 Aug 11 13:14 galera.cache
-rw-rw---- 1 mysql mysql 104 Aug 11 13:14 grastate.dat
-rw-rw---- 1 mysql mysql 18874368 Aug 11 13:14 ibdata1
-rw-rw---- 1 mysql mysql 67108864 Aug 11 13:14 ib_logfile0
-rw-rw---- 1 mysql mysql 67108864 Aug 11 12:35 ib_logfile1
drwx------ 2 mysql mysql 4096 Aug 11 12:33 mysql
-rw-rw---- 1 mysql mysql 1281 Aug 11 13:14 mysql-bin.000001
-rw-rw---- 1 mysql mysql 19 Aug 11 13:13 mysql-bin.index
s...

Read more...

Revision history for this message
Shahriyar Rzayev (rzayev-sehriyar) wrote :

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXC-997

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.