List:Commits« Previous MessageNext Message »
From:Rafal Somla Date:September 7 2012 1:05pm
Subject:bzr push into mysql-trunk branch (rafal.somla:4084 to 4086)
View as plain text  
 4086 Rafal Somla	2012-09-07
      - protocol stage tracing with MYSQL_TRACE_STAGE() hooks in libmysql code,
      - move test trace plugin to separate file, move here code for tracing protocol stage changes
        and detecting invalid events,
      - different handling of trace event parameters.

    added:
      libmysql/test_trace_plugin.cc
    modified:
      include/mysql/plugin_trace.h
      libmysql/CMakeLists.txt
      libmysql/libmysql.c
      libmysql/mysql_trace.c
      libmysql/mysql_trace.h
      sql-common/client.c
 4085 Rafal Somla	2012-08-28
      - Build options for disabling/enabling the feature.
      - Add comments to files.

    modified:
      CMakeLists.txt
      include/mysql/plugin_trace.h
      libmysql/CMakeLists.txt
      libmysql/mysql_trace.c
      libmysql/mysql_trace.h
      sql-common/client.c
      sql-common/client_plugin.c
 4084 Rafal Somla	2012-08-24
      Test trace plugin inmprovements:
      - use per-connection data storage
      - do not report invalid events if error was detected

    modified:
      libmysql/mysql_trace.c
=== modified file 'CMakeLists.txt'
--- a/CMakeLists.txt	2012-06-01 14:02:36 +0000
+++ b/CMakeLists.txt	2012-08-28 07:28:25 +0000
@@ -248,6 +248,15 @@ OPTION(OPTIMIZER_TRACE "Support tracing 
 OPTION(INNODB_COMPILER_HINTS "Compile InnoDB with compiler hints" ON)
 MARK_AS_ADVANCED(INNODB_COMPILER_HINTS)
 
+#
+# Options related to client-side protocol tracing
+#
+
+OPTION(WITH_CLIENT_PROTOCOL_TRACING
+  "Support for client-side protocol tracing plugins" ON)
+OPTION(WITH_TEST_TRACE_PLUGIN
+  "Have a built-in test protocol trace plugin in libmysql (requires WITH_CLIENT_PROTOCOL_TRACING option)" OFF)
+
 # Set DBUG_OFF and other optional release-only flags for non-debug project types
 FOREACH(BUILD_TYPE RELEASE RELWITHDEBINFO MINSIZEREL)
   FOREACH(LANG C CXX)

=== modified file 'include/mysql/plugin_trace.h'
--- a/include/mysql/plugin_trace.h	2012-08-23 14:14:44 +0000
+++ b/include/mysql/plugin_trace.h	2012-09-07 12:42:49 +0000
@@ -6,12 +6,12 @@
 
 #define PROTOCOL_STAGE_LIST(X) \
   protocol_stage_ ## X(CONNECTING) \
-  protocol_stage_ ## X(WAIT_FOR_CHALLENGE) \
+  protocol_stage_ ## X(WAIT_FOR_INIT_PACKET) \
   protocol_stage_ ## X(AUTHENTICATE) \
+  protocol_stage_ ## X(SSL_NEGOTIATION) \
   protocol_stage_ ## X(READY_FOR_COMMAND) \
-  protocol_stage_ ## X(WAIT_FOR_SIMPLE_REPLY) \
   protocol_stage_ ## X(WAIT_FOR_PACKET) \
-  protocol_stage_ ## X(WAIT_FOR_RESULTSET) \
+  protocol_stage_ ## X(WAIT_FOR_RESULT) \
   protocol_stage_ ## X(WAIT_FOR_FIELD_DEF) \
   protocol_stage_ ## X(WAIT_FOR_ROW) \
   protocol_stage_ ## X(FILE_REQUEST) \
@@ -19,6 +19,44 @@
   protocol_stage_ ## X(WAIT_FOR_PS_PARAMETER) \
   protocol_stage_ ## X(DISCONNECTED)
 
+/*
+  ---------------------- -----------------------------------------------------
+  Connection events
+  ---------------------- -----------------------------------------------------
+  CONNECTING             Client is connecting to the server.
+  CONNECTED              Physical connection has been established.
+  DISCONNECTED           Connection with server was broken.
+  ---------------------- -----------------------------------------------------
+  SSL events
+  ---------------------- -----------------------------------------------------
+  SEND_SSL_REQUEST       Client is sending SSL connection request.
+  SSL_CONNECT            Client is initiating SSL handshake.
+  SSL_CONNECTED          SSL connection has been established.
+  ---------------------- -----------------------------------------------------
+  Authentication events
+  ---------------------- -----------------------------------------------------
+  CHALLENGE_RECEIVED     Client received authentication challenge.
+  AUTH_PLUGIN            Client selects an authentication plugin to be used 
+                         in the following authentication exchange.
+  SEND_AUTH_RESPONSE     Client sends response to the authentication 
+                         challenge.
+  SEND_AUTH_DATA         Client sends extra authentication data packet.
+  AUTHENTICATED          Server has accepted connection.
+  ---------------------- -----------------------------------------------------
+  Command phase events
+  ---------------------- -----------------------------------------------------
+  SEND_COMMAND           Cleint is sending a command to the server.
+  SEND_FILE              Client is sending local file contents to the server.
+  ---------------------- -----------------------------------------------------
+  General events
+  ---------------------- -----------------------------------------------------
+  READ_PACKET            Client starts waiting for a packet from server.
+  PACKET_RECEIVED        A packet from server has been received.
+  PACKET_SENT            After successful sending of a packet to the server.
+  ERROR                  Client detected an error.
+  ---------------------- -----------------------------------------------------
+*/
+
 #define TRACE_EVENT_LIST(X) \
   trace_event_ ## X(ERROR) \
   trace_event_ ## X(CONNECTING) \
@@ -27,7 +65,7 @@
   trace_event_ ## X(SEND_SSL_REQUEST) \
   trace_event_ ## X(SSL_CONNECT) \
   trace_event_ ## X(SSL_CONNECTED) \
-  trace_event_ ## X(CHALLENGE_RECEIVED) \
+  trace_event_ ## X(INIT_PACKET_RECEIVED) \
   trace_event_ ## X(AUTH_PLUGIN) \
   trace_event_ ## X(SEND_AUTH_RESPONSE) \
   trace_event_ ## X(SEND_AUTH_DATA) \
@@ -56,6 +94,17 @@ enum trace_event {
 };
 
 
+struct st_trace_event_args
+{
+  const char    *plugin_name;
+  int            cmd;
+  const void    *hdr;
+  size_t         hdr_len;
+  const void    *pkt;
+  size_t         pkt_len;
+};
+
+
 struct st_mysql_client_plugin_TRACE;
 struct st_mysql;
 
@@ -73,15 +122,7 @@ void (trace_event_handler)(struct st_mys
                            struct st_mysql *connection_handle,
                            enum protocol_stage stage,
                            enum trace_event event,
-                           va_list args);
-typedef
-enum protocol_stage
-     (invalid_event_handler)(struct st_mysql_client_plugin_TRACE *self,
-                             void *data,
-                             struct st_mysql *connection_handle,
-                             enum protocol_stage stage,
-                             enum trace_event event);
-
+                           struct st_trace_event_args args);
 
 
 struct st_mysql_client_plugin_TRACE
@@ -90,7 +131,6 @@ struct st_mysql_client_plugin_TRACE
   tracing_start_callback *tracing_start;
   tracing_stop_callback  *tracing_stop;
   trace_event_handler    *trace_event;
-  invalid_event_handler  *invalid_event;
 };
 
 

=== modified file 'libmysql/CMakeLists.txt'
--- a/libmysql/CMakeLists.txt	2012-07-20 16:36:35 +0000
+++ b/libmysql/CMakeLists.txt	2012-09-07 12:42:49 +0000
@@ -137,7 +137,6 @@ CACHE INTERNAL "Functions exported by cl
 )
 
 SET(CLIENT_SOURCES
-  mysql_trace.c
   get_password.c 
   libmysql.c
   errmsg.c
@@ -151,8 +150,19 @@ SET(CLIENT_SOURCES
   ../sql/password.c
 )
 
+IF (WITH_CLIENT_PROTOCOL_TRACING)
+
+LIST(APPEND CLIENT_SOURCES mysql_trace.c)
+ADD_DEFINITIONS(-D CLIENT_PROTOCOL_TRACING)
+
+IF (WITH_TEST_TRACE_PLUGIN)
+  LIST(APPEND CLIENT_SOURCES test_trace_plugin.cc)
+  ADD_DEFINITIONS(-D TEST_TRACE_PLUGIN)
+ENDIF (WITH_TEST_TRACE_PLUGIN)
+
+ENDIF (WITH_CLIENT_PROTOCOL_TRACING)
+
 
-ADD_DEFINITIONS(-D TEST_TRACE_PLUGIN)
 
 # We do RESTRICT_SYMBOL_EXPORTS(yassl) elsewhere.
 # In order to get correct symbol visibility, md5.cc and sha1.cc

=== modified file 'libmysql/libmysql.c'
--- a/libmysql/libmysql.c	2012-08-24 10:53:38 +0000
+++ b/libmysql/libmysql.c	2012-09-07 12:42:49 +0000
@@ -948,6 +948,11 @@ const char *cli_read_statistics(MYSQL *m
     set_mysql_error(mysql, CR_WRONG_HOST_INFO, unknown_sqlstate);
     return mysql->net.last_error;
   }
+  /*
+    After reading the single packet with reply to COM_STATISTICS
+    we are ready for new commands.
+  */
+  MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
   return (char*) mysql->net.read_pos;
 }
 
