MDEV-23855: Use normal mutex for log_sys.mutex, log_sys.flush_order_mutex

With an unreasonably small innodb_log_file_size, the page cleaner
thread would frequently acquire log_sys.flush_order_mutex and spend
a significant portion of CPU time spinning on that mutex when
determining the checkpoint LSN.

Author: dr-m

extra/mariabackup/xtrabackup.cc

@@ -2711,7 +2711,7 @@ static bool xtrabackup_copy_logfile(bool last = false)
 
 		xtrabackup_io_throttling();
 
-		log_mutex_enter();
+		mysql_mutex_lock(&log_sys.mutex);
 		lsn_t lsn= start_lsn;
 		for (int retries= 0; retries < 100; retries++) {
 			if (log_sys.log.read_log_seg(&lsn, end_lsn)
@@ -2735,7 +2735,7 @@ static bool xtrabackup_copy_logfile(bool last = false)
 			mutex_exit(&recv_sys.mutex);
 		}
 
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 
 		if (!start_lsn) {
 			const char *reason = recv_sys.found_corrupt_log
@@ -2795,10 +2795,10 @@ static os_thread_ret_t DECLARE_THREAD(log_copying_thread)(void*)
 			break;
 		}
 
-		log_mutex_enter();
+		mysql_mutex_lock(&log_sys.mutex);
 		bool completed = metadata_to_lsn
 			&& metadata_to_lsn <= log_copy_scanned_lsn;
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 		if (completed) {
 			break;
 		}
@@ -3848,7 +3848,7 @@ static bool xtrabackup_backup_low()
 	{
 		ulint	max_cp_field;
 
-		log_mutex_enter();
+		mysql_mutex_lock(&log_sys.mutex);
 
 		if (recv_find_max_checkpoint(&max_cp_field) == DB_SUCCESS
 		    && log_sys.log.format != 0) {
@@ -3865,7 +3865,7 @@ static bool xtrabackup_backup_low()
 		} else {
 			msg("Error: recv_find_max_checkpoint() failed.");
 		}
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 	}
 
 	stop_backup_threads();
@@ -4037,20 +4037,20 @@ static bool xtrabackup_backup_func()
 	/* get current checkpoint_lsn */
 	/* Look for the latest checkpoint from any of the log groups */
 
-	log_mutex_enter();
+	mysql_mutex_lock(&log_sys.mutex);
 
 reread_log_header:
 	dberr_t err = recv_find_max_checkpoint(&max_cp_field);
 
 	if (err != DB_SUCCESS) {
 		msg("Error: cannot read redo log header");
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 		goto fail;
 	}
 
 	if (log_sys.log.format == 0) {
 		msg("Error: cannot process redo log before MariaDB 10.2.2");
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 		goto fail;
 	}
 
@@ -4067,7 +4067,7 @@ static bool xtrabackup_backup_func()
 	    != mach_read_from_8(buf + LOG_CHECKPOINT_OFFSET))
 		goto reread_log_header;
 
-	log_mutex_exit();
+	mysql_mutex_unlock(&log_sys.mutex);
 
 	xtrabackup_init_datasinks();
 
@@ -4603,7 +4603,7 @@ xb_delta_open_matching_space(
 		return OS_FILE_CLOSED;
 	}
 
-	log_mutex_enter();
+	mysql_mutex_lock(&log_sys.mutex);
 	if (!fil_is_user_tablespace_id(info.space_id)) {
 found:
 		/* open the file and return its handle */
@@ -4616,7 +4616,7 @@ xb_delta_open_matching_space(
 			msg("mariabackup: Cannot open file %s\n", real_name);
 		}
 exit:
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 		return file;
 	}
 

storage/innobase/buf/buf0flu.cc

