Skip to content

Commit f448a80

Browse files
author
Jan Lindström
committed
MDEV-9422: Checksum errors on restart when killing busy instance that uses encrypted XtraDB tables
Analysis: -- InnoDB has n (>0) redo-log files. -- In the first page of redo-log there is 2 checkpoint records on fixed location (checkpoint is not encrypted) -- On every checkpoint record there is up to 5 crypt_keys containing the keys used for encryption/decryption -- On crash recovery we read all checkpoints on every file -- Recovery starts by reading from the latest checkpoint forward -- Problem is that latest checkpoint might not always contain the key we need to decrypt all the redo-log blocks (see MDEV-9422 for one example) -- Furthermore, there is no way to identify is the log block corrupted or encrypted For example checkpoint can contain following keys : write chk: 4 [ chk key ]: [ 5 1 ] [ 4 1 ] [ 3 1 ] [ 2 1 ] [ 1 1 ] so over time we could have a checkpoint write chk: 13 [ chk key ]: [ 14 1 ] [ 13 1 ] [ 12 1 ] [ 11 1 ] [ 10 1 ] killall -9 mysqld causes crash recovery and on crash recovery we read as many checkpoints as there is log files, e.g. read [ chk key ]: [ 13 1 ] [ 12 1 ] [ 11 1 ] [ 10 1 ] [ 9 1 ] read [ chk key ]: [ 14 1 ] [ 13 1 ] [ 12 1 ] [ 11 1 ] [ 10 1 ] [ 9 1 ] This is problematic, as we could still scan log blocks e.g. from checkpoint 4 and we do not know anymore the correct key. CRYPT INFO: for checkpoint 14 search 4 CRYPT INFO: for checkpoint 13 search 4 CRYPT INFO: for checkpoint 12 search 4 CRYPT INFO: for checkpoint 11 search 4 CRYPT INFO: for checkpoint 10 search 4 CRYPT INFO: for checkpoint 9 search 4 (NOTE: NOT FOUND) For every checkpoint, code generated a new encrypted key based on key from encryption plugin and random numbers. Only random numbers are stored on checkpoint. Fix: Generate only one key for every log file. If checkpoint contains only one key, use that key to encrypt/decrypt all log blocks. If checkpoint contains more than one key (this is case for databases created using MariaDB server version 10.1.0 - 10.1.12 if log encryption was used). If looked checkpoint_no is found from keys on checkpoint we use that key to decrypt the log block. For encryption we use always the first key. If the looked checkpoint_no is not found from keys on checkpoint we use the first key. Modified code also so that if log is not encrypted, we do not generate any empty keys. If we have a log block and no keys is found from checkpoint we assume that log block is unencrypted. Log corruption or missing keys is found by comparing log block checksums. If we have a keys but current log block checksum is correct we again assume log block to be unencrypted. This is because current implementation stores checksum only before encryption and new checksum after encryption but before disk write is not stored anywhere.
1 parent d1e6c40 commit f448a80

File tree

14 files changed

+237
-67
lines changed

14 files changed

+237
-67
lines changed

‎mysql-test/suite/encryption/r/innodb-log-encrypt-crash.result

Lines changed: 19 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
call mtr.add_suppression("InnoDB: New log files created, LSN=.*");
2+
call mtr.add_suppression("InnoDB: Creating foreign key constraint system tables.");
3+
call mtr.add_suppression("InnoDB: Error: Table .*");
4+
CREATE TABLE t1 (
5+
pk bigint auto_increment,
6+
col_int int,
7+
col_int_key int,
8+
col_char char(12),
9+
col_char_key char(12),
10+
primary key (pk),
11+
key (`col_int_key` ),
12+
key (`col_char_key` )
13+
) ENGINE=InnoDB;
14+
CREATE TABLE t2 LIKE t1;
15+
INSERT INTO t1 VALUES (NULL,1,1,'foo','foo'),(NULL,2,2,'bar','bar'),(NULL,3,3,'baz','baz'),(NULL,4,4,'qux','qux');
16+
INSERT INTO t2
17+
SELECT NULL, a1.col_int, a1.col_int_key, a1.col_char, a1.col_char_key
18+
FROM t1 a1, t1 a2, t1 a3, t1 a4, t1 a5, t1 a6, t1 a7, t1 a8, t1 a9, t1 a10;
19+
DROP TABLE t1, t2;

