MDEV-23711 make mariabackup innodb redo log read error message more clearbb-10.4-10.4.14-MDEV-23711-redo-log-overwrite

log_t::files::read_log_seg() returns error when:

1) Calculated log block number does not correspond to read log block
number. This can be caused by:
  a) Garbage or an incompletely written log block. We can exclude this
  case by checking log block checksum if it's enabled(see innodb-log-checksums,
  encrypted log block contains checksum always).
  b) The log block is overwritten. In this case checksum will be correct and
  read log block number will be greater then requested one.

2) When log block length is wrong. In this case recv_sys.found_corrupt_log
is set.

3) When redo log block checksum is wrong. In this case innodb code
writes messages to error log with the following prefix: "Invalid log
block checksum."

The fix processes all the cases above.

5 files changed, 117 insertions, 3 deletions

diff --git a/extra/mariabackup/xtrabackup.cc b/extra/mariabackup/xtrabackup.cc
index 67e38ebf821..6cc1ca7d523 100644
--- a/extra/mariabackup/xtrabackup.cc
+++ b/extra/mariabackup/xtrabackup.cc
@@ -2766,6 +2766,7 @@ static bool xtrabackup_copy_logfile(bool last = false)
 	ut_a(dst_log_file != NULL);
 	ut_ad(recv_sys.is_initialised());
 
+	bool overwritten_block = false;
 	lsn_t	start_lsn;
 	lsn_t	end_lsn;
 
@@ -2791,6 +2792,12 @@ static bool xtrabackup_copy_logfile(bool last = false)
 		}
 
 		if (lsn == start_lsn) {
+			overwritten_block= !recv_sys.found_corrupt_log
+				&& (innodb_log_checksums || log_sys.log.is_encrypted())
+				&& log_block_calc_checksum_crc32(log_sys.buf) ==
+					log_block_get_checksum(log_sys.buf)
+				&& log_block_get_hdr_no(log_sys.buf) >
+					log_block_convert_lsn_to_no(start_lsn);
 			start_lsn = 0;
 		} else {
 			mutex_enter(&recv_sys.mutex);
@@ -2801,9 +2808,15 @@ static bool xtrabackup_copy_logfile(bool last = false)
 		log_mutex_exit();
 
 		if (!start_lsn) {
-			die(recv_sys.found_corrupt_log
-			    ? "xtrabackup_copy_logfile() failed: corrupt log."
-			    : "xtrabackup_copy_logfile() failed.");
+			const char *reason = recv_sys.found_corrupt_log
+				? "corrupt log."
+				: (overwritten_block
+					? "redo log block is overwritten,  please increase redo log size."
+					: ((innodb_log_checksums || log_sys.log.is_encrypted())
+						? "redo log block checksum does not match."
+						: "unknown reason as innodb_log_checksums is switched off and redo"
+							" log is not encrypted."));
+			die("xtrabackup_copy_logfile() failed: %s", reason);
 			return true;
 		}
 	} while (start_lsn == end_lsn);
diff --git a/mysql-test/suite/mariabackup/innodb_redo_overwrite.opt b/mysql-test/suite/mariabackup/innodb_redo_overwrite.opt
new file mode 100644
index 00000000000..7111d384b40
--- /dev/null
+++ b/mysql-test/suite/mariabackup/innodb_redo_overwrite.opt
@@ -0,0 +1 @@
+--loose-innodb-log-file-size=1048576 --loose-innodb-log-files-in-group=2
diff --git a/mysql-test/suite/mariabackup/innodb_redo_overwrite.result b/mysql-test/suite/mariabackup/innodb_redo_overwrite.result
new file mode 100644
index 00000000000..571bfd35c70
--- /dev/null
+++ b/mysql-test/suite/mariabackup/innodb_redo_overwrite.result
@@ -0,0 +1,28 @@
+CREATE TABLE t(i INT) ENGINE=INNODB;
+INSERT INTO t VALUES
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+(0), (1), (2), (3), (4), (5), (6), (7), (8), (9);
+# Generate enough data to overwrite innodb redo log
+# on the next "INSERT INTO t SELECT * FROM t" execution.
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+INSERT INTO t SELECT * FROM t;
+# xtrabackup backup
+FOUND 1 /failed: redo log block is overwritten/ in backup.log
+FOUND 1 /failed: redo log block checksum does not match/ in backup.log
+FOUND 1 /failed: unknown reason/ in backup.log
+DROP TABLE t;
diff --git a/mysql-test/suite/mariabackup/innodb_redo_overwrite.test b/mysql-test/suite/mariabackup/innodb_redo_overwrite.test
new file mode 100644
index 00000000000..55e754f18d7
--- /dev/null
+++ b/mysql-test/suite/mariabackup/innodb_redo_overwrite.test
@@ -0,0 +1,70 @@
+--source include/have_innodb.inc
+--source include/have_debug_sync.inc
+
+CREATE TABLE t(i INT) ENGINE=INNODB;
+
+INSERT INTO t VALUES
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
+  (0), (1), (2), (3), (4), (5), (6), (7), (8), (9);
+--echo # Generate enough data to overwrite innodb redo log
+--echo # on the next "INSERT INTO t SELECT * FROM t" execution.
+--let $i = 0
+while ($i < 9) {
+INSERT INTO t SELECT * FROM t;
+--inc $i
+}
+
+--echo # xtrabackup backup
+--let $targetdir=$MYSQLTEST_VARDIR/tmp/backup
+--let $backuplog=$MYSQLTEST_VARDIR/tmp/backup.log
+
+--let before_innodb_log_copy_thread_started=INSERT INTO test.t SELECT * FROM test.t
+
+--disable_result_log
+--error 1
+--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --dbug=+d,mariabackup_events > $backuplog
+--enable_result_log
+
+--let SEARCH_PATTERN=failed: redo log block is overwritten
+--let SEARCH_FILE=$backuplog
+--source include/search_pattern_in_file.inc
+--remove_file $backuplog
+--rmdir $targetdir
+
+--let before_innodb_log_copy_thread_started=INSERT INTO test.t VALUES (0), (1), (2), (3), (4), (5), (6), (7), (8), (9)
+
+--disable_result_log
+--error 1
+--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --dbug=+d,mariabackup_events,log_checksum_mismatch > $backuplog
+--enable_result_log
+
+--let SEARCH_PATTERN=failed: redo log block checksum does not match
+--let SEARCH_FILE=$backuplog
+--source include/search_pattern_in_file.inc
+--remove_file $backuplog
+--rmdir $targetdir
+
+--let before_innodb_log_copy_thread_started=INSERT INTO test.t SELECT * FROM test.t LIMIT 50000
+
+--disable_result_log
+--error 1
+--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --innodb-log-checksums=0 --dbug=+d,mariabackup_events  > $backuplog
+--enable_result_log
+
+--let SEARCH_PATTERN=failed: unknown reason
+--let SEARCH_FILE=$backuplog
+--source include/search_pattern_in_file.inc
+--remove_file $backuplog
+--rmdir $targetdir
+
+--let before_innodb_log_copy_thread_started=
+
+DROP TABLE t;
diff --git a/storage/innobase/log/log0recv.cc b/storage/innobase/log/log0recv.cc
index bc116fec152..e9112244ae7 100644
--- a/storage/innobase/log/log0recv.cc
+++ b/storage/innobase/log/log0recv.cc
@@ -961,6 +961,8 @@ fail:
 					 }
 			 });
 
+			DBUG_EXECUTE_IF("log_checksum_mismatch", { cksum = crc + 1; });
+
 			if (crc != cksum) {
 				ib::error() << "Invalid log block checksum."
 					    << " block: " << block_number