MDEV-32968 InnoDB fails to restore tablespace first page from doublew…

…rite buffer when page is empty

- InnoDB fails to find the space id from the page0 of
the tablespace. In that case, InnoDB can use
doublewrite buffer to recover the page0 and write
into the file.

- buf_dblwr_t::init_or_load_pages(): Loads only the pages
which are valid.(page lsn >= checkpoint). To do that,
InnoDB has to open the redo log before system
tablespace, read the latest checkpoint information.

recv_dblwr_t::find_first_page():
1) Iterate the doublewrite buffer pages and find the 0th page
2) Read the tablespace flags, space id from the 0th page.
3) Read the 1st, 2nd and 3rd page from tablespace file and
compare the space id with the space id which is stored
in doublewrite buffer.
4) If it matches then we can write into the file.
5) Return space which matches the pages from the file.

SysTablespace::read_lsn_and_check_flags(): Remove the
retry logic for validating the first page. After
restoring the first page from doublewrite buffer,
assign tablespace flags by reading the first page.

recv_recovery_read_max_checkpoint(): Reads the maximum
checkpoint information from log file

recv_recovery_from_checkpoint_start(): Avoid reading
the checkpoint header information from log file

Datafile::validate_first_page(): Throw error in case
of first page validation fails.

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

@@ -1,7 +1,7 @@
 #
 # MDEV-32242 innodb.doublewrite test case always is skipped
 #
-create table t1 (f1 int primary key, f2 blob) engine=innodb;
+create table t1 (f1 int primary key, f2 blob) stats_persistent=0, engine=innodb;
 start transaction;
 insert into t1 values(1, repeat('#',12));
 insert into t1 values(2, repeat('+',12));
@@ -19,6 +19,7 @@ XA PREPARE 'x';
 disconnect dml;
 connection default;
 flush table t1 for export;
+# Kill the server
 # restart
 FOUND 1 /InnoDB: Restoring page \[page id: space=[1-9][0-9]*, page number=0\] of datafile/ in mysqld.1.err
 FOUND 1 /InnoDB: Recovered page \[page id: space=[1-9][0-9]*, page number=3\]/ in mysqld.1.err
@@ -33,5 +34,27 @@ f1	f2
 3	////////////
 4	------------
 5	............
+connect  dml,localhost,root,,;
+XA START 'x';
+insert into t1 values (6, repeat('%', @@innodb_page_size/2));
+XA END 'x';
+XA PREPARE 'x';
+disconnect dml;
+connection default;
+flush table t1 for export;
+# Kill the server
+# restart
+FOUND 2 /InnoDB: Restoring page \[page id: space=[1-9][0-9]*, page number=0\] of datafile/ in mysqld.1.err
+XA ROLLBACK 'x';
+check table t1;
+Table	Op	Msg_type	Msg_text
+test.t1	check	status	OK
+select f1, f2 from t1;
+f1	f2
+1	############
+2	++++++++++++
+3	////////////
+4	------------
+5	............
 drop table t1;
 # End of 10.5 tests

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

@@ -1,3 +1,4 @@
+call mtr.add_suppression("InnoDB: Header page consists of zero bytes in datafile:");
 SET GLOBAL innodb_file_per_table=ON;
 FLUSH TABLES;
 CREATE TABLE t1(a INT PRIMARY KEY) ENGINE=InnoDB;
@@ -89,7 +90,7 @@ SELECT * FROM INFORMATION_SCHEMA.ENGINES
 WHERE engine = 'innodb'
 AND support IN ('YES', 'DEFAULT', 'ENABLED');
 ENGINE	SUPPORT	COMMENT	TRANSACTIONS	XA	SAVEPOINTS
