Debug notes

In this post I will show you an interesting problem that we experienced when querying a SQL Server database with Dapper. I will use a simplified data model and a sample application so you could reproduce the issue on your own. Our sample table will look as follows:

create table Stats (
    StatsDay datetime not null,
    EventName varchar(100) not null,
    Item varchar(100) not null,
    Value int null,
    constraint PK_Stats primary key(Item,EventName,StatsDay)
)

For our test scenario let’s fill the Stats table with aggregated query statistics gathered by SQL Server:

insert into Stats(StatsDay, EventName, Item, Value) 
select CONVERT(date,last_execution_time,101), 'query', convert(varchar(max), query_plan_hash, 1), sum(execution_count) 
    from sys.dm_exec_query_stats group by CONVERT(date,last_execution_time,101), convert(varchar(max), query_plan_hash, 1)

Now, it’s time to query this table with Dapper. Our sample application will return the number of executions for a query plan with a hash provided by the user:

using System;
using System.Data.SqlClient;
using Dapper;

public class Program 
{
    class Stat 
    {
        public DateTime StatsDay { get; set; }
        public String EventName { get; set; }
        public String Item { get; set; }
        public int Value { get; set; }
    }

    public static void Main(String[] args) {
        if (args.Length == 0) {
            Console.WriteLine("You must provide query plan hash");
            return;
        }
    
        using (var conn = new SqlConnection("Server=localhost;Database=testdb;Trusted_Connection=true")) {
            conn.Open();
            
            var query = conn.Query<Stat>("select * from Stats where Item = @queryPlanHash and EventName = 'query' and StatsDay > @startDate", 
                              new { queryPlanHash = args[0], startDate = DateTime.Today.AddDays(-7) });
            
            foreach (var st in query) {
                Console.WriteLine("Number of executions of {0} on {1} was {2}", args[0], st.StatsDay, st.Value);
            }
        }
    }
}

After running the application with SQL Profiler listening, we should find in its log a query similar to the one below:

exec sp_executesql N'select * from Stats where Item = @queryPlanHash and EventName = ''query'' and StatsDay > @startDate',N'@queryPlanHash nvarchar(4000),@startDate datetime',@queryPlanHash=N'0x00D2A282AC36D843',@startDate='2013-05-08 00:00:00'

Query plan:

In SQL Server 2005 you may even end up with an index scan. So why didn’t the query result in a simple index seek? SQL Server 2012 gives us a hint, showing a warning on the SELECT node:

Type conversion in expression (CONVERT_IMPLICIT(nvarchar(100),[testdb].[dbo].[Stats].[Item],0)) may affect “CardinalityEstimate” in query plan choice

When looking closer at the query generated by Dapper we can see that the text parameters are by default sent as nvarchars, when in our Stats table the item column is of type varchar. This forces SQL Server to convert a parameter from multi- to single-byte string. Fortunately, we can easily fix this by just informing Dapper that our parameter should be a single-byte string (there is a special DbString type in Dapper for this purpose):

            var query = conn.Query<Stat>("select * from Stats where Item = @queryPlanHash and EventName = 'query' and StatsDay > @startDate", 
                              new { queryPlanHash = new DbString() { Value = args[0], IsAnsi = true, Length = 100 }, 
                              startDate = DateTime.Today.AddDays(-7) });

After the fix the query looks as follows:

exec sp_executesql N'select * from Stats where Item = @queryPlanHash and EventName = ''query'' and StatsDay > @startDate',N'@queryPlanHash varchar(100),@startDate datetime',@queryPlanHash='0x00D2A282AC36D843',@startDate='2013-05-08 00:00:00'

and generates the anticipated index seek in the query plan: