| Bug #72475 | Binlog events with binlog_format=MIXED are unconditionally logged in ROW format | ||
|---|---|---|---|
| Submitted: | 28 Apr 2014 20:28 | Modified: | 5 Dec 2017 14:07 |
| Reporter: | Ovais Tariq | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S2 (Serious) |
| Version: | 5.5.37, 5.5.38 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[28 Apr 2014 21:09]
Todd Farmer
Hi Ovais, Thanks for your bug report, but I believe this to be consistent with the documented behavior: " If a statement is logged by row and the session that executed the statement has any temporary tables, logging by row is used for all subsequent statements (except for those accessing temporary tables) until all temporary tables in use by that session are dropped. This is true whether or not any temporary tables are actually logged. Temporary tables cannot be logged using row-based format; thus, once row-based logging is used, all subsequent statements using that table are unsafe. The server approximates this condition by treating all statements executed during the session as unsafe until the session no longer holds any temporary tables. " http://dev.mysql.com/doc/refman/5.6/en/binary-log-mixed.html If you believe this doesn't fully explain the behavior you report, can you help me better understand why? I'll mark this as "Not a Bug" for now, but happy to reconsider with additional information. Thanks!
[28 Apr 2014 22:04]
Ovais Tariq
Todd Farmer, Sadly the explanation does not make complete sense. What does not make sense is why the server approximates all statements as unsafe, if the only statements unsafe are the ones that use the temporary table: "Temporary tables cannot be logged using row-based format; thus, once row-based logging is used, all subsequent statements using that table are unsafe. The server approximates this condition by treating all statements executed during the session as unsafe until the session no longer holds any temporary tables." Since the server already has logic to figure out which statements are true and which are not, then why cannot the same logic be applied to the subsequent statements?
[28 Apr 2014 22:36]
Ovais Tariq
Reopening as a bug there is unintended consequences from the current implementation. So if there are two sessions session-1 and session-2, once session-1 creates a temporary table and uses that, all subsequent statements in session-1 are treated as unsafe and logged in ROW format. However, other session session-2 is an altogether different session and queries are logged based on whether they are safe to use with STATEMENT format or not. However, on downstream slave (with log-slave-updates) the statements from session-2 are also logged in ROW format, every query from every session is logged in ROW format because traditional slave runs everything using a single slave-thread. Corresponding binlog events from the master are: #140429 0:26:47 server id 1 end_log_pos 977 Table_map: `test`.`t2` mapped to number 33 #140429 0:26:47 server id 1 end_log_pos 1053 Update_rows: table id 33 flags: STMT_END_F BINLOG ' p9VeUxMBAAAALAAAANEDAAAAACEAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI= p9VeUxgBAAAATAAAAB0EAAAAACEAAAAAAAEAAv///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 1053 #140429 0:26:47 server id 1 end_log_pos 1080 Xid = 16 COMMIT/*!*/; # at 1080 #140429 0:27:10 server id 1 end_log_pos 1148 Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1398724030/*!*/; BEGIN /*!*/; # at 1148 # at 1192 #140429 0:27:10 server id 1 end_log_pos 1192 Table_map: `test`.`t2` mapped to number 33 #140429 0:27:10 server id 1 end_log_pos 1240 Write_rows: table id 33 flags: STMT_END_F BINLOG ' vtVeUxMBAAAALAAAAKgEAAAAACEAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI= vtVeUxcBAAAAMAAAANgEAAAAACEAAAAAAAEAAv/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 1240 #140429 0:27:10 server id 1 end_log_pos 1267 Xid = 17 COMMIT/*!*/; # at 1267 #140429 0:27:49 server id 1 end_log_pos 1335 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1398724069/*!*/; BEGIN /*!*/; # at 1335 #140429 0:27:49 server id 1 end_log_pos 1444 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1398724069/*!*/; insert into t2 values(8, 'simple_insert_stmt') /*!*/; As you can see that the last insert has a different thread_id because it is executed in a different session then the one that is working with temp table. Now for the same queries the downstream slave shows the following: #140429 0:26:47 server id 1 end_log_pos 950 Table_map: `test`.`t2` mapped to number 33 #140429 0:26:47 server id 1 end_log_pos 1026 Update_rows: table id 33 flags: STMT_END_F BINLOG ' p9VeUxMBAAAALAAAALYDAAAAACEAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI= p9VeUxgBAAAATAAAAAIEAAAAACEAAAAAAAEAAv///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 1026 #140429 0:26:47 server id 1 end_log_pos 1053 Xid = 10 COMMIT/*!*/; # at 1053 #140429 0:27:10 server id 1 end_log_pos 1112 Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1398724030/*!*/; BEGIN /*!*/; # at 1112 # at 1156 #140429 0:27:10 server id 1 end_log_pos 1156 Table_map: `test`.`t2` mapped to number 33 #140429 0:27:10 server id 1 end_log_pos 1204 Write_rows: table id 33 flags: STMT_END_F BINLOG ' vtVeUxMBAAAALAAAAIQEAAAAACEAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI= vtVeUxcBAAAAMAAAALQEAAAAACEAAAAAAAEAAv/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 1204 #140429 0:27:10 server id 1 end_log_pos 1231 Xid = 14 COMMIT/*!*/; # at 1231 #140429 0:27:49 server id 1 end_log_pos 1290 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1398724069/*!*/; BEGIN /*!*/; # at 1290 # at 1334 #140429 0:27:49 server id 1 end_log_pos 1334 Table_map: `test`.`t2` mapped to number 33 #140429 0:27:49 server id 1 end_log_pos 1387 Write_rows: table id 33 flags: STMT_END_F BINLOG ' 5dVeUxMBAAAALAAAADYFAAAAACEAAAAAAAEABHRlc3QAAnQyAAID/gL+IAI= 5dVeUxcBAAAANQAAAGsFAAAAACEAAAAAAAEAAv/8CAAAABJzaW1wbGVfaW5zZXJ0X3N0bXQ= '/*!*/; ### INSERT INTO `test`.`t2` ### SET ### @1=8 /* INT meta=0 nullable=0 is_null=0 */ ### @2='simple_insert_stmt' /* STRING(32) meta=65056 nullable=1 is_null=0 */ # at 1387 #140429 0:27:49 server id 1 end_log_pos 1414 Xid = 16 COMMIT/*!*/; As you can see above the downstream slave wrongly logs the last insert in row format. This is a consequence of the current implementation which you referenced from the manual.
[30 Apr 2014 21:50]
Todd Farmer
Hi Ovais, Thanks for further analysis. In discussion with replication developers, they agree that the current implementation uses a simplification to avoid having to track certain aspects. The impacts of this simplification may have optimization aspects (avoid excessive evaluation or tracking), but also have downstream impacts on the slave. This may also impact in-development features, such as multi-threaded slave, and requires further analysis. In short, this seems like a valid feature request to change the documented behavior.
[1 May 2014 4:07]
Ovais Tariq
Great. That's good to hear. i propose that to deal with temporary tables with MIXED mode replication, the only check should be to see if any query involves reading or writing to a temporary table and then such a query should be logged as ROW. The server is already aware when it executes a statement, as to whether the statement accesses a temporary table, hence it can apply the same logic to the following statements, without having to unconditionally take every statement as an unsafe statement.
[27 May 2014 9:58]
MySQL Verification Team
Hello Ovais, Thank you for the report/feature request!. Verified as described. Thanks, Umesh
[27 Feb 2015 15:32]
Laurynas Biveinis
Bug 72475 patch for 5.7.5 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: bug72475-5.7.5.patch (application/octet-stream, text), 187.94 KiB.
[27 Feb 2015 15:33]
Laurynas Biveinis
Patch author George Lorch.
[1 Dec 2016 14:36]
Laurynas Biveinis
Bug 72475 patch for 8.0.0 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: bug72475-8.0.0.patch (application/octet-stream, text), 178.04 KiB.
[2 Dec 2016 4:25]
MySQL Verification Team
Thank you Laurynas for the contribution/patch. Thanks, Umesh
[14 Apr 2017 9:11]
Laurynas Biveinis
Bug 72475 fix for 8.0.1 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: bug72475-8.0.1.patch (application/octet-stream, text), 171.19 KiB.
[20 Jul 2017 18:50]
Laurynas Biveinis
A fix in 8.0.2 "BUG#24411680 SET BINLOG_FORMAT DOES NOT GENERATE ERROR WHEN THERE ARE TEMPORARY TABLES" pointed out that this fix must also adjust the rules of session binlog format change too when there are open temporary tables. The correct rules now seem to be: forbid change from ROW or MIXED to STATEMENT when there are opened temp tables, as then their CREATE TEMPORARY TABLE might not have been binlogged. All other changes are allowed. A 8.0.2 patch refresh will contain this change. Since the follow-up patch for bug 83003 introduces tracking of binlog format at table create time, with that patch it would be possible to relax this further and only forbid binlog format change if there indeed exists at least one temp table whose CREATE was not binlogged, but currently I'm not planning to implement that, and IMHO moving in and out of SBR with temp tables open seems to be risky with or without the patches anyway.
[4 Aug 2017 19:34]
Laurynas Biveinis
Bug 72475 fix for 8.0.2 (*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.
Contribution: bug72475-8.0.2.patch (application/octet-stream, text), 179.42 KiB.
[4 Aug 2017 19:36]
Laurynas Biveinis
The 8.0.2 implements changed session binlog format change rules as described above. If the change is forbidden, the same error ER_TEMP_TABLE_PREVENTS_SWITCH_OUT_OF_RBR is returned, although now its name and message are misleading.
[5 Dec 2017 14:07]
Margaret Fisher
Posted by developer: Changelog entry added for MySQL 8.0.4: The behavior of mixed format replication has changed with regards to temporary tables. Previously, when mixed binary logging format was in use, if a statement was logged by row and the session that executed the statement had any temporary tables, all subsequent statements were treated as unsafe and logged in row-based format until all temporary tables in use by that session were dropped. Also, on a replication slave with log_slave_updates enabled, row-based logging was incorrectly continued across all subsequent sessions for the duration of the connection, as reported in the bug. Now, when mixed binary logging format is in use, statements that exclusively use temporary tables are not logged. Statements that involve a mix of temporary and non-temporary tables are logged on the master only for the operations on non-temporary tables, and the operations on temporary tables are not logged. The exception is if the creation of a temporary table was recorded in the binary log using statement-based format. In this case, a DROP TEMPORARY TABLE IF EXISTS statement is logged on the master when the temporary table is dropped. With this change in behavior, the remaining statements in the session that do not involve temporary tables no longer need to be treated as unsafe. The safe statements are now logged in statement-based format, and the unsafe statements are logged in row-based format, according to the normal behavior for mixed format replication, regardless of the presence of temporary tables in the session. Also, the issue reported in the bug has been fixed so that subsequent sessions using the connection now use the appropriate logging format for the session, regardless of the format used by earlier sessions. When binlog_format is ROW or STATEMENT, the behavior remains as before. For row-based binary logging format, operations on temporary tables are not logged, with the exception of the DROP TEMPORARY TABLE IF EXISTS statement as for mixed format. For statement-based binary logging format, operations on temporary tables are logged on the master and replicated on the slave, provided that the statements involving temporary tables can be logged safely using statement-based format. binlog_format=STATEMENT is now the only logging mode in which temporary tables are replicated on the slave. You cannot now change the binlog_format setting from ROW or MIXED to STATEMENT at runtime, because any CREATE TEMPORARY TABLE statements will have been omitted from the binary log in the previous mode. You can still switch from STATEMENT to ROW or MIXED format, even when temporary tables have been created. Thanks to George Lorch and Laurynas Biveinis from Percona for the patch. Documentation changes also made in the following topics: https://dev.mysql.com/doc/refman/8.0/en/binary-log-mixed.html https://dev.mysql.com/doc/refman/8.0/en/binary-log-setting.html https://dev.mysql.com/doc/refman/8.0/en/replication-rbr-usage.html https://dev.mysql.com/doc/refman/8.0/en/replication-features-temptables.html
Description: 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 for the whole duration of the connection. However, I could only repeat this with only a specific set of queries. This is specially problematic for those connections that stay connected for very lengthy periods, such as when using persistent connections or connections pools, or the MySQL slave server's slave SQL thread. How to repeat: 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)