Binlog events with binlog_format=MIXED are unconditionally logged in ROW format in some cases

Bug #1313901 reported by Ovais Tariq
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MySQL Server
Unknown
Unknown
Percona Server moved to https://jira.percona.com/projects/PS
Fix Released
Medium
George Ormond Lorch III
5.1
Invalid
Undecided
Unassigned
5.5
Fix Released
Medium
George Ormond Lorch III
5.6
Fix Released
Medium
George Ormond Lorch III

Bug Description

Percona Server version:
Server version: 5.5.36-34.2-rel34.2-log Percona Server with XtraDB (GPL), Release rel34.2, Revision 648

When master and slave (with log-slave-updates enabled) are both running with MIXED mode replication and master executes a query that is logged in ROW format, after that query any other query that would be otherwise safe to log in STATEMENT format is unconditionally logged in ROW format.

The test case be repeated as follows:
-- Prepare the test case data on the master:
CREATE TABLE `t2` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `c` char(32) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1018 DEFAULT CHARSET=latin1;

INSERT INTO `t2` VALUES (1, 'dummy'), (2, 'foo'), (3, 'ping'), (4, 'ding'), (5, 'ring');

create temporary table t2_temp(`id` int(11) NOT NULL, `c` char(32) DEFAULT NULL) ENGINE=InnoDB;

create index idx1 on t2_temp(id);

insert into t2_temp values(4, 'hello'), (5, 'world');

master [localhost] {msandbox} (test) > select * from t2;
+----+-------+
| id | c |
+----+-------+
| 1 | dummy |
| 2 | foo |
| 3 | ping |
| 4 | ding |
| 5 | ring |
+----+-------+
5 rows in set (0.00 sec)

master [localhost] {msandbox} (test) > select * from t2_temp
    -> ;
+----+-------+
| id | c |
+----+-------+
| 4 | hello |
| 5 | world |
+----+-------+
2 rows in set (0.00 sec)

-- Now the below query when executed is correctly logged in ROW format on the master because it is an unsafe statement:
master [localhost] {msandbox} (test) > update t2, t2_temp set t2.c='updated' where t2.id=t2_temp.id;
Query OK, 2 rows affected (0.00 sec)
Rows matched: 2 Changed: 2 Warnings: 0

-- However the next simple insert is incorrectly logged in ROW format:
master [localhost] {msandbox} (test) > insert into t2 values(6, 'simple_insert');
Query OK, 1 row affected (0.00 sec)

This is true for any further queries that are executed, they are unconditionally logged in ROW format unless the connection is disconnected and a new connection to MySQL server is made.

-- Binary log events on the master:
mysqlbinlog -v data/mysql-bin.000008

# at 602
#140428 21:24:34 server id 1 end_log_pos 759 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713074/*!*/;
SET @@session.pseudo_thread_id=7/*!*/;
create temporary table t2_temp(`id` int(11) NOT NULL, `c` char(32) DEFAULT NULL) ENGINE=InnoDB
/*!*/;
# at 759
#140428 21:25:05 server id 1 end_log_pos 854 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713105/*!*/;
create index idx1 on t2_temp(id)
/*!*/;
# at 854
#140428 21:26:06 server id 1 end_log_pos 922 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
BEGIN
/*!*/;
# at 922
#140428 21:26:06 server id 1 end_log_pos 1037 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
insert into t2_temp values(4, 'hello'), (5, 'world')
/*!*/;
# at 1037
#140428 21:26:06 server id 1 end_log_pos 1106 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
COMMIT
/*!*/;
# at 1106
#140428 21:27:13 server id 1 end_log_pos 1183 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713233/*!*/;
BEGIN
/*!*/;
# at 1183
# at 1227
#140428 21:27:13 server id 1 end_log_pos 1227 Table_map: `test`.`t2` mapped to number 35
#140428 21:27:13 server id 1 end_log_pos 1303 Update_rows: table id 35 flags: STMT_END_F

