Bug#35916912 Performance degradation from 8.0.30 onwards related to performance_schema

This fix reduces performance overhead of the statement instrumentation,
in the performance_schema implementation.

Problem
=======

1)

The new g_telemetry global atomic pointer is not protected against false
sharing on the CPU cache line.

2)

The statement instrumentation makes unnecessary copies of MESSAGE_TEXT,
which is using 512 bytes, and is most of the time empty.

Fix
===

1)

Declared g_telemetry using a dedicated cache line, to avoid false sharing.

This helps because this atomic is expected to be "read only",
and will not change during the server lifetime except when installing
or uninstalling a telemetry component.

Keeping a shared copy in each CPU cache should reduce the atomic overhead.

2)

The diagnostics area has been fixed to keep track of the message text
length.

The performance schema instrumentation now only copies the message text
when it is not empty, saving overhead in memcpy().

The data layout in events_statements_current / history / history_long
has changed to improve data locality for other attributes,
and also reduce overhead in memcpy().

Change-Id: I6a80af3547e98eccbb1e39c806f603462b665cef

Author: marcalff

sql/sql_error.cc

@@ -347,6 +347,7 @@ Diagnostics_area::Diagnostics_area(bool allow_unlimited_conditions)
   memset(m_current_statement_cond_count_by_qb, 0,
          sizeof(m_current_statement_cond_count_by_qb));
   m_message_text[0] = '\0';
+  m_message_text_length = 0;
 }
 
 Diagnostics_area::~Diagnostics_area() {}
