MDEV-39694 innodb_log_archive=ON recovery fails if no tablespaces exist

extra/mariabackup/xtrabackup.cc

@@ -4447,6 +4447,8 @@ xb_load_tablespaces()
 		return(DB_ERROR);
 	}
 
+	log_sys.latch.wr_lock();
+
 	for (int i= 0; i < 10; i++) {
 		err = srv_sys_space.open_or_create(false, false, &sum_of_new_sizes);
 		if (err == DB_PAGE_CORRUPTED || err == DB_CORRUPTION) {
@@ -4456,13 +4458,15 @@ xb_load_tablespaces()
 		 break;
 	}
 
+	log_sys.latch.wr_unlock();
+
 	if (err != DB_SUCCESS) {
 		msg("Could not open data files.\n");
 		return(err);
 	}
 
 	/* Add separate undo tablespaces to fil_system */
-	err = srv_undo_tablespaces_init(false, nullptr);
+	err = srv_undo_tablespaces_init(nullptr);
 
 	if (err != DB_SUCCESS) {
 		return(err);

mysql-test/suite/innodb/disabled.def

@@ -0,0 +1,4 @@
+doublewrite_debug : FIXME
+log_archive_recovery : FIXME
+log_file_size_online : FIXME
+undo_upgrade_debug : FIXME

mysql-test/suite/innodb/r/log_corruption_recovery.result

@@ -6,21 +6,24 @@ call mtr.add_suppression("InnoDB: Set innodb_force_recovery=1");
 call mtr.add_suppression("InnoDB: Cannot apply log to \\[page id: space=127, page number=0\\] of corrupted file '.*test/t\\.ibd");
 call mtr.add_suppression("(InnoDB: Plugin|Plugin 'InnoDB')");
 call mtr.add_suppression("InnoDB: Page .* Current system log sequence number 123(38|54)");
+call mtr.add_suppression("InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespaces but not the log");
+call mtr.add_suppression("InnoDB: Failed to read page 3 from file '.*ibdata1'");
+call mtr.add_suppression("InnoDB: (File '.*ibdata1'|The change buffer) is corrupted");
 SET GLOBAL innodb_fast_shutdown=0;
 # restart
 SELECT * FROM INFORMATION_SCHEMA.ENGINES
 WHERE engine = 'innodb'
 AND support IN ('YES', 'DEFAULT', 'ENABLED');
 ENGINE	SUPPORT	COMMENT	TRANSACTIONS	XA	SAVEPOINTS
-NOT FOUND /InnoDB: Page .* Current system log sequence number/ in mysqld.1.err
+FOUND 1 /InnoDB: Page .* Current system log sequence number/ in mysqld.1.err
 # restart: --innodb-force-recovery=1
 SELECT * FROM INFORMATION_SCHEMA.ENGINES
 WHERE engine = 'innodb'
 AND support IN ('YES', 'DEFAULT', 'ENABLED');
 ENGINE	SUPPORT	COMMENT	TRANSACTIONS	XA	SAVEPOINTS
 InnoDB	YES	Supports transactions, row-level locking, foreign keys and encryption for tables	YES	YES	YES
 FOUND 1 /InnoDB: Page .* Current system log sequence number/ in mysqld.1.err
-FOUND 2 /InnoDB: OPT_PAGE_CHECKSUM mismatch on \[page id: space=127, page number=0\]/ in mysqld.1.err
+FOUND 1 /InnoDB: OPT_PAGE_CHECKSUM mismatch on \[page id: space=127, page number=0\]/ in mysqld.1.err
 FOUND 1 /InnoDB: Cannot apply log to \[page id: space=127, page number=0\] of corrupted file .*test/t\.ibd/ in mysqld.1.err
 # restart
 SELECT * FROM INFORMATION_SCHEMA.ENGINES

mysql-test/suite/innodb/r/undo_upgrade_debug.result

@@ -7,33 +7,38 @@ call mtr.add_suppression("Plugin 'InnoDB' init function returned error");
 call mtr.add_suppression("Plugin 'InnoDB' registration as a STORAGE ENGINE failed");
 set global innodb_fast_shutdown=0;
 # case 1: Abort after resetting TRX_SYS page rollback segments
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=4 --debug_dbug=+d,after_rseg_reset_abort
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=4
+# restart: --innodb_undo_tablespaces=4 --debug_dbug=+d,after_rseg_reset_abort
+# restart: --innodb_undo_tablespaces=4
 # Should list 4 undo log tablespaces
 undo001
 undo002
 undo003
 undo004
 # case 2: Abort after deleting the old undo tablespaces
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=2 --debug_dbug=+d,after_deleting_old_undo_abort
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=2
+# restart: --innodb_undo_tablespaces=2 --debug_dbug=+d,after_deleting_old_undo_abort
+# restart: --innodb_undo_tablespaces=2
 # Should list 2 undo log tablespaces
 undo001
 undo002
+undo003
+undo004
 # case 3: Abort after successfully deleting the old undo tablespace
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=3 --debug_dbug=+d,after_deleting_old_undo_success
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=3
+# restart: --innodb_undo_tablespaces=3 --debug_dbug=+d,after_deleting_old_undo_success
+# restart: --innodb_undo_tablespaces=3
 # Should list 3 undo log tablespaces
 undo001
 undo002
 undo003
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=4
+undo004
+# restart: --innodb_undo_tablespaces=4
 # Should list 4 undo log tablespaces
 undo001
 undo002
 undo003
 undo004
-# restart: --innodb-log-recovery-start=0 --innodb_undo_tablespaces=2
+# restart: --innodb_undo_tablespaces=2
 # Should list 2 undo log tablespaces
 undo001
 undo002
+undo003
+undo004

mysql-test/suite/innodb/t/log_archive_recovery.test

@@ -0,0 +1,20 @@
+--source include/have_innodb.inc
+
+let bugdir= $MYSQLTEST_VARDIR/tmp/log_archive_recovery;
+--mkdir $bugdir
+--let $dirs= --innodb-data-home-dir=$bugdir --innodb-log-group-home-dir=$bugdir
+--let $dirs=$dirs --innodb-undo-directory=$bugdir
+
+--let $restart_parameters= $dirs --innodb-log-archive --innodb-undo-tablespaces=3 --innodb-log-recovery-start=12288
+--source include/restart_mysqld.inc
+CREATE TABLE t(a INT)ENGINE=InnoDB;
+--source include/shutdown_mysqld.inc
+
+--remove_file $bugdir/ibdata1
+--source include/start_mysqld.inc
+--error ER_UNKNOWN_STORAGE_ENGINE
+SELECT * FROM t;
+--write_file $bugdir/ibdata1
+EOF
+--source include/restart_mysqld.inc
+SELECT * FROM t;

mysql-test/suite/innodb/t/log_corruption_recovery.test

@@ -17,6 +17,10 @@ call mtr.add_suppression("InnoDB: Cannot apply log to \\[page id: space=127, pag
 call mtr.add_suppression("(InnoDB: Plugin|Plugin 'InnoDB')");
 # Allow innodb_force_recovery=1 to write up to 10 FILE_CHECKPOINT records
 call mtr.add_suppression("InnoDB: Page .* Current system log sequence number 123(38|54)");
+call mtr.add_suppression("InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespaces but not the log");
+call mtr.add_suppression("InnoDB: Failed to read page 3 from file '.*ibdata1'");
+call mtr.add_suppression("InnoDB: (File '.*ibdata1'|The change buffer) is corrupted");
+
 SET GLOBAL innodb_fast_shutdown=0;
 --source include/shutdown_mysqld.inc
 --move_file $DATADIR/ib_logfile0 $DATADIR/ib_logfile0.old

mysql-test/suite/innodb/t/undo_upgrade_debug.test

@@ -15,45 +15,45 @@ call mtr.add_suppression("Plugin 'InnoDB' registration as a STORAGE ENGINE faile
 set global innodb_fast_shutdown=0;
 
 --echo # case 1: Abort after resetting TRX_SYS page rollback segments
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=4 --debug_dbug="+d,after_rseg_reset_abort";
+let $restart_parameters=--innodb_undo_tablespaces=4 --debug_dbug="+d,after_rseg_reset_abort";
 
 --source include/restart_mysqld.inc
 
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=4;
+let $restart_parameters=--innodb_undo_tablespaces=4;
 --source include/restart_mysqld.inc
 
 --echo # Should list 4 undo log tablespaces
 list_files $MYSQLD_DATADIR undo*;
 
 --echo # case 2: Abort after deleting the old undo tablespaces
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=2 --debug_dbug="+d,after_deleting_old_undo_abort";
+let $restart_parameters=--innodb_undo_tablespaces=2 --debug_dbug="+d,after_deleting_old_undo_abort";
 
 --source include/restart_mysqld.inc
 
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=2;
+let $restart_parameters=--innodb_undo_tablespaces=2;
 --source include/restart_mysqld.inc
 
 --echo # Should list 2 undo log tablespaces
 list_files $MYSQLD_DATADIR undo*;
 
 --echo # case 3: Abort after successfully deleting the old undo tablespace
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=3 --debug_dbug="+d,after_deleting_old_undo_success";
+let $restart_parameters=--innodb_undo_tablespaces=3 --debug_dbug="+d,after_deleting_old_undo_success";
 
 --source include/restart_mysqld.inc
 
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=3;
+let $restart_parameters=--innodb_undo_tablespaces=3;
 --source include/restart_mysqld.inc
 
 --echo # Should list 3 undo log tablespaces
 list_files $MYSQLD_DATADIR undo*;
 
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=4;
+let $restart_parameters=--innodb_undo_tablespaces=4;
 --source include/restart_mysqld.inc
 
 --echo # Should list 4 undo log tablespaces
 list_files $MYSQLD_DATADIR undo*;
 
-let $restart_parameters=--innodb-log-recovery-start=0 --innodb_undo_tablespaces=2;
+let $restart_parameters=--innodb_undo_tablespaces=2;
 --source include/restart_mysqld.inc
 
 --echo # Should list 2 undo log tablespaces

storage/innobase/buf/buf0flu.cc

@@ -2786,7 +2786,7 @@ static void buf_flush_page_cleaner() noexcept
 
       do
       {
-        if (recv_recovery_is_on())
+        if (recv_recovery_is_on() || recv_sys.is_corrupt_log())
           continue;
         create_spare_archive= buf_flush_archive_create(create_spare_archive);
         IF_DBUG(if (log_sys.last_checkpoint_lsn > log_sys.get_first_lsn() &&
@@ -2795,8 +2795,7 @@ static void buf_flush_page_cleaner() noexcept
                      _db_keyword_(nullptr, "ib_log_checkpoint_avoid_hard", 1)))
                   continue,);
         if (log_sys.check_for_checkpoint() ||
-            (!srv_startup_is_before_trx_rollback_phase &&
-             srv_operation <= SRV_OPERATION_EXPORT_RESTORED))
+            srv_operation <= SRV_OPERATION_EXPORT_RESTORED)
           create_spare_archive= log_checkpoint();
       }
       while (false);

storage/innobase/fil/fil0fil.cc

@@ -888,7 +888,7 @@ static void fil_space_free_low(fil_space_t *space) noexcept
 {
 	/* The tablespace must not be in fil_system.named_spaces. */
 	ut_ad(srv_fast_shutdown == 2 || !srv_was_started
-	      || space->max_lsn == 0);
+	      || space->max_lsn <= 1);
 	ut_ad(!space->referenced());
 
 	for (fil_node_t* node = UT_LIST_GET_FIRST(space->chain);
@@ -935,15 +935,15 @@ bool fil_space_free(uint32_t id, bool x_latched) noexcept
 		if (!recv_recovery_is_on()) {
 			log_sys.latch.wr_lock();
 
-			if (space->max_lsn) {
+			if (space->max_lsn > 1) {
 				ut_d(space->max_lsn = 0);
 				fil_system.named_spaces.remove(*space);
 			}
 
 			log_sys.latch.wr_unlock();
 		} else {
 			ut_ad(log_sys.latch_have_wr());
-			if (space->max_lsn) {
+			if (space->max_lsn > 1) {
 				space->max_lsn = 0;
 				fil_system.named_spaces.remove(*space);
 			}
@@ -1558,19 +1558,28 @@ fil_space_t *fil_space_t::get(uint32_t id) noexcept
 @param path           file path
 @param new_path       new file path for type=FILE_RENAME
 @return number of bytes written */
-inline size_t mtr_t::log_file_op(mfile_type_t type, uint32_t space_id,
-                                 const char *path, const char *new_path)
-  noexcept
+size_t mtr_t::log_file_op(mfile_type_t type, uint32_t space_id,
+                          const char *path, const char *new_path) noexcept
 {
   ut_ad((new_path != nullptr) == (type == FILE_RENAME));
   ut_ad(!(byte(type) & 15));
-  ut_ad(!is_predefined_tablespace(space_id));
+  ut_ad(!is_system_tablespace(space_id));
 
+#ifdef UNIV_DEBUG
+  if (log_sys.archive)
+  {
+    int n{0}; uint32_t id;
+    if (1 == sscanf(path, "undo%03" PRIu32 "%n", &id, &n) && !path[n] &&
+        id - 1 + srv_undo_space_id_start == space_id)
+      goto valid_name;
+  }
+#endif
   /* fil_name_parse() requires that there be at least one path
   separator and that the file path end with ".ibd" or "ibb". */
   ut_ad(strchr(path, '/'));
   ut_ad(!strcmp(&path[strlen(path) - strlen(DOT_IBD)], DOT_IBD) ||
         !strcmp(&path[strlen(path) - strlen(DOT_IBB)], DOT_IBB));
+  ut_d(valid_name:)
 
   m_modifications= true;
   if (!is_logged())
@@ -1727,7 +1736,7 @@ fil_space_t *fil_space_t::drop(uint32_t id, pfs_os_file_t *detached_handle)
   This clean-up corresponds to fil_space_free(). */
   log_sys.latch.wr_lock();
   ut_ad((space->pending() & ~NEEDS_FSYNC) == (STOPPING | CLOSING));
-  if (space->max_lsn != 0)
+  if (space->max_lsn > 1)
   {
     space->max_lsn= 0;
     fil_system.named_spaces.remove(*space);
@@ -3087,65 +3096,7 @@ void fil_delete_file(const char *ibd_filepath) noexcept
   }
 }
 
-#ifdef UNIV_DEBUG
-/** Check that a tablespace is valid for mtr_commit().
-@param[in]	space	persistent tablespace that has been changed */
-static
-void fil_space_validate_for_mtr_commit(const fil_space_t *space) noexcept
-{
-	mysql_mutex_assert_not_owner(&fil_system.mutex);
-	ut_ad(space != NULL);
-	ut_ad(!is_predefined_tablespace(space->id));
-	ut_ad(!space->is_being_imported());
-
-	/* We are serving mtr_commit(). While there is an active
-	mini-transaction, we should have !space->is_stopping(). This is
-	guaranteed by meta-data locks or transactional locks. */
-	ut_ad(!space->is_stopping() || space->referenced());
-}
-#endif /* UNIV_DEBUG */
-
-/** Note that a non-predefined persistent tablespace has been modified
-by redo log.
-@param[in,out]	space	tablespace */
-void fil_names_dirty(fil_space_t *space) noexcept
-{
-	ut_ad(log_sys.latch_have_wr());
-	ut_ad(recv_recovery_is_on());
-	ut_ad(!srv_read_only_mode);
-	ut_ad(log_sys.get_lsn() != 0);
-	ut_ad(space->max_lsn == 0);
-	ut_d(fil_space_validate_for_mtr_commit(space));
-
-	if (UNIV_UNLIKELY(recv_sys.rpo != 0)) {
-		/* The log is read-only; do not write to it */
-		return;
-	}
-
-	fil_system.named_spaces.push_back(*space);
-	space->max_lsn = log_sys.get_lsn();
-}
-
-/** Write a FILE_MODIFY record when a non-predefined persistent
-tablespace was modified for the first time since fil_names_clear(). */
-ATTRIBUTE_NOINLINE ATTRIBUTE_COLD void mtr_t::name_write() noexcept
-{
-  ut_ad(log_sys.latch_have_wr());
-  ut_d(fil_space_validate_for_mtr_commit(m_user_space));
-  ut_ad(!m_user_space->max_lsn);
-  m_user_space->max_lsn= log_sys.get_lsn();
-
-  fil_system.named_spaces.push_back(*m_user_space);
-  ut_ad(UT_LIST_GET_LEN(m_user_space->chain) == 1);
-
-  mtr_t mtr{nullptr};
-  mtr.start();
-  mtr.log_file_op(FILE_MODIFY, m_user_space->id,
-                  UT_LIST_GET_FIRST(m_user_space->chain)->name);
-  mtr.commit_files();
-}
-
-/** On a log checkpoint, reset fil_names_dirty_and_write() flags
+/** On a log checkpoint, reset mtr_t::name_write() flags
 and write out FILE_MODIFY if needed, and write FILE_CHECKPOINT.
 @param lsn  checkpoint LSN
 @return current LSN */
@@ -3185,7 +3136,7 @@ ATTRIBUTE_COLD lsn_t fil_names_clear(lsn_t lsn) noexcept
 			fil_system.named_spaces.erase(it);
 		}
 
-		/* max_lsn is the last LSN where fil_names_dirty_and_write()
+		/* max_lsn is the last LSN where mtr_t::name_write()
 		was called. If we kept track of "min_lsn" (the first LSN
 		where max_lsn turned nonzero), we could avoid the
 		fil_names_clear() call if min_lsn > lsn. */

storage/innobase/fsp/fsp0sysspace.cc

@@ -565,6 +565,7 @@ SysTablespace::open_file(
 @return DB_SUCCESS or error code */
 inline dberr_t SysTablespace::read_lsn_and_check_flags()
 {
+	ut_ad(log_sys.latch_have_wr());
 	dberr_t	err;
 
 	files_t::iterator it = m_files.begin();
@@ -629,7 +630,6 @@ inline dberr_t SysTablespace::read_lsn_and_check_flags()
 	if (!log_sys.file_size && log_sys.format == log_t::FORMAT_3_23
 	    && srv_operation == SRV_OPERATION_NORMAL
 	    && srv_force_recovery < SRV_FORCE_NO_LOG_REDO) {
-		log_sys.latch.wr_lock();
 		/* Upgrade from 0-sized ib_logfile0. */
 		log_sys.last_checkpoint_lsn = mach_read_from_8(
 			first_page + 26/*FIL_PAGE_FILE_FLUSH_LSN*/);
@@ -648,8 +648,6 @@ inline dberr_t SysTablespace::read_lsn_and_check_flags()
 			log_sys.set_recovered_lsn(recv_sys.lsn);
 			log_sys.next_checkpoint_no = 0;
 		}
-
-		log_sys.latch.wr_unlock();
 	}
 
 	it->close();

storage/innobase/ibuf/ibuf0ibuf.cc

@@ -1022,6 +1022,9 @@ ATTRIBUTE_COLD dberr_t ibuf_upgrade()
 
 dberr_t ibuf_upgrade_needed()
 {
+  if (srv_force_recovery == SRV_FORCE_NO_LOG_REDO)
+    return DB_SUCCESS;
+
   mtr_t mtr{nullptr};
   mtr.start();
   mtr.x_lock_space(fil_system.sys_space);