BINLOG '
kateUxMBAAAALAAAAMsEAAAAACMAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI=
kateUxgBAAAATAAAABcFAAAAACMAAAAAAAEAAv///AQAAAAEZGluZ/wEAAAAB3VwZGF0ZWT8BQAA
AARyaW5n/AUAAAAHdXBkYXRlZA==
'/*!*/;
### UPDATE test.t2
### WHERE
### @1=4
### @2='ding'
### SET
### @1=4
### @2='updated'
### UPDATE test.t2
### WHERE
### @1=5
### @2='ring'
### SET
### @1=5
### @2='updated'
# at 1303
#140428 21:27:13 server id 1 end_log_pos 1330 Xid = 350
COMMIT/*!*/;
# at 1330
#140428 21:28:03 server id 1 end_log_pos 1398 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713283/*!*/;
BEGIN
/*!*/;
# at 1398
# at 1442
#140428 21:28:03 server id 1 end_log_pos 1442 Table_map: `test`.`t2` mapped to number 35
#140428 21:28:03 server id 1 end_log_pos 1490 Write_rows: table id 35 flags: STMT_END_F

BINLOG '
w6teUxMBAAAALAAAAKIFAAAAACMAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI=
w6teUxcBAAAAMAAAANIFAAAAACMAAAAAAAEAAv/8BgAAAA1zaW1wbGVfaW5zZXJ0
'/*!*/;
### INSERT INTO test.t2
### SET
### @1=6
### @2='simple_insert'
# at 1490
#140428 21:28:03 server id 1 end_log_pos 1517 Xid = 352
COMMIT/*!*/;

-- Binlog events on the slave
# at 463
#140428 21:24:34 server id 1 end_log_pos 620 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713074/*!*/;
create temporary table t2_temp(`id` int(11) NOT NULL, `c` char(32) DEFAULT NULL) ENGINE=InnoDB
/*!*/;
# at 620
#140428 21:25:05 server id 1 end_log_pos 715 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713105/*!*/;
create index idx1 on t2_temp(id)
/*!*/;
# at 715
#140428 21:26:06 server id 1 end_log_pos 783 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
BEGIN
/*!*/;
# at 783
#140428 21:26:06 server id 1 end_log_pos 898 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
insert into t2_temp values(4, 'hello'), (5, 'world')
/*!*/;
# at 898
#140428 21:26:06 server id 1 end_log_pos 967 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713166/*!*/;
COMMIT
/*!*/;
# at 967
#140428 21:27:13 server id 1 end_log_pos 1026 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713233/*!*/;
BEGIN
/*!*/;
# at 1026
# at 1070
#140428 21:27:13 server id 1 end_log_pos 1070 Table_map: `test`.`t2` mapped to number 34
#140428 21:27:13 server id 1 end_log_pos 1146 Update_rows: table id 34 flags: STMT_END_F

BINLOG '
kateUxMBAAAALAAAAC4EAAAAACIAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI=
kateUxgBAAAATAAAAHoEAAAAACIAAAAAAAEAAv///AQAAAAEZGluZ/wEAAAAB3VwZGF0ZWT8BQAA
AARyaW5n/AUAAAAHdXBkYXRlZA==
'/*!*/;
### UPDATE test.t2
### WHERE
### @1=4 /* INT meta=0 nullable=0 is_null=0 */
### @2='ding' /* STRING(32) meta=65056 nullable=1 is_null=0 */
### SET
### @1=4 /* INT meta=0 nullable=0 is_null=0 */
### @2='updated' /* STRING(32) meta=65056 nullable=1 is_null=0 */
### UPDATE test.t2
### WHERE
### @1=5 /* INT meta=0 nullable=0 is_null=0 */
### @2='ring' /* STRING(32) meta=65056 nullable=1 is_null=0 */
### SET
### @1=5 /* INT meta=0 nullable=0 is_null=0 */
### @2='updated' /* STRING(32) meta=65056 nullable=1 is_null=0 */
# at 1146
#140428 21:27:13 server id 1 end_log_pos 1173 Xid = 547
COMMIT/*!*/;
# at 1173
#140428 21:28:03 server id 1 end_log_pos 1232 Query thread_id=7 exec_time=0 error_code=0
SET TIMESTAMP=1398713283/*!*/;
BEGIN
/*!*/;
# at 1232
# at 1276
#140428 21:28:03 server id 1 end_log_pos 1276 Table_map: `test`.`t2` mapped to number 34
#140428 21:28:03 server id 1 end_log_pos 1324 Write_rows: table id 34 flags: STMT_END_F

