1 files changed, 49 insertions, 120 deletions

diff --git a/storage/xtradb/log/log0recv.cc b/storage/xtradb/log/log0recv.cc
index 01975712d99..afb8b7f00b8 100644
--- a/storage/xtradb/log/log0recv.cc
+++ b/storage/xtradb/log/log0recv.cc
@@ -2,7 +2,7 @@
 
 Copyright (c) 1997, 2016, Oracle and/or its affiliates. All Rights Reserved.
 Copyright (c) 2012, Facebook Inc.
-Copyright (c) 2017, MariaDB Corporation. All Rights Reserved.
+Copyright (c) 2017, MariaDB Corporation.
 
 This program is free software; you can redistribute it and/or modify it under
 the terms of the GNU General Public License as published by the Free Software
@@ -80,7 +80,7 @@ this must be less than UNIV_PAGE_SIZE as it is stored in the buffer pool */
 #define RECV_READ_AHEAD_AREA	32
 
 /** The recovery system */
-UNIV_INTERN recv_sys_t*	recv_sys = NULL;
+UNIV_INTERN recv_sys_t*	recv_sys;
 /** TRUE when applying redo log records during crash recovery; FALSE
 otherwise.  Note that this is FALSE while a background thread is
 rolling back incomplete transactions. */
@@ -132,9 +132,6 @@ UNIV_INTERN ibool	recv_is_making_a_backup	= FALSE;
 UNIV_INTERN ibool	recv_is_from_backup	= FALSE;
 # define buf_pool_get_curr_size() (5 * 1024 * 1024)
 #endif /* !UNIV_HOTBACKUP */
-/** The following counter is used to decide when to print info on
-log scan */
-static ulint	recv_scan_print_counter;
 
 /** The type of the previous parsed redo log record */
 static ulint	recv_previous_parsed_rec_type;
@@ -305,8 +302,6 @@ recv_sys_var_init(void)
 
 	recv_no_ibuf_operations = FALSE;
 
-	recv_scan_print_counter	= 0;
-
 	recv_previous_parsed_rec_type	= 999999;
 
 	recv_previous_parsed_rec_offset	= 0;
@@ -417,6 +412,7 @@ recv_sys_init(
 		recv_sys->last_block_buf_start, OS_FILE_LOG_BLOCK_SIZE));
 
 	recv_sys->found_corrupt_log = FALSE;
+	recv_sys->progress_time = ut_time();
 
 	recv_max_page_lsn = 0;
 
