MDEV-32445 InnoDB may corrupt its log before upgrading it on startup

Problem:
========
 During upgrade, InnoDB does write the redo log for adjusting
the tablespace size or tablespace flags even before the log
has upgraded to configured format. This could lead to data
inconsistent if any crash happened during upgrade process.

Fix:
===
srv_start(): Write the tablespace flags adjustment, increased
tablespace size redo log only after redo log upgradation.

log_write_low(), log_reserve_and_write_fast(): Check whether
the redo log is in physical format.

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

+call mtr.add_suppression("InnoDB: The change buffer is corrupted");
+call mtr.add_suppression("InnoDB: Tablespace size stored in header is 768 pages, but the sum of data file sizes is 384 pages");
+call mtr.add_suppression("InnoDB: adjusting FSP_SPACE_FLAGS of file");
+# restart: --innodb-data-home-dir=MYSQLTEST_VARDIR/tmp/log_upgrade --innodb-log-group-home-dir=MYSQLTEST_VARDIR/tmp/log_upgrade --innodb-force-recovery=5 --innodb-log-file-size=4m --innodb_page_size=32k --innodb_buffer_pool_size=10M
+SELECT COUNT(*) FROM INFORMATION_SCHEMA.ENGINES
+WHERE engine = 'innodb'
+AND support IN ('YES', 'DEFAULT', 'ENABLED');
+COUNT(*)
+1
+FOUND 1 /InnoDB: Upgrading redo log:/ in mysqld.1.err
+# restart
+# End of 10.5 tests

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

+--source include/have_innodb.inc
+--source include/big_test.inc
+--source include/not_embedded.inc
+call mtr.add_suppression("InnoDB: The change buffer is corrupted");
+call mtr.add_suppression("InnoDB: Tablespace size stored in header is 768 pages, but the sum of data file sizes is 384 pages");
+call mtr.add_suppression("InnoDB: adjusting FSP_SPACE_FLAGS of file");
+--source include/shutdown_mysqld.inc
+let bugdir= $MYSQLTEST_VARDIR/tmp/log_upgrade;
+--mkdir $bugdir
+--let SEARCH_FILE = $MYSQLTEST_VARDIR/log/mysqld.1.err
+--let $dirs= --innodb-data-home-dir=$bugdir --innodb-log-group-home-dir=$bugdir
+
+# Test case similar to log_upgrade.test
+perl;
+do "$ENV{MTR_SUITE_DIR}/../innodb/include/crc32.pl";
+my $polynomial = 0x82f63b78; # CRC-32C
+
+die unless open OUT, ">", "$ENV{bugdir}/ibdata1";
+binmode OUT;
+
+my $head = pack("Nx[18]", 0);
+# Add FSP_SPACE_FLAGS as 49152 (10.1.0...10.1.20), page_size = 32k
+my $body = pack("x[8]Nx[4]Nx[2]Nx[32696]", 768, 49152, 97937874);
+my $ck = mycrc32($head, 0, $polynomial) ^ mycrc32($body, 0, $polynomial);
+print OUT pack("N",$ck).$head.pack("x[12]").$body.pack("Nx[4]",$ck);
+# Dummy pages 1..6.
+print OUT chr(0) x (6 * 32768);
+# Dictionary header page (page 7).
+$head = pack("Nx[18]", 7);
+$body = pack("x[32]Nx[8]Nx[32674]", 8, 9);
+$ck = mycrc32($head, 0, $polynomial) ^ mycrc32($body, 0, $polynomial);
+print OUT pack("N",$ck).$head.pack("x[12]").$body.pack("Nx[4]",$ck);
+
+# Empty SYS_TABLES page (page 8).
+$head = pack("NNNx[8]n", 8, ~0, ~0, 17855);
+$body = pack("nnx[31]Cx[20]", 2, 124, 1);
+$body .= pack("nxnn", 0x801, 3, 116) . "infimum";
+$body .= pack("xnxnxx", 0x901, 0x803) . "supremum";
+$body .= pack("x[32632]nn", 116, 101);
+$ck = mycrc32($head, 0, $polynomial) ^ mycrc32($body, 0, $polynomial);
+print OUT pack("N",$ck).$head.pack("x[12]").$body.pack("Nx[4]",$ck);
+
+# Empty SYS_INDEXES page (page 9).
+$head = pack("NNNx[8]n", 9, ~0, ~0, 17855);
+$body = pack("nnx[31]Cx[20]", 2, 124, 3);
+$body .= pack("nxnn", 0x801, 3, 116) . "infimum";
+$body .= pack("xnxnxx", 0x901, 0x803) . "supremum";
+$body .= pack("x[32632]nn", 116, 101);
+$ck = mycrc32($head, 0, $polynomial) ^ mycrc32($body, 0, $polynomial);
+print OUT pack("N",$ck).$head.pack("x[12]").$body.pack("Nx[4]",$ck);
+
+die unless seek(OUT, 768 * 16384 - 1, 0);
+print OUT chr(0);
+close OUT or die;
+
+die unless open OUT, ">", "$ENV{bugdir}/ib_logfile0";
+binmode OUT;
+$_= pack("Nx[5]nx[5]", 1, 0x1286) . "BogoDB 4.3.2.1" . chr(0) x 478;
+print OUT $_, pack("N", mycrc32($_, 0, $polynomial));
+# checkpoint page 1 and all-zero checkpoint 2
+$_= pack("x[13]nCNNx[484]", 0x1286, 12, 2, 0x80c);
+print OUT $_, pack("N", mycrc32($_, 0, $polynomial));
+die unless seek(OUT, 0x1FFFFFFFF, 0);
+print OUT chr(0);
+close OUT or die;
+die unless open OUT, ">", "$ENV{bugdir}/ib_logfile1";
+binmode OUT;
+die unless seek(OUT, 0x800, 0); # the first 2048 bytes are unused!
+$_= pack("Nnnx[500]", 0x80000944, 12, 12);
+print OUT $_, pack("N", mycrc32($_, 0, $polynomial));
+die unless seek(OUT, 0x1FFFFFFFF, 0);
+print OUT chr(0);
+close OUT or die;
+EOF
+
+--let $restart_parameters= $dirs --innodb-force-recovery=5 --innodb-log-file-size=4m --innodb_page_size=32k --innodb_buffer_pool_size=10M
+--source include/start_mysqld.inc
+SELECT COUNT(*) FROM INFORMATION_SCHEMA.ENGINES
+WHERE engine = 'innodb'
+AND support IN ('YES', 'DEFAULT', 'ENABLED');
+--source include/shutdown_mysqld.inc
+--let SEARCH_PATTERN= InnoDB: Upgrading redo log:
+--source include/search_pattern_in_file.inc
+--let $restart_parameters= $dirs
+
+--remove_files_wildcard $bugdir
+--rmdir $bugdir
+--let $restart_parameters=
+--source include/start_mysqld.inc
+
+--echo # End of 10.5 tests