@@ -357,6 +358,7 @@ void Diagnostics_area::reset_diagnostics_area() {
   set_overwrite_status(false);
   // Don't take chances in production.
   m_message_text[0] = '\0';
+  m_message_text_length = 0;
   m_mysql_errno = 0;
   m_affected_rows = 0;
   m_last_insert_id = 0;
@@ -381,10 +383,13 @@ void Diagnostics_area::set_ok_status(ulonglong affected_rows,
   m_last_statement_cond_count = current_statement_cond_count();
   m_affected_rows = affected_rows;
   m_last_insert_id = last_insert_id;
-  if (message_text)
+  if (message_text) {
     strmake(m_message_text, message_text, sizeof(m_message_text) - 1);
-  else
+    m_message_text_length = strlen(m_message_text);
+  } else {
     m_message_text[0] = '\0';
+    m_message_text_length = 0;
+  }
   m_status = DA_OK;
 }
 
@@ -443,6 +448,7 @@ void Diagnostics_area::set_error_status(uint mysql_errno,
   memcpy(m_returned_sqlstate, returned_sqlstate, SQLSTATE_LENGTH);
   m_returned_sqlstate[SQLSTATE_LENGTH] = '\0';
   strmake(m_message_text, message_text, sizeof(m_message_text) - 1);
+  m_message_text_length = strlen(m_message_text);
 
   m_status = DA_ERROR;
 }

sql/sql_error.h

@@ -377,6 +377,11 @@ class Diagnostics_area {
     return m_message_text;
   }
 
+  uint message_text_length() const {
+    assert(m_status == DA_ERROR || m_status == DA_OK);
+    return m_message_text_length;
+  }
+
   uint mysql_errno() const {
     assert(m_status == DA_ERROR);
     return m_mysql_errno;
@@ -624,6 +629,11 @@ class Diagnostics_area {
   */
   char m_message_text[MYSQL_ERRMSG_SIZE];
 
+  /**
+    Length, in bytes, of m_message_text.
+  */
+  uint m_message_text_length;
+
   /**
     SQL RETURNED_SQLSTATE condition item.
     This member is always NUL terminated.

storage/perfschema/mysql_server_telemetry_traces_service_imp.cc

@@ -199,7 +199,7 @@ bool server_telemetry_traces_service_initialized = false;
 #endif /* HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE */
 
 // currently registered collection of telemetry trace callbacks
-std::atomic<telemetry_t *> g_telemetry = nullptr;
+PFS_ALIGNED PFS_cacheline_atomic_ptr<telemetry_t *> g_telemetry;
 
 // locking for callback register/unregister
 mysql_mutex_t LOCK_pfs_tracing_callback;
@@ -213,7 +213,7 @@ static PSI_mutex_info info_LOCK_pfs_tracing_callback = {
 
 void initialize_mysql_server_telemetry_traces_service() {
 #ifdef HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE
-  g_telemetry = nullptr;
+  g_telemetry.m_ptr = nullptr;
 
   assert(!server_telemetry_traces_service_initialized);
 
@@ -231,7 +231,7 @@ void cleanup_mysql_server_telemetry_traces_service() {
     mysql_mutex_destroy(&LOCK_pfs_tracing_callback);
     server_telemetry_traces_service_initialized = false;
   }
-  g_telemetry = nullptr;
+  g_telemetry.m_ptr = nullptr;
 #endif /* HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE */
 }
 
@@ -254,7 +254,7 @@ bool impl_register_telemetry(telemetry_t *telemetry [[maybe_unused]]) {
   // telemetry available, if we would need to uninstall previous component using
   // this before installing new one
   mysql_mutex_lock(&LOCK_pfs_tracing_callback);
-  g_telemetry = telemetry;
+  g_telemetry.m_ptr = telemetry;
   mysql_mutex_unlock(&LOCK_pfs_tracing_callback);
   // Success
   return false;
@@ -268,8 +268,8 @@ bool impl_unregister_telemetry(telemetry_t *telemetry [[maybe_unused]]) {
 #ifdef HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE
   if (!server_telemetry_traces_service_initialized) return true;
   mysql_mutex_lock(&LOCK_pfs_tracing_callback);
-  if (g_telemetry == telemetry) {
-    g_telemetry = nullptr;
+  if (g_telemetry.m_ptr == telemetry) {
+    g_telemetry.m_ptr = nullptr;
     mysql_mutex_unlock(&LOCK_pfs_tracing_callback);
     // Success
     return false;

storage/perfschema/mysql_server_telemetry_traces_service_imp.h

@@ -26,6 +26,8 @@
 #include <mysql/components/services/mysql_server_telemetry_traces_service.h>
 #include <mysql/plugin.h>
 
+#include "pfs_global.h"
+
 /**
   @file storage/perfschema/mysql_server_telemetry_traces_service_imp.h
   The performance schema implementation of server telemetry traces service.
@@ -45,7 +47,7 @@ bool impl_unregister_telemetry(telemetry_t *telemetry);
 
 extern mysql_mutex_t LOCK_pfs_tracing_callback;
 #ifdef HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE
-extern std::atomic<telemetry_t *> g_telemetry;
+extern PFS_cacheline_atomic_ptr<telemetry_t *> g_telemetry;
 #endif /* HAVE_PSI_SERVER_TELEMETRY_TRACES_INTERFACE */
 
 #endif /* MYSQL_SERVER_TELEMETRY_TRACES_SERVICE_IMP_H */

storage/perfschema/pfs.cc

@@ -3672,14 +3672,14 @@ void pfs_detect_telemetry_vc(PSI_thread *thread [[maybe_unused]]) {
   assert(pfs_thread != nullptr);
 
   // Dirty read
-  telemetry_t *actual_telemetry = g_telemetry.load();
+  telemetry_t *actual_telemetry = g_telemetry.m_ptr.load();
 
   telemetry_t *expected_telemetry = pfs_thread->m_telemetry;
 
   if (actual_telemetry != expected_telemetry) {
     server_telemetry_tracing_lock();
     // Safe read
-    actual_telemetry = g_telemetry.load();
+    actual_telemetry = g_telemetry.m_ptr.load();
     if (actual_telemetry != expected_telemetry) {
       if (expected_telemetry == nullptr) {
         pfs_thread->m_telemetry = actual_telemetry;
@@ -6608,6 +6608,7 @@ void pfs_start_statement_vc(PSI_statement_locker *locker, const char *db,
       pfs->m_sqltext_cs_number = system_charset_info->number; /* default */
 
       pfs->m_message_text[0] = '\0';
+      pfs->m_message_text_length = 0;
       pfs->m_sql_errno = 0;
       pfs->m_sqlstate[0] = '\0';
       pfs->m_error_count = 0;
@@ -6957,15 +6958,22 @@ void pfs_end_statement_vc(PSI_statement_locker *locker, void *stmt_da) {
             reinterpret_cast<PFS_events_statements *>(state->m_statement);
         assert(pfs != nullptr);
 
+        size_t message_text_length;
         pfs_dirty_state dirty_state;
         thread->m_stmt_lock.allocated_to_dirty(&dirty_state);
 
         switch (da->status()) {
           case Diagnostics_area::DA_EMPTY:
             break;
           case Diagnostics_area::DA_OK:
-            memcpy(pfs->m_message_text, da->message_text(), MYSQL_ERRMSG_SIZE);
-            pfs->m_message_text[MYSQL_ERRMSG_SIZE] = 0;
+            message_text_length = da->message_text_length();
+            if (message_text_length > 0) {
+              memcpy(pfs->m_message_text, da->message_text(),
+                     message_text_length);
+            }
+            pfs->m_message_text[message_text_length] = '\0';
+            pfs->m_message_text_length = message_text_length;
+
             pfs->m_rows_affected = da->affected_rows();
             pfs->m_warning_count = da->last_statement_cond_count();
             memcpy(pfs->m_sqlstate, "00000", SQLSTATE_LENGTH);
@@ -6974,8 +6982,14 @@ void pfs_end_statement_vc(PSI_statement_locker *locker, void *stmt_da) {
             pfs->m_warning_count = da->last_statement_cond_count();
             break;
           case Diagnostics_area::DA_ERROR:
-            memcpy(pfs->m_message_text, da->message_text(), MYSQL_ERRMSG_SIZE);
-            pfs->m_message_text[MYSQL_ERRMSG_SIZE] = 0;
+            message_text_length = da->message_text_length();
+            if (message_text_length > 0) {
+              memcpy(pfs->m_message_text, da->message_text(),
+                     message_text_length);
+            }
+            pfs->m_message_text[message_text_length] = '\0';
+            pfs->m_message_text_length = message_text_length;
+
             pfs->m_sql_errno = da->mysql_errno();
             memcpy(pfs->m_sqlstate, da->returned_sqlstate(), SQLSTATE_LENGTH);
             pfs->m_error_count++;

storage/perfschema/pfs_events_statements.cc

@@ -153,7 +153,7 @@ void cleanup_events_statements_history_long() {
 
 static inline void copy_events_statements(PFS_events_statements *dest,
                                           const PFS_events_statements *source) {
-  /* Copy all attributes except SQL TEXT and DIGEST */
+  /* Copy all attributes except SQL TEXT, DIGEST and MESSAGE_TEXT */
   dest->PFS_events::operator=(*source);
   memcpy(&dest->m_statement_id, &source->m_statement_id,
          pointer_cast<const char *>(&source->m_sqltext) -
@@ -171,6 +171,15 @@ static inline void copy_events_statements(PFS_events_statements *dest,
 
   /* Copy DIGEST */
   dest->m_digest_storage.copy(&source->m_digest_storage);
+
+  /* Copy MESSAGE_TEXT */
+  const uint message_text_length = source->m_message_text_length;
+
+  if (message_text_length > 0) {
+    memcpy(dest->m_message_text, source->m_message_text, message_text_length);
+  }
+  dest->m_message_text[message_text_length] = '\0';
+  dest->m_message_text_length = message_text_length;
 }
 
 /**

storage/perfschema/pfs_events_statements.h

@@ -63,8 +63,6 @@ struct PFS_events_statements : public PFS_events {
   /** Locked time. */
   ulonglong m_lock_time;
 
-  /** Diagnostics area, message text. */
-  char m_message_text[MYSQL_ERRMSG_SIZE + 1];
   /** Diagnostics area, error number. */
   uint m_sql_errno;
   /** Diagnostics area, @c SQLSTATE. */
@@ -144,6 +142,14 @@ struct PFS_events_statements : public PFS_events {
     and always point to pre allocated memory.
   */
   sql_digest_storage m_digest_storage;
+
+  /**
+    Length of @c m_message_text.
+    This is placed __before__ m_message_text[], for data locality.
+  */
+  uint m_message_text_length;
+  /** Diagnostics area, message text. */
+  char m_message_text[MYSQL_ERRMSG_SIZE + 1];
 };
 
 void insert_events_statements_history(PFS_thread *thread,

storage/perfschema/pfs_global.h

@@ -102,6 +102,18 @@ struct PFS_cacheline_atomic_size_t {
   PFS_cacheline_atomic_size_t() : m_size_t(0) {}
 };
 
+/**
+  An atomic<T> variable, guaranteed to be alone in a CPU cache line.
+  This is for performance, for variables accessed very frequently.
+*/
+template <class T>
+struct PFS_cacheline_atomic_ptr {
+  std::atomic<T> m_ptr;
+  char m_full_cache_line[PFS_CACHE_LINE_SIZE - sizeof(std::atomic<T>)];
+
+  PFS_cacheline_atomic_ptr() : m_ptr(nullptr) {}
+};
+
 struct PFS_builtin_memory_class;
 
 /** Memory allocation for the performance schema. */

storage/perfschema/table_events_statements.cc

@@ -342,8 +342,13 @@ int table_events_statements_common::make_row_part_1(
                      m_row.m_source, sizeof(m_row.m_source),
                      m_row.m_source_length);
 
-  memcpy(m_row.m_message_text, statement->m_message_text,
-         sizeof(m_row.m_message_text));
+  m_row.m_message_text_length = statement->m_message_text_length;
+  if (m_row.m_message_text_length > 0) {
+    memcpy(m_row.m_message_text, statement->m_message_text,
+           m_row.m_message_text_length);
+  }
+  m_row.m_message_text[m_row.m_message_text_length] = '\0';
+
   memcpy(m_row.m_sqlstate, statement->m_sqlstate, SQLSTATE_LENGTH);
 
   m_row.m_sql_errno = statement->m_sql_errno;
@@ -532,7 +537,7 @@ int table_events_statements_common::read_row_values(TABLE *table,
           }
           break;
         case 19: /* MESSAGE_TEXT */
-          len = (uint)strlen(m_row.m_message_text);
+          len = m_row.m_message_text_length;
           if (len) {
             set_field_varchar_utf8mb4(f, m_row.m_message_text, len);
           } else {

storage/perfschema/table_events_statements.h

@@ -116,6 +116,7 @@ struct row_events_statements {
 
   /** Column MESSAGE_TEXT. */
   char m_message_text[MYSQL_ERRMSG_SIZE + 1];
+  uint m_message_text_length;
   /** Column MYSQL_ERRNO. */
   uint m_sql_errno;
   /** Column RETURNED_SQLSTATE. */

storage/perfschema/unittest/stub_server_telemetry.h

@@ -33,4 +33,4 @@ SERVICE_TYPE(mysql_server_telemetry_traces_v1)
 SERVICE_IMPLEMENTATION(performance_schema, mysql_server_telemetry_traces_v1){
     nullptr, nullptr, nullptr};
 
-std::atomic<telemetry_t *> g_telemetry = nullptr;
+PFS_cacheline_atomic_ptr<telemetry_t *> g_telemetry;