static void

EF Code First tracing - logging the SQL

Published Tuesday 14 February 2012

I wanted to log the SQL so I can profile a Entity Framework Code First application.

MVC Mini-Profiler only works in an ASP MVC application- not in console or unit tests.

The tracing and caching providers for Entity Framework expect ObjectContexts (EF 4.0), not DbContexts. But we can make them work.

Scenario:
I have a code first project with my DbContext, called NorthwindContext.
I have a unit test project, with a test that uses NorthwindContext

Here's the steps.

1. Download the providers.
2 (Optional): review the Q&A and apply some of the suggested patches.
3. Build the solution.
4. The unit test project will reference the dlls from the tracing provider
EFProviderWrapperToolkit.dll
EFTracingProvider.dll
5. Add an App.config to the unit test project something like this:
<?xml version="1.0" encoding="utf-8"?>
<configuration>
  <connectionStrings>
    <add name="NorthwindContext" 
         providerName="System.Data.SqlClient" 
         connectionString="Data Source=.\SQLEXPRESS;Initial Catalog=Northwind;Integrated Security=True;Pooling=False;MultipleActiveResultSets=True" />
  </connectionStrings>
  <system.data>
    <DbProviderFactories>
      <add name="EF Tracing Data Provider" 
           invariant="EFTracingProvider" 
           description="Tracing Provider Wrapper" 
           type="EFTracingProvider.EFTracingProviderFactory, EFTracingProvider, Version=1.0.0.0, Culture=neutral, PublicKeyToken=def642f226e0e59b" />
      <add name="EF Generic Provider Wrapper" 
           invariant="EFProviderWrapper" 
           description="Generic Provider Wrapper" 
           type="EFProviderWrapperToolkit.EFProviderWrapperFactory, EFProviderWrapperToolkit, Version=1.0.0.0, Culture=neutral, PublicKeyToken=def642f226e0e59b" />
    </DbProviderFactories>
  </system.data>
</configuration>
6. In the DbContext, we need to use two of the base constructors
        public NorthwindContext()
        {
            //default ctor, uses app.config connection string named "NorthwindContext"
        }
 
        public NorthwindContext(DbConnection connection)
            :base(connection,true)
        {
           //ctor uses for tracing 
        }
7. In my test, you need to use the overload that takes the DbConnection.
            using (var context = new NorthwindContext(
                CreateConnectionWrapper(@"name=NorthwindContext")))
            {
 
                //profile this!
                var product = context.ProductCollection.Find(1);
            }
8. And add the CreateConnectionWrapper method:
private static DbConnection CreateConnectionWrapper(string nameOrConnectionString)
{
    var providerInvariantName = "System.Data.SqlClient";
    var connectionString = nameOrConnectionString;
    //name=connectionName format
    var index = nameOrConnectionString.IndexOf('=');
    if (index > 0 && nameOrConnectionString.Substring(0, index).Trim()
        .Equals("name"StringComparison.OrdinalIgnoreCase))
    {
        nameOrConnectionString = nameOrConnectionString
            .Substring(index + 1).Trim();
    }
    //look up connection string name
    var connectionStringSetting =
        ConfigurationManager.ConnectionStrings[nameOrConnectionString];
    if (connectionStringSetting != null)
    {
        providerInvariantName = connectionStringSetting.ProviderName;
        connectionString = connectionStringSetting.ConnectionString;
    }
    //create the special connection string with the provider name in it
    var wrappedConnectionString = "wrappedProvider=" + 
        providerInvariantName + ";" + 
        connectionString;
    //create the tracing wrapper
    var connection = new EFTracingConnection
                            {
                                ConnectionString = wrappedConnectionString
                            };
    //hook up logging here
    connection.CommandFinished +=
        (sender, args) => Console.WriteLine(args.ToTraceString());
    return connection;
}
This should cope with connection strings in the 3 common forms ("Northwind", "name=Northwind" and "Data Source=.\SQLEXPRESS;Initial Catalog=Northwind ...")

Note the line to hook up logging (subscribing to the connection.CommandFinished event). We could simply have used
EFTracingProviderConfiguration.LogToConsole = true;

Or you can hook up to log4net or EntLib logging to those tracing events.

Previously: EF Code First Many to Many Mapping (05 Feb 2012)