storage/innobase/include/log0log.inl

@@ -270,6 +270,7 @@ log_reserve_and_write_fast(
 	}
 
 	lsn_t lsn = log_sys.get_lsn();
+	ut_ad(log_sys.is_physical());
 	*start_lsn = lsn;
 
 	memcpy(log_sys.buf + log_sys.buf_free, str, len);

storage/innobase/mtr/mtr0mtr.cc

@@ -850,6 +850,8 @@ static void log_write_low(const void *str, size_t size)
       len= trailer_offset - log_sys.buf_free % OS_FILE_LOG_BLOCK_SIZE;
     }
 
+    ut_ad(log_sys.is_physical());
+
     memcpy(log_sys.buf + log_sys.buf_free, str, len);
 
     size-= len;

storage/innobase/srv/srv0start.cc

@@ -1555,91 +1555,6 @@ dberr_t srv_start(bool create_new_db)
 
 		fil_system.space_id_reuse_warned = false;
 
-		if (!srv_read_only_mode) {
-			const ulint flags = FSP_FLAGS_PAGE_SSIZE();
-			for (ulint id = 0; id <= srv_undo_tablespaces; id++) {
-				if (fil_space_t* space = fil_space_get(id)) {
-					fsp_flags_try_adjust(space, flags);
-				}
-			}
-
-			if (sum_of_new_sizes > 0) {
-				/* New data file(s) were added */
-				mtr.start();
-				mtr.x_lock_space(fil_system.sys_space,
-						 __FILE__, __LINE__);
-				buf_block_t* block = buf_page_get(
-					page_id_t(0, 0), 0,
-					RW_SX_LATCH, &mtr);
-				ulint size = mach_read_from_4(
-					FSP_HEADER_OFFSET + FSP_SIZE
-					+ block->frame);
-				ut_ad(size == fil_system.sys_space
-				      ->size_in_header);
-				size += sum_of_new_sizes;
-				mtr.write<4>(*block,
-					     FSP_HEADER_OFFSET + FSP_SIZE
-					     + block->frame, size);
-				fil_system.sys_space->size_in_header
-					= uint32_t(size);
-				mtr.commit();
-				/* Immediately write the log record about
-				increased tablespace size to disk, so that it
-				is durable even if mysqld would crash
-				quickly */
-				log_buffer_flush_to_disk();
-			}
-		}
-
-#ifdef UNIV_DEBUG
-		{
-			mtr.start();
-			buf_block_t* block = buf_page_get(page_id_t(0, 0), 0,
-							  RW_S_LATCH, &mtr);
-			ut_ad(mach_read_from_4(FSP_SIZE + FSP_HEADER_OFFSET
-					       + block->frame)
-			      == fil_system.sys_space->size_in_header);
-			mtr.commit();
-		}
-#endif
-		const ulint	tablespace_size_in_header
-			= fil_system.sys_space->size_in_header;
-		const ulint	sum_of_data_file_sizes
-			= srv_sys_space.get_sum_of_sizes();
-		/* Compare the system tablespace file size to what is
-		stored in FSP_SIZE. In srv_sys_space.open_or_create()
-		we already checked that the file sizes match the
-		innodb_data_file_path specification. */
-		if (srv_read_only_mode
-		    || sum_of_data_file_sizes == tablespace_size_in_header) {
-			/* Do not complain about the size. */
-		} else if (!srv_sys_space.can_auto_extend_last_file()
-			   || sum_of_data_file_sizes
-			   < tablespace_size_in_header) {
-			ib::error() << "Tablespace size stored in header is "
-				<< tablespace_size_in_header
-				<< " pages, but the sum of data file sizes is "
-				<< sum_of_data_file_sizes << " pages";
-
-			if (srv_force_recovery == 0
-			    && sum_of_data_file_sizes
-			    < tablespace_size_in_header) {
-				ib::error() <<
-					"Cannot start InnoDB. The tail of"
-					" the system tablespace is"
-					" missing. Have you edited"
-					" innodb_data_file_path in my.cnf"
-					" in an inappropriate way, removing"
-					" data files from there?"
-					" You can set innodb_force_recovery=1"
-					" in my.cnf to force"
-					" a startup if you are trying to"
-					" recover a badly corrupt database.";
-
-				return(srv_init_abort(DB_ERROR));
-			}
-		}
-
 		if (srv_operation == SRV_OPERATION_RESTORE
 		    || srv_operation == SRV_OPERATION_RESTORE_EXPORT) {
 			buf_flush_sync();
@@ -1667,7 +1582,6 @@ dberr_t srv_start(bool create_new_db)
 			}
 			return(err);
 		}
