CODEWITHSUNDEEP
c#sql-serverperformanceentity-frameworkentity-framework-6
HugoRune
HugoRune

Reputation: 13829

Measuring time for each Entity Framework query

To measure and debug the times for each query in Entity Framework 6.3, I implemented a DbCommandInterceptor, as per the accepted answer to a related question:

public class EFLogger : IDbCommandInterceptor
{
    public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        startMeasuring(command, interceptionContext);
    }

    public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
    {
        stopMeasuring(command, interceptionContext);
    }
    ...
}

DbInterception.Add(new EFLogger());

This works fine, it is called before and after each command is sent to the database, and I can measure the time it took.

However, it only measures the time until the SqlDataReader is initialized. Most of the time for each query is is spend while the SqlDataReader is iterated and consumed. I want to find out how long this takes for each query, ideally without adding stopwatch code for every statement.

Can I somehow intercept when the SqlDataReader is closed or the 'final' record is read?

I realize that the SqlDataReader might not always be consumed entirely, so the final record could be hard to detect. For now, I am only interested in cases where the SqlDataReader is iterated until the end.

It seems like the IDbCommandInterceptor interface does not provide any events for that.

Is there any other mechanism for capturing the moment when the reader is closed?

Or could I inject a custom DbDataReader wrapper into the Entity Framework code? Or is there an alternative approach from the SQL Server side?

Upvotes: 5

Views: 2405

Answers (1)

Arjun Vachhani
Arjun Vachhani

Reputation: 1958

You can output log to console context.Database.Log = Console.Write see https://learn.microsoft.com/en-us/ef/ef6/fundamentals/logging-and-interception for more information.

using (var context = new BlogContext())
{
    context.Database.Log = Console.Write; // set Database.Log property inside dbContex constructor to log all queries
    //your query here
}

this will output every query with parameters passed and time it took to execute the query.

Upvotes: 3

Related Questions