@@ -132,7 +132,7 @@ static void buf_flush_validate_skip()
 void buf_flush_insert_into_flush_list(buf_block_t* block, lsn_t lsn)
 {
 	mysql_mutex_assert_not_owner(&buf_pool.mutex);
-	ut_ad(log_flush_order_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.flush_order_mutex);
 	ut_ad(lsn);
 
 	mysql_mutex_lock(&buf_pool.flush_list_mutex);
@@ -1564,7 +1564,7 @@ ulint buf_flush_lists(ulint max_n, lsn_t lsn)
 static bool log_checkpoint_low(lsn_t oldest_lsn, lsn_t end_lsn)
 {
   ut_ad(!srv_read_only_mode);
-  ut_ad(log_mutex_own());
+  mysql_mutex_assert_owner(&log_sys.mutex);
   ut_ad(oldest_lsn <= end_lsn);
   ut_ad(end_lsn == log_sys.get_lsn());
   ut_ad(!recv_no_log_write);
@@ -1581,7 +1581,7 @@ static bool log_checkpoint_low(lsn_t oldest_lsn, lsn_t end_lsn)
   {
     /* Do nothing, because nothing was logged (other than a
     FILE_CHECKPOINT record) since the previous checkpoint. */
-    log_mutex_exit();
+    mysql_mutex_unlock(&log_sys.mutex);
     return true;
   }
 
@@ -1602,12 +1602,12 @@ static bool log_checkpoint_low(lsn_t oldest_lsn, lsn_t end_lsn)
   {
     flush_lsn= log_sys.get_lsn();
     ut_ad(flush_lsn >= end_lsn + SIZE_OF_FILE_CHECKPOINT);
-    log_mutex_exit();
+    mysql_mutex_unlock(&log_sys.mutex);
     log_write_up_to(flush_lsn, true, true);
-    log_mutex_enter();
+    mysql_mutex_lock(&log_sys.mutex);
     if (log_sys.last_checkpoint_lsn >= oldest_lsn)
     {
-      log_mutex_exit();
+      mysql_mutex_unlock(&log_sys.mutex);
       return true;
     }
   }
@@ -1619,13 +1619,13 @@ static bool log_checkpoint_low(lsn_t oldest_lsn, lsn_t end_lsn)
   if (log_sys.n_pending_checkpoint_writes)
   {
     /* A checkpoint write is running */
-    log_mutex_exit();
+    mysql_mutex_unlock(&log_sys.mutex);
     return false;
   }
 
   log_sys.next_checkpoint_lsn= oldest_lsn;
   log_write_checkpoint_info(end_lsn);
-  ut_ad(!log_mutex_own());
+  mysql_mutex_assert_not_owner(&log_sys.mutex);
 
   return true;
 }
@@ -1649,13 +1649,13 @@ static bool log_checkpoint()
     fil_flush_file_spaces();
   }
 
-  log_mutex_enter();
+  mysql_mutex_lock(&log_sys.mutex);
   const lsn_t end_lsn= log_sys.get_lsn();
-  log_flush_order_mutex_enter();
+  mysql_mutex_lock(&log_sys.flush_order_mutex);
   mysql_mutex_lock(&buf_pool.flush_list_mutex);
   const lsn_t oldest_lsn= buf_pool.get_oldest_modification(end_lsn);
   mysql_mutex_unlock(&buf_pool.flush_list_mutex);
-  log_flush_order_mutex_exit();
+  mysql_mutex_unlock(&log_sys.flush_order_mutex);
   return log_checkpoint_low(oldest_lsn, end_lsn);
 }
 
@@ -1672,7 +1672,7 @@ ATTRIBUTE_COLD void buf_flush_wait_flushed(lsn_t sync_lsn)
 {
   ut_ad(sync_lsn);
   ut_ad(sync_lsn < LSN_MAX);
-  ut_ad(!log_mutex_own());
+  mysql_mutex_assert_not_owner(&log_sys.mutex);
   ut_ad(!srv_read_only_mode);
 
   if (recv_recovery_is_on())
@@ -1732,7 +1732,7 @@ ATTRIBUTE_COLD void buf_flush_wait_flushed(lsn_t sync_lsn)
 @param lsn buf_pool.get_oldest_modification(LSN_MAX) target */
 void buf_flush_ahead(lsn_t lsn)
 {
-  ut_ad(!log_mutex_own());
+  mysql_mutex_assert_not_owner(&log_sys.mutex);
   ut_ad(!srv_read_only_mode);
 
   if (recv_recovery_is_on())
@@ -1792,12 +1792,12 @@ ATTRIBUTE_COLD static void buf_flush_sync_for_checkpoint(lsn_t lsn)
       fil_flush_file_spaces();
     }
 
-    log_mutex_enter();
+    mysql_mutex_lock(&log_sys.mutex);
     const lsn_t newest_lsn= log_sys.get_lsn();
-    log_flush_order_mutex_enter();
+    mysql_mutex_lock(&log_sys.flush_order_mutex);
     mysql_mutex_lock(&buf_pool.flush_list_mutex);
     lsn_t measure= buf_pool.get_oldest_modification(0);
-    log_flush_order_mutex_exit();
+    mysql_mutex_unlock(&log_sys.flush_order_mutex);
     const lsn_t checkpoint_lsn= measure ? measure : newest_lsn;
 
     if (checkpoint_lsn > log_sys.last_checkpoint_lsn + SIZE_OF_FILE_CHECKPOINT)
@@ -1809,12 +1809,12 @@ ATTRIBUTE_COLD static void buf_flush_sync_for_checkpoint(lsn_t lsn)
     }
     else
     {
-      log_mutex_exit();
+      mysql_mutex_unlock(&log_sys.mutex);
       if (!measure)
         measure= LSN_MAX;
     }
 
