WL#11009 - Logging services: log writers: add error ID to traditional error log

Follow-up patch to add error ID to the error messages logged from the
plugins.

As part of this patch, error logging is changed in the following
plugins to log error message with the new error IDs introduced:

  Rewriter
  connection_control
  Xplugin
  Keyring plugins
  Group Replication
  authentication_ldap

RB: 18531

Author: phulakun

include/mysql/components/services/log_builtins.h

@@ -1,4 +1,4 @@
-/* Copyright (c) 2017, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2017, 2018, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License, version 2.0,
@@ -713,6 +713,15 @@ extern SERVICE_TYPE(log_builtins_string) *log_bs;
             .lookup_quoted(ecode, "Plugin " LOG_SUBSYSTEM_TAG " reported",\
                            ## __VA_ARGS__)
 
+#define LogPluginErrV(severity, ecode, vl) \
+  LogEvent().prio(severity)\
+            .errcode(ecode)\
+            .subsys(LOG_SUBSYSTEM_TAG)\
+            .source_line(__LINE__)\
+            .source_file(MY_BASENAME)\
+            .function(__FUNCTION__)\
+            .lookup_quotedv(ecode, "Plugin " LOG_SUBSYSTEM_TAG " reported", vl)
+
 #define LogPluginErrMsg(severity, ecode, ...) \
   LogEvent().prio(severity)\
             .errcode(ecode)\
@@ -736,6 +745,8 @@ inline void dummy_log_message(longlong severity MY_ATTRIBUTE((unused)),
   dummy_log_message(severity, ecode, ## __VA_ARGS__)
 #define LogPluginErr(severity, ecode, ...) \
   dummy_log_message(severity, ecode, ## __VA_ARGS__)
+#define LogPluginErrV(severity, ecode, ...) \
+  dummy_log_message(severity, ecode, ## __VA_ARGS__)
 #define LogPluginErrMsg(severity, ecode, ...) \
   dummy_log_message(severity, ecode, ## __VA_ARGS__)
 
@@ -1242,6 +1253,14 @@ class LogEvent
     return *this;
   }
 
+  LogEvent &lookup_quotedv(longlong errcode, const char *tag, va_list vl)
+  {
+    msg_tag= tag;
+    set_message_by_errcode(errcode, vl);
+
+    return *this;
+  }
+
   /**
     Add a ad hoc integer value with the given key.
 

mysql-test/suite/query_rewrite_plugins/r/errors.result

@@ -47,7 +47,7 @@ UPDATE error_log SET line = replace ( line, '\r', '' );
 # Avoid seeing any other error that might be there.
 SELECT search_error_log( '[Error]', "%Plugin Rewriter reported: 'Wrong%" );
 search_error_log( '[Error]', "%Plugin Rewriter reported: 'Wrong%" )
-[ERROR] [MY-011235] Plugin Rewriter reported: 'Wrong column count or names when loading rules.'
+[ERROR] [MY-011274] Plugin Rewriter reported: 'Wrong column count or names when loading rules.'
 SHOW STATUS LIKE 'Rewriter_number_reloads';
 Variable_name	Value
 Rewriter_number_reloads	1
@@ -70,7 +70,7 @@ UPDATE error_log SET line = replace ( line, '\r', '' );
 # Avoid seeing any other error that might be there.
 SELECT search_error_log( '[Error]', "%Plugin Rewriter reported: 'Wrong%" );
 search_error_log( '[Error]', "%Plugin Rewriter reported: 'Wrong%" )
-[ERROR] [MY-011235] Plugin Rewriter reported: 'Wrong column count or names when loading rules.'
+[ERROR] [MY-011274] Plugin Rewriter reported: 'Wrong column count or names when loading rules.'
 SHOW STATUS LIKE 'Rewriter_number_reloads';
 Variable_name	Value
 Rewriter_number_reloads	1

plugin/connection_control/CMakeLists.txt

@@ -1,4 +1,4 @@
-# Copyright (c) 2016, 2017, Oracle and/or its affiliates. All rights reserved.
+# Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 #
 # This program is free software; you can redistribute it and/or modify
 # it under the terms of the GNU General Public License, version 2.0,
@@ -28,3 +28,4 @@ MYSQL_ADD_PLUGIN(connection_control
 		 MODULE_ONLY)
 
 ADD_DEFINITIONS(-DMYSQL_SERVER)
+ADD_DEFINITIONS(-DLOG_SUBSYSTEM_TAG="CONNECTION_CONTROL")

plugin/connection_control/connection_control.cc

@@ -1,4 +1,4 @@
-/* Copyright (c) 2016, 2017, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License, version 2.0,
@@ -20,8 +20,6 @@
    along with this program; if not, write to the Free Software
    Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301  USA */
 