@@ -1422,6 +1427,8 @@ my_bool cli_read_prepare_result(MYSQL *m
   {
     MYSQL_DATA *param_data;
 
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_PS_PARAMETER);
+    
     /* skip parameters data: we don't support it yet */
     if (!(param_data= (*mysql->methods->read_rows)(mysql, (MYSQL_FIELD*)0, 7)))
       DBUG_RETURN(1);
@@ -1433,6 +1440,8 @@ my_bool cli_read_prepare_result(MYSQL *m
     if (!(mysql->server_status & SERVER_STATUS_AUTOCOMMIT))
       mysql->server_status|= SERVER_STATUS_IN_TRANS;
 
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_FIELD_DEF);
+
     if (!(fields_data= (*mysql->methods->read_rows)(mysql,(MYSQL_FIELD*)0,7)))
       DBUG_RETURN(1);
     if (!(stmt->fields= unpack_fields(mysql, fields_data,&stmt->mem_root,
@@ -1440,6 +1449,9 @@ my_bool cli_read_prepare_result(MYSQL *m
 				      mysql->server_capabilities)))
       DBUG_RETURN(1);
   }
+
+  MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+
   stmt->field_count=  field_count;
   stmt->param_count=  (ulong) param_count;
   DBUG_PRINT("exit",("field_count: %u  param_count: %u  warning_count: %u",
@@ -4309,6 +4321,12 @@ int cli_read_binary_rows(MYSQL_STMT *stm
       mysql->server_status= uint2korr(cp+3);
       DBUG_PRINT("info",("status: %u  warning_count: %u",
                          mysql->server_status, mysql->warning_count));
+#if defined(CLIENT_PROTOCOL_TRACING)
+      if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+        MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+      else
+        MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
       DBUG_RETURN(0);
     }
   }

=== modified file 'libmysql/mysql_trace.c'
--- a/libmysql/mysql_trace.c	2012-08-24 14:58:05 +0000
+++ b/libmysql/mysql_trace.c	2012-09-07 12:42:49 +0000
@@ -1,15 +1,50 @@
+/**
+  @file
+
+  Client-side protocol tracing infrastructure
+  ===========================================
+
+  If a plugin of type MYSQL_CLIENT_TRACE_PLUGIN is loaded into 
+  libmysql and its instance is pointed by the global trace_plugin
+  pointer, this plugin is notified of various protocol trace events 
+  (see include/mysql/plugin_trace.h for the list).
+
+  These trace events are generated with MYSQL_TRACE() macro put in 
+  relevant places in libmysql code. The macro calls mysql_trace_trace()
+  function defined here. This function calls trace plugin's 
+  trace_event() method, if it is defined.
+
+  To correctly interpret each trace event, trace plugin is informed
+  of the current protocol stage (see include/mysql/plugin_trace.h for
+  list of stages). Function mysql_trace_trace() calls 
+  protocol_stage_change() function which analyses trace events and
+  updates current protocol stage accordingly.
+
+  If an event which is invalid for a given protocol stage is detected
+  and if trace plugin defines invalid_event() method, this method is
+  called and it determines if tracing should continue and what should
+  be the next protocol stage. If invalid_event() method is not defined,
+  tracing of the connection is interrupted upon detecting 
+  invalid event.
+*/
+
 #include <my_global.h>
 #include "mysql.h"
 #include "mysql_trace.h"
 
-/*
+#include <string.h>    /* memcpy */
+
+/**
   The global trace_plugin pointer. If it is not NULL, it points at a
   loaded trace plugin which should be used to trace all connections made
   to the server.
 */
 struct st_mysql_client_plugin_TRACE *trace_plugin= NULL;
 
-
+/*
+  Macros for manipulating trace_info structure 
+  defined in mysql_trace.h
+*/
 #define GET_DATA(TI)      (TI)->trace_plugin_data
 #define SET_DATA(TI,D)    GET_DATA(TI) = (D)
 #define GET_STAGE(TI)     (TI)->stage
@@ -18,983 +53,103 @@ struct st_mysql_client_plugin_TRACE *tra
 #define SET_PS_INFO(TI,P,C) do { (TI)->param_count= (P); (TI)->col_count= (C); } while(0)
 #define GET_PS_INFO(TI,P,C) do { (P)= (TI)->param_count; (C)= (TI)->col_count; } while(0)
 
+
 #ifndef DBUG_OFF
+/*
+  Functions for gettig names of trace events and protocol
+  stages for debugging purposes.
+*/
 
-#define protocol_stage_name(X) case PROTOCOL_STAGE_ ## X: return #X;
+#define protocol_stage_get_name(X) case PROTOCOL_STAGE_ ## X: return #X;
 
 const char* stage_name(enum protocol_stage stage)
 {
   switch(stage)
   {
-  PROTOCOL_STAGE_LIST(name)
+  PROTOCOL_STAGE_LIST(get_name)
   default: return "<unknown stage>";
   }
 }
 
 
-#define trace_event_name(X) case TRACE_EVENT_ ## X: return #X;
+#define trace_event_get_name(X) case TRACE_EVENT_ ## X: return #X;
 
 const char* event_name(enum trace_event ev)
 {
   switch(ev)
   {
-  TRACE_EVENT_LIST(name)
+  TRACE_EVENT_LIST(get_name)
   default: return "<unknown event>";
   }
 }
 
 #endif
 
-int    protocol_stage_change(struct st_mysql_trace_info*, enum trace_event, va_list);
 
-void mysql_trace_trace(struct st_mysql_client_plugin_TRACE *plugin,
-                       enum trace_event ev, 
-                       struct st_mysql  *m, ...)
+void mysql_trace_start(struct st_mysql *m)
 {
-  va_list args, args_copy;                                          \
-  struct st_mysql_trace_info *trace_info= TRACE_DATA(m);
-
-  if (ev == TRACE_EVENT_CONNECTING)
-  {
-    /* Initialize tracing in a new connection. */
-
-    trace_info= my_malloc(sizeof(struct st_mysql_trace_info), 
-                          MYF(MY_ZEROFILL));
-    if (!trace_info)
-      return;
-
-    TRACE_DATA(m)= trace_info;
-    SET_STAGE(trace_info, CONNECTING);
-    SET_DATA(trace_info, 
-             plugin->tracing_start ?
-             plugin->tracing_start(plugin, m, PROTOCOL_STAGE_CONNECTING) :
-             NULL
-            );
-  }
-
+  struct st_mysql_trace_info *trace_info;
+ 
+  trace_info= my_malloc(sizeof(struct st_mysql_trace_info), 
+                        MYF(MY_ZEROFILL));
   if (!trace_info)
-  {
-    /* 
-      There is no trace_info structure for this connection (out of memory?).
-      We are bailing out.
-    */
     return;
-  }
-
-  va_start(args,m);
 
-  /*
-    We pass event args to plugins trace_event method and later also to
-    protocol_stage_change() function. The same va_list value can not be
-    parsed twice so we need to make a copy for the second use.
-
-    Note: __va_copy() is a non-standard extension of gcc. We assume 
-    here that if va_list values can not be copied with assignemnt then
-    __va_copy() macro is defined.
-  */
-
-#ifdef __va_copy
-  __va_copy(args_copy, args);
-#else
-  args_copy= args;
-#endif
-
-  if (plugin->trace_event)
-  {
-    plugin->trace_event(plugin, GET_DATA(trace_info), m,
-                        GET_STAGE(trace_info), ev, args);
-  }
+  trace_info->plugin= trace_plugin;
+  trace_info->stage=  PROTOCOL_STAGE_CONNECTING;
 
-  /* Follow protocol stage changes */
-
-  if (protocol_stage_change(trace_info, ev, args_copy))
-  {
-    /*
-      If plugin's invalid_event callback is defined, inform 
-      the plugin about invalid event and let it determine which
-      protocol stage should be assumed now. Otherwise set protocol
-      stage to CLOSED which will end tracing in this connection.
-    */
-    if(plugin->invalid_event)
-      GET_STAGE(trace_info)= 
-        plugin->invalid_event(plugin, m, 
-                              GET_DATA(trace_info),
-                              GET_STAGE(trace_info),
-                              ev);
-    else
-      SET_STAGE(trace_info, DISCONNECTED);
-  }
-
-  va_end(args);                  
-
-  /* Stop tracing if end of connection. */
-
-  if (TEST_STAGE(trace_info, DISCONNECTED))
-  {
-    plugin->tracing_stop(plugin, m, GET_DATA(trace_info));
-    //my_free(GET_DATA(trace_info));
-    SET_DATA(trace_info, NULL);
-  }
+  if (trace_info->plugin->tracing_start)
+    trace_info->trace_plugin_data=
+      trace_info->plugin->tracing_start(
+        trace_info->plugin, 
+        m, PROTOCOL_STAGE_CONNECTING);
+  else
+    trace_info->trace_plugin_data= NULL;
 
+  TRACE_DATA(m)= trace_info;
 }
 
 
-// ===========================
-//  Protocol stage tracing
-// ===========================
-
-typedef unsigned char byte;
-
-/*
-  Macro to get packet pointer and length from a variable
-  argument list.
-*/
-#define get_pkt(ARGS, BUF, LEN) \
-  do {                          \
-    LEN= va_arg(args, size_t);  \
-    BUF= va_arg(args, byte*);   \
-  } while (0)
-
+/**
+  Report a protocol trace event to trace plugin.
 
-#define OK_PACKET(PKT)    (*(PKT) == 0x00)
-#define ERR_PACKET(PKT)   (*(PKT) == 0xFF)
-#define EOF_PACKET(PKT)   (*(PKT) == 0xFE)
-#define FILE_REQUEST(PKT) (*(PKT) == 0xFB)
+  Calls plugin's trace_event() method, if it is defined, passing to
+  it the event, the current protocol stage and event arguments (if any).
 
+  After reporting event to the plugin, the current protocol stage is
+  updated with protocol_stage_change() function.
 
-void test_packet_dump(const char*, void*, size_t);
-
-/*
-  Returns zero if protocol stage was correctly updated, non-zero otherwise (invalid trace event).
+  @param plugin   the trace plugin
+  @param ev       trace event to be reported
+  @param m        MYSQL connection handle
+  @param args     trace event arguments
 */
-int protocol_stage_change(struct st_mysql_trace_info *ti, enum trace_event ev, va_list args)
-{
-  //printf("Tracing stage change at %s, event %s\n", stage_name(GET_STAGE(ti)), event_name(ev));
-
-  /*
-    ERROR trace event never changes the current protocol stage.
-  */
-  if (ev == TRACE_EVENT_ERROR)
-    return 0;
-
-  /*
-    Move to DISCONNECTED stage if connection was closed by client.
-  */
-  if (ev == TRACE_EVENT_DISCONNECTED)
-  {
-    SET_STAGE(ti, DISCONNECTED);
-    return 0;
-  }
-
- 
-  switch (GET_STAGE(ti))
-  {
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_CONNECTING:
-    /*
-      This is the first stage of the protocol, when client is establishing
-      physical connection with the server. After connection is established
-      protocol moves to WAIT_FOR_CHALLENGE stage where the first 
-      authentication challenge packet is expected from the server.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_CONNECTING:         return 0;
-    case TRACE_EVENT_CONNECTED:          SET_STAGE(ti, WAIT_FOR_CHALLENGE); return 0;
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_CHALLENGE:
-    /*
-      In this stage client waits for the first challenge packet from the
-      server. When it is received, protocol movest to AUTHENTICATE stage
-      where client authorizes itself against server.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET:        return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:    return 0;
-    case TRACE_EVENT_CHALLENGE_RECEIVED: SET_STAGE(ti, AUTHENTICATE); return 0;
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_AUTHENTICATE:
-    /*
-      In this stage client exchanges various packets with the server to:
-      - authenticate itself against the server,
-      - negotiante client/server capabilities and connection parameters,
-      - establish encrypted SSL connection.
-      At any moment during this exchange server can send an ERR packet
-      indicating that it rejects the connection.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_AUTHENTICATED:     SET_STAGE(ti, READY_FOR_COMMAND); return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          Move to DISCONNECTED stage if ERR packet was received from the
-          server.
-        */
-        if (ERR_PACKET(pkt))
-          SET_STAGE(ti, DISCONNECTED);
-
-        return 0;
-      }
-    case TRACE_EVENT_SEND_SSL_REQUEST:
-    case TRACE_EVENT_SSL_CONNECT:
-    case TRACE_EVENT_SSL_CONNECTED:
-    case TRACE_EVENT_AUTH_PLUGIN:
-    case TRACE_EVENT_SEND_AUTH_RESPONSE:
-    case TRACE_EVENT_SEND_AUTH_DATA:
-    case TRACE_EVENT_READ_PACKET:
-    case TRACE_EVENT_PACKET_SENT:
-      return 0;
-
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_READY_FOR_COMMAND:
-    /*
-      This is the stage when client can send a command to the server.
-      After sending command packet to the server, PACKET_SENT trace
-      event happens. The next stage depends on whether a result set
-      is expected after the command, or just OK/ERR reply or it is 
-      a command with no reply from server.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_SEND_COMMAND:
-      ti->last_command = va_arg(args, int);
-      /* Reset PS information stored in trace info record */
-      SET_PS_INFO(ti, 0, 0);
-      return 0;
-
-    case TRACE_EVENT_PACKET_SENT:
-      switch (ti->last_command)
-      {
-      case COM_QUIT:         SET_STAGE(ti, DISCONNECTED);       break;
-      case COM_STMT_PREPARE: SET_STAGE(ti, WAIT_FOR_PS_DESCRIPTION); break;
-      case COM_QUERY:
-      case COM_STMT_EXECUTE: SET_STAGE(ti, WAIT_FOR_RESULTSET); break;
-
-      /* 
-         No server reply is expected after these commands so we reamin ready
-         for the next command.
-      */
-      case COM_REFRESH:
-      case COM_STMT_SEND_LONG_DATA: 
-      case COM_STMT_CLOSE:
-      case COM_REGISTER_SLAVE:
-        return 0;
-
-      /*
-        These replication commands are not supported and are reported as
-        invalid events (trace plugin can decide how to continue).
-      */
-      case COM_BINLOG_DUMP:
-      case COM_BINLOG_DUMP_GTID:
-      case COM_TABLE_DUMP:
-        return 1;
-
-      /*
-        After COM_PROCESS_INFO server sends a regular result set.
-      */
-      case COM_PROCESS_INFO:
-        SET_STAGE(ti, WAIT_FOR_RESULTSET);
-        break;
-
-      /*
-        Server replies to COM_STATISTICS with a single packet 
-        containing a string with statistics information.
-      */
-      case COM_STATISTICS:
-        SET_STAGE(ti, WAIT_FOR_PACKET);
-        break;
-
-      case COM_CHANGE_USER:
-        SET_STAGE(ti, AUTHENTICATE);
-        break;
-
-      default:
-        SET_STAGE(ti, WAIT_FOR_SIMPLE_REPLY);
-        break;
-      };
-      return 0;
-  
-    case TRACE_EVENT_AUTH_PLUGIN:
-      /*
-        The AUTH_PLUGIN event can happen in READY_FOR_COMMAND stage
-        before COM_CHANGE_USER is executed. When the command is executed
-        the stage will be changed to AUTHENTICATE.
-      */
-      return 0;
-
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_SIMPLE_REPLY:
-    /*
-      This stage is reached after a command which produces no result set.
-      Server can reply with ERR or OK packet, indicating command execution
-      error or success, respectively.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          If the expected ERR, EOF or OK packet is received, we are ready for
-          a new command. Otherwise something is wrong and we report invalid
-          event.
-        */
-
-        if (ERR_PACKET(pkt) || OK_PACKET(pkt) || EOF_PACKET(pkt))
-        {
-          SET_STAGE(ti, READY_FOR_COMMAND);
-          return 0;
-        }
-
-        return 1;
-      }
-      
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_PACKET:
-    /*
-      After some commands (COM_STATISTICS) server sends just a
-      single packet and then it is ready for processing more
-      commands.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED: 
-      SET_STAGE(ti, READY_FOR_COMMAND);
-      return 0;      
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_RESULTSET:
-    /*
-      This stage is reached after a command which can produce a result set
-      (COM_QUERY or COM_STMT_EXECUTE). In this stage a single packet is 
-      received from the server informing about the result of the query:
-      - ERR packet informs that error has happened when processing query,
-      - OK packet informs that query produced no result set,
-      - FILE_REQUEST packet asks client to send contents of a given file,
-      Otherwise information about the number of columns in the result set
-      is received.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-
-        get_pkt(args, pkt, pkt_len);
-
-//        test_packet_dump("== resultset packet", pkt, pkt_len);
-
-        /*
-          If server sends ERR, query processing is done
-          and next stage is READY_FOR_COMMAND.
-        */
-
-        if (ERR_PACKET(pkt))
-        {
-          SET_STAGE(ti, READY_FOR_COMMAND);
-          return 0;
-        }
-
-        /*
-          If server sends FILE_REQUEST packet, we move to FILE_REQUEST
-          stage of the protocol.
-        */
-        if (FILE_REQUEST(pkt))
-        {
-          SET_STAGE(ti, FILE_REQUEST);
-          return 0;
-        }
-
-        /*
-          If query generates no data, server replies with OK packet. In
-          case of a multi-query, more result sets can follow, as 
-          indicated by SERVER_MORE_RESULTS_EXISTS flag in the OK packet.
-          If the flag is set we move to WAIT_FOR_RESULTSET stage to 
-          read the following result set(s).
-        */
-        if (OK_PACKET(pkt))
-        {
-          /* Extract flags from the OK packet */
-          unsigned int flags;
-          pkt++;                         /* cmd header */
-          (void)net_field_length(&pkt);  /* affected_rows */
-          (void)net_field_length(&pkt);  /* last_insert_id */
-          flags= uint2korr(pkt);
-
-          if (SERVER_MORE_RESULTS_EXISTS & flags)
-            SET_STAGE(ti, WAIT_FOR_RESULTSET);
-          else
-            SET_STAGE(ti, READY_FOR_COMMAND);
-          return 0;
-        }
-
-        /*
-          Otherwise a result set is expected from the server so we move
-          to WAIT_FOR_FIELD_DEF stage.
-        */
-
-        SET_STAGE(ti, WAIT_FOR_FIELD_DEF);
-        return 0;
-      }
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_FIELD_DEF:
-    /*
-      In this stage definitions of row fields are read from server. This
-      can happen when reading query result set, or after preparing
-      a statement which produces result set or upon explicit COM_FIELD_LIST 
-      request.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          If the received packet is not an EOF packet, then it is description
-          of the next row field and we can continue, remaining in the same stage.
-
-          To correctly recognize EOF packets we have to check its length, because
-          a field description packet can theoretically start with byte 0xFE - the 
-          same as the first byte of the EOF packet. 
-          
-          This can happen if the first length-encoded string in the packet starts 
-          with 8-byte length-encoded integer whose first byte is 0xFE. In this
-          case the string and thus the whole packet is longer than 9 bytes and\
-          EOF packet is always shorter than 9 bytes.
-        */
-
-        if (!(EOF_PACKET(pkt) && pkt_len < 9))
-          return 0;
-
-        /*
-          If this WAIT_FOR_FIELD_DEF stage was reached after COM_STMT_PREPARE or
-          COM_FIELD_LIST then the EOF packet ends proccesing of the command and 
-          next stage is READY_FOR_COMMAND. 
-          Otherwise we are reading a result set and the field definitions have 
-          ended - next stage is WAIT_FOR_ROW.
-        */
-        switch (ti->last_command)
-        {
-        case COM_STMT_PREPARE:
-        case COM_FIELD_LIST:
-          SET_STAGE(ti, READY_FOR_COMMAND);
-          break;
-        default:
-          SET_STAGE(ti, WAIT_FOR_ROW);
-        }
-
-        return 0;
-      }
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_ROW:
-    /*
-      This stage is entered when reading a result set, after receiving
-      its metadata. In this stage server sends packets with rows unitl
-      EOF or ERR packet is sent.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-        unsigned int flags;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          If ERR packet is received, an error has happened and reading
-          the result set is done. Next stage is READY_FOR_COMMAND.
-        */
-
-        if (ERR_PACKET(pkt))
-        {
-          SET_STAGE(ti, READY_FOR_COMMAND);
-          return 0;
-        }
-
-        /*
-          Otherwise row packets are received until we get an EOF packet.
-          We need to check packet length again, because a text-protocol
-          row packet starts with a length-encoded string and thus its
-          first byte can be 0xFE.
-        */
-
-        if (!(EOF_PACKET(pkt) && pkt_len < 9)) 
-          return 0;
-
-        /*
-          In case of a multi-resutset a SERVER_MORE_RESULTS_EXISTS flag can 
-          be set in the EOF packet. In that case next resultset will follow
-          and the next stage is WAIT_FOR_RESULTSET. If 
-          SERVER_MORE_RESULTS_EXISTS flag is not set, next stage is 
-          READY_FOR_COMMAND.
-        */
-
-        flags= uint2korr(pkt+3);
-
-//        fprintf(stderr, "== EOF packet flags: 0x%x\n", flags);
-
-        if (SERVER_MORE_RESULTS_EXISTS & flags)
-          SET_STAGE(ti, WAIT_FOR_RESULTSET);
-        else
-          SET_STAGE(ti, READY_FOR_COMMAND);
-
-        return 0;
-      }
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_PS_DESCRIPTION:
-    /*
-      This stage is entered after executing COM_PREPARE_STMT command.
-      Server  should send stmt OK packet with information about the
-      statement.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 1;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-        unsigned col_count, param_count;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          If we do not get OK packet here, something is wrong.
-        */
-        if (!OK_PACKET(pkt))
-          return 1;
-
-        /*
-          Otherwise we read information about statement parameters
-          (param_count) and produced result set (col_count) and store
-          it in the ti structure.
-        */
-
-        col_count   = uint2korr(pkt+5);
-        param_count = uint2korr(pkt+7);
-
-        SET_PS_INFO(ti, param_count, col_count);
-
-        /*
-          If statement has parameters then next stage is 
-          WAIT_FOR_PS_PARAMETER, where server sends parameter
-          descriptions.
-        */
-
-        if (0 < param_count)
-        {
-          SET_STAGE(ti, WAIT_FOR_PS_PARAMETER);
-          return 0;
-        }
-
-        /*
-          Otherwise, if statement has no parameters but produces
-          a result set, the next stage is WAIT_FOR_FIELD_DEF where
-          server sends descriptions of result set fields.
-        */
-
-        if (0 < col_count)
-        {
-          SET_STAGE(ti, WAIT_FOR_FIELD_DEF);
-          return 0;
-        }
-
-        /*
-          Otherwise (no parameters and no result set), preparing 
-          the statement is done and next stage is READY_FOR_COMMAND.
-        */
-
-        SET_STAGE(ti, READY_FOR_COMMAND);
-        return 0;
-      }
-    default: return 1;
-    }
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_WAIT_FOR_PS_PARAMETER:
-    /*
-      This stage is reached after COM_PREPARE_STMT command and after
-      receiving the stmt OK packet from the server (if the statement 
-      has parameters). Server sends descriptions of the parameters in 
-      the same format in which result set fields are described.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_READ_PACKET: return 0;
-    case TRACE_EVENT_PACKET_RECEIVED:
-      {
-        byte   *pkt;
-        size_t pkt_len;
-        unsigned param_count, col_count;
-
-        get_pkt(args, pkt, pkt_len);
-
-        /*
-          Sending parameter descriptions continues until an EOF 
-          packet is received. To correctly recognize EOF packet 
-          we must check the packet length the same as 
-          in WAIT_FOR_FILED_DEF stage.
-        */
-
-        if (!(EOF_PACKET(pkt) && pkt_len < 9))
-        {
-          return 0;
-        }
-
-        /*
-          After receiving EOF packets next stage depends on whether
-          the statement produces any result set, in which case column
-          definitions will follow, or not.
-
-          We decide this based on statement info stored in the ti 
-          structure.
-        */
-
-        GET_PS_INFO(ti, param_count, col_count);
-
-        if (0 < col_count)
-          SET_STAGE(ti, WAIT_FOR_FIELD_DEF);
-        else
-          SET_STAGE(ti, READY_FOR_COMMAND);
-
-        return 0;
-      }
-    default: return 1;
-    }
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_FILE_REQUEST:
-    /*
-      At this stage client should send a single packet
-      containing contnents of the file requested by the server.
-    */
-    switch (ev)
-    {
-    case TRACE_EVENT_SEND_FILE: return 0;
-    case TRACE_EVENT_PACKET_SENT:
-      {
-        size_t len = va_arg(args, size_t);
-        // empty packet indicates end of file - then server can
-        // send a result set
-        if (0 == len)
-          SET_STAGE(ti, WAIT_FOR_RESULTSET);
-        return 0;
-      }
-    
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  case PROTOCOL_STAGE_DISCONNECTED:
-    /*
-      This is the final stage reached when connection with
-      server ends.
-    */
-    switch (ev)
-    {
-    default: return 1;  // invalid event
-    };
-    break;
-
-  /* ----------------------------- */
-  default: return 1;  // unknown protocol stage
-
-  }  // switch (<protocol stage>)
-
-  return 1;
-}
-
 
