Merge 10.0 into 10.1

Also, implement MDEV-11027 a little differently from 5.5 and 10.0:

recv_apply_hashed_log_recs(): Change the return type back to void
(DB_SUCCESS was always returned).

Report progress also via systemd using sd_notifyf().

1 files changed, 59 insertions, 159 deletions

diff --git a/storage/innobase/log/log0recv.cc b/storage/innobase/log/log0recv.cc
index 104b5b6b421..d088ae9f3df 100644
--- a/storage/innobase/log/log0recv.cc
+++ b/storage/innobase/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) 2013, 2017, MariaDB Corporation. All Rights Reserved.
+Copyright (c) 2013, 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
@@ -78,7 +78,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. */
@@ -134,9 +134,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;
@@ -311,8 +308,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;
@@ -426,6 +421,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;
 
@@ -435,33 +431,18 @@ recv_sys_init(
 	mutex_exit(&(recv_sys->mutex));
 }
 
-/********************************************************//**
-Empties the hash table when it has been fully processed.
-@return DB_SUCCESS when successfull or DB_ERROR when fails. */
+/** Empty a fully processed hash table. */
 static
-dberr_t
-recv_sys_empty_hash(void)
-/*=====================*/
+void
+recv_sys_empty_hash()
 {
 	ut_ad(mutex_own(&(recv_sys->mutex)));
-
-	if (recv_sys->n_addrs != 0) {
-		fprintf(stderr,
-			"InnoDB: Error: %lu pages with log records"
-			" were left unprocessed!\n"
-			"InnoDB: Maximum page number with"
-			" log records on it %lu\n",
-			(ulong) recv_sys->n_addrs,
-			(ulong) recv_max_parsed_page_no);
-		return DB_ERROR;
-	}
+	ut_a(recv_sys->n_addrs == 0);
 
 	hash_table_free(recv_sys->addr_hash);
 	mem_heap_empty(recv_sys->heap);
 
 	recv_sys->addr_hash = hash_create(buf_pool_get_curr_size() / 512);
-
-	return DB_SUCCESS;
 }
 
 #ifndef UNIV_HOTBACKUP
@@ -1716,7 +1697,9 @@ recv_recover_page_func(
 
 	mtr_commit(&mtr);
 
-	mutex_enter(&(recv_sys->mutex));
+	ib_time_t time = ut_time();
+
+	mutex_enter(&recv_sys->mutex);
 
 	if (recv_max_page_lsn < page_lsn) {
 		recv_max_page_lsn = page_lsn;
@@ -1724,11 +1707,17 @@ 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 (ulint n = --recv_sys->n_addrs) {
+		if (recv_sys->report(time)) {
+			ib_logf(IB_LOG_LEVEL_INFO,
+				"To recover: " ULINTPF " pages from log", n);
+			sd_notifyf(0, "STATUS=To recover: " ULINTPF
+				   " pages from log", n);
+		}
+	}
 
+	mutex_exit(&recv_sys->mutex);
 }
 
 #ifndef UNIV_HOTBACKUP
@@ -1774,62 +1763,50 @@ 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.
-@return DB_SUCCESS when successfull or DB_ERROR when fails. */
+/** 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
-dberr_t
-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 */
+void
+recv_apply_hashed_log_recs(bool last_batch)
 {
-	recv_addr_t* recv_addr;
-	ulint	i;
-	ibool	has_printed	= FALSE;
-	ulong progress;
-	mtr_t	mtr;
-	dberr_t err = DB_SUCCESS;
-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) == mutex_own(&log_sys->mutex));
+	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);
+		sd_notifyf(0, "STATUS=%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))) {
 
@@ -1838,24 +1815,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(
@@ -1868,21 +1833,9 @@ loop:
 							  page_no);
 				}
 
-				mutex_enter(&(recv_sys->mutex));
+				mutex_enter(&recv_sys->mutex);
 			}
 		}
-
-		progress = (ulong) (i * 100)
-                                   / hash_get_n_cells(recv_sys->addr_hash);
-		if (has_printed
-		    && progress
-		    != ((i + 1) * 100)
-		    / hash_get_n_cells(recv_sys->addr_hash)) {
-
-			fprintf(stderr, "%lu ", progress);
-			sd_notifyf(0, "STATUS=Applying batch of log records for"
-				   " InnoDB: Progress %lu", progress);
-		}
 	}
 
 	/* Wait until all the pages have been processed */
@@ -1896,12 +1849,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
@@ -1939,16 +1887,9 @@ loop:
 	recv_sys->apply_log_recs = FALSE;
 	recv_sys->apply_batch_on = FALSE;
 
-	err = recv_sys_empty_hash();
-
-	if (has_printed) {
-		fprintf(stderr, "InnoDB: Apply batch completed\n");
-		sd_notify(0, "STATUS=InnoDB: Apply batch completed");
-	}
-
-	mutex_exit(&(recv_sys->mutex));
+	recv_sys_empty_hash();
 
-	return err;
+	mutex_exit(&recv_sys->mutex);
 }
 #else /* !UNIV_HOTBACKUP */
 /*******************************************************************//**
@@ -1971,11 +1912,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++) {
@@ -2087,16 +2023,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);
-			sd_notifyf(0, "STATUS=Applying batch of log records for"
-				   " backup InnoDB: Progress %lu",
-				   (ulong) (100 * i) / n_hash_cells);
-		}
 	}
 	sd_notify(0, "STATUS=InnoDB: Apply batch for backup completed");
 
@@ -2797,11 +2723,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();
@@ -2861,19 +2786,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 */
 
@@ -2893,12 +2805,7 @@ recv_scan_log_recs(
 			log yet: they would be produced by ibuf
 			operations */
 
-			*err = recv_apply_hashed_log_recs(FALSE);
-
-			if (*err != DB_SUCCESS) {
-				/* Finish processing because of error */
-				return (TRUE);
-			}
+			recv_apply_hashed_log_recs(false);
 		}
 #endif /* !UNIV_HOTBACKUP */
 
@@ -2982,11 +2889,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
@@ -2997,9 +2899,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();
@@ -3984,7 +3884,7 @@ recv_recovery_from_archive_start(
 
 	if (limit_lsn != LSN_MAX) {
 
-		recv_apply_hashed_log_recs(FALSE);
+		recv_apply_hashed_log_recs(false);
 
 		recv_reset_logs(0, FALSE, recv_sys->recovered_lsn);
 	}