| Bug #47175 | failing INSERT, transaction, replication out of sync | ||
|---|---|---|---|
| Submitted: | 7 Sep 2009 13:25 | Modified: | 7 Mar 2010 1:53 |
| Reporter: | Matthias Leich | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Row Based Replication ( RBR ) | Severity: | S3 (Non-critical) |
| Version: | 5.1,5.4 | OS: | Any |
| Assigned to: | Alfranio Tavares Correia Junior | CPU Architecture: | Any |
[23 Sep 2009 2:47]
Alfranio Tavares Correia Junior
See also BUG#47287.
[23 Sep 2009 3:47]
Alfranio Tavares Correia Junior
The problem in this bug stems from the fact that the failing statement, which has changed a non-transactional table, does not get through the binary log even after calling ROLLBACK to finish the transaction. This problem will be partially fixed in BUG#47287 as an early statement that fails and has changed non-transactional tables will be automatically written to the binary log as follows: COMMANDS: CREATE TABLE `tt_1_innodb` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)) ENGINE = Innodb; CREATE TABLE `nt_1_myisam` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)) ENGINE = MyISAM; INSERT INTO nt_1_myisam VALUES (1, NULL) , (2, 1); SET AUTOCOMMIT = 0; CREATE TABLE nt_2_myisam ( f2 INT, f1 INTEGER , PRIMARY KEY (f1)) ENGINE = MyISAM; INSERT INTO nt_2_myisam VALUES (NULL, 1); COMMIT; --error ER_DUP_ENTRY INSERT INTO nt_2_myisam SELECT * FROM nt_1_myisam; ROLLBACK; BINLOG: Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 4 Format_desc 1 106 Server ver: 5.1.39-debug-log, Binlog ver: 4 master-bin.000001 106 Query 1 251 use `test`; CREATE TABLE `tt_1_innodb` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)) ENGINE = Innodb master-bin.000001 251 Query 1 396 use `test`; CREATE TABLE `nt_1_myisam` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)) ENGINE = MyISAM master-bin.000001 396 Query 1 464 BEGIN master-bin.000001 464 Table_map 1 515 table_id: 23 (test.nt_1_myisam) master-bin.000001 515 Write_rows 1 558 table_id: 23 flags: STMT_END_F master-bin.000001 558 Query 1 627 COMMIT master-bin.000001 627 Query 1 771 use `test`; CREATE TABLE nt_2_myisam ( f2 INT, f1 INTEGER , PRIMARY KEY (f1)) ENGINE = MyISAM master-bin.000001 771 Query 1 839 BEGIN master-bin.000001 839 Table_map 1 890 table_id: 24 (test.nt_2_myisam) master-bin.000001 890 Write_rows 1 924 table_id: 24 flags: STMT_END_F master-bin.000001 924 Query 1 993 COMMIT master-bin.000001 993 Query 1 1061 BEGIN master-bin.000001 1061 Table_map 1 1112 table_id: 24 (test.nt_2_myisam) master-bin.000001 1112 Write_rows 1 1150 table_id: 24 flags: STMT_END_F master-bin.000001 1150 Query 1 1221 ROLLBACK However, there is another problem not fixed by BUG#47287 and that would pop up if we slightly change the statements: INSERT INTO tt_1_innodb SELECT * FROM nt_1_myisam; --error ER_DUP_ENTRY INSERT INTO nt_2_myisam SELECT * FROM nt_1_myisam; ROLLBACK; In this case, nothing is written to the binary log although a non-transactional table was updated. This happen because in row mode: thd->transaction.all.modified_non_trans_table is not set to true and the following code in the log.cc is not executed: if ((all && thd->transaction.all.modified_non_trans_table) || (!all && thd->transaction.stmt.modified_non_trans_table && !(thd->options & (OPTION_BEGIN | OPTION_NOT_AUTOCOMMIT))) || (!all && thd->transaction.stmt.modified_non_trans_table && !trx_data->at_least_one_stmt && thd->current_stmt_binlog_row_based) || ((thd->options & OPTION_KEEP_LOG))) { Query_log_event qev(thd, STRING_WITH_LEN("ROLLBACK"), TRUE, TRUE, 0); error= binlog_end_trans(thd, trx_data, &qev, all); }
[23 Sep 2009 5:14]
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/84236 3118 Alfranio Correia 2009-09-23 BUG#47175 failing INSERT, transaction, replication out of sync In the RBR mode, a failing INSERT...SELECT statement was not corretly setting the variable THD::transaction.all.modified_non_trans_table and as such if a rollback was requested and no other non-transactional table updated, nothing was written to the binary log. To fix the bug, we set the variable regardless the replication mode.
[29 Sep 2009 10:10]
Luis Soares
Will be fixed after WL#2687 is pushed in future release.
[4 Nov 2009 1:33]
Alfranio Tavares Correia Junior
Pushed to mysql-5.1-rep+3 revision-id: alfranio.correia@sun.com-20091103190256-637o8qxlveikrt3i
[12 Nov 2009 23:56]
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/90290 3120 Alfranio Correia 2009-11-12 Post-fix for WL#2687 WL#5072 BUG#40278 BUG#47175 Create a set of test cases to see if some DDL statements implicitly commit a transaction on the NDB and are written directly to the binary log without going through either the Statement- or Transactional-Cache.
[13 Nov 2009 0:18]
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/90291 3120 Alfranio Correia 2009-11-13 Post-fix for WL#2687 WL#5072 BUG#40278 BUG#47175 Create a set of test cases to see if some DDL statements implicitly commit a transaction on the NDB and are written directly to the binary log without going through either the Statement- or Transactional-Cache.
[18 Jan 2010 12:06]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@ibmvm-20100118120357-hnzhgadkpzqfnvsc) (version source revid:alik@ibmvm-20100118115413-kd3klpine09yyktw) (merge vers: 6.0.14-alpha) (pib:16)
[18 Jan 2010 12:07]
Bugs System
Pushed into mysql-next-mr (revid:alik@ibmvm-20100118120111-73dulkgc893it4r9) (version source revid:alik@ibmvm-20100118115335-0stecyzftqm7bqx6) (pib:16)
[19 Jan 2010 8:45]
Jon Stephens
Documented bugfix in the 5.6.0 and 6.0.14 changelogs. Set NDI state, waiting for further merges.
[15 Feb 2010 10:17]
Jon Stephens
Discussed with Alfranio; no further merges expected. Closed.
[6 Mar 2010 11:06]
Bugs System
Pushed into 5.5.3-m3 (revid:alik@sun.com-20100306103849-hha31z2enhh7jwt3) (version source revid:vvaintroub@linux-rbsx-20100118220048-5vnyqi5ghsbgmdsd) (merge vers: 5.5.99-m3) (pib:16)
[7 Mar 2010 1:53]
Paul DuBois
Moved 5.6.0 changelog entry to 5.5.3.
Description: My script: ========== --source include/master-slave.inc --disable_warnings DROP TABLE IF EXISTS t1,t2; --enable_warnings connection master; CREATE TABLE `t1` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)); INSERT INTO t1 VALUES (1, NULL) , (2, 1); SET AUTOCOMMIT = 0; CREATE TABLE t2 ( f2 INT, f1 INTEGER , PRIMARY KEY (f1)) ENGINE = MyISAM; INSERT INTO t2 VALUES (NULL, 1); COMMIT; SHOW CREATE TABLE t2; SELECT * FROM t2; --sync_slave_with_master --echo # Switch to slave ---------------------------------- connection slave; SHOW CREATE TABLE t2; SELECT * FROM t2; --echo # Switch to master ---------------------------------- connection master; --error ER_DUP_ENTRY INSERT INTO t2 SELECT * FROM t1; SELECT * FROM t2; --sync_slave_with_master --echo # Switch to slave ---------------------------------- connection slave; SELECT * FROM t2; --echo # Switch to master ---------------------------------- connection master; ROLLBACK; SELECT * FROM t2; --sync_slave_with_master --echo # Switch to slave ---------------------------------- connection slave; SELECT * FROM t2; --echo # Switch to master ---------------------------------- connection master; UPDATE t2 SET f2 = 8 ; COMMIT WORK; --sync_slave_with_master DROP TABLE t1,t2; --sync_slave_with_master The outcome (a bit edited): =========================== ... DROP TABLE IF EXISTS t1,t2; CREATE TABLE `t1` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)); INSERT INTO t1 VALUES (1, NULL) , (2, 1); SET AUTOCOMMIT = 0; CREATE TABLE t2 ( f2 INT, f1 INTEGER , PRIMARY KEY (f1)) ENGINE = MyISAM; INSERT INTO t2 VALUES (NULL, 1); COMMIT; SHOW CREATE TABLE t2; Table Create Table t2 CREATE TABLE `t2` ( `f2` int(11) DEFAULT NULL, `f1` int(11) NOT NULL DEFAULT '0', PRIMARY KEY (`f1`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 SELECT * FROM t2; f2 f1 NULL 1 # Switch to slave ---------------------------------- SHOW CREATE TABLE t2; Table Create Table t2 CREATE TABLE `t2` ( `f2` int(11) DEFAULT NULL, `f1` int(11) NOT NULL DEFAULT '0', PRIMARY KEY (`f1`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 SELECT * FROM t2; f2 f1 NULL 1 <--- Ok, table definition and content is in sync # Switch to master ---------------------------------- INSERT INTO t2 SELECT * FROM t1; ERROR 23000: Duplicate entry '1' for key 'PRIMARY' SELECT * FROM t2; f2 f1 NULL 1 1 0 # Switch to slave ---------------------------------- SELECT * FROM t2; f2 f1 NULL 1 <--- This is ok in case we get the row after *whatever* transaction end. # Switch to master ---------------------------------- ROLLBACK; SELECT * FROM t2; f2 f1 NULL 1 1 0 <--- Ok, t1 uses MyISAM -> row not removed # Switch to slave ---------------------------------- SELECT * FROM t2; f2 f1 NULL 1 <--- !!! Replication out of sync !!! # Switch to master ---------------------------------- UPDATE t2 SET f2 = 8 ; <--- Here the slave stops with Last_SQL_Errno 1032 Last_SQL_Error Could not execute Update_rows event on table test.t2; Can't find record in 't2', Error_code: 1032; handler error HA_ERR_KEY_NOT_FOUND; ... SHOW BINLOG EVENTS IN 'master-bin.000001'; ========================================== Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 4 Format_desc 1 107 Server ver: 5.4.4-alpha-debug-log, Binlog ver: 4 Query 1 196 use `test`; DROP TABLE IF EXISTS t1,t2 Query 1 316 use `test`; CREATE TABLE `t1` ( f1 INTEGER, f2 INT, PRIMARY KEY (f1)) Query 1 384 BEGIN Table_map 1 426 table_id: 16 (test.t1) Write_rows 1 469 table_id: 16 flags: STMT_END_F Query 1 538 COMMIT Query 1 673 use `test`; CREATE TABLE t2 ( f2 INT, f1 INTEGER , PRIMARY KEY (f1)) ENGINE = MyISAM Query 1 741 BEGIN Table_map 1 783 table_id: 17 (test.t2) Write_rows 1 817 table_id: 17 flags: STMT_END_F Query 1 886 COMMIT <----- Here is something missing. There was the failing INSERT t2 (but inserted one row becasue of MyISAM use) followed by ROLLBACK. Query 1 954 BEGIN Table_map 1 996 table_id: 17 (test.t2) Update_rows 1 1036 table_id: 17 Update_rows 1 1076 table_id: 17 flags: STMT_END_F Query 1 1145 COMMIT Interesting observation: ======================== If I replace the INSERT INTO t2 SELECT * FROM t1 by INSERT INTO t2 VALUES (1, NULL) , (2, 1); than - t1 on master has finally the same content - the ROLLBACK gets a Warnings: Warning 1196 Some non-transactional changed tables couldn't be rolled back Ok, correct but why not also in case of INSERT SELECT - replication stays in sync My environment: --------------- - mysql-next-bugfixing 2009-09-05 - mysql-5.1-bugteam 2009-08-28 - ./BUILD/compile-pentium64-debug-max - Linux OpenSuSE 11.0 (64 Bit) - Intel Core2Duo How to repeat: See above ./mysql-test-run --mysqld=--binlog-format=row \ --no-check-testcases <script>