-// ===========================
-//  Test plugin
-// ===========================
-
-#ifdef TEST_TRACE_PLUGIN
-
-tracing_start_callback test_trace_plugin_start;
-tracing_stop_callback  test_trace_plugin_stop;
-trace_event_handler    test_trace_plugin_trace;
-invalid_event_handler  test_trace_plugin_invalid_event;
-
-int test_trace_plugin_init(char *a, size_t b, int argc, va_list args);
-int test_trace_plugin_deinit();
-
-
-struct st_mysql_client_plugin_TRACE test_trace_plugin=
-{
-  MYSQL_CLIENT_TRACE_PLUGIN,
-  MYSQL_CLIENT_TRACE_PLUGIN_INTERFACE_VERSION,
-  "test_trace_plugin",
-  "Rafal Somla",
-  "A plugin for testing protocl tracing infrastructure",
-  {0,1,0},
-  "GPL",
-  NULL,
-  test_trace_plugin_init,
-  test_trace_plugin_deinit,
-  NULL,                            // option handling
-  test_trace_plugin_start,
-  test_trace_plugin_stop,
-  test_trace_plugin_trace,
-  test_trace_plugin_invalid_event
-};
-
-
-#include <ctype.h>  // For isprint()
-
-void hexdump(void *ptr, int buflen) {
-  unsigned char *buf = (unsigned char*)ptr;
-  int i, j;
-  for (i=0; i<buflen; i+=16) {
-    printf("%06x: ", i);
-    for (j=0; j<16; j++)
-      if (i+j < buflen)
-        printf("%02x ", buf[i+j]);
-      else
-        printf("   ");
-    printf(" ");
-    for (j=0; j<16; j++)
-      if (i+j < buflen)
-        printf("%c", isprint(buf[i+j]) ? buf[i+j] : '.');
-    printf("\n");
-  }
-} 
-
-void test_packet_dump(const char *title, void *pkt, size_t len)
-{
-  printf("== %s ==\n", title);
-  hexdump(pkt, len > 512 ? 512 : len);
-  printf("==================\n");
-}
-
-
-static my_bool test_trace_log_enabled= 0;
-
-void test_trace_log(const char *fmt, ...)
-{
-  va_list args;
-
-  if (!test_trace_log_enabled)
-    return;
-
-  va_start(args, fmt);
-  vfprintf(stderr, fmt, args);
-  fprintf(stderr, "\n");
-  va_end(args);
-}
-
-
-struct st_test_trace_plugin_data
-{
- char   error;
- int    saved_cmd;
- char   saved_cmd_hdr[128];
- size_t saved_cmd_hdr_len;
- char   saved_cmd_args[128];
- size_t saved_cmd_args_len;
- char   saved_pkt[128];
- size_t saved_pkt_len;
-};
-
-
-void*
-test_trace_plugin_start(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)), 
-                        MYSQL *conn __attribute__((unused)), enum protocol_stage stage)
-{
-  struct st_test_trace_plugin_data *data;
-  test_trace_log("Starting tracing connection in stage %s", stage_name(stage));
-  data= my_malloc(sizeof(struct st_test_trace_plugin_data), MYF(MY_ZEROFILL));
-  return data;
-}
-
-void
-test_trace_plugin_stop(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)), 
-                       MYSQL *conn __attribute__((unused)), 
-                       void *data)
-{
-  my_free(data);
-  test_trace_log("Connection tracing ended");
-}
-
-struct st_test_trace_plugin_data dummy_data;
-
-void 
-test_trace_plugin_trace(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)),
-                        void *data_ptr, MYSQL *conn, 
-                        enum protocol_stage stage, enum trace_event ev, 
-                        va_list args)
+void mysql_trace_trace(struct st_mysql  *m,
+                       enum trace_event ev, 
+                       struct st_trace_event_args args)
 {
-  struct st_test_trace_plugin_data *data= data_ptr ? data_ptr : &dummy_data;
-
-  test_trace_log("%02d = %s = Trace event: %s", 
-                 conn->thread_id, stage_name(stage), event_name(ev));
+  struct st_mysql_trace_info *trace_info= TRACE_DATA(m);
+  struct st_mysql_client_plugin_TRACE *plugin= trace_info ? trace_info->plugin : NULL;
 
-//  saved_cmd= 0;
-//  saved_cmd_hdr= saved_cmd_args= saved_pkt= NULL;
+  DBUG_ASSERT(trace_info);
 
-  if (ev == TRACE_EVENT_ERROR)
-  {
-    struct st_mysql *m = (struct st_mysql*)conn;
-    int         errnum= m->net.last_errno;
-    const char* error= m->net.last_error;
-    test_trace_log("  = Error %d: %s", errnum, error);
-    data->error= 1;
-  }
+  /* Call plugin's trace_event() method if defined */
 
-  switch (ev)
+  if (plugin->trace_event)
   {
-  case TRACE_EVENT_SEND_COMMAND:
-    // command, hdrsize, argsize, hdr, args
-    data->saved_cmd=          va_arg(args, int);
-    data->saved_cmd_hdr_len=  va_arg(args, size_t);
-    data->saved_cmd_args_len= va_arg(args, size_t);
-
-    if (data->saved_cmd_hdr_len > sizeof(data->saved_cmd_hdr))
-      data->saved_cmd_hdr_len= sizeof(data->saved_cmd_hdr);
-
-    if (data->saved_cmd_args_len > sizeof(data->saved_cmd_args))
-      data->saved_cmd_args_len= sizeof(data->saved_cmd_args);
-
-    memcpy(data->saved_cmd_hdr, va_arg(args, void*), data->saved_cmd_hdr_len);
-    memcpy(data->saved_cmd_args, va_arg(args, void*), data->saved_cmd_args_len);
-
-    if (COM_QUERY == data->saved_cmd)
-      test_trace_log("== QUERY: %s", data->saved_cmd_args);
-    else
-      test_trace_log("== cmd: %d", data->saved_cmd);
-    break;
-
-  case TRACE_EVENT_PACKET_RECEIVED:
-    // size, packet
-    data->saved_pkt_len= va_arg(args, size_t);
-    if (data->saved_pkt_len > sizeof(data->saved_pkt))
-      data->saved_pkt_len= sizeof(data->saved_pkt);
-    memcpy(data->saved_pkt, va_arg(args, void*), data->saved_pkt_len);
-    break;
-
-  default:
-    // do nothing
-    break;
+    plugin->trace_event(plugin, GET_DATA(trace_info), m,
+                        GET_STAGE(trace_info), ev, args);
   }
-}
-
-
-enum protocol_stage
-test_trace_plugin_invalid_event(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)),
-                                void *data_ptr, 
-                                MYSQL *conn __attribute__((unused)),
-                                enum protocol_stage stage,
-                                enum trace_event ev)
-{
-  struct st_test_trace_plugin_data *data= data_ptr ? data_ptr : &dummy_data;
-
-  if (PROTOCOL_STAGE_DISCONNECTED == stage)
-    return stage;
-
-  if (data->error)
-    return stage;
-
-  if (PROTOCOL_STAGE_WAIT_FOR_RESULTSET == stage
-      && TRACE_EVENT_SEND_COMMAND == ev
-      && COM_QUIT == data->saved_cmd)
-    return PROTOCOL_STAGE_DISCONNECTED;
 
-  printf("= %s = Event %s is invalid in this stage\n", stage_name(stage), event_name(ev));
-  if(data->saved_pkt)
-    test_packet_dump("Received packet", data->saved_pkt, data->saved_pkt_len);
-
-  printf("= last command: %d\n", data->saved_cmd);
+  /* Stop tracing if end of connection. */
 
-  if(data->saved_cmd_hdr || data->saved_cmd_args)
+  if (TEST_STAGE(trace_info, DISCONNECTED)
+      || TRACE_EVENT_DISCONNECTED == ev)
   {
-    test_packet_dump("CMD header", data->saved_cmd_hdr, data->saved_cmd_hdr_len);
-    test_packet_dump("CMD args", data->saved_cmd_args, data->saved_cmd_args_len);
+    plugin->tracing_stop(plugin, m, GET_DATA(trace_info));
+    my_free(trace_info);
+    TRACE_DATA(m)= NULL;
   }
-  
-  fflush(stdout);
-
-  //assert(0);
-  return PROTOCOL_STAGE_DISCONNECTED;
-}
-
-
-int test_trace_plugin_init(char *a __attribute__((unused)), 
-                           size_t b __attribute__((unused)), 
-                           int argc __attribute__((unused)), 
-                           va_list args __attribute__((unused)))
-{
-  const char *opt= getenv("MYSQL_TEST_TRACE_PLUGIN_LOGGING");
-
-  if (opt && '0' != *opt)
-    test_trace_log_enabled= 1;
 
-  test_trace_log("Test trace plugin initialized");
-  return 0;
 }
