Merge lp:~laurynas-biveinis/percona-server/bug1012715-5.1 into lp:percona-server/5.1

[Laurynas Biveinis]

Fix bug 1012715 (Crash resistant replication breaks with binlog XA
transaction recovery). The cause is that slave position is recorded
to InnoDB transaction system header at the XA COMMIT stage. If a
crash happens between XA PREPARE and COMMIT stages, the prepared
InnoDB transaction will not have the slave position recorded and thus
will fail to update it once it is replayed during binlog crash
recovery. The slave log position update is inherent part of changes
made by transaction, thus the correct place is the XA PREPARE stage.

- Store the slave log positions to the current InnoDB transaction in
  innobase_xa_prepare(), not innobase_commit_low().
- Write the slave log positions in the current InnoDB transaction to
  the transaction system header page in trx_prepare_off_kernel()
  instead of trx_commit_off_kernel().
- New crash injection site "crash_innodb_before_commit" at
  innobase_commit() that triggers just before the "real" transaction
  commits.
- New test case rpl_percona_crash_resistant_rpl to test both this bug
  fix and the feature in general.

Jenkins: http://jenkins.percona.com/job/percona-server-5.1-param/333/

Issue #22478

[Laurynas Biveinis (laurynas-biveinis)]

Found one issue myself.

The testcase has one sync bug: lines 88--91 do not sync slave with master first, thus might result in slave shutdown while slave SQL thread is still executing.

review: Needs Fixing

=== added file 'Percona-Server/mysql-test/suite/rpl/r/rpl_percona_crash_resistant_rpl.result'
--- Percona-Server/mysql-test/suite/rpl/r/rpl_percona_crash_resistant_rpl.result	1970-01-01 00:00:00 +0000
+++ Percona-Server/mysql-test/suite/rpl/r/rpl_percona_crash_resistant_rpl.result	2012-06-28 14:03:20 +0000
@@ -0,0 +1,42 @@
+include/master-slave.inc
+[connection master]
+DROP TABLE IF EXISTS t1;
+CREATE TABLE t1 (id INT(11) NOT NULL AUTO_INCREMENT, PRIMARY KEY(id)) ENGINE=InnoDB;
+INSERT INTO t1 VALUES ();
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+1
+include/rpl_restart_server.inc [server_number=2]
+include/start_slave.inc
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+1
+STOP SLAVE;
+include/wait_for_slave_to_stop.inc
+INSERT INTO t1 VALUES();
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+2
+SET GLOBAL debug="d,crash_commit_before";
+START SLAVE;
+include/rpl_start_server.inc [server_number=2]
+include/start_slave.inc
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+2
+STOP SLAVE;
+include/wait_for_slave_to_stop.inc
+INSERT INTO t1 VALUES();
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+3
+SET GLOBAL debug="d,crash_innodb_before_commit";
+START SLAVE;
+include/rpl_start_server.inc [server_number=2]
+include/start_slave.inc
+SELECT COUNT(*) FROM t1;
+COUNT(*)
+3
+DROP TABLE t1;
+STOP SLAVE;
+include/wait_for_slave_to_stop.inc

=== added file 'Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl-slave.opt'
--- Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl-slave.opt	1970-01-01 00:00:00 +0000
+++ Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl-slave.opt	2012-06-28 14:03:20 +0000
@@ -0,0 +1,1 @@
+--innodb-overwrite-relay-log-info=TRUE --skip-core-file --skip-stack-trace