-FOUND 1 /\[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
+FOUND 1 /\[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
 FOUND 1 /\[ERROR\] InnoDB: Datafile .*u1.*\. Cannot determine the space ID from the first 64 pages/ in mysqld.1.err
 NOT FOUND /\[Note\] InnoDB: Cannot read first page of .*u2.ibd/ in mysqld.1.err
 # Fault 7: Missing or wrong data file and innodb_force_recovery
@@ -98,11 +99,11 @@ SELECT * FROM INFORMATION_SCHEMA.ENGINES
 WHERE engine = 'innodb'
 AND support IN ('YES', 'DEFAULT', 'ENABLED');
 ENGINE	SUPPORT	COMMENT	TRANSACTIONS	XA	SAVEPOINTS
-FOUND 1 /\[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
+FOUND 1 /\[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
 FOUND 1 /InnoDB: At LSN: \d+: unable to open file .*u[1-5].ibd for tablespace/ in mysqld.1.err
 FOUND 1 /\[ERROR\] InnoDB: Cannot replay rename of tablespace \d+ from '.*u4.ibd' to '.*u6.ibd' because the target file exists/ in mysqld.1.err
 # restart: --innodb-force-recovery=1
-FOUND 1 /\[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
+FOUND 1 /\[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd/ in mysqld.1.err
 FOUND 1 /InnoDB: At LSN: \d+: unable to open file .*u[1-5].ibd for tablespace/ in mysqld.1.err
 FOUND 1 /\[Warning\] InnoDB: Tablespace \d+ was not found at .*u[1-5].ibd, and innodb_force_recovery was set. All redo log for this tablespace will be ignored!/ in mysqld.1.err
 # restart

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

@@ -17,14 +17,15 @@ call mtr.add_suppression("InnoDB: A bad Space ID was found in datafile");
 call mtr.add_suppression("InnoDB: Checksum mismatch in datafile: ");
 call mtr.add_suppression("InnoDB: Inconsistent tablespace ID in .*t1\\.ibd");
 call mtr.add_suppression("\\[Warning\\] Found 1 prepared XA transactions");
+call mtr.add_suppression("InnoDB: Header page consists of zero bytes in datafile:");
 --enable_query_log
 
 let INNODB_PAGE_SIZE=`select @@innodb_page_size`;
 let MYSQLD_DATADIR=`select @@datadir`;
 let ALGO=`select @@innodb_checksum_algorithm`;
 let SEARCH_FILE= $MYSQLTEST_VARDIR/log/mysqld.1.err;
 
-create table t1 (f1 int primary key, f2 blob) engine=innodb;
+create table t1 (f1 int primary key, f2 blob) stats_persistent=0, engine=innodb;
 
 start transaction;
 insert into t1 values(1, repeat('#',12));
@@ -38,7 +39,7 @@ commit work;
 SET GLOBAL innodb_fast_shutdown = 0;
 let $shutdown_timeout=;
 --source include/restart_mysqld.inc
-
+--source ../include/no_checkpoint_start.inc
 connect (dml,localhost,root,,);
 XA START 'x';
 insert into t1 values (6, repeat('%', @@innodb_page_size/2));
@@ -50,8 +51,8 @@ connection default;
 flush table t1 for export;
 
 let $restart_parameters=;
-let $shutdown_timeout=0;
---source include/shutdown_mysqld.inc
+--let CLEANUP_IF_CHECKPOINT=drop table t1, unexpected_checkpoint;
+--source ../include/no_checkpoint_end.inc
 
 perl;
 use IO::Handle;
@@ -119,6 +120,35 @@ let SEARCH_PATTERN=InnoDB: Recovered page \[page id: space=[1-9][0-9]*, page num
 XA ROLLBACK 'x';
 check table t1;
 select f1, f2 from t1;
+
+--source ../include/no_checkpoint_start.inc
+connect (dml,localhost,root,,);
+XA START 'x';
+insert into t1 values (6, repeat('%', @@innodb_page_size/2));
+XA END 'x';
+XA PREPARE 'x';
+disconnect dml;
+connection default;
+
+flush table t1 for export;
+
+let $restart_parameters=;
+--source ../include/no_checkpoint_end.inc
+
+# Zero out the first page in file and try to recover from dblwr
+perl;
+use IO::Handle;
+open(FILE, "+<", "$ENV{'MYSQLD_DATADIR'}test/t1.ibd") or die;
+syswrite(FILE, chr(0) x $ENV{INNODB_PAGE_SIZE});
+close FILE;
+EOF
+
+--source include/start_mysqld.inc
+let SEARCH_PATTERN=InnoDB: Restoring page \[page id: space=[1-9][0-9]*, page number=0\] of datafile;
+--source include/search_pattern_in_file.inc
+XA ROLLBACK 'x';
+check table t1;
+select f1, f2 from t1;
 drop table t1;
 
 --echo # End of 10.5 tests

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

@@ -17,6 +17,7 @@ call mtr.add_suppression("Plugin 'InnoDB' (init function returned error|registra
 call mtr.add_suppression("InnoDB: A bad Space ID was found in datafile");
 call mtr.add_suppression("InnoDB: Checksum mismatch in datafile: ");
 call mtr.add_suppression("InnoDB: Inconsistent tablespace ID in .*t1\\.ibd");
+call mtr.add_suppression("InnoDB: Header page consists of zero bytes in datafile:");
 --enable_query_log
 
 let INNODB_PAGE_SIZE=`select @@innodb_page_size`;

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

@@ -7,6 +7,8 @@
 # Embedded server does not support crashing
 --source include/not_embedded.inc
 
+call mtr.add_suppression("InnoDB: Header page consists of zero bytes in datafile:");
+
 SET GLOBAL innodb_file_per_table=ON;
 FLUSH TABLES;
 
@@ -172,6 +174,7 @@ call mtr.add_suppression("InnoDB: Table test/u[123] in the InnoDB data dictionar
 call mtr.add_suppression("InnoDB: Cannot replay rename of tablespace.*");
 call mtr.add_suppression("InnoDB: Attempted to open a previously opened tablespace");
 call mtr.add_suppression("InnoDB: Recovery cannot access file");
+call mtr.add_suppression("InnoDB: Cannot read first page in datafile:");
 FLUSH TABLES;
 --enable_query_log
 
@@ -215,7 +218,7 @@ EOF
 --source include/start_mysqld.inc
 eval $check_no_innodb;
 
-let SEARCH_PATTERN= \[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
+let SEARCH_PATTERN= \[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
 --source include/search_pattern_in_file.inc
 
 let SEARCH_PATTERN= \[ERROR\] InnoDB: Datafile .*u1.*\. Cannot determine the space ID from the first 64 pages;
@@ -240,7 +243,7 @@ let SEARCH_PATTERN= \[Note\] InnoDB: Cannot read first page of .*u2.ibd;
 --source include/start_mysqld.inc
 eval $check_no_innodb;
 
-let SEARCH_PATTERN= \[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
+let SEARCH_PATTERN= \[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
 --source include/search_pattern_in_file.inc
 
 let SEARCH_PATTERN= InnoDB: At LSN: \d+: unable to open file .*u[1-5].ibd for tablespace;
@@ -253,7 +256,7 @@ let SEARCH_PATTERN= \[ERROR\] InnoDB: Cannot replay rename of tablespace \d+ fro
 
 --source include/restart_mysqld.inc
 
-let SEARCH_PATTERN= \[Note\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
+let SEARCH_PATTERN= \[ERROR\] InnoDB: Header page consists of zero bytes in datafile: .*u1.ibd;
 --source include/search_pattern_in_file.inc
 
 let SEARCH_PATTERN= InnoDB: At LSN: \d+: unable to open file .*u[1-5].ibd for tablespace;

storage/innobase/buf/buf0dblwr.cc

@@ -324,11 +324,14 @@ dberr_t buf_dblwr_t::init_or_load_pages(pfs_os_file_t file, const char *path)
     os_file_flush(file);
   }
   else
-    for (ulint i= 0; i < size * 2; i++, page += srv_page_size)
-      if (mach_read_from_8(my_assume_aligned<8>(page + FIL_PAGE_LSN)))
-        /* Each valid page header must contain a nonzero FIL_PAGE_LSN field. */
+  {
+    alignas(8) char checkpoint[8];
+    mach_write_to_8(checkpoint, log_sys.next_checkpoint_lsn);
+    for (auto i= size * 2; i--; page += srv_page_size)
+      if (memcmp_aligned<8>(page + FIL_PAGE_LSN, checkpoint, 8) >= 0)
+        /* Valid pages are not older than the log checkpoint. */
         recv_sys.dblwr.add(page);
-
+  }
   err= DB_SUCCESS;
   goto func_exit;
 }

storage/innobase/fsp/fsp0file.cc

@@ -475,17 +475,24 @@ Datafile::validate_for_recovery()
 
 		err = find_space_id();
 		if (err != DB_SUCCESS || m_space_id == 0) {
-			ib::error() << "Datafile '" << m_filepath << "' is"
-				" corrupted. Cannot determine the space ID from"
-				" the first 64 pages.";
+
+			m_space_id = recv_sys.dblwr.find_first_page(
+				m_filepath, m_handle);
+
+			if (m_space_id) goto free_first_page;
+
+			sql_print_error(
+				"InnoDB: Datafile '%s' is corrupted."
+				" Cannot determine the space ID from"
+				" the first 64 pages.", m_filepath);
 			return(err);
 		}
 
 		if (recv_sys.dblwr.restore_first_page(
 			m_space_id, m_filepath, m_handle)) {
 			return(DB_CORRUPTION);
 		}
-
+free_first_page:
 		/* Free the previously read first page and then re-validate. */
 		free_first_page();
 		err = validate_first_page(0);
@@ -531,9 +538,9 @@ Datafile::validate_first_page(lsn_t* flush_lsn)
 
 	if (error_txt != NULL) {
 err_exit:
-		ib::info() << error_txt << " in datafile: " << m_filepath
-			<< ", Space ID:" << m_space_id  << ", Flags: "
-			<< m_flags;
+		sql_print_error("InnoDB: %s in datafile: %s, Space ID: %zu, "
+				"Flags: %zu", error_txt, m_filepath,
+				m_space_id, m_flags);
 		m_is_valid = false;
 		free_first_page();
 		return(DB_CORRUPTION);

storage/innobase/fsp/fsp0sysspace.cc

@@ -574,7 +574,7 @@ SysTablespace::read_lsn_and_check_flags(lsn_t* flushed_lsn)
 	}
 
 	err = it->read_first_page(
-		m_ignore_read_only ?  false : srv_read_only_mode);
+		m_ignore_read_only && srv_read_only_mode);
 
 	if (err != DB_SUCCESS) {
 		return(err);
@@ -588,20 +588,17 @@ SysTablespace::read_lsn_and_check_flags(lsn_t* flushed_lsn)
 
 	/* Check the contents of the first page of the
 	first datafile. */
-	for (int retry = 0; retry < 2; ++retry) {
+	err = it->validate_first_page(flushed_lsn);
 
-		err = it->validate_first_page(flushed_lsn);
-
-		if (err != DB_SUCCESS
-		    && (retry == 1
-			|| recv_sys.dblwr.restore_first_page(
+	if (err != DB_SUCCESS) {
+		if (recv_sys.dblwr.restore_first_page(
 				it->m_space_id, it->m_filepath,
-				it->handle()))) {
-
+				it->handle())) {
 			it->close();
-
 			return(err);
 		}
+		err = it->read_first_page(
+			m_ignore_read_only && srv_read_only_mode);
 	}
 
 	/* Make sure the tablespace space ID matches the

storage/innobase/include/buf0dblwr.h

@@ -103,7 +103,8 @@ class buf_dblwr_t
   If we are upgrading from a version before MySQL 4.1, then this
   function performs the necessary update operations to support
   innodb_file_per_table. If we are in a crash recovery, this function
-  loads the pages from double write buffer into memory.
+  loads the pages from double write buffer which are not older than
+  the checkpoint into memory.
   @param file File handle
   @param path Path name of file
   @return DB_SUCCESS or error code */

storage/innobase/include/log0recv.h

@@ -49,6 +49,11 @@ recv_find_max_checkpoint(ulint* max_field)
 ATTRIBUTE_COLD void recv_recover_page(fil_space_t* space, buf_page_t* bpage)
 	MY_ATTRIBUTE((nonnull));
 
+/** Read the latest checkpoint information from log file
+and store it in log_sys.next_checkpoint and recv_sys.mlog_checkpoint_lsn
+@return error code or DB_SUCCESS */
+dberr_t recv_recovery_read_max_checkpoint();
+
 /** Start recovering from a redo log checkpoint.
 @param[in]	flush_lsn	FIL_PAGE_FILE_FLUSH_LSN
 of first system tablespace page
@@ -141,7 +146,18 @@ struct recv_dblwr_t
   @param file      tablespace file handle
   @return whether the operation failed */
   bool restore_first_page(
-         ulint space_id, const char *name, os_file_t file);
+         ulint space_id, const char *name, pfs_os_file_t file);
+
+  /** Restore the first page of the given tablespace from
+  doublewrite buffer.
+  1) Find the page which has page_no as 0
+  2) Read first 3 pages from tablespace file
+  3) Compare the space_ids from the pages with page0 which
+  was retrieved from doublewrite buffer
+  @param name tablespace filepath
+  @param file tablespace file handle
+  @return space_id or 0 in case of error */
+  uint32_t find_first_page(const char *name, pfs_os_file_t file);
 
   typedef std::deque<byte*, ut_allocator<byte*> > list;