-
-int test_trace_plugin_deinit()
-{
-  test_trace_log("Test trace plugin de-initialized");
-  return 0;
-}
-
-#endif

=== modified file 'libmysql/mysql_trace.h'
--- a/libmysql/mysql_trace.h	2012-08-24 10:53:38 +0000
+++ b/libmysql/mysql_trace.h	2012-09-07 12:42:49 +0000
@@ -1,12 +1,20 @@
 #ifndef MYSQL_TRACE_INCLUDED
 #define MYSQL_TRACE_INCLUDED
 
+#if !defined(CLIENT_PROTOCOL_TRACING) || defined(MYSQL_SERVER)
+
+#define MYSQL_TRACE(E,M,ARGS)
+#define MYSQL_TRACE_STAGE(M,S)
+
+#else
+
 #include <mysql/plugin_trace.h>
 #include <sql_common.h>        /* for MYSQL_EXTENSION() */
 #include <stdarg.h>
 
 struct st_mysql_trace_info 
 {
+  struct st_mysql_client_plugin_TRACE *plugin;
   void *trace_plugin_data;
   enum protocol_stage stage;
   enum enum_server_command  last_command; // Last command sent to server
@@ -14,50 +22,62 @@ struct st_mysql_trace_info 
   unsigned col_count;
 };
 
