MDEV-39040 log_sys.latch performance lost to PERFORMANCE_SCHEMA

extra/mariabackup/xtrabackup.cc

@@ -5515,7 +5515,7 @@ static bool xtrabackup_backup_func()
 
 	/* get current checkpoint_lsn */
 	{
-		log_sys.latch.wr_lock(SRW_LOCK_CALL);
+		log_sys.latch.wr_lock();
 		mysql_mutex_lock(&recv_sys.mutex);
 		dberr_t err = recv_sys.find_checkpoint();
 		log_sys.latch.wr_unlock();

mysql-test/suite/perfschema/r/sxlock_func.result

@@ -10,7 +10,6 @@ name
 wait/synch/rwlock/innodb/dict_operation_lock
 wait/synch/rwlock/innodb/fil_space_latch
 wait/synch/rwlock/innodb/lock_latch
-wait/synch/rwlock/innodb/log_latch
 wait/synch/rwlock/innodb/trx_i_s_cache_lock
 wait/synch/rwlock/innodb/trx_purge_latch
 wait/synch/rwlock/innodb/trx_rseg_latch
@@ -44,7 +43,6 @@ ORDER BY event_name;
 event_name
 wait/synch/rwlock/innodb/fil_space_latch
 wait/synch/rwlock/innodb/lock_latch
-wait/synch/rwlock/innodb/log_latch
 SELECT event_name FROM performance_schema.events_waits_history_long
 WHERE event_name = 'wait/synch/sxlock/innodb/index_tree_rw_lock'
 AND operation IN ('try_shared_lock','shared_lock') LIMIT 1;

storage/innobase/buf/buf0flu.cc

@@ -1854,7 +1854,7 @@ inline void log_t::write_checkpoint(lsn_t checkpoint, lsn_t end_lsn) noexcept
 
     if (srv_file_flush_method != SRV_O_DSYNC)
       ut_a(log.flush());
-    latch.wr_lock(SRW_LOCK_CALL);
+    latch.wr_lock();
     resizing= resize_lsn.load(std::memory_order_relaxed);
   }
 
@@ -2009,7 +2009,7 @@ static void log_checkpoint_low(lsn_t oldest_lsn, lsn_t end_lsn) noexcept
   {
     log_sys.latch.wr_unlock();
     log_write_up_to(flush_lsn, true);
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
   }
 
   ut_ad(oldest_lsn > log_sys.last_checkpoint_lsn);
@@ -2042,7 +2042,7 @@ static void log_checkpoint() noexcept
     fil_flush_file_spaces();
   }
 
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   const lsn_t end_lsn= log_sys.get_lsn();
   mysql_mutex_lock(&buf_pool.flush_list_mutex);
   const lsn_t oldest_lsn= buf_pool.get_oldest_modification(end_lsn);
@@ -2089,7 +2089,7 @@ ATTRIBUTE_COLD void buf_flush_wait(lsn_t lsn, bool checkpoint) noexcept
     mysql_mutex_unlock(&buf_pool.flush_list_mutex);
     os_aio_wait_until_no_pending_writes(false);
 
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     mysql_mutex_lock(&buf_pool.flush_list_mutex);
 
     if (checkpoint)
@@ -2216,7 +2216,7 @@ static void buf_flush_sync_for_checkpoint(lsn_t lsn) noexcept
     fil_flush_file_spaces();
   }
 
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   const lsn_t newest_lsn= log_sys.get_lsn();
   mysql_mutex_lock(&buf_pool.flush_list_mutex);
   lsn_t measure= buf_pool.get_oldest_modification(0);
@@ -2228,7 +2228,7 @@ static void buf_flush_sync_for_checkpoint(lsn_t lsn) noexcept
   {
     mysql_mutex_unlock(&buf_pool.flush_list_mutex);
     log_checkpoint_low(checkpoint_lsn, newest_lsn);
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     mysql_mutex_lock(&buf_pool.flush_list_mutex);
     measure= buf_pool.get_oldest_modification(0);
   }