=== added file 'Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl.test'
--- Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl.test	1970-01-01 00:00:00 +0000
+++ Percona-Server/mysql-test/suite/rpl/t/rpl_percona_crash_resistant_rpl.test	2012-06-28 14:03:20 +0000
@@ -0,0 +1,95 @@
+# Tests for Percona crash-resistant replication feature
+--source include/have_innodb_plugin.inc
+--source include/master-slave.inc
+--source include/not_valgrind.inc
+--source include/not_crashrep.inc
+--source include/have_debug.inc
+
+#
+# Setup
+#
+
+--disable_query_log
+call mtr.add_suppression("InnoDB: Warning: innodb_overwrite_relay_log_info is enabled.");
+--enable_query_log
+
+connection master;
+
+--disable_warnings
+DROP TABLE IF EXISTS t1;
+--enable_warnings
+
+CREATE TABLE t1 (id INT(11) NOT NULL AUTO_INCREMENT, PRIMARY KEY(id)) ENGINE=InnoDB;
+
+#
+# Test the non-crashing case
+#
+
+INSERT INTO t1 VALUES ();
+SELECT COUNT(*) FROM t1;
+
+sync_slave_with_master;
+--let $rpl_server_number= 2
+--source include/rpl_restart_server.inc
+--source include/start_slave.inc
+SELECT COUNT(*) FROM t1;
+
+#
+# Test the crashing case where relay-log.info needs not to be overwritten
+#
+
+STOP SLAVE;
+--source include/wait_for_slave_to_stop.inc
+
+connection master;
+INSERT INTO t1 VALUES();
+SELECT COUNT(*) FROM t1;
+
+connection slave;
+SET GLOBAL debug="d,crash_commit_before";
+--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.2.expect
+--error 0,2013
+START SLAVE;
+--source include/wait_until_disconnected.inc
+--enable_reconnect
+
+--let $rpl_server_number= 2
+--source include/rpl_start_server.inc
+--source include/start_slave.inc
+connection master;
+sync_slave_with_master;
+SELECT COUNT(*) FROM t1;
+
+#
+# Test crash with XA transaction recovery (bug 1012715)
+#
+STOP SLAVE;
+--source include/wait_for_slave_to_stop.inc
+connection master;
+INSERT INTO t1 VALUES();
+SELECT COUNT(*) FROM t1;
+
+connection slave;
+SET GLOBAL debug="d,crash_innodb_before_commit";
+--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.2.expect
+--error 0,2013
+START SLAVE;
+--source include/wait_until_disconnected.inc
+--enable_reconnect
+
+--let $rpl_server_number= 2
+--source include/rpl_start_server.inc
+--source include/start_slave.inc
+SELECT COUNT(*) FROM t1;
+
+#
+# Cleanup
+# 
+
+connection master;
+DROP TABLE t1;
+
+sync_slave_with_master;
+
+STOP SLAVE;
+--source include/wait_for_slave_to_stop.inc

=== modified file 'Percona-Server/storage/innodb_plugin/handler/ha_innodb.cc'
--- Percona-Server/storage/innodb_plugin/handler/ha_innodb.cc	2012-05-09 04:14:12 +0000
+++ Percona-Server/storage/innodb_plugin/handler/ha_innodb.cc	2012-06-28 14:03:20 +0000
@@ -2770,26 +2770,6 @@
 		return;
 	}
 
-#ifdef HAVE_REPLICATION
-#ifdef MYSQL_SERVER
-	THD *thd=current_thd;
-
-	if (thd && thd->slave_thread) {
-		/* Update the replication position info inside InnoDB */
-		trx->mysql_master_log_file_name
-			= active_mi->rli.group_master_log_name;
-		trx->mysql_master_log_pos
-			= ((ib_int64_t)active_mi->rli.group_master_log_pos +
-			   ((ib_int64_t)active_mi->rli.future_event_relay_log_pos -
-			    (ib_int64_t)active_mi->rli.group_relay_log_pos));
-		trx->mysql_relay_log_file_name
-			= active_mi->rli.group_relay_log_name;
-		trx->mysql_relay_log_pos
-			= (ib_int64_t)active_mi->rli.future_event_relay_log_pos;
-	}
-#endif /* MYSQL_SERVER */
-#endif /* HAVE_REPLICATION */
-
 	trx_commit_for_mysql(trx);
 }
 