+
 #define TRACE_DATA(M)   (MYSQL_EXTENSION(M)->trace_data)
 
-#ifndef MYSQL_SERVER
+void mysql_trace_trace(struct st_mysql*,
+                       enum trace_event,
+                       struct st_trace_event_args);
+void mysql_trace_start(struct st_mysql*);
+
+#define MYSQL_TRACE(E,M,ARGS)                    \
+  do {                                           \
+  if (NULL == TRACE_DATA(M)) break;              \
+  {                                              \
+    struct st_trace_event_args event_args=       \
+                          TRACE_ARGS_ ## E ARGS; \
+    mysql_trace_trace(M,                         \
+                      TRACE_EVENT_ ## E,         \
+                      event_args);               \
+  }                                              \
+  } while(0)
 
 
-void mysql_trace_trace(struct st_mysql_client_plugin_TRACE*, 
-                       enum trace_event, struct st_mysql*,
-                       ...);
-
-#define MYSQL_TRACE(E,M,ARGS)                  \
-  do {                                         \
-  if (NULL == trace_plugin) break;             \
-  mysql_trace_trace(trace_plugin,              \
-                    TRACE_EVENT_ ## E,         \
-                    M TRACE_ARGS_ ## E ARGS);  \
+#define MYSQL_TRACE_STAGE(M,S)                                  \
+  do {                                                          \
+    if (TRACE_DATA(M))                                          \
+      TRACE_DATA(M)->stage= PROTOCOL_STAGE_ ## S;               \
+    else if (PROTOCOL_STAGE_CONNECTING == PROTOCOL_STAGE_ ## S) \
+      mysql_trace_start(M);                                     \
   } while(0)
 
-
-#define TRACE_ARGS_SEND_SSL_REQUEST(Size, Packet)   , Size, Packet
-#define TRACE_ARGS_SEND_AUTH_RESPONSE(Size, Packet) , Size, Packet
-#define TRACE_ARGS_SEND_AUTH_DATA(Size, Packet)     , Size, Packet
-#define TRACE_ARGS_AUTH_PLUGIN(PluginName)          , PluginName
+/*
+  Macros to parse event arguments and initialize the st_trace_event_args structure
+  accordingly.
+*/
+
+#define TRACE_ARGS_SEND_SSL_REQUEST(Size, Packet)   { NULL, 0, NULL, 0, Packet, Size }
+#define TRACE_ARGS_SEND_AUTH_RESPONSE(Size, Packet) { NULL, 0, NULL, 0, Packet, Size }
+#define TRACE_ARGS_SEND_AUTH_DATA(Size, Packet)     { NULL, 0, NULL, 0, Packet, Size }
+#define TRACE_ARGS_AUTH_PLUGIN(PluginName)          { PluginName, 0, NULL, 0, NULL, 0 }
 #define TRACE_ARGS_SEND_COMMAND(Command, HdrSize, ArgSize, Header, Args) \
-                                                    , Command, HdrSize, ArgSize, Header, Args
-#define TRACE_ARGS_SEND_FILE(Size, Packet)          , Size, Packet
-
-#define TRACE_ARGS_PACKET_SENT(Size)                , Size
-#define TRACE_ARGS_PACKET_RECEIVED(Size, Packet)    , Size, Packet
-#define TRACE_ARGS_CHALLENGE_RECEIVED(Size, Packet) , Size, Packet
-
-#define TRACE_ARGS_ERROR()
-#define TRACE_ARGS_READ_PACKET()
-#define TRACE_ARGS_CONNECT()
-#define TRACE_ARGS_CONNECTED()
-#define TRACE_ARGS_CONNECTING()
-#define TRACE_ARGS_AUTHENTICATED()
-#define TRACE_ARGS_SSL_CONNECT()
-#define TRACE_ARGS_SSL_CONNECTED()
-
+                                                    { NULL, Command, Header, HdrSize, Args, ArgSize }
+#define TRACE_ARGS_SEND_FILE(Size, Packet)          { NULL, 0, NULL, 0, Packet, Size }
 
-#else
+#define TRACE_ARGS_PACKET_SENT(Size)                { NULL, 0, NULL, 0, NULL, Size }
+#define TRACE_ARGS_PACKET_RECEIVED(Size, Packet)    { NULL, 0, NULL, 0, Packet, Size }
+#define TRACE_ARGS_INIT_PACKET_RECEIVED(Size, Packet) { NULL, 0, NULL, 0, Packet, Size }
+
+#define TRACE_ARGS_ERROR()                          { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_READ_PACKET()                    { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_CONNECTING()                     { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_CONNECTED()                      { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_DISCONNECTED()                   { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_AUTHENTICATED()                  { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_SSL_CONNECT()                    { NULL, 0, NULL, 0, NULL, 0 }
+#define TRACE_ARGS_SSL_CONNECTED()                  { NULL, 0, NULL, 0, NULL, 0 }
 
-#define MYSQL_TRACE(E,M,ARGS)
 
-#endif
+#endif /* !defined(CLIENT_PROTOCOL_TRACING) || defined(MYSQL_SERVER) */
 
 #endif

=== added file 'libmysql/test_trace_plugin.cc'
--- a/libmysql/test_trace_plugin.cc	1970-01-01 00:00:00 +0000
+++ b/libmysql/test_trace_plugin.cc	2012-09-07 12:42:49 +0000
@@ -0,0 +1,935 @@
+/** 
+  @file
+ 
+  ===========================
+   Test trace plugin
+  ===========================
+
+  If TEST_TRACE_PLUGIN guard is defined, this plugin is built into libmysql
+  (no plugin loading required). It prints some debug information about trace
+  events reported to it under debug keyword "test_trace". To see these debug
+  messages using the following DBUG flags:
+
+  -------------- -----------------------------------------------
+   d,test_trace  output debug messages with "test_trace" keyword
+   i             prefix each message with thread id
+   o,<path>      output to given file
+  -------------- -----------------------------------------------
+
+  For standard MySQL clients these flags can be set using --debug option, for
+  example: --debug="i:o,test_trace"
+  
+  If MYSQL_TEST_TRACE_CRASH environment variable is set to something else than 0
+  then the plugin will crash if an invalid trace event was reported to it.
+
+  NOTE: Debug information and crashing is supported only in debug builds of
+  libmysql.
+*/
+
+#include <my_global.h>
+#include "mysql.h"
+#include "mysql_trace.h"
+
+extern "C" {
+
+tracing_start_callback test_trace_plugin_start;
+tracing_stop_callback  test_trace_plugin_stop;
+trace_event_handler    test_trace_plugin_trace;
+
+int test_trace_plugin_init(char *a, size_t b, int argc, va_list args);
+int test_trace_plugin_deinit();
+
+
+struct st_mysql_client_plugin_TRACE test_trace_plugin=
+{
+  MYSQL_CLIENT_TRACE_PLUGIN,
+  MYSQL_CLIENT_TRACE_PLUGIN_INTERFACE_VERSION,
+  "test_trace_plugin",
+  "Rafal Somla",
+  "A plugin for testing protocl tracing infrastructure",
+  {0,1,0},
+  "GPL",
+  NULL,
+  test_trace_plugin_init,
+  test_trace_plugin_deinit,
+  NULL,                            // option handling
+  test_trace_plugin_start,
+  test_trace_plugin_stop,
+  test_trace_plugin_trace
+};
+
+#ifndef DBUG_OFF
+
+// These are defined in mysql_trace.c
+const char* stage_name(enum protocol_stage stage);
+const char* event_name(enum trace_event ev);
+
+#endif
+
+} // extern "C"
+
+typedef unsigned char byte;
+
+struct st_test_trace_plugin_data
+{
+  bool tracing_disabled;
+  int  last_cmd;
+  enum protocol_stage next_stage;
+  unsigned int col_count;
+};
+
+#define LOG(ARGS) DBUG_PRINT("test_trace", ARGS)
+#define DUMP(KEY,DATA,LEN) \
+  DBUG_DUMP("test_trace", (const byte*)(DATA), ((LEN) > 32 ? 32 : (LEN)))
+
+/**
+  Global flag telling if test trace plugin should crash if an
+  invalid event is reported to it.
+  
+  This can be used for detecting invalid protocol trace events in
+  MTR tests, for example. The flag is set from environment variable
+  MYSQL_TEST_TRACE_CRASH upon plugin initialization. By default it
+  is disabled.
+*/
+static bool test_trace_crash_on_invalid_event= 0;
+
+
+int 
+test_trace_plugin_init(char *a, size_t b ,int argc, va_list args)
+{
+  const char *opt= getenv("MYSQL_TEST_TRACE_CRASH");
+
+  if (opt && '0' != *opt)
+    test_trace_crash_on_invalid_event= 1;
+
+  LOG(("Test trace plugin initialized"));
+  return 0;
+}
+
+
+int 
+test_trace_plugin_deinit()
+{
+  LOG(("Test trace plugin de-initialized"));
+  return 0;
+}
+
+
+void*
+test_trace_plugin_start(struct st_mysql_client_plugin_TRACE *self, 
+                        MYSQL *conn, enum protocol_stage stage)
+{
+  LOG(("Starting tracing in stage %s", stage_name(stage)));
+
+  struct st_test_trace_plugin_data *plugin_data= new st_test_trace_plugin_data;    
+  memset(plugin_data, 0, sizeof(st_test_trace_plugin_data));  
+
+  if (plugin_data)
+    plugin_data->next_stage= PROTOCOL_STAGE_CONNECTING;
+  else
+  {
+    LOG(("Could not allocate per-connection trace data"
+         " - checking protocol flow will be disabled"));
+  }
+  return plugin_data;
+}
+
+
+void
+test_trace_plugin_stop(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)), 
+                       MYSQL *conn, void *data)
+{
+  LOG(("Tracing connection has ended"));
+  if (data)
+    my_free(data);
+}
+
+// Declare functions for checking protocol flow (defined below)
+
+#define protocol_stage_chk_ev_declare(S)                               \
+  int check_event_ ## S(MYSQL *conn,                            \
+                        struct st_test_trace_plugin_data *data, \
+                        enum trace_event ev,                    \
+                        struct st_trace_event_args args,        \
+                        enum protocol_stage *next_stage);
+
+PROTOCOL_STAGE_LIST(chk_ev_declare)
+
+
+void 
+test_trace_plugin_trace(struct st_mysql_client_plugin_TRACE *self __attribute__((unused)),
+                        void *data_ptr, MYSQL *conn, 
+                        enum protocol_stage stage, enum trace_event ev, 
+                        struct st_trace_event_args args)
+{
+  int check= 0;
+  struct st_test_trace_plugin_data *data= static_cast<st_test_trace_plugin_data*>(data_ptr);
+
+  if (data && data->tracing_disabled)
+    return;
+
+  LOG(("stage: %s, event: %s", stage_name(stage), event_name(ev)));
+
+  if (ev == TRACE_EVENT_ERROR)
+  {
+    int         errnum= conn->net.last_errno;
+    const char* error=  conn->net.last_error;
+    LOG(("error %d: %s", errnum, error));
+    return;
+  }
+
+  if (!data)
+    return;
+
+  if (data && data->next_stage != stage)
+  {
+    LOG(("wrong stage, expected: %s", stage_name(data->next_stage)));
+    if (test_trace_crash_on_invalid_event)
+      DBUG_ASSERT(0);
+  }
+
+
+  // Show trace event details
+
+  switch (ev)
+  {
+  case TRACE_EVENT_DISCONNECTED:
+    LOG(("Connection  closed"));
+    return;
+
+  case TRACE_EVENT_SEND_COMMAND:
+    switch(args.cmd)
+    {
+    case COM_BINLOG_DUMP:
+    case COM_BINLOG_DUMP_GTID:
+    case COM_TABLE_DUMP:
+      LOG(("Replication command (%d) - disabling furthert tracing", args.cmd));
+      data->tracing_disabled= true;
+      break;
+
+    case COM_QUERY:
+      LOG(("query: %s", args.pkt));
+      break;
+
+    case COM_QUIT:
+      LOG(("COM_QUIT"));
+      break;
+    
+    /* TODO:
+    case COM_STMT_PREPARE: NEXT_STAGE(WAIT_FOR_PS_DESCRIPTION); break;
+    case COM_STMT_EXECUTE: NEXT_STAGE(WAIT_FOR_RESULT); break;
+    */
+
+    default: 
+      LOG(("cmd: %d", args.cmd));
+      if (args.hdr_len > 0)
+        DUMP("cmd hdr", args.hdr, args.hdr_len);
+      if (args.pkt_len > 0)
+        DUMP("cmd args", args.pkt, args.pkt_len);
+      break;
+    };
+    break;
+
+  case TRACE_EVENT_AUTH_PLUGIN:
+    LOG(("Using authentication plugin: %s", args.plugin_name));
+    break;
+
+  case TRACE_EVENT_SEND_SSL_REQUEST:
+  case TRACE_EVENT_SEND_AUTH_RESPONSE:
+        // TODO: Parse response and show info.
+  case TRACE_EVENT_SEND_AUTH_DATA:
+  case TRACE_EVENT_SEND_FILE:
+    DUMP("packet sent", args.pkt, args.pkt_len);
+    break;
+
+  case TRACE_EVENT_PACKET_RECEIVED:
+  case TRACE_EVENT_INIT_PACKET_RECEIVED:
+      // TODO: Parse init packet and show info.
+    DUMP("packet received", args.pkt, args.pkt_len);
+    break;
+
+  default: break;
+  }
+
+
+
+#define protocol_stage_check(S) \
+  case PROTOCOL_STAGE_ ## S: \
+    check= check_event_ ## S(conn, data, ev, args, &(data->next_stage)); \
+    break; 
+
+  switch (stage)
+  {
+    PROTOCOL_STAGE_LIST(check)
+  default:
+    LOG(("invlaid stage %d", stage));
+    if (test_trace_crash_on_invalid_event)
+      DBUG_ASSERT(0);
+  }
+
+
+  if (check)
+  {
+    LOG(("invalid event detected"));
+    if (test_trace_crash_on_invalid_event)
+      DBUG_ASSERT(0);
+  }
+}
+
+
+/*
+ Macros to recognize various types of server replies.
+*/
+#define OK_PACKET(PKT)    (*((byte*)PKT) == 0x00)
+#define ERR_PACKET(PKT)   (*((byte*)PKT) == 0xFF)
+#define EOF_PACKET(PKT)   (*((byte*)PKT) == 0xFE)
+#define FILE_REQUEST(PKT) (*((byte*)PKT) == 0xFB)
+
+
+#define NEXT_STAGE(S) do{ if(next_stage) *next_stage= PROTOCOL_STAGE_ ## S; } while(0)
+
+
+int check_event_CONNECTING(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This is the first stage of the protocol, when client is establishing
+    physical connection with the server. After connection is established
+    protocol moves to WAIT_FOR_CHALLENGE stage where the first 
+    authentication challenge packet is expected from the server.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_CONNECTING:         return 0;
+  case TRACE_EVENT_CONNECTED:          
+    NEXT_STAGE(WAIT_FOR_INIT_PACKET); return 0;
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_INIT_PACKET(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    In this stage client waits for the first challenge packet from the
+    server. When it is received, protocol movest to AUTHENTICATE stage
+    where client authorizes itself against server.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET:        return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:    return 0; // TODO: Parse init packet and show info
+  case TRACE_EVENT_INIT_PACKET_RECEIVED: NEXT_STAGE(AUTHENTICATE); return 0;
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_AUTHENTICATE(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    In this stage client exchanges various packets with the server to:
+    - authenticate itself against the server,
+    - negotiante client/server capabilities and connection parameters,
+    - establish encrypted SSL connection.
+    At any moment during this exchange server can send an ERR packet
+    indicating that it rejects the connection.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_AUTHENTICATED:     NEXT_STAGE(READY_FOR_COMMAND); return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      /*
+        Move to DISCONNECTED stage if ERR packet was received from the
+        server.
+      */
+      if (ERR_PACKET(args.pkt))
+      {
+        LOG(("Server rejected connection (ERR packet)"));
+        NEXT_STAGE(DISCONNECTED);
+      }
+
+      return 0;
+    }
+  
+  case TRACE_EVENT_AUTH_PLUGIN:
+  case TRACE_EVENT_SEND_SSL_REQUEST:
+  case TRACE_EVENT_SSL_CONNECT:
+  case TRACE_EVENT_SSL_CONNECTED:
+  case TRACE_EVENT_SEND_AUTH_RESPONSE:
+  case TRACE_EVENT_SEND_AUTH_DATA:
+  case TRACE_EVENT_READ_PACKET:
+  case TRACE_EVENT_PACKET_SENT:
+    return 0;
+
+  default: return 1;  /* invalid event */
+  };
+}
+
+int check_event_SSL_NEGOTIATION(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  switch (ev)
+  {
+  case TRACE_EVENT_PACKET_SENT:
+  case TRACE_EVENT_PACKET_RECEIVED:
+  case TRACE_EVENT_SSL_CONNECT:
+  case TRACE_EVENT_SSL_CONNECTED:
+    return 0;   
+
+  default: return 1;  /* invalid event */
+  }
+}
+
+
+int check_event_READY_FOR_COMMAND(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This is the stage when client can send a command to the server.
+    After sending command packet to the server, PACKET_SENT trace
+    event happens. The next stage depends on whether a result set
+    is expected after the command, or just OK/ERR reply or it is 
+    a command with no reply from server.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_SEND_COMMAND:
+    /* 
+      Save the command code (to be examined in the following 
+      PACKET_SENT event) and reset PS information stored in 
+      trace info record 
+    */
+    if (data)
+      data->last_cmd = args.cmd;
+
+    /*
+      Replication commands are not supported - report them as
+      invalid event so that trace plugin can decide how to proceed.
+    */
+    switch (args.cmd)
+    {
+    case COM_BINLOG_DUMP:
+    case COM_BINLOG_DUMP_GTID:
+    case COM_TABLE_DUMP:
+      return 1;
+
+    default: 
+      return 0;
+    }
+
+  case TRACE_EVENT_PACKET_SENT:
+    /*
+      Move to correct stage based on the command that was
+      reported in the preceeding SEND_COMMAND event.
+    */
+    if (!data)
+      return 1;
+    switch (data->last_cmd)
+    {
+    case COM_STMT_PREPARE: NEXT_STAGE(WAIT_FOR_PS_DESCRIPTION); break;
+    case COM_QUERY:
+    case COM_STMT_EXECUTE: NEXT_STAGE(WAIT_FOR_RESULT); break;
+
+    /* 
+       No server reply is expected after these commands so we reamin ready
+       for the next command.
+    */
+    case COM_QUIT:         //NEXT_STAGE(DISCONNECTED);       break;
+    case COM_REFRESH:
+    case COM_STMT_SEND_LONG_DATA: 
+    case COM_STMT_CLOSE:
+    case COM_REGISTER_SLAVE:
+      return 0;
+
+    /*
+      These replication commands are not supported (the SEND_COMMAND
+      event was already reported as invalid).
+    */
+    case COM_BINLOG_DUMP:
+    case COM_BINLOG_DUMP_GTID:
+    case COM_TABLE_DUMP:
+      return 1;
+
+    /*
+      After COM_PROCESS_INFO server sends a regular result set.
+    */
+    case COM_PROCESS_INFO:
+      NEXT_STAGE(WAIT_FOR_RESULT);
+      break;
+
+    /*
+      Server replies to COM_STATISTICS with a single packet 
+      containing a string with statistics information.
+    */
+    case COM_STATISTICS:
+      NEXT_STAGE(WAIT_FOR_PACKET);
+      break;
+
+    /*
+      After COM_CHANGE_USER a regular authentication exchange
+      is performad.
+    */
+    case COM_CHANGE_USER:
+      NEXT_STAGE(AUTHENTICATE);
+      break;
+
+    /*
+      For all other commands a simple OK/ERR reply from server
+      is expected.
+    */
+    default:
+      NEXT_STAGE(WAIT_FOR_RESULT);
+      break;
+    };
+    return 0;
+
+  case TRACE_EVENT_AUTH_PLUGIN:
+    /*
+      The AUTH_PLUGIN event can happen in READY_FOR_COMMAND stage
+      before COM_CHANGE_USER is executed. When the command is executed
+      the stage will be changed to AUTHENTICATE.
+    */
+    return 0;
+
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_PACKET(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    After some commands (COM_STATISTICS) server sends just a
+    single packet and then it is ready for processing more
+    commands.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 0;
+  case TRACE_EVENT_PACKET_RECEIVED: 
+    NEXT_STAGE(READY_FOR_COMMAND);
+    return 0;      
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_RESULT(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This stage is reached after a command which can produce a result set
+    (COM_QUERY or COM_STMT_EXECUTE). In this stage a single packet is 
+    received from the server informing about the result of the query:
+    - ERR packet informs that error has happened when processing query,
+    - OK packet informs that query produced no result set,
+    - FILE_REQUEST packet asks client to send contents of a given file,
+    Otherwise information about the number of columns in the result set
+    is received.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      byte *pkt= (byte*)args.pkt;
+      /*
+        If server sends ERR, query processing is done
+        and next stage is READY_FOR_COMMAND.
+      */
+      if (ERR_PACKET(pkt) || EOF_PACKET(pkt))
+      {
+        if (ERR_PACKET(pkt))
+          LOG(("Server reports error"));
+        NEXT_STAGE(READY_FOR_COMMAND);
+        return 0;
+      }
+
+      /*
+        If server sends FILE_REQUEST packet, we move to FILE_REQUEST
+        stage of the protocol.
+      */
+      if (FILE_REQUEST(pkt))
+      {
+        LOG(("Server requests file: %s", pkt+1));
+        NEXT_STAGE(FILE_REQUEST);
+        return 0;
+      }
+
+      /*
+        If query generates no data, server replies with OK packet. In
+        case of a multi-query, more result sets can follow, as 
+        indicated by SERVER_MORE_RESULTS_EXISTS flag in the OK packet.
+        If the flag is set we move to WAIT_FOR_RESULTSET stage to 
+        read the following result set(s).
+      */
+      if (OK_PACKET(args.pkt))
+      {
+        /* Extract flags from the OK packet */
+        unsigned int flags;
+        unsigned int affected_rows;
+        unsigned int last_insert_id;
+
+        pkt++;                         /* cmd header */
+        affected_rows=  net_field_length(&pkt);  /* affected_rows */
+        last_insert_id= net_field_length(&pkt);  /* last_insert_id */
+        flags= uint2korr(pkt);
+
+        LOG(("OK from server; flags: 0x%02X, affected rows: %u, last insert_id: %u",
+             flags, affected_rows, last_insert_id));
+
+        if (SERVER_MORE_RESULTS_EXISTS & flags)
+        {
+          LOG(("Expecting next result set"));
+          NEXT_STAGE(WAIT_FOR_RESULT);
+        }
+        else
+          NEXT_STAGE(READY_FOR_COMMAND);
+        return 0;
+      }
+
+      /*
+        Otherwise a result set is expected from the server so we move
+        to WAIT_FOR_FIELD_DEF stage.
+      */
+      LOG(("Expecting result set with %lu columns", net_field_length(&pkt)));
+      NEXT_STAGE(WAIT_FOR_FIELD_DEF);
+      return 0;
+    }
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_FIELD_DEF(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    In this stage definitions of row fields are read from server. This
+    can happen when reading query result set, or after preparing
+    a statement which produces result set or upon explicit COM_FIELD_LIST 
+    request.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      /*
+        If the received packet is not an EOF packet, then it is description
+        of the next row field and we can continue, remaining in the same stage.
+
+        To correctly recognize EOF packets we have to check its length, because
+        a field description packet can theoretically start with byte 0xFE - the 
+        same as the first byte of the EOF packet. 
+        
+        This can happen if the first length-encoded string in the packet starts 
+        with 8-byte length-encoded integer whose first byte is 0xFE. In this
+        case the string and thus the whole packet is longer than 9 bytes and\
+        EOF packet is always shorter than 9 bytes.
+      */
+      if (!(EOF_PACKET(args.pkt) && args.pkt_len < 9))
+      {
+        LOG(("Received next field definition"));
+        return 0;
+      }
+
+      LOG(("No more fields"));
+      /*
+        If this WAIT_FOR_FIELD_DEF stage was reached after COM_STMT_PREPARE or
+        COM_FIELD_LIST then the EOF packet ends proccesing of the command and 
+        next stage is READY_FOR_COMMAND. 
+        Otherwise we are reading a result set and the field definitions have 
+        ended - next stage is WAIT_FOR_ROW.
+      */
+      switch (data->last_cmd)
+      {
+      case COM_STMT_PREPARE:
+      case COM_FIELD_LIST:
+        NEXT_STAGE(READY_FOR_COMMAND);
+        break;
+      default:
+        LOG(("Reading result set rows"));
+        NEXT_STAGE(WAIT_FOR_ROW);
+      }
+
+      return 0;
+    }
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_ROW(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This stage is entered when reading a result set, after receiving
+    its metadata. In this stage server sends packets with rows unitl
+    EOF or ERR packet is sent.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      unsigned int flags;
+      /*
+        If ERR packet is received, an error has happened and reading
+        the result set is done. Next stage is READY_FOR_COMMAND.
+      */
+      if (ERR_PACKET(args.pkt))
+      {
+        LOG(("Server signals error"));
+        NEXT_STAGE(READY_FOR_COMMAND);
+        return 0;
+      }
+
+      /*
+        Otherwise row packets are received until we get an EOF packet.
+        We need to check packet length again, because a text-protocol
+        row packet starts with a length-encoded string and thus its
+        first byte can be 0xFE.
+      */
+      if (!(EOF_PACKET(args.pkt) && args.pkt_len < 9))
+      {
+        LOG(("Received next row"));
+        return 0;
+      }
+
+      LOG(("End of data"));
+      /*
+        In case of a multi-resutset a SERVER_MORE_RESULTS_EXISTS flag can 
+        be set in the EOF packet. In that case next resultset will follow
+        and the next stage is WAIT_FOR_RESULTSET. If 
+        SERVER_MORE_RESULTS_EXISTS flag is not set, next stage is 
+        READY_FOR_COMMAND.
+      */
+
+      flags= uint2korr(((char*)args.pkt)+3);
+
+      if (SERVER_MORE_RESULTS_EXISTS & flags)
+      {
+        LOG(("Expecting next result set"));
+        NEXT_STAGE(WAIT_FOR_RESULT);
+      }
+      else
+        NEXT_STAGE(READY_FOR_COMMAND);
+
+      return 0;
+    }
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_WAIT_FOR_PS_DESCRIPTION(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This stage is entered after executing COM_PREPARE_STMT command.
+    Server  should send stmt OK packet with information about the
+    statement.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 1;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      byte *pkt= static_cast<byte*>(const_cast<void*>(args.pkt));
+      long unsigned int stmt_id;
+      unsigned int col_count, param_count;
+
+      /*
+        If we do not get OK packet here, something is wrong.
+      */
+      if (!OK_PACKET(args.pkt))
+      {
+        LOG(("Wrong PS description"));
+        return 1;
+      }
+
+      /*
+        Otherwise we read information about statement parameters
+        (param_count) and produced result set (col_count) and store
+        it in the ti structure.
+      */
+
+      stmt_id     = uint4korr(pkt+1);
+      col_count   = uint2korr(pkt+5);
+      param_count = uint2korr(pkt+7);
+      data->col_count= col_count;
+
+      LOG(("Prepared statement %lu; params: %u, cols: %u",
+           stmt_id, param_count, col_count));
+
+      /*
+        If statement has parameters then next stage is 
+        WAIT_FOR_PS_PARAMETER, where server sends parameter
+        descriptions.
+      */
+      if (0 < param_count)
+      {
+        NEXT_STAGE(WAIT_FOR_PS_PARAMETER);
+        return 0;
+      }
+
+      /*
+        Otherwise, if statement has no parameters but produces
+        a result set, the next stage is WAIT_FOR_FIELD_DEF where
+        server sends descriptions of result set fields.
+      */
+      if (0 < col_count)
+      {
+        NEXT_STAGE(WAIT_FOR_FIELD_DEF);
+        return 0;
+      }
+
+      /*
+        Otherwise (no parameters and no result set), preparing 
+        the statement is done and next stage is READY_FOR_COMMAND.
+      */
+      NEXT_STAGE(READY_FOR_COMMAND);
+      return 0;
+    }
+  default: return 1;
+  }
+}
+
+
+int check_event_WAIT_FOR_PS_PARAMETER(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This stage is reached after COM_PREPARE_STMT command and after
+    receiving the stmt OK packet from the server (if the statement 
+    has parameters). Server sends descriptions of the parameters in 
+    the same format in which result set fields are described.
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_READ_PACKET: return 0;
+  case TRACE_EVENT_PACKET_RECEIVED:
+    {
+      /*
+        Sending parameter descriptions continues until an EOF 
+        packet is received. To correctly recognize EOF packet 
+        we must check the packet length the same as 
+        in WAIT_FOR_FILED_DEF stage.
+      */
+      if (!(EOF_PACKET(args.pkt) && args.pkt_len < 9))
+      {
+        LOG(("Received next parameter description"));
+        return 0;
+      }
+
+      LOG(("No more parameters"));
+      /*
+        After receiving EOF packets next stage depends on whether
+        the statement produces any result set, in which case column
+        definitions will follow, or not.
+
+        We decide this based on statement info stored in the ti 
+        structure.
+      */
+
+      if (0 < data->col_count)
+        NEXT_STAGE(WAIT_FOR_FIELD_DEF);
+      else
+        NEXT_STAGE(READY_FOR_COMMAND);
+
+      return 0;
+    }
+  default: return 1;
+  }
+}
+
+
+int check_event_FILE_REQUEST(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    At this stage client sends packets with the file contents
+    followed by an empty packet. After that client waits for
+    a result set from server (which can be empty).
+  */
+  switch (ev)
+  {
+  case TRACE_EVENT_SEND_FILE: return 0;
+  case TRACE_EVENT_PACKET_SENT:
+    {
+      /*
+        See if the packet sent was empty and if yes, move to
+        WAIT_FOR_RESULTSET stage.
+      */
+      if (0 == args.pkt_len)
+      {
+        LOG(("File transfer done"));
+        NEXT_STAGE(WAIT_FOR_RESULT);
+      }
+      return 0;
+    }
+  
+  default: return 1;  /* invalid event */
+  };
+}
+
+
+int check_event_DISCONNECTED(MYSQL *conn,
+                           struct st_test_trace_plugin_data *data,
+                           enum trace_event ev,
+                           struct st_trace_event_args args,
+                           enum protocol_stage *next_stage)
+{
+  /*
+    This is the final stage reached when connection with
+    server ends. No events should happen in this stage.
+  */
+  return 1;
+}
+
+
+
+
+