-
 		/* Upgrade or resize or rebuild the redo logs before
 		generating any dirty pages, so that the old redo log
 		file will not be written to. */
@@ -1735,8 +1649,92 @@ dberr_t srv_start(bool create_new_db)
 				return(srv_init_abort(err));
 			}
 		}
-
 		recv_sys.debug_free();
+
+		if (!srv_read_only_mode) {
+			const ulint flags = FSP_FLAGS_PAGE_SSIZE();
+			for (ulint id = 0; id <= srv_undo_tablespaces; id++) {
+				if (fil_space_t* space = fil_space_get(id)) {
+					fsp_flags_try_adjust(space, flags);
+				}
+			}
+
+			if (sum_of_new_sizes > 0) {
+				/* New data file(s) were added */
+				mtr.start();
+				mtr.x_lock_space(fil_system.sys_space,
+						 __FILE__, __LINE__);
+				buf_block_t* block = buf_page_get(
+					page_id_t(0, 0), 0,
+					RW_SX_LATCH, &mtr);
+				ulint size = mach_read_from_4(
+					FSP_HEADER_OFFSET + FSP_SIZE
+					+ block->frame);
+				ut_ad(size == fil_system.sys_space
+				      ->size_in_header);
+				size += sum_of_new_sizes;
+				mtr.write<4>(*block,
+					     FSP_HEADER_OFFSET + FSP_SIZE
+					     + block->frame, size);
+				fil_system.sys_space->size_in_header
+					= uint32_t(size);
+				mtr.commit();
+				/* Immediately write the log record about
+				increased tablespace size to disk, so that it
+				is durable even if mysqld would crash
+				quickly */
+				log_buffer_flush_to_disk();
+			}
+		}
+
+#ifdef UNIV_DEBUG
+		{
+			mtr.start();
+			buf_block_t* block = buf_page_get(page_id_t(0, 0), 0,
+							  RW_S_LATCH, &mtr);
+			ut_ad(mach_read_from_4(FSP_SIZE + FSP_HEADER_OFFSET
+					       + block->frame)
+			      == fil_system.sys_space->size_in_header);
+			mtr.commit();
+		}
+#endif
+		const ulint	tablespace_size_in_header
+			= fil_system.sys_space->size_in_header;
+		const ulint	sum_of_data_file_sizes
+			= srv_sys_space.get_sum_of_sizes();
+		/* Compare the system tablespace file size to what is
+		stored in FSP_SIZE. In srv_sys_space.open_or_create()
+		we already checked that the file sizes match the
+		innodb_data_file_path specification. */
+		if (srv_read_only_mode
+		    || sum_of_data_file_sizes == tablespace_size_in_header) {
+			/* Do not complain about the size. */
+		} else if (!srv_sys_space.can_auto_extend_last_file()
+			   || sum_of_data_file_sizes
+			   < tablespace_size_in_header) {
+			ib::error() << "Tablespace size stored in header is "
+				<< tablespace_size_in_header
+				<< " pages, but the sum of data file sizes is "
+				<< sum_of_data_file_sizes << " pages";
+
+			if (srv_force_recovery == 0
+			    && sum_of_data_file_sizes
+			    < tablespace_size_in_header) {
+				ib::error() <<
+					"Cannot start InnoDB. The tail of"
+					" the system tablespace is"
+					" missing. Have you edited"
+					" innodb_data_file_path in my.cnf"
+					" in an inappropriate way, removing"
+					" data files from there?"
+					" You can set innodb_force_recovery=1"
+					" in my.cnf to force"
+					" a startup if you are trying to"
+					" recover a badly corrupt database.";
+
+				return(srv_init_abort(DB_ERROR));
+			}
+		}
 	}
 
 	ut_ad(err == DB_SUCCESS);