.NET

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)

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!

For years, Connector/Net has been a key part of any MySQL & .NET developer’s toolbox.  Tracing is also a key part of a developer’s life and Connector/Net has always output trace messages.

This first post is a review of .NET tracing systems and how we changed our trace output.  The second post will cover how developers can use the new tracing format to develop new applications.

Tracing in .NET 1.x

.NET shipped with a very simple tracing system.  You have a static class named Trace that has static methods such as Write and WriteLine.  An application can use code like the following to output a message to the trace log.

Now that we have output our message, how do we direct it somewhere?  You do that with listeners.  There are a few standard listeners included in the framework (ConsoleTraceListener, XmlTraceListener, EventLogTraceListener) but you are free to create your own.  You can attach a listener at runtime or via an application configuration file.  There’s no need to show you how that is done.  You can easily find it on the web.  What we really want to talk about are changes in .NET 2 tracing and how Connector/Net makes use of it.

Tracing in .NET 2.x

Developers usually want to just trace a particular part of an application.  They may just want to get the network tracing or maybe just the file I/O.  To accommodate this, Microsoft created a new class named TraceSource.  You can really think of it as just a Trace class with a name.  Now when you add listeners via the config file you have to add them to a source with a particular name.  Here’s what it might look like.

<configuration>
  <system.diagnostics>
    <sources>
      <source name="TraceTest" switchName="SourceSwitch"
              switchType="System.Diagnostics.SourceSwitch" >
        <listeners>
          <add name="console" />
          <remove name ="Default" />
        </listeners>
      </source>
    </sources>
    <switches>
      <!-- You can set the level at which tracing is to occur -->
      <add name="SourceSwitch" value="Warning" />
      <!-- You can turn tracing off -->
      <!--add name="SourceSwitch" value="Off" -->
   </switches>
   <sharedListeners>
      <add name="console"
           type="System.Diagnostics.ConsoleTraceListener"
           initializeData="false"/>
   </sharedListeners>
 </system.diagnostics>
</configuration>

You can also specify a switch level, a filter level, and trace options (like should the output include process id, thread id, timestamp, etc).

Starting with Connector/Net 6.2, we have started using TraceSource to output our trace data.  Our source is named, cleverly enough, mysql.

Using the mysql trace source

Using our new tracing is very simple. Just use a configuration block similar to what I have above except use “mysql” as the name of the source instead of “TraceTest”.  One question you may have, though, is how to add listeners to our source at runtime.  You do that with the new MySqlTrace class.  Here’s how.

MySqlTrace.Listeners.Add(new ConsoleTraceListener());

Difference is in the details

We’ve also increased the level of detail included in our trace messages.  Each trace message includes a counter value that attaches it to other trace messages belong to the same connection.  We did this to enable the development of applications such as a powerful log viewer that will also serve as a visual trace listener.  With this app, a developer would be able to query the log output for various scenarios.  Examples would be “show me all queries where all the rows were not read

So where to from here?

There’s much more to say about our new trace output and, in my next post, I’ll go into the exact format of the data, and we (and you) can use that data to create new and exciting trace listeners.