Tracking Query Performance with Entity Framework Core Interceptors

Entity Framework Core (EF Core) is a powerful ORM (Object-Relational Mapper) for .NET applications. One of its advanced features is the interception system, which lets you hook into low-level database operations. In this blog post, we’ll look at using EF Core interceptors to track how long queries take to execute.

What Are Interceptors?

Interceptors in EF Core allow you to run custom logic whenever certain database operations occur, such as opening connections, committing transactions, or executing commands. This feature, introduced in EF Core 3.x, is similar to the interception capabilities in EF 6.

By using interceptors, you can:

• Execute custom logic before or after a database operation.
• Bypass the actual execution of the operation and provide alternative results.

Setting Up a Performance Interceptor

Let’s create a simple interceptor to log any database query that takes longer than 2 seconds to execute.

Step 1: Create the Interceptor Class

First, we need to define our interceptor class by extending DbCommandInterceptor. In this class, we'll override methods to capture query execution details.

using Microsoft.EntityFrameworkCore.Diagnostics;
using Microsoft.Extensions.Logging;
using System.Data.Common;
using System.Threading;
using System.Threading.Tasks;

public class PerformanceInterceptor : DbCommandInterceptor
{
    private readonly ILogger _logger;

    public PerformanceInterceptor(ILoggerFactory loggerFactory)
    {
        _logger = loggerFactory.CreateLogger(nameof(PerformanceInterceptor));
    }

    public override ValueTask<DbDataReader> ReaderExecutedAsync(DbCommand command, CommandExecutedEventData eventData, DbDataReader result, CancellationToken cancellationToken = default)
    {
        if (eventData.Duration.TotalMilliseconds > 2000)
        {
            LogLongQuery(command, eventData);
        }
        return base.ReaderExecutedAsync(command, eventData, result, cancellationToken);
    }

    public override DbDataReader ReaderExecuted(DbCommand command, CommandExecutedEventData eventData, DbDataReader result)
    {
        if (eventData.Duration.TotalMilliseconds > 2000)
        {
            LogLongQuery(command, eventData);
        }
        return base.ReaderExecuted(command, eventData, result);
    }

    private void LogLongQuery(DbCommand command, CommandExecutedEventData eventData)
    {
        _logger.LogWarning($"Long query: {command.CommandText}. Duration: {eventData.Duration.TotalMilliseconds} ms");
    }
}

In this class:

• We use ILogger to log the query details.
• We override ReaderExecutedAsync and ReaderExecuted methods to intercept query executions.
• If a query takes longer than 2000 milliseconds (2 seconds), we log a warning with the query text and its duration.

Step 2: Configure the Interceptor in Your DbContext

Next, we need to register our interceptor in the DbContext configuration.

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Logging;

ILoggerFactory loggerFactory = LoggerFactory.Create(builder => { builder.AddConsole(); });

builder.Services.AddDbContext<OKtoGridDbContext>(options =>
{
    options.UseNpgsql(connectionString).AddInterceptors(new PerformanceInterceptor(loggerFactory));
});

Here:

• We create an ILoggerFactory to enable console logging.
• We add the PerformanceInterceptor to the DbContext options.

Step 3: Running the Application

With everything set up, any time a query takes longer than 2 seconds, a warning will be logged to the console with the query text and its execution time.

Conclusion

Using EF Core interceptors, you can easily monitor the performance of your database queries. This helps in identifying slow queries and optimizing them to improve your application’s performance. Give this a try in your own projects to keep your queries running efficiently!

For more updates and insights, and to connect with me, feel free to follow me on LinkedIn:

🔗 [Connect on LinkedIn]

Let’s stay connected and continue the conversation!