BINLOG '
w6teUxMBAAAALAAAAPwEAAAAACIAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI=
w6teUxcBAAAAMAAAACwFAAAAACIAAAAAAAEAAv/8BgAAAA1zaW1wbGVfaW5zZXJ0
'/*!*/;
### INSERT INTO test.t2
### SET
### @1=6 /* INT meta=0 nullable=0 is_null=0 */
### @2='simple_insert' /* STRING(32) meta=65056 nullable=1 is_null=0 */
# at 1324
#140428 21:28:03 server id 1 end_log_pos 1351 Xid = 549
COMMIT/*!*/;

Disconnecting the active connection and then reconnecting and then executing a similar INSERT query causes it to be logged correctly in STATEMENT format:
master [localhost] {msandbox} (test) > insert into t2 values(8, 'simple_insert_stmt');
Query OK, 1 row affected (0.00 sec)

- binlog event on the master
# at 299
#140428 22:11:38 server id 1 end_log_pos 414 Query thread_id=5 exec_time=0 error_code=0
use `test`/*!*/;
SET TIMESTAMP=1398715898/*!*/;
DROP /*!40005 TEMPORARY */ TABLE IF EXISTS `t2_temp`
/*!*/;
# at 414
#140428 22:11:48 server id 1 end_log_pos 482 Query thread_id=6 exec_time=0 error_code=0
SET TIMESTAMP=1398715908/*!*/;
BEGIN
/*!*/;
# at 482
#140428 22:11:48 server id 1 end_log_pos 591 Query thread_id=6 exec_time=0 error_code=0
SET TIMESTAMP=1398715908/*!*/;
insert into t2 values(8, 'simple_insert_stmt')
/*!*/;
# at 591
#140428 22:11:48 server id 1 end_log_pos 618 Xid = 39
COMMIT/*!*/;

- binlog event on the slave
# at 1546
#140428 21:43:18 server id 1 end_log_pos 1655 Query thread_id=9 exec_time=0 error_code=0
use `test`/*!*/;
SET TIMESTAMP=1398714198/*!*/;
insert into t2 values(8, 'simple_insert_stmt')
/*!*/;

-- Binary log format on the master:
master [localhost] {msandbox} ((none)) > show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | MIXED |
+---------------+-------+
1 row in set (0.00 sec)

-- Binary log format on the slave:
slave1 [localhost] {msandbox} ((none)) > show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | MIXED |
+---------------+-------+
1 row in set (0.00 sec)

Related branches

tags: added: i41544
tags: added: upstream
Revision history for this message
Nilnandan Joshi (nilnandan-joshi) wrote :
Download full text (6.1 KiB)

Not repeatable with PS 5.1.73, its logging as a STATEMENT for all queries with binlog-format=MIXED.