@@ -2898,6 +2878,9 @@
 	if (all
 		|| (!thd_test_options(thd, OPTION_NOT_AUTOCOMMIT | OPTION_BEGIN))) {
 
+		DBUG_EXECUTE_IF("crash_innodb_before_commit",
+				DBUG_SUICIDE(););
+
 		/* We were instructed to commit the whole transaction, or
 		this is an SQL statement end and autocommit is on */
 
@@ -10657,6 +10640,34 @@
 
 		ut_ad(trx->active_trans);
 
+		/* Update the replication position info inside InnoDB.  This is
+		different from the binlog position update that happens during
+		XA COMMIT.  In contrast to that, the slave position is an
+		actual part of the changes made by this transaction and thus
+		must be updated in the XA PREPARE stage.  */
+
+		/* Since currently there might be only one slave SQL thread, we
+		don't need to take any precautions (e.g. prepare_commit_mutex)
+		to ensure position ordering.  Revisit this in 5.6 which has
+		both the multi-threaded replication to cause us problems and
+		the group commit to solve them.  */
+
+		if (thd->slave_thread) {
+			const Relay_log_info*	rli = &active_mi->rli;
+
+			trx->mysql_master_log_file_name
+				= rli->group_master_log_name;
+			trx->mysql_master_log_pos
+				= ((ib_int64_t)rli->group_master_log_pos
+				   + ((ib_int64_t)
+				      rli->future_event_relay_log_pos
+				      - (ib_int64_t)rli->group_relay_log_pos));
+			trx->mysql_relay_log_file_name
+				= rli->group_relay_log_name;
+			trx->mysql_relay_log_pos
+				= (ib_int64_t)rli->future_event_relay_log_pos;
+		}
+
 		error = (int) trx_prepare_for_mysql(trx);
 	} else {
 		/* We just mark the SQL statement ended and do not do a

=== modified file 'Percona-Server/storage/innodb_plugin/trx/trx0trx.c'
--- Percona-Server/storage/innodb_plugin/trx/trx0trx.c	2012-04-02 02:09:15 +0000
+++ Percona-Server/storage/innodb_plugin/trx/trx0trx.c	2012-06-28 14:03:20 +0000
@@ -895,24 +895,6 @@
 			trx->mysql_log_file_name = NULL;
 		}
 
-		if (trx->mysql_master_log_file_name[0] != '\0') {
-			/* This database server is a MySQL replication slave */
-			if (!sys_header) {
-				sys_header = trx_sysf_get(&mtr);
-			}
-			trx_sys_update_mysql_binlog_offset(
-				sys_header,
-				trx->mysql_relay_log_file_name,
-				trx->mysql_relay_log_pos,
-				TRX_SYS_MYSQL_RELAY_LOG_INFO, &mtr);
-			trx_sys_update_mysql_binlog_offset(
-				sys_header,
-				trx->mysql_master_log_file_name,
-				trx->mysql_master_log_pos,
-				TRX_SYS_MYSQL_MASTER_LOG_INFO, &mtr);
-			trx->mysql_master_log_file_name = "";
-		}
-
 		/* The following call commits the mini-transaction, making the
 		whole transaction committed in the file-based world, at this
 		log sequence number. The transaction becomes 'durable' when
@@ -2002,6 +1984,23 @@
 
 		mutex_exit(&(rseg->mutex));
 
+		if (trx->mysql_master_log_file_name[0] != '\0') {
+			/* This database server is a MySQL replication slave */
+			trx_sysf_t*	sys_header	= trx_sysf_get(&mtr);
+
+			trx_sys_update_mysql_binlog_offset(
+				sys_header,
+				trx->mysql_relay_log_file_name,
+				trx->mysql_relay_log_pos,
+				TRX_SYS_MYSQL_RELAY_LOG_INFO, &mtr);
+			trx_sys_update_mysql_binlog_offset(
+				sys_header,
+				trx->mysql_master_log_file_name,
+				trx->mysql_master_log_pos,
+				TRX_SYS_MYSQL_MASTER_LOG_INFO, &mtr);
+			trx->mysql_master_log_file_name = "";
+		}
+
 		/*--------------*/
 		mtr_commit(&mtr);	/* This mtr commit makes the
 					transaction prepared in the file-based