| Bug #59338 | Inconsistency in binlog for statements that don't change any rows STATEMENT SBR | ||
|---|---|---|---|
| Submitted: | 6 Jan 2011 19:05 | Modified: | 9 Feb 2011 21:26 |
| Reporter: | Leandro Morgado | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1.50 | OS: | Any |
| Assigned to: | Alfranio Tavares Correia Junior | CPU Architecture: | Any |
[6 Jan 2011 19:13]
Leandro Morgado
Work around:
master [localhost] {msandbox} (test) > RESET MASTER;
Query OK, 0 rows affected (0.00 sec)
master [localhost] {msandbox} (test) > INSERT INTO t1(c1, c2) VALUES ('a', 'b') ON DUPLICATE KEY UPDATE c1='a', c2='b',c3=NOW();
Query OK, 2 rows affected (0.01 sec)
master [localhost] {msandbox} (test) > SELECT * FROM t1;+----+------+---------------------+
| c1 | c2 | c3 |
+----+------+---------------------+
| a | b | 2011-01-06 20:12:34 |
+----+------+---------------------+
1 row in set (0.00 sec)
master [localhost] {msandbox} (test) > SHOW BINLOG EVENTS\G
*************************** 1. row ***************************
Log_name: mysql-bin.000001
Pos: 4
Event_type: Format_desc
Server_id: 1
End_log_pos: 106
Info: Server ver: 5.1.50-enterprise-gpl-advanced-log, Binlog ver: 4
*************************** 2. row ***************************
Log_name: mysql-bin.000001
Pos: 106
Event_type: Query
Server_id: 1
End_log_pos: 182
Info: BEGIN
*************************** 3. row ***************************
Log_name: mysql-bin.000001
Pos: 182
Event_type: Query
Server_id: 1
End_log_pos: 341
Info: use `test`; INSERT INTO t1(c1, c2) VALUES ('a', 'b') ON DUPLICATE KEY UPDATE c1='a', c2='b',c3=NOW()
*************************** 4. row ***************************
Log_name: mysql-bin.000001
Pos: 341
Event_type: Xid
Server_id: 1
End_log_pos: 368
Info: COMMIT /* xid=148 */
4 rows in set (0.00 sec)
[7 Jan 2011 13:48]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/128170 3535 Alfranio Correia 2011-01-07 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional engine is updated. INSERT ON DUPLICATE KEY UPDATE was not following the rule above and was not being written to the binary log, if then engine was Innodb.
[7 Jan 2011 16:12]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/128186 3535 Alfranio Correia 2011-01-07 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb.
[19 Jan 2011 11:31]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129169 3535 Alfranio Correia 2011-01-19 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb.
[21 Jan 2011 12:57]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129330 3535 Alfranio Correia 2011-01-21 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb. @ mysql-test/extra/rpl_tests/rpl_insert_duplicate.test Added test case. @ mysql-test/extra/rpl_tests/rpl_insert_ignore.test Updated test case. @ mysql-test/include/commit.inc Updated test case as the calls to the binary log have changed for INSERT ON DUPLICATE and INSERT IGNORE. @ mysql-test/r/commit_1innodb.result Updated result file. @ mysql-test/suite/rpl/r/rpl_row_insert_duplicate.result Added a test case. @ mysql-test/suite/rpl/r/rpl_row_insert_ignore.result Added a test case. @ mysql-test/suite/rpl/r/rpl_stm_mixed_insert_duplicate.result Added a test case. @ mysql-test/suite/rpl/r/rpl_stm_mixed_insert_ignore.result Added a test case. @ mysql-test/suite/rpl/t/rpl_row_insert_duplicate.test Added a test case. @ mysql-test/suite/rpl/t/rpl_row_insert_ignore.test Added a test case. @ mysql-test/suite/rpl/t/rpl_stm_mixed_insert_duplicate.test Added a test case. @ mysql-test/suite/rpl/t/rpl_stm_mixed_insert_ignore.test Update the test case, in order to run it only in SBR and MIXED modes. Note that another test case was created for the ROW mode.
[27 Jan 2011 15:33]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129787 3555 Alfranio Correia 2011-01-27 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb. @ mysql-test/extra/rpl_tests/rpl_insert_duplicate.test Added test case. @ mysql-test/extra/rpl_tests/rpl_insert_ignore.test Updated test case. @ mysql-test/include/commit.inc Updated test case as the calls to the binary log have changed for INSERT ON DUPLICATE and INSERT IGNORE. @ mysql-test/r/commit_1innodb.result Updated result file. @ mysql-test/suite/rpl/r/rpl_insert_duplicate.result Added test case. @ mysql-test/suite/rpl/r/rpl_insert_ignore.result Updated result file. @ mysql-test/suite/rpl/t/rpl_insert_duplicate.test Added test case. @ mysql-test/suite/rpl/t/rpl_insert_ignore.test Improved test case.
[27 Jan 2011 16:15]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129792 3555 Alfranio Correia 2011-01-27 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb. @ mysql-test/extra/rpl_tests/rpl_insert_duplicate.test Added test case. @ mysql-test/extra/rpl_tests/rpl_insert_ignore.test Updated test case. @ mysql-test/include/commit.inc Updated test case as the calls to the binary log have changed for INSERT ON DUPLICATE and INSERT IGNORE. @ mysql-test/r/commit_1innodb.result Updated result file. @ mysql-test/suite/rpl/r/rpl_insert_duplicate.result Added test case. @ mysql-test/suite/rpl/r/rpl_insert_ignore.result Updated result file. @ mysql-test/suite/rpl/t/rpl_insert_duplicate.test Added test case. @ mysql-test/suite/rpl/t/rpl_insert_ignore.test Improved test case.
[28 Jan 2011 12:10]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/129851 3555 Alfranio Correia 2011-01-28 BUG#59338 Inconsistency in binlog for statements that don't change any rows STATEMENT SBR In SBR, if a statement does not fail, it is always written to the binary log, regardless if rows are changed or not. If there is a failure, a statement is only written to the binary log if a non-transactional (.e.g. MyIsam) engine is updated. INSERT ON DUPLICATE KEY UPDATE and INSERT IGNORE were not following the rule above and were not written to the binary log, if then engine was Innodb. @ mysql-test/extra/rpl_tests/rpl_insert_duplicate.test Added test case. @ mysql-test/extra/rpl_tests/rpl_insert_ignore.test Updated test case. @ mysql-test/include/commit.inc Updated test case as the calls to the binary log have changed for INSERT ON DUPLICATE and INSERT IGNORE. @ mysql-test/r/commit_1innodb.result Updated result file. @ mysql-test/suite/rpl/r/rpl_insert_duplicate.result Added test case. @ mysql-test/suite/rpl/r/rpl_insert_ignore.result Updated result file. @ mysql-test/suite/rpl/t/rpl_insert_duplicate.test Added test case. @ mysql-test/suite/rpl/t/rpl_insert_ignore.test Improved test case.
[31 Jan 2011 14:33]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/130048 3570 Alfranio Correia 2011-01-31 Post-fix for BUG#59338.
[31 Jan 2011 14:39]
Bugs System
Pushed into mysql-5.1 5.1.56 (revid:alfranio.correia@oracle.com-20110131143133-tbrk92p7b691sy7v) (version source revid:alfranio.correia@oracle.com-20110131143133-tbrk92p7b691sy7v) (merge vers: 5.1.56) (pib:24)
[31 Jan 2011 14:39]
Bugs System
Pushed into mysql-5.5 5.5.10 (revid:alfranio.correia@oracle.com-20110131143404-lhpp8lyvdm48z54o) (version source revid:alfranio.correia@oracle.com-20110131143404-lhpp8lyvdm48z54o) (merge vers: 5.5.10) (pib:24)
[31 Jan 2011 14:41]
Bugs System
Pushed into mysql-trunk 5.6.2 (revid:alfranio.correia@oracle.com-20110131143645-adjsz57nh921np4f) (version source revid:alfranio.correia@oracle.com-20110131143645-adjsz57nh921np4f) (merge vers: 5.6.2) (pib:24)
[1 Feb 2011 16:21]
Jon Stephens
Documented bugfix as follows in the 5.1.56, 5.5.10, and 5.6.2 changelogs:
When using the statement-based logging format, INSERT ON
DUPLICATE KEY UPDATE and INSERT IGNORE statements affecting
transactional tables that did not fail were not written to the
binary log if they did not insert any rows. (With
statement-based logging, all successful statements should be
logged, whether they do or do not they cause any rows to be
changed.)
Closed.
[9 Feb 2011 21:26]
Jon Stephens
Already documented in the 5.1.56 and 5.5.10 changelogs. Closed.
[23 Sep 2011 19:48]
Mark Callaghan
I don't understand the testcase for rpl_insert_ignore. The bug was that INSERT IGNORE didn't write to the binlog for when no rows were modified. But the testcase INSERT IGNORE statement inserts 2 rows from t2 into t1
Description: When using STATEMENT based replication, an INSERT ON DUPLICATE KEY UPDATE statement that does not change data (Rows .. Changed: 0) will not be recorded in the binary log. However, an similar UPDATE statement will. This inconsistent behaviour is not desirable. How to repeat: master [localhost] {msandbox} (test) > SELECT VERSION(); +------------------------------------+ | VERSION() | +------------------------------------+ | 5.1.50-enterprise-gpl-advanced-log | +------------------------------------+ 1 row in set (0.00 sec) master [localhost] {msandbox} (test) > SHOW VARIABLES LIKE "binlog_format"; +---------------+-----------+ | Variable_name | Value | +---------------+-----------+ | binlog_format | STATEMENT | +---------------+-----------+ 1 row in set (0.00 sec) ************************************************************************ ============ TEST CASE FOR INSERT ON DUPLICATE KEY UPDATE ============== CREATE TABLE t1 ( c1 varchar(15) NOT NULL, c2 varchar(20) DEFAULT NULL, c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, PRIMARY KEY (c1) ) ENGINE=InnoDB DEFAULT CHARSET=latin1; INSERT INTO t1(c1, c2) VALUES ('a', 'b'); SELECT * FROM t1; INSERT INTO t1(c1, c2) VALUES ('a', 'b') ON DUPLICATE KEY UPDATE c1='a', c2='b'; SELECT * FROM t1; ============ RESULT FOR INSERT ON DUPLICATE KEY UPDATE ================= master [localhost] {msandbox} (test) > CREATE TABLE t1 ( -> c1 varchar(15) NOT NULL, -> c2 varchar(20) DEFAULT NULL, -> c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, -> PRIMARY KEY (c1) -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1; Query OK, 0 rows affected (0.01 sec) master [localhost] {msandbox} (test) > INSERT INTO t1(c1, c2) VALUES ('a', 'b'); Query OK, 1 row affected (0.01 sec) master [localhost] {msandbox} (test) > SELECT * FROM t1; +----+------+---------------------+ | c1 | c2 | c3 | +----+------+---------------------+ | a | b | 2011-01-06 20:01:26 | +----+------+---------------------+ 1 row in set (0.00 sec) master [localhost] {msandbox} (test) > INSERT INTO t1(c1, c2) VALUES ('a', 'b') ON DUPLICATE KEY UPDATE c1='a', c2='b'; Query OK, 0 rows affected (0.00 sec) master [localhost] {msandbox} (test) > SELECT * FROM t1;+----+------+---------------------+ | c1 | c2 | c3 | +----+------+---------------------+ | a | b | 2011-01-06 20:01:26 | +----+------+---------------------+ 1 row in set (0.00 sec) master [localhost] {msandbox} (test) > SHOW BINLOG EVENTS\G*************************** 1. row *************************** Log_name: mysql-bin.000001 Pos: 4 Event_type: Format_desc Server_id: 1 End_log_pos: 106 Info: Server ver: 5.1.50-enterprise-gpl-advanced-log, Binlog ver: 4 *************************** 2. row *************************** Log_name: mysql-bin.000001 Pos: 106 Event_type: Query Server_id: 1 End_log_pos: 381 Info: use `test`; CREATE TABLE t1 ( c1 varchar(15) NOT NULL, c2 varchar(20) DEFAULT NULL, c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, PRIMARY KEY (c1) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 *************************** 3. row *************************** Log_name: mysql-bin.000001 Pos: 381 Event_type: Query Server_id: 1 End_log_pos: 449 Info: BEGIN *************************** 4. row *************************** Log_name: mysql-bin.000001 Pos: 449 Event_type: Query Server_id: 1 End_log_pos: 552 Info: use `test`; INSERT INTO t1(c1, c2) VALUES ('a', 'b') *************************** 5. row *************************** Log_name: mysql-bin.000001 Pos: 552 Event_type: Xid Server_id: 1 End_log_pos: 579 Info: COMMIT /* xid=140 */ 5 rows in set (0.00 sec) CONCLUSION: We never see the INSERT .. ON DUPLICATE KEY UPDATE statement in the binlog. ************************************************************************ ====================== TEST CASE FOR UPDATE ============================ CREATE TABLE t1 ( c1 varchar(15) NOT NULL, c2 varchar(20) DEFAULT NULL, c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, PRIMARY KEY (c1) ) ENGINE=InnoDB DEFAULT CHARSET=latin1; INSERT INTO t1(c1, c2) VALUES ('a', 'b'); SELECT * FROM t1; UPDATE t1 SET c1='a', c2='b' WHERE c1='a' AND c2='b'; SELECT * FROM t1; ====================== RESULT FOR UPDATE ========================== master [localhost] {msandbox} (test) > CREATE TABLE t1 ( -> c1 varchar(15) NOT NULL, -> c2 varchar(20) DEFAULT NULL, -> c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, -> PRIMARY KEY (c1) -> ) ENGINE=InnoDB DEFAULT CHARSET=latin1; Query OK, 0 rows affected (0.01 sec) master [localhost] {msandbox} (test) > INSERT INTO t1(c1, c2) VALUES ('a', 'b'); Query OK, 1 row affected (0.01 sec) master [localhost] {msandbox} (test) > SELECT * FROM t1; +----+------+---------------------+ | c1 | c2 | c3 | +----+------+---------------------+ | a | b | 2011-01-06 19:58:42 | +----+------+---------------------+ 1 row in set (0.00 sec) -- notice Changed:0 below master [localhost] {msandbox} (test) > UPDATE t1 SET c1='a', c2='b' WHERE c1='a' AND c2='b'; Query OK, 0 rows affected (0.00 sec) Rows matched: 1 Changed: 0 Warnings: 0 master [localhost] {msandbox} (test) > SELECT * FROM t1; +----+------+---------------------+ | c1 | c2 | c3 | +----+------+---------------------+ | a | b | 2011-01-06 19:58:42 | +----+------+---------------------+ 1 row in set (0.00 sec) master [localhost] {msandbox} (test) > SHOW BINLOG EVENTS\G *************************** 1. row *************************** Log_name: mysql-bin.000001 Pos: 4 Event_type: Format_desc Server_id: 1 End_log_pos: 106 Info: Server ver: 5.1.50-enterprise-gpl-advanced-log, Binlog ver: 4 *************************** 2. row *************************** Log_name: mysql-bin.000001 Pos: 106 Event_type: Query Server_id: 1 End_log_pos: 381 Info: use `test`; CREATE TABLE t1 ( c1 varchar(15) NOT NULL, c2 varchar(20) DEFAULT NULL, c3 timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, PRIMARY KEY (c1) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 *************************** 3. row *************************** Log_name: mysql-bin.000001 Pos: 381 Event_type: Query Server_id: 1 End_log_pos: 449 Info: BEGIN *************************** 4. row *************************** Log_name: mysql-bin.000001 Pos: 449 Event_type: Query Server_id: 1 End_log_pos: 552 Info: use `test`; INSERT INTO t1(c1, c2) VALUES ('a', 'b') *************************** 5. row *************************** Log_name: mysql-bin.000001 Pos: 552 Event_type: Xid Server_id: 1 End_log_pos: 579 Info: COMMIT /* xid=132 */ *************************** 6. row *************************** Log_name: mysql-bin.000001 Pos: 579 Event_type: Query Server_id: 1 End_log_pos: 647 Info: BEGIN *************************** 7. row *************************** Log_name: mysql-bin.000001 Pos: 647 Event_type: Query Server_id: 1 End_log_pos: 762 Info: use `test`; UPDATE t1 SET c1='a', c2='b' WHERE c1='a' AND c2='b' *************************** 8. row *************************** Log_name: mysql-bin.000001 Pos: 762 Event_type: Query Server_id: 1 End_log_pos: 831 Info: COMMIT 8 rows in set (0.00 sec) CONCLUSION: Row 7 of the binlog events show that the UPDATE was logged. Suggested fix: This is inconsistent as no statement changes rows but one is logged and the other one isn't. I think either both are logged or non are. Binary logging both entries is probably safer to cover edge user cases and hacks like this: mysql> UPDATE tbl SET col = 1 WHERE @@server_id = 2;