nil@Dell-XPS:~/sandboxes/rsandbox_Percona-Server-5_1_73/master/data$ mysqlbinlog -v mysql-bin.000002
/*!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 266
#140605 11:32:05 server id 1 end_log_pos 497 Query thread_id=1 exec_time=0 error_code=0
use `test`/*!*/;
SET TIMESTAMP=1401948125/*!*/;
CREATE TABLE `t2` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `c` char(32) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1018 DEFAULT CHARSET=latin1
/*!*/;
# at 497
#140605 11:32:10 server id 1 end_log_pos 565 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948130/*!*/;
BEGIN
/*!*/;
# at 565
#140605 11:32:10 server id 1 end_log_pos 715 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948130/*!*/;
INSERT INTO `t2` VALUES (1, 'dummy'), (2, 'foo'), (3, 'ping'), (4, 'ding'), (5, 'ring')
/*!*/;
# at 715
#140605 11:32:10 server id 1 end_log_pos 742 Xid = 16
COMMIT/*!*/;
# at 742
#140605 11:32:15 server id 1 end_log_pos 899 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948135/*!*/;
create temporary table t2_temp(`id` int(11) NOT NULL, `c` char(32) DEFAULT NULL) ENGINE=InnoDB
/*!*/;
# at 899
#140605 11:32:20 server id 1 end_log_pos 994 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948140/*!*/;
create index idx1 on t2_temp(id)
/*!*/;
# at 994
#140605 11:32:25 server id 1 end_log_pos 1062 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948145/*!*/;
BEGIN
/*!*/;
# at 1062
#140605 11:32:25 server id 1 end_log_pos 1177 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948145/*!*/;
insert into t2_temp values(4, 'hello'), (5, 'world')
/*!*/;
# at 1177
#140605 11:32:25 server id 1 end_log_pos 1246 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948145/*!*/;
COMMIT
/*!*/;
# at 1246
#140605 11:33:13 server id 1 end_log_pos 1314 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948193/*!*/;
BEGIN
/*!*/;
# at 1314
#140605 11:33:13 server id 1 end_log_pos 1446 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948193/*!*/;
update t2, t2_temp set t2.c='updated' where t2.id=t2_temp.id
/*!*/;
# at 1446
#140605 11:33:13 server id 1 end_log_pos 1473 Xid = 22
COMMIT/*!*/;
# at 1473
#140605 11:33:23 server id 1 end_log_pos 1541 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948203/*!*/;
BEGIN
/*!*/;
# at 1541
#140605 11:33:23 server id 1 end_log_pos 1645 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401948203/*!*/;
insert into t2 values(6, 'simple_insert')
/*!*/;
# at 1645
#140605 11:33:23 server id 1 end_log_pos 1672 Xid = 23
COMMIT/*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
nil@Dell-XPS:~/sandboxes/rsandbox_Percona-Server-5_1_73/master/data$

-------------------------- On slave--------------------------

nil@Dell-XPS:~/sa...

Read more...

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

Repeatable with PS 5.6.17

nil@Dell-XPS:~/sandboxes/rsandbox_Percona-Server-5_6_17/master/data$ mysqlbinlog -v mysql-bin.000003
/*!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*/;

...

# at 510
#140605 16:45:26 server id 1 end_log_pos 752 CRC32 0x07a704f4 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966926/*!*/;
CREATE TABLE `t2` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `c` char(32) DEFAULT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=1018 DEFAULT CHARSET=latin1
/*!*/;
# at 752
#140605 16:45:30 server id 1 end_log_pos 831 CRC32 0x3461ce1d Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966930/*!*/;
BEGIN
/*!*/;
# at 831
#140605 16:45:30 server id 1 end_log_pos 992 CRC32 0xebe4b1af Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966930/*!*/;
INSERT INTO `t2` VALUES (1, 'dummy'), (2, 'foo'), (3, 'ping'), (4, 'ding'), (5, 'ring')
/*!*/;
# at 992
#140605 16:45:30 server id 1 end_log_pos 1023 CRC32 0xb1233f88 Xid = 34
COMMIT/*!*/;
# at 1023
#140605 16:45:35 server id 1 end_log_pos 1191 CRC32 0x9a2fca98 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966935/*!*/;
create temporary table t2_temp(`id` int(11) NOT NULL, `c` char(32) DEFAULT NULL) ENGINE=InnoDB
/*!*/;
# at 1191
#140605 16:45:51 server id 1 end_log_pos 1297 CRC32 0xa0c429b6 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966951/*!*/;
create index idx1 on t2_temp(id)
/*!*/;
# at 1297
#140605 16:45:55 server id 1 end_log_pos 1376 CRC32 0xceaf66ed Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966955/*!*/;
BEGIN
/*!*/;
# at 1376
#140605 16:45:55 server id 1 end_log_pos 1502 CRC32 0xbf32b6dd Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966955/*!*/;
insert into t2_temp values(4, 'hello'), (5, 'world')
/*!*/;
# at 1502
#140605 16:45:55 server id 1 end_log_pos 1582 CRC32 0x264c4a5e Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966955/*!*/;
COMMIT
/*!*/;
# at 1582
#140605 16:46:12 server id 1 end_log_pos 1663 CRC32 0x2fbc5e02 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966972/*!*/;
BEGIN
/*!*/;
# at 1663
#140605 16:46:12 server id 1 end_log_pos 1711 CRC32 0xed6f2a3b Table_map: `test`.`t2` mapped to number 71
# at 1711
#140605 16:46:12 server id 1 end_log_pos 1793 CRC32 0x6eb2924f Update_rows: table id 71 flags: STMT_END_F