-#define LOG_SUBSYSTEM_TAG "CONNECTION_CONTROL"
-
 #include "plugin/connection_control/connection_control.h"
 
 #include <mysql/plugin_audit.h>         /* mysql_event_connection */
@@ -45,16 +43,13 @@ namespace connection_control
   class Connection_control_error_handler : public Error_handler
   {
   public:
-    Connection_control_error_handler(MYSQL_PLUGIN plugin_info)
-      : m_plugin_info(plugin_info)
-    {}
-
-    void handle_error(const char * error_message)
+    void handle_error(longlong errcode, ...)
     {
-      LogPluginErr(ERROR_LEVEL, ER_CONN_CONTROL_ERROR_MSG, error_message);
+      va_list vl;
+      va_start(vl, errcode);
+      LogPluginErrV(ERROR_LEVEL, errcode, vl);
+      va_end(vl);
     }
-  private:
-    MYSQL_PLUGIN m_plugin_info;
   };
 }
 
@@ -96,7 +91,7 @@ connection_control_notify(MYSQL_THD thd,
     {
       const struct mysql_event_connection *connection_event=
         (const struct mysql_event_connection *) event;
-      Connection_control_error_handler error_handler(connection_control_plugin_info);
+      Connection_control_error_handler error_handler;
       /** Notify event coordinator */
       g_connection_event_coordinator->notify_event(thd, &error_handler,
                                                    connection_event);
@@ -129,11 +124,11 @@ connection_control_init(MYSQL_PLUGIN plugin_info)
     return 1;
 
   connection_control_plugin_info= plugin_info;
-  Connection_control_error_handler error_handler(connection_control_plugin_info);
+  Connection_control_error_handler error_handler;
   g_connection_event_coordinator= new Connection_event_coordinator();
   if (!g_connection_event_coordinator)
   {
-    error_handler.handle_error("Failed to initialize Connection_event_coordinator");
+    error_handler.handle_error(ER_CONN_CONTROL_EVENT_COORDINATOR_INIT_FAILED);
     deinit_logging_service_for_plugin(&reg_srv, &log_bi, &log_bs);
     return 1;
   }
@@ -254,7 +249,7 @@ update_failed_connections_threshold(MYSQL_THD thd MY_ATTRIBUTE((unused)),
   */
   longlong new_value= *(reinterpret_cast<const longlong *>(save));
   g_variables.failed_connections_threshold= (int64)new_value;
-  Connection_control_error_handler error_handler(connection_control_plugin_info);
+  Connection_control_error_handler error_handler;
   g_connection_event_coordinator->notify_sys_var(&error_handler,
                                                  OPT_FAILED_CONNECTIONS_THRESHOLD,
                                                  &new_value);
@@ -334,7 +329,7 @@ update_min_connection_delay(MYSQL_THD thd MY_ATTRIBUTE((unused)),
 {
   longlong new_value= *(reinterpret_cast<const longlong *>(save));
   g_variables.min_connection_delay= (int64)new_value;
-  Connection_control_error_handler error_handler(connection_control_plugin_info);
+  Connection_control_error_handler error_handler;
   g_connection_event_coordinator->notify_sys_var(&error_handler,
                                                  OPT_MIN_CONNECTION_DELAY,
                                                  &new_value);
@@ -414,7 +409,7 @@ update_max_connection_delay(MYSQL_THD thd MY_ATTRIBUTE((unused)),
 {
   longlong new_value= *(reinterpret_cast<const longlong *>(save));
   g_variables.max_connection_delay= (int64)new_value;
-  Connection_control_error_handler error_handler(connection_control_plugin_info);
+  Connection_control_error_handler error_handler;
   g_connection_event_coordinator->notify_sys_var(&error_handler,
                                                  OPT_MAX_CONNECTION_DELAY,
                                                  &new_value);

plugin/connection_control/connection_control_interfaces.h

@@ -1,4 +1,4 @@
-/* Copyright (c) 2016, 2017, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License, version 2.0,
@@ -40,7 +40,7 @@ namespace connection_control
   class Error_handler
   {
   public:
-    virtual void handle_error(const char * error_message)= 0;
+    virtual void handle_error(longlong errcode, ...)= 0;
     virtual ~Error_handler() {}
   };
 

plugin/connection_control/connection_delay.cc

@@ -30,6 +30,7 @@
 #include "my_compiler.h"
 #include "my_dbug.h"
 #include "my_systime.h"
+#include "mysqld_error.h"
 #include "plugin/connection_control/connection_control.h"
 #include "plugin/connection_control/security_context_wrapper.h"
 #include "sql/current_thd.h"            /* current_thd */
@@ -666,7 +667,8 @@ namespace connection_control
       if ((error= coordinator->notify_status_var(
                     &self, STAT_CONNECTION_DELAY_TRIGGERED, ACTION_INC)))
       {
-        error_handler->handle_error("Failed to update connection delay triggered stats");
+        error_handler->handle_error(
+          ER_CONN_CONTROL_STAT_CONN_DELAY_TRIGGERED_UPDATE_FAILED);
       }
       /*
         Invoking sleep while holding read lock on Connection_delay_action
@@ -686,12 +688,9 @@ namespace connection_control
       */
       if (m_userhost_hash.create_or_update_entry(userhost))
       {
-        char error_buffer[512];
-        memset(error_buffer, 0, sizeof(error_buffer));
-        my_snprintf(error_buffer, sizeof(error_buffer)-1,
-                    "Failed to update connection delay hash for account : %s",
-                    userhost.c_str());
-        error_handler->handle_error(error_buffer);
+        error_handler->handle_error(
+          ER_CONN_CONTROL_FAILED_TO_UPDATE_CONN_DELAY_HASH,
+          userhost.c_str());
         error= true;
       }
     }
@@ -750,7 +749,8 @@ namespace connection_control
                                                    STAT_CONNECTION_DELAY_TRIGGERED,
                                                    ACTION_RESET)))
         {
-          error_handler->handle_error("Failed to reset connection delay triggered stats");
+          error_handler->handle_error(
+            ER_CONN_CONTROL_STAT_CONN_DELAY_TRIGGERED_RESET_FAILED);
         }
         break;
       }
@@ -761,19 +761,16 @@ namespace connection_control
         if ((error= set_delay(new_delay,
                       (variable == OPT_MIN_CONNECTION_DELAY))))
         {
-          char error_buffer[512];
-          memset(error_buffer, 0, sizeof(error_buffer));
-          my_snprintf(error_buffer, sizeof(error_buffer) - 1,
-                      "Could not set %s delay for connection delay.",
-                      (variable == OPT_MIN_CONNECTION_DELAY) ? "min" : "max");
-          error_handler->handle_error(error_buffer);
+          error_handler->handle_error(
+            ER_CONN_CONTROL_FAILED_TO_SET_CONN_DELAY,
+            (variable == OPT_MIN_CONNECTION_DELAY) ? "min" : "max");
         }
         break;
       }
       default:
         /* Should never reach here. */
         DBUG_ASSERT(FALSE);
-        error_handler->handle_error("Unexpected option type for connection delay.");
+        error_handler->handle_error(ER_CONN_CONTROL_INVALID_CONN_DELAY_TYPE);
     };
     DBUG_RETURN(error);
   }