@@ -2791,7 +2791,7 @@ ATTRIBUTE_COLD void buf_flush_sync_batch(lsn_t lsn, bool checkpoint) noexcept
 {
   thd_wait_begin(nullptr, THD_WAIT_DISKIO);
   tpool::tpool_wait_begin();
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   lsn= std::max(lsn, log_sys.get_lsn());
   mysql_mutex_lock(&buf_pool.flush_list_mutex);
   buf_flush_wait(lsn, checkpoint);

storage/innobase/fil/fil0fil.cc

@@ -917,7 +917,7 @@ bool fil_space_free(uint32_t id, bool x_latched) noexcept
 		}
 
 		if (!recv_recovery_is_on()) {
-			log_sys.latch.wr_lock(SRW_LOCK_CALL);
+			log_sys.latch.wr_lock();
 
 			if (space->max_lsn) {
 				ut_d(space->max_lsn = 0);
@@ -1596,7 +1596,7 @@ fil_space_t *fil_space_t::drop(uint32_t id, pfs_os_file_t *detached_handle)
   fil_system.named_spaces. Before we set the STOPPING_WRITES flag, another
   concurrent operation could have marked the tablespace dirty again.
   This clean-up corresponds to fil_space_free(). */
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   ut_ad((space->pending() & ~NEEDS_FSYNC) == (STOPPING | CLOSING));
   if (space->max_lsn != 0)
   {

storage/innobase/fsp/fsp0sysspace.cc

@@ -616,7 +616,7 @@ inline dberr_t SysTablespace::read_lsn_and_check_flags()
 	if (!log_sys.file_size && log_sys.format == log_t::FORMAT_3_23
 	    && srv_operation == SRV_OPERATION_NORMAL
 	    && srv_force_recovery < SRV_FORCE_NO_LOG_REDO) {
-		log_sys.latch.wr_lock(SRW_LOCK_CALL);
+		log_sys.latch.wr_lock();
 		/* Upgrade from 0-sized ib_logfile0. */
 		log_sys.last_checkpoint_lsn = mach_read_from_8(
 			first_page + 26/*FIL_PAGE_FILE_FLUSH_LSN*/);

storage/innobase/handler/ha_innodb.cc

@@ -243,7 +243,7 @@ static void innodb_max_purge_lag_wait_update(THD *thd, st_mysql_sys_var *,
     if (thd_kill_level(thd))
       break;
     /* Adjust for purge_coordinator_state::refresh() */
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     const lsn_t last= log_sys.last_checkpoint_lsn,
       max_age= log_sys.max_checkpoint_age;
     const lsn_t lsn= log_sys.get_lsn();
@@ -616,7 +616,6 @@ mysql_pfs_key_t trx_i_s_cache_lock_key;
 mysql_pfs_key_t	trx_purge_latch_key;
 mysql_pfs_key_t trx_rseg_latch_key;
 mysql_pfs_key_t lock_latch_key;
-mysql_pfs_key_t	log_latch_key;
 
 /* all_innodb_rwlocks array contains rwlocks that are
 performance schema instrumented if "UNIV_PFS_RWLOCK"
@@ -632,7 +631,6 @@ static PSI_rwlock_info all_innodb_rwlocks[] =
   { &trx_purge_latch_key, "trx_purge_latch", 0 },
   { &trx_rseg_latch_key, "trx_rseg_latch", 0 },
   { &lock_latch_key, "lock_latch", 0 },
-  { &log_latch_key, "log_latch", 0 },
   { &index_tree_rw_lock_key, "index_tree_rw_lock", PSI_RWLOCK_FLAG_SX }
 };
 # endif /* UNIV_PFS_RWLOCK */
@@ -4736,7 +4734,7 @@ checkpoint complete when we have flushed the redo log.
 If we have already flushed all relevant redo log, we notify immediately.*/
 static void innodb_log_flush_request(void *cookie) noexcept
 {
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   lsn_t flush_lsn= log_sys.get_flushed_lsn();
   /* Load lsn relaxed after flush_lsn was loaded from the same cache line */
   const lsn_t lsn= log_sys.get_lsn();
@@ -18467,7 +18465,7 @@ checkpoint_now_set(THD* thd, st_mysql_sys_var*, void*, const void *save)
   mysql_mutex_unlock(&LOCK_global_system_variables);
   while (!thd_kill_level(thd))
   {
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     lsn_t cp= log_sys.last_checkpoint_lsn.load(std::memory_order_relaxed),
       lsn= log_sys.get_lsn();
     log_sys.latch.wr_unlock();
@@ -18694,7 +18692,7 @@ static void innodb_log_file_size_update(THD *thd, st_mysql_sys_var*,
         mysql_mutex_unlock(&buf_pool.flush_list_mutex);
         if (!resizing || !log_sys.resize_running(thd))
           break;
-        log_sys.latch.wr_lock(SRW_LOCK_CALL);
+        log_sys.latch.wr_lock();
         while (resizing > log_sys.get_lsn())
         {
           ut_ad(!log_sys.is_mmap());

storage/innobase/include/log0log.h

@@ -195,14 +195,14 @@ struct log_t
   /** log file size in bytes, including the header */
   lsn_t file_size;
 
-#ifdef LOG_LATCH_DEBUG
-  typedef srw_lock_debug log_rwlock;
+#if defined LOG_LATCH_DEBUG && defined UNIV_DEBUG
+  typedef srw_lock_debug_simple log_rwlock;
 
   bool latch_have_wr() const { return latch.have_wr(); }
   bool latch_have_rd() const { return latch.have_rd(); }
   bool latch_have_any() const { return latch.have_any(); }
 #else
-  typedef srw_lock log_rwlock;
+  typedef srw_lock_low log_rwlock;
 # ifndef UNIV_DEBUG
 # elif defined SUX_LOCK_GENERIC
   bool latch_have_wr() const { return true; }

storage/innobase/include/srw_lock.h

@@ -622,4 +622,54 @@ class srw_lock_debug : private srw_lock
   /** @return whether this thread is holding rd_lock() or wr_lock() */
   bool have_any() const noexcept;
 };
+
+# ifndef LOG_LATCH_DEBUG
+# elif !defined UNIV_PFS_RWLOCK
+typedef srw_lock_debug srw_lock_debug_simple;
+# else
+class srw_lock_debug_simple : private ssux_lock_impl<false>
+{
+  /** The owner of the exclusive lock (0 if none) */
+  std::atomic<pthread_t> writer;
+  /** Protects readers */
+  mutable srw_mutex readers_lock;
+  /** Threads that hold the lock in shared mode */
+  std::atomic<std::unordered_multiset<pthread_t>*> readers;
+
+  /** Register a read lock. */
+  void readers_register() noexcept;
+
+public:
+  void init() noexcept;
+  void destroy() noexcept;
+
+#ifndef SUX_LOCK_GENERIC
+  /** @return whether any lock may be held by any thread */
+  bool is_locked_or_waiting() const noexcept
+  { return ssux_lock_impl::is_locked_or_waiting(); }
+  /** @return whether an exclusive lock may be held by any thread */
+  bool is_write_locked() const noexcept
+  { return ssux_lock_impl::is_write_locked(); }
+#endif
+
+  /** Acquire an exclusive lock */
+  void wr_lock() noexcept;
+  /** @return whether an exclusive lock was acquired */
+  bool wr_lock_try() noexcept;
+  /** Release after wr_lock() */
+  void wr_unlock() noexcept;
+  /** Acquire a shared lock */
+  void rd_lock() noexcept;
+  /** @return whether a shared lock was acquired */
+  bool rd_lock_try() noexcept;
+  /** Release after rd_lock() */
+  void rd_unlock() noexcept;
+  /** @return whether this thread is between rd_lock() and rd_unlock() */
+  bool have_rd() const noexcept;
+  /** @return whether this thread is between wr_lock() and wr_unlock() */
+  bool have_wr() const noexcept;
+  /** @return whether this thread is holding rd_lock() or wr_lock() */
+  bool have_any() const noexcept;
+};
+# endif
 #endif

storage/innobase/include/univ.i

@@ -496,7 +496,6 @@ extern mysql_pfs_key_t index_tree_rw_lock_key;
 extern mysql_pfs_key_t index_online_log_key;
 extern mysql_pfs_key_t trx_sys_rw_lock_key;
 extern mysql_pfs_key_t lock_latch_key;
-extern mysql_pfs_key_t log_latch_key;
 extern mysql_pfs_key_t trx_rseg_latch_key;
 # endif /* UNIV_PFS_RWLOCK */
 #endif /* HAVE_PSI_INTERFACE */

storage/innobase/log/log0log.cc

@@ -92,7 +92,7 @@ void log_t::create() noexcept
   ut_ad(this == &log_sys);
   ut_ad(!is_initialised());
 
-  latch.SRW_LOCK_INIT(log_latch_key);
+  latch.init();
   write_lsn_offset= 0;
   /* LSN 0 and 1 are reserved; @see buf_page_t::oldest_modification_ */
   base_lsn.store(FIRST_LSN, std::memory_order_relaxed);
@@ -504,7 +504,7 @@ void log_t::close_file(bool really_close) noexcept
 /** @return the current log sequence number (may be stale) */
 lsn_t log_get_lsn() noexcept
 {
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   lsn_t lsn= log_sys.get_lsn();
   log_sys.latch.wr_unlock();
   return lsn;
@@ -523,7 +523,7 @@ static void log_resize_acquire() noexcept
            group_commit_lock::ACQUIRED);
   }
 
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
 }
 
 /** Release the latches that protect the log. */
@@ -924,7 +924,7 @@ void log_t::persist(lsn_t lsn) noexcept
 ATTRIBUTE_NOINLINE
 static void log_write_persist(lsn_t lsn) noexcept
 {
-  log_sys.latch.wr_lock(SRW_LOCK_CALL);
+  log_sys.latch.wr_lock();
   log_sys.persist(lsn);
   log_sys.latch.wr_unlock();
 }
@@ -1167,7 +1167,7 @@ void log_write_up_to(lsn_t lsn, bool durable,
   if (write_lock.acquire(lsn, durable ? nullptr : callback) ==
       group_commit_lock::ACQUIRED)
   {
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     pending_write_lsn= write_lock.release(log_sys.writer());
   }
 
@@ -1231,7 +1231,7 @@ void log_t::clear_mmap() noexcept
 #ifdef HAVE_PMEM
   if (!is_opened())
   {
-    ut_d(latch.wr_lock(SRW_LOCK_CALL));
+    ut_d(latch.wr_lock());
     ut_ad(!resize_in_progress());
     ut_ad(get_lsn() == get_flushed_lsn(std::memory_order_relaxed));
     ut_d(latch.wr_unlock());
@@ -1299,7 +1299,7 @@ ATTRIBUTE_COLD void log_t::checkpoint_margin() noexcept
 
   while (check_for_checkpoint())
   {
-    latch.wr_lock(SRW_LOCK_CALL);
+    latch.wr_lock();
     ut_ad(!recv_no_log_write);
 
     if (!check_for_checkpoint())
@@ -1509,7 +1509,7 @@ log_print(
 /*======*/
 	FILE*	file)	/*!< in: file where to print */
 {
-	log_sys.latch.wr_lock(SRW_LOCK_CALL);
+	log_sys.latch.wr_lock();
 
 	const lsn_t lsn= log_sys.get_lsn();
 	mysql_mutex_lock(&buf_pool.flush_list_mutex);

storage/innobase/log/log0recv.cc

@@ -810,7 +810,7 @@ static struct
     log_sys.latch.wr_unlock();
     fil_space_t *space= fil_system.sys_space;
     buf_block_t *free_block= buf_LRU_get_free_block(false);
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
     mysql_mutex_lock(&recv_sys.mutex);
 
     for (auto d= defers.begin(); d != defers.end(); )
@@ -3898,7 +3898,7 @@ bool recv_sys_t::apply_batch(uint32_t space_id, fil_space_t *&space,
   unlock_relock:
     mysql_mutex_unlock(&mutex);
   relock:
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
   relock_last:
     mysql_mutex_lock(&mutex);
   get_last:
@@ -4178,7 +4178,7 @@ void recv_sys_t::apply(bool last_batch)
         recv_sys.mutex. */
         free_block= buf_LRU_get_free_block(false);
         if (!last_batch)
-          log_sys.latch.wr_lock(SRW_LOCK_CALL);
+          log_sys.latch.wr_lock();
         mysql_mutex_lock(&mutex);
         pages_it= pages.begin();
       }
@@ -4235,7 +4235,7 @@ void recv_sys_t::apply(bool last_batch)
   {
     buf_flush_sync_batch(lsn, false);
     buf_pool_invalidate();
-    log_sys.latch.wr_lock(SRW_LOCK_CALL);
+    log_sys.latch.wr_lock();
   }
   else if (srv_operation == SRV_OPERATION_RESTORE ||
            srv_operation == SRV_OPERATION_RESTORE_EXPORT)
@@ -4835,7 +4835,7 @@ dberr_t recv_recovery_from_checkpoint_start()
 
 	recv_sys.recovery_on = true;
 
-	log_sys.latch.wr_lock(SRW_LOCK_CALL);
+	log_sys.latch.wr_lock();
 	log_sys.set_capacity();
 
 	/* Start reading the log from the checkpoint lsn. */