Wednesday, January 6, 2010

Tracing changes in MySQL Connector/Net 6.2 – Part 2

In our last installment we found our hero investigating the tracing changes found in Connector/Net 6.2.  This time we’ll take a closer look at the format of the trace data and how developers can use that information to write new and interesting trace listeners.

Understanding the plumbing

The first thing we need to understand is a little about how the trace messages are routed.  The main method we are interested in is TraceSource.TraceEvent.  Here is the signature.

public void TraceEvent(
TraceEventType eventType,
int id,
string format,
params Object[] args)


All the other TraceSource methods like TraceInformation eventually boil down to a call to TraceEvent.  TraceEvent will run through all the attached listeners and call the TraceEvent method on each.



The default behavior of listeners is to eventually call String.Format using the format given.  It plugs the parameters in and comes out with a string that can be sent to the console, to a file, or some other output.  Thankfully Microsoft saw fit to make TraceEvent virtual allowing derivative listeners to override and do interesting things.



How we use TraceEvent



Here is the signature for TraceListener.TraceEvent.



public virtual void TraceEvent(
TraceEventCache eventCache,
string source,
TraceEventType eventType,
int id,
string format,
params Object[] args)


eventCache is provided by the framework and contains information such as process id, thread id, timestamp, etc.


source  is the name of the TraceSource that provided the event


eventType is the .NET defined type of this event.  This can have values such as Information, Warning, Error, etc.


id  is the application provided event id.  This value is application defined and we’ll explain how we use it later in this post.


format is the parameters string message that listeners such as ConsoleTraceListener would use for output


args is the array of arguments available to plug into the format string.  This is the actual data for the event.



The key to using the data provided in TraceEvent is simply to know that the data always comes in a specific order and format.  The following information only applies to events coming from the mysql source.  The eventCache, source, eventType, and format parameters are self explanatory so we’ll start with id.



The id parameter is our MySql-centric event id.  We wanted to give very specific information about the type of event.  We have a public enum available in the 6.2 assembly called MySqlTraceEventType.  Here is the definition.



public enum MySqlTraceEventType : int
{
ConnectionOpened = 1,
ConnectionClosed,
QueryOpened,
ResultOpened,
ResultClosed,
QueryClosed,
StatementPrepared,
StatementExecuted,
StatementClosed,
NonQuery,
UsageAdvisorWarning,
Warning,
Error
}


Before we talk about the event-specific data points, let me mention about a small problem we needed to solve.  We wanted to have a numeric id attached to each event that would allow all the events belonging to a given query to be gathered together.  The only way we could accomplish that was to use a counter that gets incremented each time a driver is opened.  (remember we needed a value that is unique on the same thread so we can’t use process id, thread id, or event MySQL server thread id). We’ll call this the driver id and every event that comes from the mysql source has this driver id as the first member in the args array.



Here’s a table that lists each mysql event and what the arguments array looks like.  Please keep in mind that these arguments start in the second element (index == 1)























































































Event Arguments
ConnectionOpened connection string
ConnectionClosed <none>
QueryOpened mysql connection id, query text
ResultOpened field count, affected rows (-1 if select), inserted id (-1 if select)
ResultClosed total rows read, rows skipped, size of resultset (in bytes)
QueryClosed <none>
StatementPrepared prepared sql, statement id
StatementExecuted statement id, mysql server thread id
StatementClosed statement id
NonQuery <varies>
UsageAdvisorWarning usage advisor flag (see below)
Warning level, code, message
Error error  number, message


Here’s the definition of the publicly available UsageAdvisorWarningFlags enum.



public enum UsageAdvisorWarningFlags
{
NoIndex = 1,
BadIndex,
SkippedRows,
SkippedColumns,
FieldConversion
}


So that’s it.  This information will be documented and may change slightly as we find problems.  In fact we’ve already identified a small issue and may add a “current database” parameter to the connection opened event since the current database can be different than what is set on the connection string.  Be sure, when we make these changes they’ll be documented and by checking the version of the assemblies involved you can do the right thing.



Armed with this information you should be able to go forth and make very interesting trace sniffing apps for MySQL.  If you accept such a challenge, drop me a line.  I would love to know what you think!

No comments:

Post a Comment