From 1b478a7abab63aa10dc56b4f4fc7e8a5a8916fd7 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Marko=20M=C3=A4kel=C3=A4?= Date: Tue, 10 Oct 2017 10:28:54 +0300 Subject: [PATCH] MDEV-13311 Presence of old logs in 10.2.7 will corrupt restored instance (change in behavior) Mariabackup 10.2.7 would delete the redo log files after a successful --prepare operation. If the user is manually copying the prepared files instead of using the --copy-back option, it could happen that some old redo log file would be preserved in the restored location. These old redo log files could cause corruption of the restored data files when the server is started up. We prevent this scenario by creating a "poisoned" redo log file ib_logfile0 at the end of the --prepare step. The poisoning consists of simply truncating the file to an empty file. InnoDB will refuse to start up on an empty redo log file. copy_back(): Delete all redo log files in the target if the source file ib_logfile0 is empty. (Previously we did this if the source file is missing.) SRV_OPERATION_RESTORE_EXPORT: A new variant of SRV_OPERATION_RESTORE when the --export option is specified. In this mode, we will keep deleting all redo log files, instead of truncating the first one. delete_log_files(): Add a parameter for the first file to delete, to be passed as 0 or 1. innobase_start_or_create_for_mysql(): In mariabackup --prepare, tolerate an empty ib_logfile0 file. Otherwise, require the first redo log file to be longer than 4 blocks (2048 bytes). Unless --export was specified, truncate the first log file at the end of --prepare. --- extra/mariabackup/backup_copy.cc | 3 +- extra/mariabackup/xtrabackup.cc | 3 +- .../suite/innodb/r/log_file_size.result | 8 +++ mysql-test/suite/innodb/t/log_file_size.test | 25 ++++++-- .../mariabackup/xb_file_key_management.result | 1 + .../mariabackup/xb_file_key_management.test | 1 + storage/innobase/include/srv0srv.h | 6 +- storage/innobase/log/log0recv.cc | 12 ++-- storage/innobase/srv/srv0start.cc | 57 ++++++++++++++++--- storage/innobase/trx/trx0trx.cc | 1 + 10 files changed, 96 insertions(+), 21 deletions(-) diff --git a/extra/mariabackup/backup_copy.cc b/extra/mariabackup/backup_copy.cc index 19cb768cd01..dfe482963a6 100644 --- a/extra/mariabackup/backup_copy.cc +++ b/extra/mariabackup/backup_copy.cc @@ -1707,7 +1707,8 @@ copy_back() if it exists. */ ds_data = ds_create(dst_dir, DS_TYPE_LOCAL); - if (!file_exists("ib_logfile0")) { + MY_STAT stat_arg; + if (!my_stat("ib_logfile0", &stat_arg, MYF(0)) || !stat_arg.st_size) { /* After completed --prepare, redo log files are redundant. We must delete any redo logs at the destination, so that the database will not jump to a different log sequence number diff --git a/extra/mariabackup/xtrabackup.cc b/extra/mariabackup/xtrabackup.cc index 40736709a39..4b6d0d2cc55 100644 --- a/extra/mariabackup/xtrabackup.cc +++ b/extra/mariabackup/xtrabackup.cc @@ -4793,7 +4793,8 @@ xtrabackup_prepare_func(char** argv) if (!ok) goto error_cleanup; } - srv_operation = SRV_OPERATION_RESTORE; + srv_operation = xtrabackup_export + ? SRV_OPERATION_RESTORE_EXPORT : SRV_OPERATION_RESTORE; if (innodb_init_param()) { goto error_cleanup; diff --git a/mysql-test/suite/innodb/r/log_file_size.result b/mysql-test/suite/innodb/r/log_file_size.result index b576061e74b..e049b34ad81 100644 --- a/mysql-test/suite/innodb/r/log_file_size.result +++ b/mysql-test/suite/innodb/r/log_file_size.result @@ -1,4 +1,12 @@ CREATE TABLE t1(a INT PRIMARY KEY) ENGINE=InnoDB; +SELECT * FROM INFORMATION_SCHEMA.ENGINES +WHERE engine = 'innodb' +AND support IN ('YES', 'DEFAULT', 'ENABLED'); +ENGINE SUPPORT COMMENT TRANSACTIONS XA SAVEPOINTS +FOUND 1 /InnoDB: Log file .*ib_logfile0 size 0 is too small/ in mysqld.1.err +CHECK TABLE t1; +Table Op Msg_type Msg_text +test.t1 check status OK BEGIN; INSERT INTO t1 VALUES (42); SELECT * FROM t1; diff --git a/mysql-test/suite/innodb/t/log_file_size.test b/mysql-test/suite/innodb/t/log_file_size.test index 206444115fc..140198de4ab 100644 --- a/mysql-test/suite/innodb/t/log_file_size.test +++ b/mysql-test/suite/innodb/t/log_file_size.test @@ -23,14 +23,33 @@ call mtr.add_suppression("InnoDB: Log file .*ib_logfile[01].* size"); call mtr.add_suppression("InnoDB: Unable to open .*ib_logfile0. to check native AIO read support"); FLUSH TABLES; --enable_query_log +let MYSQLD_DATADIR= `select @@datadir`; +CREATE TABLE t1(a INT PRIMARY KEY) ENGINE=InnoDB; + +--source include/shutdown_mysqld.inc +--move_file $MYSQLD_DATADIR/ib_logfile0 $MYSQLD_DATADIR/ib_logfile.old +write_file $MYSQLD_DATADIR/ib_logfile0; +EOF +let $check_no_innodb=SELECT * FROM INFORMATION_SCHEMA.ENGINES +WHERE engine = 'innodb' +AND support IN ('YES', 'DEFAULT', 'ENABLED'); --let $restart_parameters= --innodb-thread-concurrency=1 --innodb-log-file-size=1m --innodb-log-files-in-group=2 ---source include/restart_mysqld.inc +--source include/start_mysqld.inc + +eval $check_no_innodb; +--remove_file $MYSQLD_DATADIR/ib_logfile0 +--move_file $MYSQLD_DATADIR/ib_logfile.old $MYSQLD_DATADIR/ib_logfile.0 +--source include/shutdown_mysqld.inc +let SEARCH_FILE= $MYSQLTEST_VARDIR/log/mysqld.1.err; +let SEARCH_PATTERN= InnoDB: Log file .*ib_logfile0 size 0 is too small; +--source include/search_pattern_in_file.inc +--source include/start_mysqld.inc +CHECK TABLE t1; --let $restart_parameters= --innodb-thread-concurrency=100 --innodb-log-file-size=10M --innodb-log-files-in-group=2 --source include/restart_mysqld.inc -CREATE TABLE t1(a INT PRIMARY KEY) ENGINE=InnoDB; BEGIN; INSERT INTO t1 VALUES (42); @@ -52,9 +71,7 @@ SELECT * FROM t1; INSERT INTO t1 VALUES (0),(123); -let MYSQLD_DATADIR= `select @@datadir`; let SEARCH_ABORT = NOT FOUND; -let SEARCH_FILE= $MYSQLTEST_VARDIR/log/mysqld.1.err; BEGIN; DELETE FROM t1 WHERE a>0; diff --git a/mysql-test/suite/mariabackup/xb_file_key_management.result b/mysql-test/suite/mariabackup/xb_file_key_management.result index 8972da32f8b..721d10a9d91 100644 --- a/mysql-test/suite/mariabackup/xb_file_key_management.result +++ b/mysql-test/suite/mariabackup/xb_file_key_management.result @@ -9,6 +9,7 @@ INSERT INTO t VALUES('foobar2'); # remove datadir # xtrabackup move back # restart server +ib_logfile0 SELECT * FROM t; c foobar1 diff --git a/mysql-test/suite/mariabackup/xb_file_key_management.test b/mysql-test/suite/mariabackup/xb_file_key_management.test index 3887a889aaa..2a176952053 100644 --- a/mysql-test/suite/mariabackup/xb_file_key_management.test +++ b/mysql-test/suite/mariabackup/xb_file_key_management.test @@ -24,6 +24,7 @@ exec $XTRABACKUP --prepare --target-dir=$targetdir; --enable_result_log --list_files $targetdir ib_logfile* +--cat_file $targetdir/ib_logfile0 SELECT * FROM t; DROP TABLE t; diff --git a/storage/innobase/include/srv0srv.h b/storage/innobase/include/srv0srv.h index a51520e881c..e24aa89f046 100644 --- a/storage/innobase/include/srv0srv.h +++ b/storage/innobase/include/srv0srv.h @@ -508,10 +508,12 @@ enum srv_operation_mode { SRV_OPERATION_NORMAL, /** Mariabackup taking a backup */ SRV_OPERATION_BACKUP, - /** Mariabackup restoring a backup */ + /** Mariabackup restoring a backup for subsequent --copy-back */ SRV_OPERATION_RESTORE, /** Mariabackup restoring the incremental part of a backup */ - SRV_OPERATION_RESTORE_DELTA + SRV_OPERATION_RESTORE_DELTA, + /** Mariabackup restoring a backup for subsequent --export */ + SRV_OPERATION_RESTORE_EXPORT }; /** Current mode of operation */ diff --git a/storage/innobase/log/log0recv.cc b/storage/innobase/log/log0recv.cc index fd0940b08df..a91b62d11d9 100644 --- a/storage/innobase/log/log0recv.cc +++ b/storage/innobase/log/log0recv.cc @@ -1922,7 +1922,8 @@ void recv_apply_hashed_log_recs(bool last_batch) { ut_ad(srv_operation == SRV_OPERATION_NORMAL - || srv_operation == SRV_OPERATION_RESTORE); + || srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT); mutex_enter(&recv_sys->mutex); @@ -1941,7 +1942,8 @@ recv_apply_hashed_log_recs(bool last_batch) ut_ad(!last_batch == log_mutex_own()); recv_no_ibuf_operations = !last_batch - || srv_operation == SRV_OPERATION_RESTORE; + || srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT; ut_d(recv_no_log_write = recv_no_ibuf_operations); @@ -2960,7 +2962,8 @@ static dberr_t recv_init_missing_space(dberr_t err, const recv_spaces_t::const_iterator& i) { - if (srv_operation == SRV_OPERATION_RESTORE) { + if (srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT) { ib::warn() << "Tablespace " << i->first << " was not" " found at " << i->second.name << " when" " restoring a (partial?) backup. All redo log" @@ -3118,7 +3121,8 @@ recv_recovery_from_checkpoint_start(lsn_t flush_lsn) dberr_t err = DB_SUCCESS; ut_ad(srv_operation == SRV_OPERATION_NORMAL - || srv_operation == SRV_OPERATION_RESTORE); + || srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT); /* Initialize red-black tree for fast insertions into the flush_list during recovery process. */ diff --git a/storage/innobase/srv/srv0start.cc b/storage/innobase/srv/srv0start.cc index 1002cc566fb..d6dd5805186 100644 --- a/storage/innobase/srv/srv0start.cc +++ b/storage/innobase/srv/srv0start.cc @@ -397,13 +397,14 @@ create_log_file( /** Delete all log files. @param[in,out] logfilename buffer for log file name @param[in] dirnamelen length of the directory path -@param[in] n_files number of files to delete */ +@param[in] n_files number of files to delete +@param[in] i first file to delete */ static void -delete_log_files(char* logfilename, size_t dirnamelen, unsigned n_files) +delete_log_files(char* logfilename, size_t dirnamelen, uint n_files, uint i=0) { /* Remove any old log files. */ - for (unsigned i = 0; i < n_files; i++) { + for (; i < n_files; i++) { sprintf(logfilename + dirnamelen, "ib_logfile%u", i); /* Ignore errors about non-existent files or files @@ -911,6 +912,7 @@ srv_undo_tablespaces_init(bool create_new_db) } /* fall through */ case SRV_OPERATION_RESTORE: + case SRV_OPERATION_RESTORE_EXPORT: ut_ad(!create_new_db); /* Check if any of the UNDO tablespace needs fix-up because @@ -1321,6 +1323,7 @@ srv_shutdown_all_bg_threads() break; case SRV_OPERATION_NORMAL: case SRV_OPERATION_RESTORE: + case SRV_OPERATION_RESTORE_EXPORT: if (!buf_page_cleaner_is_active && os_aio_all_slots_free()) { os_aio_wake_all_threads_at_shutdown(); @@ -1492,7 +1495,8 @@ innobase_start_or_create_for_mysql() unsigned i = 0; ut_ad(srv_operation == SRV_OPERATION_NORMAL - || srv_operation == SRV_OPERATION_RESTORE); + || srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT); if (srv_force_recovery == SRV_FORCE_NO_LOG_REDO) { srv_read_only_mode = true; @@ -1982,7 +1986,9 @@ innobase_start_or_create_for_mysql() if (err == DB_NOT_FOUND) { if (i == 0) { if (srv_operation - == SRV_OPERATION_RESTORE) { + == SRV_OPERATION_RESTORE + || srv_operation + == SRV_OPERATION_RESTORE_EXPORT) { return(DB_SUCCESS); } if (flushed_lsn @@ -2046,6 +2052,26 @@ innobase_start_or_create_for_mysql() } if (i == 0) { + if (size == 0 + && (srv_operation + == SRV_OPERATION_RESTORE + || srv_operation + == SRV_OPERATION_RESTORE_EXPORT)) { + /* Tolerate an empty ib_logfile0 + from a previous run of + mariabackup --prepare. */ + return(DB_SUCCESS); + } + /* The first log file must consist of + at least the following 512-byte pages: + header, checkpoint page 1, empty, + checkpoint page 2, redo log page(s) */ + if (size <= OS_FILE_LOG_BLOCK_SIZE * 4) { + ib::error() << "Log file " + << logfilename << " size " + << size << " is too small"; + return(srv_init_abort(DB_ERROR)); + } srv_log_file_size = size; } else if (size != srv_log_file_size) { @@ -2312,11 +2338,13 @@ files_checked: recv_recovery_from_checkpoint_finish(); - if (srv_operation == SRV_OPERATION_RESTORE) { + if (srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT) { /* After applying the redo log from SRV_OPERATION_BACKUP, flush the changes - to the data files and delete the log file. - No further change to InnoDB files is needed. */ + to the data files and truncate or delete the log. + Unless --export is specified, no further change to + InnoDB files is needed. */ ut_ad(!srv_force_recovery); ut_ad(srv_n_log_files_found <= 1); ut_ad(recv_no_log_write); @@ -2326,8 +2354,18 @@ files_checked: fil_close_log_files(true); log_group_close_all(); if (err == DB_SUCCESS) { + bool trunc = srv_operation + == SRV_OPERATION_RESTORE; + /* Delete subsequent log files. */ delete_log_files(logfilename, dirnamelen, - srv_n_log_files_found); + srv_n_log_files_found, trunc); + if (trunc) { + /* Truncate the first log file. */ + strcpy(logfilename + dirnamelen, + "ib_logfile0"); + FILE* f = fopen(logfilename, "w"); + fclose(f); + } } return(err); } @@ -2792,6 +2830,7 @@ innodb_shutdown() case SRV_OPERATION_BACKUP: case SRV_OPERATION_RESTORE: case SRV_OPERATION_RESTORE_DELTA: + case SRV_OPERATION_RESTORE_EXPORT: fil_close_all_files(); break; case SRV_OPERATION_NORMAL: diff --git a/storage/innobase/trx/trx0trx.cc b/storage/innobase/trx/trx0trx.cc index 2408e4bdaf4..ffba8f314fb 100644 --- a/storage/innobase/trx/trx0trx.cc +++ b/storage/innobase/trx/trx0trx.cc @@ -620,6 +620,7 @@ trx_free_prepared( && trx->is_recovered && (!srv_was_started || srv_operation == SRV_OPERATION_RESTORE + || srv_operation == SRV_OPERATION_RESTORE_EXPORT || srv_read_only_mode || srv_force_recovery >= SRV_FORCE_NO_TRX_UNDO))); ut_a(trx->magic_n == TRX_MAGIC_N);