WL#6226: Protocol tracing - client side
Affects: Server-5.7
—
Status: Complete
Rationale ========= This opens a possibility to collect data about performance of client-server connection (on client side). The CTA plugin for libmysql will use this protocol-tracing infrastructure. Description =========== Define hooks inside client library code which allow tracing of protocol events such as: - sending packets to server, - receiving various kinds of server replies (simple ERR/OK, resultset metadata, resultset rows etc), - various stages of authentication handshake. Normally these hooks will do nothing (and should introduce minimal overhead). But there will be a possibility to load a trace plugin, which would be invoked by the hooks and which can process the events in some way. Notes ===== - Pushed to mysql-trunk on 2013-07-24. User Documentation ================== http://dev.mysql.com/doc/relnotes/mysql/5.7/en/news-5-7-2.html http://dev.mysql.com/doc/refman/5.7/en/writing-protocol-trace-plugins.html
A new type of client-side plugin, MYSQL_CLIENT_TRACE_PLUGIN will be defined.
Such trace plugin, if loaded into libmysql, will receive notifications about
various events related to MySQL protocol exchange with the server. It is up to
the plugin to decide what to do with this information.
Only one trace plugin can be loaded at a time. Attempts to load another plugin
of type MYSQL_CLIENT_TRACE_PLUGIN when one is already loaded will trigger an
error.
After plugin is loaded, all new connections will be traced using that plugin.
Connections which were active at the time of loading the plugin will not be
traced.
Note: Only new connections can be traced and tracing always starts in
CONNECTING stage. An on-going connection which was not traced from the beginning
can not be traced later.
Trace plugin methods
====================
A trace plugin will provide the following methods:
tracing_start
-------------
Called when tracing with this plugin is enabled on a connection.
Input:
- pointer to the plugin instance (self),
- connection handle,
Output:
- pointer to plugin-specific, per-connection data (if any).
A trace plugin might want to maintain a per-connection information. It can
return a pointer to memory area holding such information. It will be stored in a
connection handle and passed to other plugin methods.
tracing_stop
------------
Called when tracing with this plugin on a connection has stopped.
Input:
- pointer to the plugin instance (self),
- connection handle,
- this plugin's per-connection data (if any),
Output: none.
If a plugin allocated any per-connection resources, it should de-allocate them
here.
trace_event
-----------
Called when a trace event occurs.
Input:
- pointer to the plugin instance (self),
- trace event
- current protocol stage
- connection handle
- plugin's per-connection data (if any),
- optional trace event parameters.
Output:
Indication whether tracing of the connection should be stopped here or
continued.
It is up to the plugin to decide what to do in this method. However, it can not
send queries or other commands to the server because trace_event method can be
called inside on-going conversation between client and server. The only
exception is the AUTHENTICATED trace event (see below). When this event is
passed to trace_event() method, the state of the client is such that it can send
new queries and commands to the server. Generating of trace events will be
suppressed for queries and commands issued inside trace_event() method.
Trace events
============
A trace plugin will be notified of the following events:
---------------------- -----------------------------------------------------
Connection events
---------------------- -----------------------------------------------------
CONNECTING Client is connecting to the server.
CONNECTED Physical connection has been established.
DISCONNECTED Connection with server was terminated.
---------------------- -----------------------------------------------------
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
---------------------- -----------------------------------------------------
INIT_PACKET_RECEIVED Client received initial handshake packet.
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.
---------------------- -----------------------------------------------------
Note: The following commands used for replication are not supported:
COM_BINLOG_DUMP, COM_BINLOG_DUMP_GTID, COM_TABLE_DUMP. When such command is
issued by client, tracing of the connection will stop after sending DISCONNECTED
event to the plugin.
Trace event data
----------------
For same events additional information will be passed to event handler:
- Packet to be sent and its length for: SEND_SSL_REQUEST,
SEND_AUTH_RESPONSE, SEND_AUTH_DATA, SEND_FILE.
- For SEND_COMMAND, the command code and header and arguments part of the
command packet with their lengths (as accepted by net_write_command).
- Packet received from server and its length for: PACKET_RECEIVED and
CHALLENGE_RECEIVED.
- Authentication plugin name for AUTH_PLUGIN.
MySQL protocol stages
=====================
A client following the MySQL protocol goes through several stages of it. Each
stage determines what packets can be expected from the server or can be send by
the client.
Upon receiving each trace event, trace plugin will be notified of the current
protocol stage so that it can correctly interpret the event.
These are the possible protocol stages and the transitions between them.
.. digraph:: protocol_stages
CONNECTING -> WAIT_FOR_INIT_PACKET;
CONNECTING -> DISCONNECTED [ label = "failed connection" ];
WAIT_FOR_INIT_PACKET -> AUTHENTICATE;
WAIT_FOR_INIT_PACKET -> SSL_NEGOTIATION -> AUTHENTICATE;
AUTHENTICATE -> READY_FOR_COMMAND [ label = "accepted" ];
AUTHENTICATE -> DISCONNECTED [ label = "rejected" ];
READY_FOR_COMMAND -> DISCONNECTED [ label = "COM_QUIT" ];
READY_FOR_COMMAND -> AUTHENTICATE [ label="after change user" ];
READY_FOR_COMMAND -> WAIT_FOR_PACKET -> READY_FOR_COMAND;
READY_FOR_COMMAND -> WAIT_FOR_RESULT
READY_FOR_COMMAND -> WAIT_FOR_PS_DESCRIPTION
[ label="after prepare command" ];
READY_FOR_COMMAND -> WAIT_FOR_FIELD_DEF
[ label="COM_FIELD_LIST" ];
WAIT_FOR_RESULT -> READY_FOR_COMMAND [ label="simple reply" ];
WAIT_FOR_RESULT -> WAIT_FOR_FIELD_DEF;
WAIT_FOR_RESULT -> FILE_REQUEST;
WAIT_FOR_FIELD_DEF -> WAIT_FOR_ROW [ label="in a resultset" ];
WAIT_FOR_FIELD_DEF -> READY_FOR_COMMAND
[ label="after describe table or prepare command" ];
WAIT_FOR_ROW -> READY_FOR_COMMAND;
WAIT_FOR_ROW -> WAIT_FOR_RESULT [ label="multi-resultset" ];
WAIT_FOR_PS_DESCRIPTION -> WAIT_FOR_PS_PARAMETER;
WAIT_FOR_PS_DESCRIPTION -> READY_FOR_COMMAND
[ label="no params and result" ];
WAIT_FOR_PS_DESCRIPTION -> WAIT_FOR_FIELD_DEF [ label="no params" ];
WAIT_FOR_PS_PARAMETER -> WAIT_FOR_FIELD_DEF;
WAIT_FOR_PS_PARAMETER -> READY_FOR_COMMAND [ label="no result" ];
FILE_REQUEST -> WAIT_FOR_RESULT [label="when whole file sent"];
Per-connection data for protocol tracing
========================================
The protocol tracing subsystem will store the following data in each connection
handle:
------------------- -------------------------------------------------------
plugin pointer to the plugin tracing this connection
------------------- -------------------------------------------------------
trace_plugin_data pointer to the plugin specific data as returned by
plugin's tracing_start method
------------------- -------------------------------------------------------
stage current stage of the protocol
------------------- -------------------------------------------------------
struct st_mysql_trace_info
{
struct st_mysql_client_plugin_TRACE *plugin;
void *trace_plugin_data;
enum mysql_trace_stage stage;
};
A pointer to st_mysql_trace_info struture will be stored inside
st_mysql_extension structure pointed by MYSQL::extension member:
struct st_mysql_extension {
struct st_mysql_trace_info *trace_data;
}
The MYSQL::extension will be allocated only if used. Macro GET_EXTENSION(M) will
return a pointer to the extension member of MYSQL handle M, allocating it if not
done already. The memory pointed by MYSQL::extension will be freed inside
mysql_close() function.
Trace plugin API
================
typedef
void* (tracing_start_callback)(struct st_mysql_client_plugin_TRACE *self,
struct st_mysql *connection_handle,
enum mysql_trace_stage stage);
typedef
void (tracing_stop_callback)(struct st_mysql_client_plugin_TRACE *self,
struct st_mysql *connection_handle,
void *plugin_data, short int shutdown);
typedef
int (trace_event_handler)(struct st_mysql_client_plugin_TRACE *self,
void *data,
struct st_mysql *connection_handle,
enum mysql_trace_stage stage,
enum mysql_trace_event event,
struct st_trace_event_args args);
struct st_mysql_client_plugin_TRACE
{
MYSQL_CLIENT_PLUGIN_HEADER
tracing_start_callback *tracing_start;
tracing_stop_callback *tracing_stop;
trace_event_handler *trace_event;
};
enum mysql_trace_stage contains PROTOCOL_STAGE_XXX constant for each
protocol stage specified in HLS.
enum mysql_trace_event contains TRACE_EVENT_XXX constant for each trace
event specified in HLS.
Structure st_trace_event_args contains members to store all possible trace event
arguments:
struct st_trace_event_args
{
const char *plugin_name;
int cmd;
const unsigned char *hdr;
size_t hdr_len;
const unsigned char *pkt;
size_t pkt_len;
};
Various events store their arguments in the structure as follows. Unused members
are set to 0/NULL.
AUTH_PLUGIN
------------- ----------------------------------
plugin_name the name of the plugin
------------- ----------------------------------
SEND_COMMAND
------------- ----------------------------------
cmd the command code
hdr pointer to command packet header
hdr_len length of the header
pkt pointer to command arguments
pkt_len length of arguments
------------- ----------------------------------
Other SEND_* and *_RECEIVED events
------------- ----------------------------------
pkt the data sent or received
pkt_len length of the data
------------- ----------------------------------
PACKET_SENT
------------- ----------------------------------
pkt_len number of bytes sent
------------- ----------------------------------
Global trace plugin pointer
===========================
A global pointer to the loaded trace plugin instance will be defined:
extern "C" struct st_mysql_client_plugin_TRACE *trace_plugin;
Initially this pointer will be NULL. It will be set inside add_plugin() function
in cleint_plugin.c if it is discovered that the plugin being added is a trace
plugin.
If a trace plugin is loaded and trace_plugin is not NULL, an attempt to load
another trace plugin will lead to an error.
When a trace plugin is loaded, trace events in on-going connections will not be
reported to it. Only new connections starting in CONNECTING phase will be traced
with the plugin. Connections which are traced and for which trace events are
reported to the trace plugin are distinguished by the fact that for them
MYSQL::extension->trace_data is not NULL.
Handling of trace events
========================
In places where trace events happen, trace hook will be inserted. It will
be a call of MYSQL_TRACE macro like this:
MYSQL_TRACE(PACKET_RECEIVED, mysql, (len, net->read_pos));
where PACKET_RECEIVED is the event which happens, followed by connection
handle and optional event parameters.
The macro will expand to code for processing trace event. However, processing
will be skipped if global trace_plugin pointer is NULL (no trace plugin loaded
yet) or this connection is not traced (MYSQL::extension->trace_data is NULL).
Tracing connection is initialized and connection's trace_data allocated when
CONNECTING stage is set with MYSQL_TRACE_STAGE() macro (see below).
The logic for processing trace event in MYSQL_TRACE(Event, M, Args) macro will
be as follows.
Note: not all of the logic needs to be in the macro expansion. For
efficiency, mostly the initial test determining whether further processing will
be done should be inlined as macro expansion. The actual event
processing logic can be implemented as inline functions for example.
--------------------------------------------------------------------
if trace_plugin is NULL or M->extension->trace_data is NULL
then do nothing and stop;
let trace_data= M->extension->trace_data;
if defined, call trace_event(...) method of trace_plugin passing to it:
- current event: Event,
- connection handle: M,
- current protocol stage: trace_data->stage,
- plugin's per-connection data: trace_data->trace_plugin_data,
- event arguments: Args.
if current stage or Event is DISCONNECTED
or trace_event() method returned non-zero value
then
call tracing_stop(...) method of trace_plugin, if defined.
free M->extension->trace_data and set it to NULL (this disables
further tracing in this connection);
fi
--------------------------------------------------------------------
Protocol Stage Changes
======================
Hooks will be placed in code in places where new protocol stage is entered.
These will be calls of MYSQL_TRACE_STAGE() macro like this:
MYSQL_TRACE_STAGE(mysql, WAIT_FOR_RESULT);
The macro will store the new protocol stage in mysql->extension->tace_data.stage
and this will be used when next trace event is reported to the trace plugin.
If the stage is CONNECTING, tracing in the connection will be initialized
(unless trace_plugin is NULL):
1. allocate trace_data structure and store pointer to it in
mysql->extension,
2. set trace_data.plugin to trace_plugin, trace_plugin.stage to CONNECTING,
3. call plugins trace_start() method, if defined.
4. if trace_start() returned a pointer, store it in
trace_data.trace_plugin_data, otherwise it is set to NULL.
Thread safety
=============
Tracing infrastructure does not enforce any synchronization between different
application threads. This should be safe, assuming that only one application
thread can use given MYSQL connection instance. Under that assumption the only
shared resource is the global trace_plugin pointer. Even without
synchronization, the following code is thread safe:
if trace_plugin not NULL then
use trace_plugin ...
fi
This is because tace_plugin can be set from NULL to something not-NULL in a
parallel thread, but once it is not-NULL, its value will never change.
Important Note
--------------
Trace plugin methods must be thread-safe, as they can be called from different
threads without any synchronization.
Implementation
==============
A tree with patch implementing this WL can be found here:
bzr+ssh://myrepo.no.oracle.com/bzrroot/rsomla/mysql-wl6226
If configured with WITH_TEST_TRACE_PLUGIN build option, it will build libmysql
with built-in, pre-loaded test trace plugin and all the standard clients will
use this plugin. Test plugin will produce diagnostic output on stderr if
MYSQL_TEST_TRACE_DEBUG environment variable is set to something else than 0.
Note: Test trace plugin can disclose passwords and other security sensitive
information in the diagnostic output.
Example output
--------------
test_trace: Test trace plugin initialized
test_trace: Starting tracing in stage CONNECTING
test_trace: stage: CONNECTING, event: CONNECTING
test_trace: stage: CONNECTING, event: ERROR
test_trace: error 2038: Can't open shared memory; client could not create reque
t event (0)
test_trace: stage: CONNECTING, event: CONNECTED
test_trace: stage: WAIT_FOR_INIT_PACKET, event: READ_PACKET
test_trace: stage: WAIT_FOR_INIT_PACKET, event: PACKET_RECEIVED
test_trace: packet received: 74 bytes
0A 35 2E 35 2E 32 37 00 51 00 00 00 28 3F 43 73 .5.5.27.Q...(?Cs
3C 6C 2E 3F 00 FF F7 21 02 00 0F 80 15 00 00 00
Copyright (c) 2000, 2024, Oracle Corporation and/or its affiliates. All rights reserved.