=== modified file 'sql-common/client.c'
--- a/sql-common/client.c	2012-08-23 19:41:04 +0000
+++ b/sql-common/client.c	2012-09-07 12:42:49 +0000
@@ -757,10 +757,61 @@ cli_advanced_command(MYSQL *mysql, enum 
 
   MYSQL_TRACE(PACKET_SENT, mysql, (header_length + arg_length)); 
 
+#if defined(CLIENT_PROTOCOL_TRACING)
+  switch (command)
+  {
+  case COM_STMT_PREPARE:
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_PS_DESCRIPTION);
+    break;
+
+  /* 
+    No server reply is expected after these commands so we reamin ready
+    for the next command.
+ */
+  case COM_REFRESH:
+  case COM_STMT_SEND_LONG_DATA: 
+  case COM_STMT_CLOSE:
+  case COM_REGISTER_SLAVE:
+  case COM_QUIT:
+    break;
+
+  /*
+    These replication commands are not supported and we bail out
+    by pretending that connection has been closed.
+  */
+  case COM_BINLOG_DUMP:
+  case COM_BINLOG_DUMP_GTID:
+  case COM_TABLE_DUMP:
+    MYSQL_TRACE(DISCONNECTED, mysql, ());
+    break;
+
+  /*
+    After COM_CHANGE_USER a regular authentication exchange
+    is performed.
+  */
+  case COM_CHANGE_USER:
+    MYSQL_TRACE_STAGE(mysql, AUTHENTICATE);
+    break;
+
+  /*
+    Server replies to COM_STATISTICS with a single packet 
+    containing a string with statistics information.
+  */
+  case COM_STATISTICS:
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_PACKET);
+    break;
+
+  default: MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT); break;
+  }
+#endif
+
   result=0;
   if (!skip_check)