-    ut_ad(!log_mutex_own());
+    mysql_mutex_assert_not_owner(&log_sys.mutex);
 
     /* After attempting log checkpoint, check if we have reached our target. */
     const lsn_t target= buf_flush_sync_lsn;

storage/innobase/fil/fil0fil.cc

@@ -885,18 +885,18 @@ fil_space_free(
 		}
 
 		if (!recv_recovery_is_on()) {
-			log_mutex_enter();
+			mysql_mutex_lock(&log_sys.mutex);
 		}
 
-		ut_ad(log_mutex_own());
+		mysql_mutex_assert_owner(&log_sys.mutex);
 
 		if (space->max_lsn != 0) {
 			ut_d(space->max_lsn = 0);
 			UT_LIST_REMOVE(fil_system.named_spaces, space);
 		}
 
 		if (!recv_recovery_is_on()) {
-			log_mutex_exit();
+			mysql_mutex_unlock(&log_sys.mutex);
 		}
 
 		fil_space_free_low(space);
@@ -1916,14 +1916,14 @@ dberr_t fil_delete_tablespace(ulint id, bool if_exists,
 		}
 		mutex_exit(&fil_system.mutex);
 
-		log_mutex_enter();
+		mysql_mutex_lock(&log_sys.mutex);
 
 		if (space->max_lsn != 0) {
 			ut_d(space->max_lsn = 0);
 			UT_LIST_REMOVE(fil_system.named_spaces, space);
 		}
 
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 		fil_space_free_low(space);
 
 		if (!os_file_delete(innodb_data_file_key, path)
@@ -2204,11 +2204,11 @@ fil_rename_tablespace(
 
 	if (!recv_recovery_is_on()) {
 		fil_name_write_rename(id, old_file_name, new_file_name);
-		log_mutex_enter();
+		mysql_mutex_lock(&log_sys.mutex);
 	}
 
 	/* log_sys.mutex is above fil_system.mutex in the latching order */
-	ut_ad(log_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.mutex);
 	mutex_enter(&fil_system.mutex);
 	space->release();
 	ut_ad(space->name == old_space_name);
@@ -2230,7 +2230,7 @@ fil_rename_tablespace(
 	}
 
 	if (!recv_recovery_is_on()) {
-		log_mutex_exit();
+		mysql_mutex_unlock(&log_sys.mutex);
 	}
 
 	ut_ad(space->name == old_space_name);
@@ -3667,7 +3667,7 @@ void
 fil_names_dirty(
 	fil_space_t*	space)
 {
-	ut_ad(log_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.mutex);
 	ut_ad(recv_recovery_is_on());
 	ut_ad(log_sys.get_lsn() != 0);
 	ut_ad(space->max_lsn == 0);
@@ -3683,7 +3683,7 @@ fil_names_clear().
 @param[in,out]	space	tablespace */
 void fil_names_dirty_and_write(fil_space_t* space)
 {
-	ut_ad(log_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.mutex);
 	ut_d(fil_space_validate_for_mtr_commit(space));
 	ut_ad(space->max_lsn == log_sys.get_lsn());
 
@@ -3724,7 +3724,7 @@ fil_names_clear(
 		mtr_checkpoint_size = 75 * 1024;
 		);
 
-	ut_ad(log_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.mutex);
 	ut_ad(lsn);
 
 	mtr.start();

storage/innobase/include/fil0fil.h

@@ -1780,7 +1780,7 @@ for the first time since the latest fil_names_clear().
 @return whether any FILE_MODIFY record was written */
 inline bool fil_names_write_if_was_clean(fil_space_t* space)
 {
-	ut_ad(log_mutex_own());
+	mysql_mutex_assert_owner(&log_sys.mutex);
 
 	if (space == NULL) {
 		return(false);