Skip to content

Commit 0a224ed

Browse files
vlad-lesinvlad-lesin
committed
MDEV-23711 make mariabackup innodb redo log read error message more clear
log_group_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.
1 parent 69d536a commit 0a224ed

File tree

5 files changed

+117
-3
lines changed

5 files changed

+117
-3
lines changed

‎extra/mariabackup/xtrabackup.cc‎

Lines changed: 16 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -2773,6 +2773,7 @@ static bool xtrabackup_copy_logfile(bool last = false)
27732773
ut_a(dst_log_file != NULL);
27742774
ut_ad(recv_sys != NULL);
27752775

2776+
bool overwritten_block;
27762777
lsn_tstart_lsn;
27772778
lsn_tend_lsn;
27782779

@@ -2799,6 +2800,12 @@ static bool xtrabackup_copy_logfile(bool last = false)
27992800
}
28002801

28012802
if (lsn == start_lsn) {
2803+
overwritten_block= !recv_sys->found_corrupt_log
2804+
&& (innodb_log_checksums || log_sys->log.is_encrypted())
2805+
&& log_block_calc_checksum_crc32(log_sys->buf) ==
2806+
log_block_get_checksum(log_sys->buf)
2807+
&& log_block_get_hdr_no(log_sys->buf) >
2808+
log_block_convert_lsn_to_no(start_lsn);
28022809
start_lsn = 0;
28032810
} else {
28042811
mutex_enter(&recv_sys->mutex);
@@ -2809,9 +2816,15 @@ static bool xtrabackup_copy_logfile(bool last = false)
28092816
log_mutex_exit();
28102817

28112818
if (!start_lsn) {
2812-
die(recv_sys->found_corrupt_log
2813-
? "xtrabackup_copy_logfile() failed: corrupt log."
2814-
: "xtrabackup_copy_logfile() failed.");
2819+
const char *reason = recv_sys->found_corrupt_log
2820+
? "corrupt log."
2821+
: (overwritten_block
2822+
? "redo log block is overwritten, please increase redo log size with innodb_log_file_size parameter."
2823+
: ((innodb_log_checksums || log_sys->log.is_encrypted())
2824+
? "redo log block checksum does not match."
2825+
: "unknown reason as innodb_log_checksums is switched off and redo"
2826+
" log is not encrypted."));
2827+
die("xtrabackup_copy_logfile() failed: %s", reason);
28152828
return true;
28162829
}
28172830
} while (start_lsn == end_lsn);

‎mysql-test/suite/mariabackup/innodb_redo_overwrite.opt‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1 @@
1+
--loose-innodb-log-file-size=1048576 --loose-innodb-log-files-in-group=2

‎mysql-test/suite/mariabackup/innodb_redo_overwrite.result‎

Lines changed: 28 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,28 @@
1+
CREATE TABLE t(i INT) ENGINE=INNODB;
2+
INSERT INTO t VALUES
3+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
4+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
5+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
6+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
7+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
8+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
9+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
10+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
11+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
12+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9);
13+
# Generate enough data to overwrite innodb redo log
14+
# on the next "INSERT INTO t SELECT * FROM t" execution.
15+
INSERT INTO t SELECT * FROM t;
16+
INSERT INTO t SELECT * FROM t;
17+
INSERT INTO t SELECT * FROM t;
18+
INSERT INTO t SELECT * FROM t;
19+
INSERT INTO t SELECT * FROM t;
20+
INSERT INTO t SELECT * FROM t;
21+
INSERT INTO t SELECT * FROM t;
22+
INSERT INTO t SELECT * FROM t;
23+
INSERT INTO t SELECT * FROM t;
24+
# xtrabackup backup
25+
FOUND 1 /failed: redo log block is overwritten/ in backup.log
26+
FOUND 1 /failed: redo log block checksum does not match/ in backup.log
27+
FOUND 1 /failed: unknown reason/ in backup.log
28+
DROP TABLE t;

‎mysql-test/suite/mariabackup/innodb_redo_overwrite.test‎

Lines changed: 70 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,70 @@
1+
--source include/have_innodb.inc
2+
--source include/have_debug_sync.inc
3+
4+
CREATE TABLE t(i INT) ENGINE=INNODB;
5+
6+
INSERT INTO t VALUES
7+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
8+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
9+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
10+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
11+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
12+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
13+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
14+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
15+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9),
16+
(0), (1), (2), (3), (4), (5), (6), (7), (8), (9);
17+
--echo # Generate enough data to overwrite innodb redo log
18+
--echo # on the next "INSERT INTO t SELECT * FROM t" execution.
19+
--let $i = 0
20+
while ($i < 9) {
21+
INSERT INTO t SELECT * FROM t;
22+
--inc $i
23+
}
24+
25+
--echo # xtrabackup backup
26+
--let $targetdir=$MYSQLTEST_VARDIR/tmp/backup
27+
--let $backuplog=$MYSQLTEST_VARDIR/tmp/backup.log
28+
29+
--let before_innodb_log_copy_thread_started=INSERT INTO test.t SELECT * FROM test.t
30+
31+
--disable_result_log
32+
--error 1
33+
--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --dbug=+d,mariabackup_events > $backuplog
34+
--enable_result_log
35+
36+
--let SEARCH_PATTERN=failed: redo log block is overwritten
37+
--let SEARCH_FILE=$backuplog
38+
--source include/search_pattern_in_file.inc
39+
--remove_file $backuplog
40+
--rmdir $targetdir
41+
42+
--let before_innodb_log_copy_thread_started=INSERT INTO test.t VALUES (0), (1), (2), (3), (4), (5), (6), (7), (8), (9)
43+
44+
--disable_result_log
45+
--error 1
46+
--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --dbug=+d,mariabackup_events,log_checksum_mismatch > $backuplog
47+
--enable_result_log
48+
49+
--let SEARCH_PATTERN=failed: redo log block checksum does not match
50+
--let SEARCH_FILE=$backuplog
51+
--source include/search_pattern_in_file.inc
52+
--remove_file $backuplog
53+
--rmdir $targetdir
54+
55+
--let before_innodb_log_copy_thread_started=INSERT INTO test.t SELECT * FROM test.t LIMIT 50000
56+
57+
--disable_result_log
58+
--error 1
59+
--exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --backup --target-dir=$targetdir --innodb-log-checksums=0 --dbug=+d,mariabackup_events > $backuplog
60+
--enable_result_log
61+
62+
--let SEARCH_PATTERN=failed: unknown reason
63+
--let SEARCH_FILE=$backuplog
64+
--source include/search_pattern_in_file.inc
65+
--remove_file $backuplog
66+
--rmdir $targetdir
67+
68+
--let before_innodb_log_copy_thread_started=
69+
70+
DROP TABLE t;

‎storage/innobase/log/log0recv.cc‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -965,6 +965,8 @@ log_group_read_log_seg(
965965
}
966966
});
967967

968+
DBUG_EXECUTE_IF("log_checksum_mismatch", { cksum = crc + 1; });
969+
968970
if (crc != cksum) {
969971
ib::error() << "Invalid log block checksum."
970972
<< " block: " << block_number

0 commit comments

Comments
 (0)