@@ -942,7 +939,7 @@ namespace connection_control
                                                                  &connection_event_delay_lock);
     if (!g_max_failed_connection_handler)
     {
-      error_handler->handle_error("Failed to initialization Connection_delay_action");
+      error_handler->handle_error(ER_CONN_CONTROL_DELAY_ACTION_INIT_FAILED);
       return true;
     }
     g_max_failed_connection_handler->init(coordinator);

plugin/connection_control/connection_delay_api.h

@@ -1,4 +1,4 @@
-/* Copyright (c) 2016, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License, version 2.0,

plugin/keyring/CMakeLists.txt

@@ -1,4 +1,4 @@
-# Copyright (c) 2016, 2017, Oracle and/or its affiliates. All rights reserved.
+# Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 #
 # This program is free software; you can redistribute it and/or modify
 # it under the terms of the GNU General Public License, version 2.0,
@@ -77,6 +77,8 @@ ELSE()
                      MODULE_OUTPUT_NAME "keyring_file")
 ENDIF()
 
+ADD_DEFINITIONS(-DLOG_SUBSYSTEM_TAG="keyring_file")
+
 IF(SSL_DEFINES)
   ADD_DEFINITIONS(${SSL_DEFINES})
 ENDIF()

plugin/keyring/buffered_file_io.cc

@@ -1,4 +1,4 @@
-/* Copyright (c) 2016, 2017, Oracle and/or its affiliates. All rights reserved.
+/* Copyright (c) 2016, 2018, Oracle and/or its affiliates. All rights reserved.
 
    This program is free software; you can redistribute it and/or modify
    it under the terms of the GNU General Public License, version 2.0,
@@ -30,6 +30,7 @@
 
 #include "my_compiler.h"
 #include "my_dbug.h"
+#include "mysqld_error.h"
 
 namespace keyring {
 
@@ -105,7 +106,7 @@ bool Buffered_file_io::check_file_structure(File file, size_t file_size)
       return checker->check_file_structure(file, file_size, &digest) == FALSE;
      }) == checkers.end())
   {
-    logger->log(MY_ERROR_LEVEL, "Incorrect Keyring file");
+    logger->log(ERROR_LEVEL, ER_KEYRING_INCORRECT_FILE);
     return TRUE;
   }
   return FALSE;
@@ -155,8 +156,7 @@ bool Buffered_file_io::recreate_keyring_from_backup_if_backup_exists()
     return FALSE; //no backup file to recover from
   if (load_file_into_buffer(backup_file, &buffer))
   {
-    logger->log(MY_WARNING_LEVEL, "Found malformed keyring backup file - "
-                                  "removing it");
+    logger->log(WARNING_LEVEL, ER_KEYRING_FOUND_MALFORMED_BACKUP_FILE);
     file_io.close(backup_file, MYF(0));
     // if backup file was successfully removed then we have one keyring file
     return remove_backup(MYF(MY_WME));
@@ -171,8 +171,7 @@ bool Buffered_file_io::recreate_keyring_from_backup_if_backup_exists()
       file_io.close(keyring_file, MYF(MY_WME)) < 0)
 
   {
-    logger->log(MY_ERROR_LEVEL, "Error while restoring keyring from backup file"
-                                " cannot overwrite keyring with backup");
+    logger->log(ERROR_LEVEL, ER_KEYRING_FAILED_TO_RESTORE_FROM_BACKUP_FILE);
     return TRUE;
   }
   return remove_backup(MYF(MY_WME));
@@ -222,8 +221,7 @@ bool Buffered_file_io::flush_buffer_to_file(Buffer *buffer,
                   SHA256_DIGEST_LENGTH, MYF(0)) == SHA256_DIGEST_LENGTH)
     return FALSE;
 
-  logger->log(MY_ERROR_LEVEL, "Error while flushing in-memory keyring into "
-                              "keyring file");
+  logger->log(ERROR_LEVEL, ER_KEYRING_FAILED_TO_FLUSH_KEYRING_TO_FILE);
   return TRUE;
 }