How to log/get a SQL query auto-generated by Dapper Extensions?

Question

I am using Dapper Extensions (DE) as ORM. It is consumed in Data Access Layer which is implemented using Repository pattern. SQL Express is back-end RDBMS.

DE automatically generates most of the queries for me. I want to log those auto-generated queries for debugging purpose.

There are two ways I can see to achieve this: -

1. Get the SQL query generated by DE (before or after it is executed) and write it to log. This is preferred way for me as I already have my logging module (using log4net) in place. The only thing I need is the SQL generated by DE.
2. Integrate DE with some logging tool. I read this answer. It looks possible using MiniProfiler tool; but as I said above, I already have my logging module in place. I do not want to use other tool just for logging SQL queries.

How to log/get a SQL query auto-generated by Dapper Extensions without using any other logging tool?

The other similar question is about Dapper. This question is about Dapper Extensions.

Syncretize

Possible duplicate of Is there any way to trace\log the sql using Dapper? – Stasny

@DaveInCaz: This is no way duplicate. 1) That question is about Dapper; this is about Dapper Extensions. 2) I have already read that question and mentioned it in my question at bottom; please have a look. 3) Although one of my answer here boils down to Dapper only solution, other answer is explicitly for Dapper Extensions. – Syncretize

If you are using MSSQL SQL Server Profiler would be a great way without adding any dependencies to your project. – Knotgrass

Answer 1

Dapper Extensions project is open source; everyone knows that. I downloaded it from GitHub and modified it to meet my needs.

Dapper Extensions build/generate SQL query internally in SqlGeneratorImpl class. There are multiple methods in this class those generate the various queries.

I added following property in DapperExtensions.DapperExtensions static class:

static string lastGeneratedQuery;
public static string LastGeneratedQuery
{
    get
    {
        lock(_lock)
        {
            return lastGeneratedQuery;
        }
    }
    internal set
    {
        lock(_lock)
        {
            lastGeneratedQuery = value;
        }
    }
}

Also, set this property in various methods of SqlGeneratorImpl class. Following is an example how I set it in Select method.

public virtual string Select(IClassMapper classMap, IPredicate predicate, IList<ISort> sort, IDictionary<string, object> parameters)
{
    ......
    ......

    StringBuilder sql = new StringBuilder(string.Format("SELECT {0} FROM {1}",
    ......
    ......

    DapperExtensions.LastGeneratedQuery = sql.ToString();

    return sql.ToString();
}

Basic tests run well; I have not yet tested this thoroughly. I will update this answer in case of any change.

Please note that I do not recommend this as standard solution; this is just a hack that works for my needs. I would really like to see this as a regular feature in library. Please post an answer if you have better solution. Otherwise, please comment to improve the solution suggested here.

After merging this pull request in master branch, hopefully this is now available out of the box and no need to download and modify the toolkit source code anymore. Note that I have not verified this.

Syncretize

Fair enough :) I'd still go with miniprofiler personally, but I guess we're already using that... – Enthetic

Answer 2

Looking at the comment from @MarcGravell and this question about doing the same with Dapper, MiniProfiler.Integrations is better way to implement logging for Dapper Extensions.

Above linked question is about Dapper. But Dapper Extensions uses Dapper internally. So, if logging is implemented for Dapper, same works for Dapper Extensions as well.

More details could be found on GitHub.

Sample code is as below:

var factory = new SqlServerDbConnectionFactory(connectionString);
CustomDbProfiler cp = new CustomDbProfiler();
using(var connection = DbConnectionFactoryHelper.New(factory, cp))
{
    //DB Code
}
string log = cp.ProfilerContext.GetCommands();

You can use in-build CustomDbProfiler using CustomDbProfiler.Current if that suits your need. cp.ProfilerContext.GetCommands() will return ALL the commands (success and failed) no matter how many times you call the method. I am not sure but, it might be maintaining concatenated string (StringBuilder may be) internally. If this is the case, this may slow down the performance. But, in my case, logging is disabled by default. I only enable logging when I need to debug something. So this is not a problem for me.

This also may raise memory footprint issue if single connection is used over very large scope. To avoid this, make sure CustomDbProfiler instance is disposed properly.

As mentioned in question, initially, I wanted to avoid this way (using external tool/library). But, MiniProfiler.Integrations is NOT writing the log itself. I can simply get all the queries generated and provide those to my logger module to dump into the file. That is why, this looks more suitable to me now.

---

MiniProfiler.dll internally implements similar logic (in StackExchange.Profiling.Data.ProfiledDbConnection and StackExchange.Profiling.Data.ProfiledDbCommand classes) which is mentioned here and here. So, if I decide to (in future may be) bypass MiniProfiler, I can use this implementation myself.

Syncretize