+  {
     result= ((mysql->packet_length=cli_safe_read(mysql)) == packet_error ?
 	     1 : 0);
+  }
+
 end:
   DBUG_PRINT("exit",("result: %d", result));
   DBUG_RETURN(result);
@@ -822,6 +873,12 @@ my_bool flush_one_result(MYSQL *mysql)
     mysql->server_status=uint2korr(pos);
     pos+=2;
   }
+#if defined(CLIENT_PROTOCOL_TRACING)
+  if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+  else
+    MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
   return FALSE;
 }
 
@@ -860,6 +917,12 @@ my_bool opt_flush_ok_packet(MYSQL *mysql
       mysql->warning_count=uint2korr(pos);
       pos+=2;
     }
+#if defined(CLIENT_PROTOCOL_TRACING)
+    if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+      MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+    else
+      MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
   }
   return FALSE;
 }
@@ -989,6 +1052,7 @@ void end_server(MYSQL *mysql)
   net_end(&mysql->net);
   free_old_query(mysql);
   errno= save_errno;
+  MYSQL_TRACE(DISCONNECTED, mysql, ());
   DBUG_VOID_RETURN;
 }
 
@@ -1594,6 +1658,12 @@ MYSQL_DATA *cli_read_rows(MYSQL *mysql,M
     DBUG_PRINT("info",("status: %u  warning_count:  %u",
 		       mysql->server_status, mysql->warning_count));
   }