BINLOG '
fFGQUxMBAAAAMAAAAK8GAAAAAEcAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI7Km/t
fFGQUx8BAAAAUgAAAAEHAAAAAEcAAAAAAAEAAgAC///8BAAAAARkaW5n/AQAAAAHdXBkYXRlZPwF
AAAABHJpbmf8BQAAAAd1cGRhdGVkT5Kybg==
'/*!*/;
### UPDATE `test`.`t2`
### WHERE
### @1=4
### @2='ding'
### SET
### @1=4
### @2='updated'
### UPDATE `test`.`t2`
### WHERE
### @1=5
### @2='ring'
### SET
### @1=5
### @2='updated'
# at 1793
#140605 16:46:12 server id 1 end_log_pos 1824 CRC32 0xd08404b8 Xid = 40
COMMIT/*!*/;
# at 1824
#140605 16:46:18 server id 1 end_log_pos 1896 CRC32 0x1160fc18 Query thread_id=1 exec_time=0 error_code=0
SET TIMESTAMP=1401966978/*!*/;
BEGIN
/*!*/;
# at 1896
#140605 16:46:18 server id 1 end_log...

Read more...

Revision history for this message
Ovais Tariq (ovais-tariq) wrote :

Simplified version of one of the mtr test cases pertinent to this bug

Revision history for this message
Ovais Tariq (ovais-tariq) wrote :
Download full text (3.2 KiB)

Running the above mtr test case on upstream 5.5.37 produces the following result:

CREATE TABLE t1 (a int);
CREATE TABLE t2 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) );
CREATE TABLE t3 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) );
CREATE TRIGGER tr1 AFTER DELETE ON t2 FOR EACH ROW INSERT INTO t3 () VALUES ();
CREATE TEMPORARY TABLE t1_tmp (i1 int);
ALTER TABLE t1_tmp ADD COLUMN b INT;
DELETE FROM t2;
CREATE TEMPORARY TABLE t2_tmp (a int);
ALTER TABLE t1_tmp ADD COLUMN c INT;
### assertion: assert that slave has no temporary tables opened
SHOW STATUS LIKE 'Slave_open_temp_tables';
Variable_name Value
Slave_open_temp_tables 1
DROP TABLE t1_tmp, t2;
INSERT INTO t2_tmp SELECT CEIL(RAND() * 1000);
INSERT INTO t1 VALUES (1);
INSERT INTO t3 SELECT * FROM t2_tmp;
DROP TEMPORARY TABLE t2_tmp;
INSERT INTO t1 VALUES (2);
### assertion: assert that slave has no temporary tables opened
SHOW STATUS LIKE 'Slave_open_temp_tables';
Variable_name Value
Slave_open_temp_tables 0
DROP TABLE t3, t1;
show binlog events from <binlog_start>;
Log_name Pos Event_type Server_id End_log_pos Info
slave-bin.000001 # Query # # use `test`; CREATE TABLE t1 (a int)
slave-bin.000001 # Query # # use `test`; CREATE TABLE t2 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) )
slave-bin.000001 # Query # # use `test`; CREATE TABLE t3 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) )
slave-bin.000001 # Query # # use `test`; CREATE DEFINER=`root`@`localhost` TRIGGER tr1 AFTER DELETE ON t2 FOR EACH ROW INSERT INTO t3 () VALUES ()
slave-bin.000001 # Query # # use `test`; CREATE TEMPORARY TABLE t1_tmp (i1 int)
slave-bin.000001 # Query # # use `test`; ALTER TABLE t1_tmp ADD COLUMN b INT
slave-bin.000001 # Query # # DROP TEMPORARY TABLE IF EXISTS `test`.`t1_tmp` /* generated by server */
slave-bin.000001 # Query # # use `test`; DROP TABLE `t2` /* generated by server */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Table_map # # table_id: # (test.t1)
slave-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Table_map # # table_id: # (test.t3)
slave-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # DROP TEMPORARY TABLE IF EXISTS `test`.`t2_tmp` /* generated by server */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Query # # use `test`; INSERT INTO t1 VALUES (2)
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # use `test`; DROP TABLE `t3`,`t1` ...