‎mysql-test/suite/encryption/r/innodb-log-encrypt.result

Lines changed: 18 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,7 @@ begin
88
declare current_num int;
99
set current_num = 0;
1010
while current_num < repeat_count do
11-
insert into t1 values(current_num, substring(MD5(RAND()), -64), REPEAT('secredsecredsecred',10));
11+
insert into t1 values(current_num, substring(MD5(RAND()), -64), REPEAT('privatejanprivate',10));
1212
set current_num = current_num + 1;
1313
end while;
1414
end//
@@ -22,34 +22,34 @@ select count(*) from t1;
2222
count(*)
2323
2000
2424
# ibdata1 yes on expecting NOT FOUND
25-
NOT FOUND /secredsecred/ in ibdata1
25+
NOT FOUND /privatejanprivate/ in ibdata1
2626
# t1 yes on expecting NOT FOUND
27-
NOT FOUND /secredsecred/ in t1.ibd
27+
NOT FOUND /privatejanprivate/ in t1.ibd
2828
# log0 yes on expecting NOT FOUND
29-
NOT FOUND /secredsecred/ in ib_logfile0
29+
NOT FOUND /privatejanprivate/ in ib_logfile0
3030
# log1 yes on expecting NOT FOUND
31-
NOT FOUND /secredsecred/ in ib_logfile1
31+
NOT FOUND /privatejanprivate/ in ib_logfile1
3232
# Restart mysqld --innodb_encrypt_log=0
33-
insert into t1 values(5000, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
34-
insert into t1 values(5001, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
35-
insert into t1 values(5002, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
36-
insert into t1 values(5003, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
37-
insert into t1 values(5004, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
33+
insert into t1 values(5000, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
34+
insert into t1 values(5001, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
35+
insert into t1 values(5002, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
36+
insert into t1 values(5003, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
37+
insert into t1 values(5004, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
3838
# ibdata1 yes on expecting NOT FOUND
39-
NOT FOUND /secredsecred/ in ibdata1
39+
NOT FOUND /privatejanprivate/ in ibdata1
4040
# t1 yes on expecting NOT FOUND
41-
NOT FOUND /secredsecred/ in t1.ibd
41+
NOT FOUND /privatejanprivate/ in t1.ibd
4242
# log0 yes on expecting NOT FOUND
43-
NOT FOUND /secredsecred/ in ib_logfile0
43+
NOT FOUND /privatejanprivate/ in ib_logfile0
4444
# log1 yes on expecting NOT FOUND
45-
NOT FOUND /secredsecred/ in ib_logfile1
45+
NOT FOUND /privatejanprivate/ in ib_logfile1
4646
# ibdata1 yes on expecting NOT FOUND
47-
NOT FOUND /notsecred/ in ibdata1
47+
NOT FOUND /publicmessage/ in ibdata1
4848
# t1 yes on expecting NOT FOUND
49-
NOT FOUND /notsecred/ in t1.ibd
49+
NOT FOUND /publicmessage/ in t1.ibd
5050
# log0 no on expecting FOUND/NOTFOUND depending where insert goes
51-
FOUND /notsecred/ in ib_logfile0
51+
FOUND /publicmessage/ in ib_logfile0
5252
# log1 no on expecting FOUND/NOTFOUND depending where insert goes
53-
NOT FOUND /notsecred/ in ib_logfile1
53+
NOT FOUND /publicmessage/ in ib_logfile1
5454
drop procedure innodb_insert_proc;
5555
drop table t1;

‎mysql-test/suite/encryption/t/innodb-log-encrypt-crash.opt

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
--innodb-encrypt-log=ON
2+
--plugin-load-add=$FILE_KEY_MANAGEMENT_SO
3+
--loose-file-key-management
4+
--loose-file-key-management-filename=$MYSQL_TEST_DIR/std_data/logkey.txt
5+
--file-key-management-encryption-algorithm=aes_cbc
6+
--innodb-buffer-pool-size=128M

‎mysql-test/suite/encryption/t/innodb-log-encrypt-crash.test

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
-- source include/have_innodb.inc
2+
-- source include/not_embedded.inc
3+
-- source filekeys_plugin.inc
4+
5+
call mtr.add_suppression("InnoDB: New log files created, LSN=.*");
6+
call mtr.add_suppression("InnoDB: Creating foreign key constraint system tables.");
7+
call mtr.add_suppression("InnoDB: Error: Table .*");
8+
9+
#
10+
# MDEV-9422: Checksum errors on restart when killing busy instance that uses encrypted XtraDB tables
11+
#
12+
13+
CREATE TABLE t1 (
14+
pk bigint auto_increment,
15+
col_int int,
16+
col_int_key int,
17+
col_char char(12),
18+
col_char_key char(12),
19+
primary key (pk),
20+
key (`col_int_key` ),
21+
key (`col_char_key` )
22+
) ENGINE=InnoDB;
23+
CREATE TABLE t2 LIKE t1;
24+
25+
INSERT INTO t1 VALUES (NULL,1,1,'foo','foo'),(NULL,2,2,'bar','bar'),(NULL,3,3,'baz','baz'),(NULL,4,4,'qux','qux');
26+
INSERT INTO t2
27+
SELECT NULL, a1.col_int, a1.col_int_key, a1.col_char, a1.col_char_key
28+
FROM t1 a1, t1 a2, t1 a3, t1 a4, t1 a5, t1 a6, t1 a7, t1 a8, t1 a9, t1 a10;
29+
30+
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
31+
--shutdown_server 0
32+
--source include/wait_until_disconnected.inc
33+
34+
--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
35+
--enable_reconnect
36+
--source include/wait_until_connected_again.inc
37+
38+
DROP TABLE t1, t2;

‎mysql-test/suite/encryption/t/innodb-log-encrypt.test

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@ begin
2828
declare current_num int;
2929
set current_num = 0;
3030
while current_num < repeat_count do
31-
insert into t1 values(current_num, substring(MD5(RAND()), -64), REPEAT('secredsecredsecred',10));
31+
insert into t1 values(current_num, substring(MD5(RAND()), -64), REPEAT('privatejanprivate',10));
3232
set current_num = current_num + 1;
3333
end while;
3434
end//
@@ -43,13 +43,15 @@ set autocommit=1;
4343
update t1 set c1 = c1 +1;
4444
select count(*) from t1;
4545

46+
-- source include/restart_mysqld.inc
47+
4648
--let $MYSQLD_DATADIR=`select @@datadir`
4749
--let ib1_IBD = $MYSQLD_DATADIR/ibdata1
4850
--let t1_IBD = $MYSQLD_DATADIR/test/t1.ibd
4951
--let log0 = $MYSQLD_DATADIR/ib_logfile0
5052
--let log1 = $MYSQLD_DATADIR/ib_logfile1
5153
--let SEARCH_RANGE = 10000000
52-
--let SEARCH_PATTERN=secredsecred
54+
--let SEARCH_PATTERN=privatejanprivate
5355

5456
--echo # ibdata1 yes on expecting NOT FOUND
5557
-- let SEARCH_FILE=$ib1_IBD
@@ -68,13 +70,13 @@ select count(*) from t1;
6870
-- let $restart_parameters=--innodb_encrypt_log=0
6971
-- source include/restart_mysqld.inc
7072

71-
insert into t1 values(5000, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
72-
insert into t1 values(5001, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
73-
insert into t1 values(5002, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
74-
insert into t1 values(5003, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
75-
insert into t1 values(5004, substring(MD5(RAND()), -64), REPEAT('notsecred',10));
73+
insert into t1 values(5000, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
74+
insert into t1 values(5001, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
75+
insert into t1 values(5002, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
76+
insert into t1 values(5003, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
77+
insert into t1 values(5004, substring(MD5(RAND()), -64), REPEAT('publicmessage',10));
7678

77-
--let SEARCH_PATTERN=secredsecred
79+
--let SEARCH_PATTERN=privatejanprivate
7880
--echo # ibdata1 yes on expecting NOT FOUND
7981
-- let SEARCH_FILE=$ib1_IBD
8082
-- source include/search_pattern_in_file.inc
@@ -88,7 +90,7 @@ insert into t1 values(5004, substring(MD5(RAND()), -64), REPEAT('notsecred',10))
8890
-- let SEARCH_FILE=$log1
8991
-- source include/search_pattern_in_file.inc
9092

91-
--let SEARCH_PATTERN=notsecred
93+
--let SEARCH_PATTERN=publicmessage
9294
--echo # ibdata1 yes on expecting NOT FOUND
9395
-- let SEARCH_FILE=$ib1_IBD
9496
-- source include/search_pattern_in_file.inc

‎storage/innobase/include/log0recv.h

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -498,6 +498,18 @@ use these free frames to read in pages when we start applying the
498498
log records to the database. */
499499
extern ulint recv_n_pool_free_frames;
500500

501+
/******************************************************//**
502+
Checks the 4-byte checksum to the trailer checksum field of a log
503+
block. We also accept a log block in the old format before
504+
InnoDB-3.23.52 where the checksum field contains the log block number.
505+
@return TRUE if ok, or if the log block may be in the format of InnoDB
506+
version predating 3.23.52 */
507+
ibool
508+
log_block_checksum_is_ok_or_old_format(
509+
/*===================================*/
510+
const byte* block, /*!< in: pointer to a log block */
511+
bool print_err); /*!< in print error ? */
512+
501513
#ifndef UNIV_NONINL
502514
#include "log0recv.ic"
503515
#endif

‎storage/innobase/log/log0crypt.cc

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
/*****************************************************************************
22
33
Copyright (C) 2013, 2015, Google Inc. All Rights Reserved.
4-
Copyright (C) 2014, 2015, MariaDB Corporation. All Rights Reserved.
4+
Copyright (C) 2014, 2016, MariaDB Corporation. All Rights Reserved.
55
66
This program is free software; you can redistribute it and/or modify it under
77
the terms of the GNU General Public License as published by the Free Software
@@ -156,12 +156,21 @@ log_blocks_crypt(
156156
info ? info->key_version : 0,
157157
log_block_start_lsn);
158158
#endif
159+
/* If no key is found from checkpoint assume the log_block
160+
to be unencrypted. If checkpoint contains the encryption key
161+
compare log_block current checksum, if checksum matches,
162+
block can't be encrypted. */
159163
if (info == NULL ||
160-
info->key_version == UNENCRYPTED_KEY_VER) {
164+
info->key_version == UNENCRYPTED_KEY_VER ||
165+
(log_block_checksum_is_ok_or_old_format(log_block, false) &&
166+
what == ENCRYPTION_FLAG_DECRYPT)) {
161167
memcpy(dst_block, log_block, OS_FILE_LOG_BLOCK_SIZE);
162168
goto next;
163169
}
164170

171+
ut_ad(what == ENCRYPTION_FLAG_DECRYPT ? !log_block_checksum_is_ok_or_old_format(log_block, false) :
172+
log_block_checksum_is_ok_or_old_format(log_block, false));
173+
165174
// Assume log block header is not encrypted
166175
memcpy(dst_block, log_block, LOG_BLOCK_HDR_SIZE);
167176

‎storage/innobase/log/log0log.cc

Lines changed: 20 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
33
Copyright (c) 1995, 2015, Oracle and/or its affiliates. All Rights Reserved.
44
Copyright (c) 2009, Google Inc.
5-
Copyright (c) 2013, SkySQL Ab. All Rights Reserved.
5+
Copyright (C) 2014, 2016, MariaDB Corporation. All Rights Reserved.
66
77
Portions of this file contain modifications contributed and copyrighted by
88
Google, Inc. Those modifications are gratefully acknowledged and are described
@@ -52,6 +52,9 @@ Created 12/9/1995 Heikki Tuuri
5252
#include "trx0roll.h"
5353
#include "srv0mon.h"
5454

55+
/* Used for debugging */
56+
// #define DEBUG_CRYPT 1
57+
5558
/*
5659
General philosophy of InnoDB redo-logs:
5760
@@ -2358,8 +2361,24 @@ log_group_read_log_seg(
23582361
(ulint) (source_offset % UNIV_PAGE_SIZE),
23592362
len, buf, NULL, 0);
23602363

2364+
#ifdef DEBUG_CRYPT
2365+
fprintf(stderr, "BEFORE DECRYPT: block: %lu checkpoint: %lu %.8lx %.8lx offset %lu\n",
2366+
log_block_get_hdr_no(buf),
2367+
log_block_get_checkpoint_no(buf),
2368+
log_block_calc_checksum(buf),
2369+
log_block_get_checksum(buf), source_offset);
2370+
#endif
2371+
23612372
log_decrypt_after_read(buf, len);
23622373

2374+
#ifdef DEBUG_CRYPT
2375+
fprintf(stderr, "AFTER DECRYPT: block: %lu checkpoint: %lu %.8lx %.8lx\n",
2376+
log_block_get_hdr_no(buf),
2377+
log_block_get_checkpoint_no(buf),
2378+
log_block_calc_checksum(buf),
2379+
log_block_get_checksum(buf));
2380+
#endif
2381+
23632382
start_lsn += len;
23642383
buf += len;
23652384

‎storage/innobase/log/log0recv.cc

Lines changed: 11 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -923,11 +923,11 @@ block. We also accept a log block in the old format before
923923
InnoDB-3.23.52 where the checksum field contains the log block number.
924924
@return TRUE if ok, or if the log block may be in the format of InnoDB
925925
version predating 3.23.52 */
926-
static
927926
ibool
928927
log_block_checksum_is_ok_or_old_format(
929928
/*===================================*/
930-
const byte* block) /*!< in: pointer to a log block */
929+
const byte* block, /*!< in: pointer to a log block */
930+
bool print_err) /*!< in print error ? */
931931
{
932932
#ifdef UNIV_LOG_DEBUG
933933
return(TRUE);
@@ -950,11 +950,13 @@ log_block_checksum_is_ok_or_old_format(
950950
return(TRUE);
951951
}
952952

953-
fprintf(stderr, "BROKEN: block: %lu checkpoint: %lu %.8lx %.8lx\n",
954-
log_block_get_hdr_no(block),
955-
log_block_get_checkpoint_no(block),
956-
log_block_calc_checksum(block),
957-
log_block_get_checksum(block));
953+
if (print_err) {
954+
fprintf(stderr, "BROKEN: block: %lu checkpoint: %lu %.8lx %.8lx\n",
955+
log_block_get_hdr_no(block),
956+
log_block_get_checkpoint_no(block),
957+
log_block_calc_checksum(block),
958+
log_block_get_checksum(block));
959+
}
958960

959961
return(FALSE);
960962
}
@@ -2686,12 +2688,12 @@ recv_scan_log_recs(
26862688
log_block_convert_lsn_to_no(scanned_lsn));
26872689
*/
26882690
if (no != log_block_convert_lsn_to_no(scanned_lsn)
2689-
|| !log_block_checksum_is_ok_or_old_format(log_block)) {
2691+
|| !log_block_checksum_is_ok_or_old_format(log_block, true)) {
26902692
log_crypt_err_t log_crypt_err;
26912693

26922694
if (no == log_block_convert_lsn_to_no(scanned_lsn)
26932695
&& !log_block_checksum_is_ok_or_old_format(
2694-
log_block)) {
2696+
log_block, true)) {
26952697
fprintf(stderr,
26962698
"InnoDB: Log block no %lu at"
26972699
" lsn " LSN_PF " has\n"

‎storage/xtradb/include/log0recv.h

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,7 +43,8 @@ UNIV_INTERN
4343
ibool
4444
log_block_checksum_is_ok_or_old_format(
4545
/*===================================*/
46-
const byte* block); /*!< in: pointer to a log block */
46+
const byte* block, /*!< in: pointer to a log block */
47+
bool print_err); /*!< in print error ? */
4748

4849
/*******************************************************//**
4950
Calculates the new value for lsn when more data is added to the log. */

0 commit comments

Comments
 (0)