+#if defined(CLIENT_PROTOCOL_TRACING)
+  if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+  else
+    MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
   DBUG_PRINT("exit", ("Got %lu rows", (ulong) result->rows));
   DBUG_RETURN(result);
 }
@@ -1621,6 +1691,12 @@ read_one_row(MYSQL *mysql,uint fields,MY
       mysql->warning_count= uint2korr(net->read_pos+1);
       mysql->server_status= uint2korr(net->read_pos+3);
     }
+#if defined(CLIENT_PROTOCOL_TRACING)
+    if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+      MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+    else
+      MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
     return 1;				/* End of data */
   }
   prev_pos= 0;				/* allowed to write at packet[-1] */
@@ -2340,7 +2416,7 @@ static auth_plugin_t sha256_password_cli
 #ifdef AUTHENTICATION_WIN
 extern auth_plugin_t win_auth_client_plugin;
 #endif
-#ifdef TEST_TRACE_PLUGIN
+#if defined(CLIENT_PROTOCOL_TRACING) && defined(TEST_TRACE_PLUGIN)
 extern auth_plugin_t test_trace_plugin;
 #endif
 
@@ -2355,7 +2431,7 @@ struct st_mysql_client_plugin *mysql_cli
 #ifdef AUTHENTICATION_WIN
   (struct st_mysql_client_plugin *)&win_auth_client_plugin,
 #endif
-#ifdef TEST_TRACE_PLUGIN
+#if defined(CLIENT_PROTOCOL_TRACING) && defined(TEST_TRACE_PLUGIN)
   (struct st_mysql_client_plugin *)&test_trace_plugin,
 #endif
   0
@@ -2664,6 +2740,8 @@ static int send_client_reply_packet(MCPV
       goto error;
     }
 
+    MYSQL_TRACE_STAGE(mysql, SSL_NEGOTIATION);
+
     /* Create the VioSSLConnectorFd - init SSL and load certs */
     if (!(ssl_fd= new_VioSSLConnectorFd(options->ssl_key,
                                         options->ssl_cert,
@@ -2708,6 +2786,7 @@ static int send_client_reply_packet(MCPV
     }
 
     MYSQL_TRACE(SSL_CONNECTED, mysql, ());
+    MYSQL_TRACE_STAGE(mysql, AUTHENTICATE);
   }
 #endif /* HAVE_OPENSSL */
 
@@ -3013,7 +3092,7 @@ int run_plugin_auth(MYSQL *mysql, char *
   mpvio.db= db;
   mpvio.plugin= auth_plugin;
 
-  MYSQL_TRACE(AUTH_PLUGIN, mysql, (auth_plugin));
+  MYSQL_TRACE(AUTH_PLUGIN, mysql, (auth_plugin->name));
 
   res= auth_plugin->authenticate_user((struct st_plugin_vio *)&mpvio, mysql);
   DBUG_PRINT ("info", ("authenticate_user returned %s", 
@@ -3087,7 +3166,7 @@ int run_plugin_auth(MYSQL *mysql, char *
     if (check_plugin_enabled(mysql, auth_plugin))
       DBUG_RETURN(1);
 
-    MYSQL_TRACE(AUTH_PLUGIN, mysql, (auth_plugin));
+    MYSQL_TRACE(AUTH_PLUGIN, mysql, (auth_plugin->name));
 
     mpvio.plugin= auth_plugin;
     res= auth_plugin->authenticate_user((struct st_plugin_vio *)&mpvio, mysql);
@@ -3259,6 +3338,7 @@ CLI_MYSQL_REAL_CONNECT(MYSQL *mysql,cons
   mysql->server_status=SERVER_STATUS_AUTOCOMMIT;
   DBUG_PRINT("info", ("Connecting"));
 
+  MYSQL_TRACE_STAGE(mysql, CONNECTING);
   MYSQL_TRACE(CONNECTING, mysql, ());
 
   /*
@@ -3610,6 +3690,7 @@ CLI_MYSQL_REAL_CONNECT(MYSQL *mysql,cons
     net->max_packet_size= mysql->options.max_allowed_packet;
 
   MYSQL_TRACE(CONNECTED, mysql, ());
+  MYSQL_TRACE_STAGE(mysql, WAIT_FOR_INIT_PACKET);
 
   /* Get version info */
   mysql->protocol_version= PROTOCOL_VERSION;	/* Assume this */
@@ -3743,7 +3824,8 @@ CLI_MYSQL_REAL_CONNECT(MYSQL *mysql,cons
 
   mysql->client_flag= client_flag;
 
-  MYSQL_TRACE(CHALLENGE_RECEIVED, mysql, (pkt_length, net->read_pos));
+  MYSQL_TRACE(INIT_PACKET_RECEIVED, mysql, (pkt_length, net->read_pos));
+  MYSQL_TRACE_STAGE(mysql, AUTHENTICATE);
 
   /*
     Part 2: invoke the plugin to send the authentication data to the server
@@ -3753,6 +3835,8 @@ CLI_MYSQL_REAL_CONNECT(MYSQL *mysql,cons
                       scramble_plugin, db))
     goto error;
 
+  MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+
   /*
     Part 3: authenticated, finish the initialization of the connection
   */
@@ -4121,6 +4205,12 @@ get_info:
 		       mysql->server_status, mysql->warning_count));
     if (pos < mysql->net.read_pos+length && net_field_length(&pos))
       mysql->info=(char*) pos;
+#if defined(CLIENT_PROTOCOL_TRACING)
+    if (mysql->server_status & SERVER_MORE_RESULTS_EXISTS)
+      MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+    else
+      MYSQL_TRACE_STAGE(mysql, READY_FOR_COMMAND);
+#endif
     DBUG_RETURN(0);
   }
 #ifdef MYSQL_CLIENT
@@ -4128,6 +4218,8 @@ get_info:
   {
     int error;
 
+    MYSQL_TRACE_STAGE(mysql, FILE_REQUEST);
+
     if (!(mysql->options.client_flag & CLIENT_LOCAL_FILES))
     {
       set_mysql_error(mysql, CR_MALFORMED_PACKET, unknown_sqlstate);
@@ -4135,6 +4227,9 @@ get_info:
     }   
 
     error= handle_local_infile(mysql,(char*) pos);
+
+    MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
+
     if ((length= cli_safe_read(mysql)) == packet_error || error)
       DBUG_RETURN(1);
     goto get_info;				/* Get info packet */
@@ -4143,6 +4238,8 @@ get_info:
   if (!(mysql->server_status & SERVER_STATUS_AUTOCOMMIT))
     mysql->server_status|= SERVER_STATUS_IN_TRANS;
 
+  MYSQL_TRACE_STAGE(mysql, WAIT_FOR_FIELD_DEF);
+
   if (!(fields=cli_read_rows(mysql,(MYSQL_FIELD*)0, protocol_41(mysql) ? 7:5)))
     DBUG_RETURN(1);
   if (!(mysql->fields=unpack_fields(mysql, fields,&mysql->field_alloc,
@@ -4151,6 +4248,9 @@ get_info:
     DBUG_RETURN(1);
   mysql->status= MYSQL_STATUS_GET_RESULT;
   mysql->field_count= (uint) field_count;
+
+  MYSQL_TRACE_STAGE(mysql, WAIT_FOR_ROW);
+
   DBUG_PRINT("exit",("ok"));
   DBUG_RETURN(0);
 }

=== modified file 'sql-common/client_plugin.c'
--- a/sql-common/client_plugin.c	2012-07-20 16:36:35 +0000
+++ b/sql-common/client_plugin.c	2012-08-28 07:28:25 +0000
@@ -36,7 +36,10 @@
 #include <sql_common.h>
 #include "errmsg.h"
 #include <mysql/client_plugin.h>
+
+#if defined(CLIENT_PROTOCOL_TRACING)
 #include <mysql/plugin_trace.h>
+#endif
 
 struct st_client_plugin_int {
   struct st_client_plugin_int *next;
@@ -145,10 +148,9 @@ add_plugin(MYSQL *mysql, struct st_mysql
     goto err1;
   }
 
-#ifndef MYSQL_SERVER
+#if defined(CLIENT_PROTOCOL_TRACING) && !defined(MYSQL_SERVER)
   if (plugin->type == MYSQL_CLIENT_TRACE_PLUGIN && NULL != trace_plugin)
   {
-    // TODO: put names of plugins in the trace log
     errmsg= "Can not load another trace plugin while one is already loaded";
     goto err1;
   }
@@ -176,7 +178,7 @@ add_plugin(MYSQL *mysql, struct st_mysql
   plugin_list[plugin->type]= p;
   net_clear_error(&mysql->net);
 
-#ifndef MYSQL_SERVER
+#if defined(CLIENT_PROTOCOL_TRACING) && !defined(MYSQL_SERVER)
   if (plugin->type == MYSQL_CLIENT_TRACE_PLUGIN)
   {
     trace_plugin = (struct st_mysql_client_plugin_TRACE*)plugin;

No bundle (reason: useless for push emails).
Thread
bzr push into mysql-trunk branch (rafal.somla:4084 to 4086) Rafal Somla12 Sep