Read more...

Revision history for this message
Ovais Tariq (ovais-tariq) wrote :

Running the attached mtr test case on binary with the potential fix by George, produces the following result:

CREATE TABLE t1 (a int);
CREATE TABLE t2 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) );
CREATE TABLE t3 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) );
CREATE TRIGGER tr1 AFTER DELETE ON t2 FOR EACH ROW INSERT INTO t3 () VALUES ();
CREATE TEMPORARY TABLE t1_tmp (i1 int);
ALTER TABLE t1_tmp ADD COLUMN b INT;
DELETE FROM t2;
CREATE TEMPORARY TABLE t2_tmp (a int);
ALTER TABLE t1_tmp ADD COLUMN c INT;
### assertion: assert that slave has no temporary tables opened
SHOW STATUS LIKE 'Slave_open_temp_tables';
Variable_name Value
Slave_open_temp_tables 0
DROP TABLE t1_tmp, t2;
INSERT INTO t2_tmp SELECT CEIL(RAND() * 1000);
INSERT INTO t1 VALUES (1);
INSERT INTO t3 SELECT * FROM t2_tmp;
DROP TEMPORARY TABLE t2_tmp;
INSERT INTO t1 VALUES (2);
### assertion: assert that slave has no temporary tables opened
SHOW STATUS LIKE 'Slave_open_temp_tables';
Variable_name Value
Slave_open_temp_tables 0
DROP TABLE t3, t1;
show binlog events from <binlog_start>;
Log_name Pos Event_type Server_id End_log_pos Info
slave-bin.000001 # Query # # use `test`; CREATE TABLE t1 (a int)
slave-bin.000001 # Query # # use `test`; CREATE TABLE t2 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) )
slave-bin.000001 # Query # # use `test`; CREATE TABLE t3 ( i1 INT NOT NULL AUTO_INCREMENT, PRIMARY KEY (i1) )
slave-bin.000001 # Query # # use `test`; CREATE DEFINER=`root`@`localhost` TRIGGER tr1 AFTER DELETE ON t2 FOR EACH ROW INSERT INTO t3 () VALUES ()
slave-bin.000001 # Query # # DROP TEMPORARY TABLE IF EXISTS `test`.`t1_tmp` /* generated by server */
slave-bin.000001 # Query # # use `test`; DROP TABLE `t2` /* generated by server */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Query # # use `test`; INSERT INTO t1 VALUES (1)
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Table_map # # table_id: # (test.t3)
slave-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # DROP TEMPORARY TABLE IF EXISTS `test`.`t2_tmp` /* generated by server */
slave-bin.000001 # Query # # BEGIN
slave-bin.000001 # Query # # use `test`; INSERT INTO t1 VALUES (2)
slave-bin.000001 # Xid # # COMMIT /* XID */
slave-bin.000001 # Query # # use `test`; DROP TABLE `t3`,`t1` /* generated by server */

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/PS-151

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

Other bug subscribers

Remote bug watches

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