@@ -1675,6 +1671,7 @@ recv_recover_page_func(
 	ibool		success;
 #endif /* !UNIV_HOTBACKUP */
 	mtr_t		mtr;
+	ib_time_t	time;
 
 	mutex_enter(&(recv_sys->mutex));
 
@@ -1852,6 +1849,8 @@ recv_recover_page_func(
 
 	mtr_commit(&mtr);
 
+	time = ut_time();
+
 	mutex_enter(&(recv_sys->mutex));
 
 	if (recv_max_page_lsn < page_lsn) {
@@ -1860,11 +1859,16 @@ recv_recover_page_func(
 
 	recv_addr->state = RECV_PROCESSED;
 
-	ut_a(recv_sys->n_addrs);
-	recv_sys->n_addrs--;
-
-	mutex_exit(&(recv_sys->mutex));
+	ut_a(recv_sys->n_addrs > 0);
+	if (--recv_sys->n_addrs && recv_sys->progress_time - time >= 15) {
+		recv_sys->progress_time = time;
+		ut_print_timestamp(stderr);
+		fprintf(stderr,
+			"  InnoDB: To recover: " ULINTPF " pages from log\n",
+			recv_sys->n_addrs);
+	}
 
+	mutex_exit(&recv_sys->mutex);
 }
 
 #ifndef UNIV_HOTBACKUP
@@ -1910,59 +1914,48 @@ recv_read_in_area(
 	}
 
 	buf_read_recv_pages(FALSE, space, zip_size, page_nos, n);
-	/*
-	fprintf(stderr, "Recv pages at %lu n %lu\n", page_nos[0], n);
-	*/
 	return(n);
 }
 
-/*******************************************************************//**
-Empties the hash table of stored log records, applying them to appropriate
-pages. */
+/** Apply the hash table of stored log records to persistent data pages.
+@param[in]	last_batch	whether the change buffer merge will be
+				performed as part of the operation */
 UNIV_INTERN
 void
-recv_apply_hashed_log_recs(
-/*=======================*/
-	ibool	allow_ibuf)	/*!< in: if TRUE, also ibuf operations are
-				allowed during the application; if FALSE,
-				no ibuf operations are allowed, and after
-				the application all file pages are flushed to
-				disk and invalidated in buffer pool: this
-				alternative means that no new log records
-				can be generated during the application;
-				the caller must in this case own the log
-				mutex */
+recv_apply_hashed_log_recs(bool last_batch)
 {
-	recv_addr_t* recv_addr;
-	ulint	i;
-	ibool	has_printed	= FALSE;
-	mtr_t	mtr;
-loop:
-	mutex_enter(&(recv_sys->mutex));
-
-	if (recv_sys->apply_batch_on) {
+	for (;;) {
+		mutex_enter(&recv_sys->mutex);
 
-		mutex_exit(&(recv_sys->mutex));
+		if (!recv_sys->apply_batch_on) {
+			break;
+		}
 
+		mutex_exit(&recv_sys->mutex);
 		os_thread_sleep(500000);
-
-		goto loop;
 	}
 
-	ut_ad((allow_ibuf == 0) == (mutex_own(&log_sys->mutex) != 0));
+	ut_ad(!last_batch == mutex_own(&log_sys->mutex));
 
-	if (!allow_ibuf) {
+	if (!last_batch) {
 		recv_no_ibuf_operations = TRUE;
 	}
 
+	if (ulint n = recv_sys->n_addrs) {
+		const char* msg = last_batch
+			? "Starting final batch to recover "
+			: "Starting a batch to recover ";
+		ib_logf(IB_LOG_LEVEL_INFO,
+			"%s" ULINTPF " pages from redo log", msg, n);
+	}
+
 	recv_sys->apply_log_recs = TRUE;
 	recv_sys->apply_batch_on = TRUE;
 
-	for (i = 0; i < hash_get_n_cells(recv_sys->addr_hash); i++) {
-
-		for (recv_addr = static_cast<recv_addr_t*>(
-				HASH_GET_FIRST(recv_sys->addr_hash, i));
-		     recv_addr != 0;
+	for (ulint i = 0; i < hash_get_n_cells(recv_sys->addr_hash); i++) {
+		for (recv_addr_t* recv_addr = static_cast<recv_addr_t*>(
+			     HASH_GET_FIRST(recv_sys->addr_hash, i));
+		     recv_addr;
 		     recv_addr = static_cast<recv_addr_t*>(
 				HASH_GET_NEXT(addr_hash, recv_addr))) {
 
@@ -1971,24 +1964,12 @@ loop:
 			ulint	page_no = recv_addr->page_no;
 
 			if (recv_addr->state == RECV_NOT_PROCESSED) {
-				if (!has_printed) {
-					ib_logf(IB_LOG_LEVEL_INFO,
-						"Starting an apply batch"
-						" of log records"
-						" to the database...");
-					fputs("InnoDB: Progress in percent: ",
-					      stderr);
-					has_printed = TRUE;
-				}
-
-				mutex_exit(&(recv_sys->mutex));
+				mutex_exit(&recv_sys->mutex);
 
 				if (buf_page_peek(space, page_no)) {
-					buf_block_t*	block;
-
+					mtr_t		mtr;
 					mtr_start(&mtr);
-
-					block = buf_page_get(
+					buf_block_t*	block = buf_page_get(
 						space, zip_size, page_no,
 						RW_X_LATCH, &mtr);
 					buf_block_dbg_add_level(
@@ -2001,19 +1982,9 @@ loop:
 							  page_no);
 				}
 
-				mutex_enter(&(recv_sys->mutex));
+				mutex_enter(&recv_sys->mutex);
 			}
 		}
-
-		if (has_printed
-		    && (i * 100) / hash_get_n_cells(recv_sys->addr_hash)
-		    != ((i + 1) * 100)
-		    / hash_get_n_cells(recv_sys->addr_hash)) {
-
-			fprintf(stderr, "%lu ", (ulong)
-				((i * 100)
-				 / hash_get_n_cells(recv_sys->addr_hash)));
-		}
 	}
 
 	/* Wait until all the pages have been processed */
@@ -2027,12 +1998,7 @@ loop:
 		mutex_enter(&(recv_sys->mutex));
 	}
 
-	if (has_printed) {
-
-		fprintf(stderr, "\n");
-	}
-
-	if (!allow_ibuf) {
+	if (!last_batch) {
 		bool	success;
 
 		/* Flush all the file pages to disk and invalidate them in
@@ -2072,11 +2038,7 @@ loop:
 
 	recv_sys_empty_hash();
 
-	if (has_printed) {
-		fprintf(stderr, "InnoDB: Apply batch completed\n");
-	}
-
-	mutex_exit(&(recv_sys->mutex));
+	mutex_exit(&recv_sys->mutex);
 }
 #else /* !UNIV_HOTBACKUP */
 /*******************************************************************//**
@@ -2099,11 +2061,6 @@ recv_apply_log_recs_for_backup(void)
 
 	block = back_block1;
 
-	ib_logf(IB_LOG_LEVEL_INFO,
-		"Starting an apply batch of log records to the database...");
-
-	fputs("InnoDB: Progress in percent: ", stderr);
-
 	n_hash_cells = hash_get_n_cells(recv_sys->addr_hash);
 
 	for (i = 0; i < n_hash_cells; i++) {
@@ -2215,13 +2172,6 @@ recv_apply_log_recs_for_backup(void)
 skip_this_recv_addr:
 			recv_addr = HASH_GET_NEXT(addr_hash, recv_addr);
 		}
-
-		if ((100 * i) / n_hash_cells
-		    != (100 * (i + 1)) / n_hash_cells) {
-			fprintf(stderr, "%lu ",
-				(ulong) ((100 * i) / n_hash_cells));
-			fflush(stderr);
-		}
 	}
 
 	recv_sys_empty_hash();
@@ -2885,11 +2835,10 @@ recv_scan_log_recs(
 #ifndef UNIV_HOTBACKUP
 			if (recv_log_scan_is_startup_type
 			    && !recv_needed_recovery) {
-
 				if (!srv_read_only_mode) {
 					ib_logf(IB_LOG_LEVEL_INFO,
-						"Log scan progressed past the "
-						"checkpoint lsn " LSN_PF "",
+						"Starting crash recovery from "
+						"checkpoint LSN=" LSN_PF,
 						recv_sys->scanned_lsn);
 
 					recv_init_crash_recovery();
@@ -2948,19 +2897,6 @@ recv_scan_log_recs(
 
 	*group_scanned_lsn = scanned_lsn;
 
-	if (recv_needed_recovery
-	    || (recv_is_from_backup && !recv_is_making_a_backup)) {
-		recv_scan_print_counter++;
-
-		if (finished || (recv_scan_print_counter % 80 == 0)) {
-
-			fprintf(stderr,
-				"InnoDB: Doing recovery: scanned up to"
-				" log sequence number " LSN_PF "\n",
-				*group_scanned_lsn);
-		}
-	}
-
 	if (more_data && !recv_sys->found_corrupt_log) {
 		/* Try to parse more log records */
 
@@ -2976,7 +2912,7 @@ recv_scan_log_recs(
 			log yet: they would be produced by ibuf
 			operations */
 
-			recv_apply_hashed_log_recs(FALSE);
+			recv_apply_hashed_log_recs(false);
 		}
 #endif /* !UNIV_HOTBACKUP */
 
@@ -3052,11 +2988,6 @@ recv_init_crash_recovery(void)
 
 	recv_needed_recovery = TRUE;
 
-	ib_logf(IB_LOG_LEVEL_INFO, "Database was not shutdown normally!");
-	ib_logf(IB_LOG_LEVEL_INFO, "Starting crash recovery.");
-	ib_logf(IB_LOG_LEVEL_INFO,
-		"Reading tablespace information from the .ibd files...");
-
 	fil_load_single_table_tablespaces();
 
 	/* If we are using the doublewrite method, we will
@@ -3067,9 +2998,7 @@ recv_init_crash_recovery(void)
 	if (srv_force_recovery < SRV_FORCE_NO_LOG_REDO) {
 
 		ib_logf(IB_LOG_LEVEL_INFO,
-			"Restoring possible half-written data pages ");
-
-		ib_logf(IB_LOG_LEVEL_INFO,
+			"Restoring possible half-written data pages "
 			"from the doublewrite buffer...");
 
 		buf_dblwr_process();