Merge lp:~akopytov/percona-xtrabackup/bug805593 into lp:percona-xtrabackup/2.0

[Alexey Kopytov]

http://jenkins.percona.com/view/Percona%20Xtrabackup/job/percona-xtrabackup-param/46/

[Stewart Smith (stewart)]

review: Approve

=== modified file 'test/run.sh'
--- test/run.sh	2011-06-29 05:38:02 +0000
+++ test/run.sh	2011-07-05 05:31:07 +0000
@@ -290,7 +290,7 @@
 echo "========================================================================"
 echo
 
-if [ -z "$force" -o $failed_count -eq 0 ]
+if [ -n "$force" -o $failed_count -eq 0 ]
 then
     kill_leftovers
 fi

=== added file 'test/t/xb_log_overwrap.sh'
--- test/t/xb_log_overwrap.sh	1970-01-01 00:00:00 +0000
+++ test/t/xb_log_overwrap.sh	2011-07-05 05:31:07 +0000
@@ -0,0 +1,38 @@
+. inc/common.sh
+
+init
+run_mysqld --innodb_log_file_size=1M --innodb_thread_concurrency=1
+load_dbase_schema sakila
+load_dbase_data sakila
+mkdir $topdir/backup
+
+run_cmd_expect_failure $XB_BIN $XB_ARGS --datadir=$mysql_datadir --backup \
+    --innodb_log_file_size=1M --target-dir=$topdir/backup --suspend-at-end &
+
+xb_pid=$!
+
+# Wait for xtrabackup to suspend
+i=0
+while [ ! -r $topdir/backup/xtrabackup_suspended ]
+do
+    sleep 1
+    i=$((i+1))
+    echo "Waited $i seconds for xtrabackup_suspended to be created"
+done
+
+# Stop the xtrabackup process
+kill -SIGSTOP $xb_pid
+ 
+# Create 2M+ of log data
+
+$MYSQL $MYSQL_ARGS -Ns -e "CREATE TABLE tmp1 ENGINE=InnoDB SELECT * FROM payment" sakila
+$MYSQL $MYSQL_ARGS -Ns -e "CREATE TABLE tmp2 ENGINE=InnoDB SELECT * FROM payment" sakila
+$MYSQL $MYSQL_ARGS -Ns -e "CREATE TABLE tmp3 ENGINE=InnoDB SELECT * FROM payment" sakila
+
+# Resume the xtrabackup process
+kill -SIGCONT $xb_pid
+
+rm -f $topdir/backup/xtrabackup_suspended
+
+# wait's return code will be the code returned by the background process
+wait $xb_pid

=== modified file 'xtrabackup.c'
--- xtrabackup.c	2011-06-30 02:33:31 +0000
+++ xtrabackup.c	2011-07-05 05:31:07 +0000
@@ -3161,7 +3161,6 @@
 		/* reference recv_scan_log_recs() */
 		{
 	byte*	log_block;
-	ulint	no;
 	LSN64	scanned_lsn;
 	ulint	data_len;
 
@@ -3173,39 +3172,51 @@
 	scanned_lsn = start_lsn;
 
 	while (log_block < log_sys->buf + RECV_SCAN_SIZE && !finished) {
-
-		no = log_block_get_hdr_no(log_block);
-
-		if (no != log_block_convert_lsn_to_no(scanned_lsn)
-		    || !log_block_checksum_is_ok_or_old_format(log_block)) {
-
-			if (no > log_block_convert_lsn_to_no(scanned_lsn)
-			    && log_block_checksum_is_ok_or_old_format(log_block)) {
-				fprintf(stderr,
-">> ###Warning###: The copying transaction log migh be overtaken already by the target.\n"
-">>              : Waiting log block no %lu, but the bumber is already %lu.\n"
-">>              : If the number equals %lu + n * %lu, it should be overtaken already.\n",
-					(ulong) log_block_convert_lsn_to_no(scanned_lsn),
-					(ulong) no,
-					(ulong) log_block_convert_lsn_to_no(scanned_lsn),
-					(ulong) (log_block_convert_lsn_to_no(
-#ifndef INNODB_VERSION_SHORT
-							 ut_dulint_create(0, log_group_get_capacity(group))
-#else
-							 log_group_get_capacity(group)
-#endif
-									  ) - 1));
-
-			} else if (no == log_block_convert_lsn_to_no(scanned_lsn)
-			    && !log_block_checksum_is_ok_or_old_format(
-								log_block)) {
-				fprintf(stderr,
-#ifndef INNODB_VERSION_SHORT
-"xtrabackup: Log block no %lu at lsn %lu %lu has\n"
-#else
-"xtrabackup: Log block no %lu at lsn %llu has\n"
-#endif
-"xtrabackup: ok header, but checksum field contains %lu, should be %lu\n",
+		ulint	no = log_block_get_hdr_no(log_block);
+		ulint	scanned_no = log_block_convert_lsn_to_no(scanned_lsn);
+		ibool	checksum_is_ok =
+			log_block_checksum_is_ok_or_old_format(log_block);
+
+		if (no != scanned_no && checksum_is_ok) {
+			ulint blocks_in_group =
+				log_block_convert_lsn_to_no(
+#ifndef INNODB_VERSION_SHORT
+					ut_dulint_create(0, log_group_get_capacity(group))
+#else
+					log_group_get_capacity(group)
+#endif
+							    ) - 1;
+
+			fprintf(stderr,
+				"xtrabackup: error:"
+				" log block numbers mismatch:\n"
+				"xtrabackup: error: expected log block no. %lu,"
+				" but got no. %lu from the log file.\n",
+				(ulong) scanned_no, (ulong) no);
+
+			if ((no - scanned_no) % blocks_in_group == 0) {
+				fprintf(stderr,
+					"xtrabackup: error:"
+					" it looks like InnoDB log has wrapped"
+					" around before xtrabackup could"
+					" process all records due to either"
+					" log copying being too slow, or "
+					" log files being too small.\n");
+			}
+
+			goto error;
+		} else if (!checksum_is_ok) {
+			/* Garbage or an incompletely written log block */
+
+			fprintf(stderr,
+				"xtrabackup: error:"
+				" Log block checksum mismatch"
+#ifndef INNODB_VERSION_SHORT
+				" (block no %lu at lsn %lu %lu): \n"
+#else
+				" (block no %lu at lsn %llu): \n"
+#endif
+				"expected %lu, calculated checksum %lu\n",
 				(ulong) no,
 #ifndef INNODB_VERSION_SHORT
 				(ulong) ut_dulint_get_high(scanned_lsn),
@@ -3215,13 +3226,8 @@
 #endif
 				(ulong) log_block_get_checksum(log_block),
 				(ulong) log_block_calc_checksum(log_block));
-			}
-
-			/* Garbage or an incompletely written log block */
-
-			finished = TRUE;
-
-			break;
+
+			goto error;
 		}
 
 		if (log_block_get_flush_bit(log_block)) {