Logging not working for slow queries with Entity Framework Core interceptors and Azure Application Insights (.NET 8 REST API)

Question

I'm facing an issue with logging request details for slow queries in my .NET 8 REST API. I'm utilizing the Interceptor feature of Microsoft.EntityFrameworkCore (v8.0.0) to capture slow queries and attempting to log them to Azure Application Insights. However, the logs are not appearing in Application Insights.

Details

• Framework: .NET 8
• Database: Azure SQL
• Entity Framework Core Version: 8.0.0
• Microsoft.ApplicationInsights.AspNetCore: 2.21.0
• Serilog.Sinks.ApplicationInsights: 3.1.0

Code

internal sealed class QueryPerformanceInterceptor(ILogger logger) : DbCommandInterceptor
{
    private readonly ILogger _logger = logger.IsNotNull();
    private const long _slowQueryThreshold = 100; // milliseconds

    public override InterceptionResult<DbDataReader> ReaderExecuting(
        DbCommand command,
        CommandEventData eventData,
        InterceptionResult<DbDataReader> result)
    {
        Stopwatch stopwatch = Stopwatch.StartNew();

        var originalResult = base.ReaderExecuting(command, eventData, result);

        stopwatch.Stop();

        if (stopwatch.ElapsedMilliseconds > _slowQueryThreshold)
        {
            LogSlowQuery(command, stopwatch.ElapsedMilliseconds);
        }

        return originalResult;
    }

    public override ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(
        DbCommand command,
        CommandEventData eventData,
        InterceptionResult<DbDataReader> result,
        CancellationToken cancellationToken = default)
    {
        Stopwatch stopwatch = Stopwatch.StartNew();

        var originalResult = base.ReaderExecuting(command, eventData, result);

        stopwatch.Stop();

        if (stopwatch.ElapsedMilliseconds > _slowQueryThreshold)
        {
            LogSlowQuery(command, stopwatch.ElapsedMilliseconds);
        }

        return new ValueTask<InterceptionResult<DbDataReader>>(result);
    }

    /// <summary>
    /// Method to log the slow query
    /// </summary>
    /// <param name="command"></param>
    /// <param name="elapsedMilliseconds"></param>
    private void LogSlowQuery(DbCommand command, long elapsedMilliseconds)
    {
        Console.WriteLine($"Slow Query ({elapsedMilliseconds} ms):  {command.CommandText}");
        _logger.LogInformation($"Slow Query ({elapsedMilliseconds} ms):  {command.CommandText}");
    }
}

Reference article: https://learn.microsoft.com/en-us/ef/core/logging-events-diagnostics/interceptors

I tested multiple APIs and was able to mock the slow queries scenario and while debugging was able to get the method LogSlowQuery executed successfully, but on searching the traces in the Application Insights I was not able to find it

What could be causing the logs for slow queries not to be sent to Application Insights?

Are there any specific configurations required for using interceptors with Application Insights logging?

Can anyone please help me here by providing their guidance?

Answer 1

I was able to resolve the issue by injecting the Serilog Logger into the QueryPerformanceInterceptor class.

Here goes the latest code :

using Microsoft.EntityFrameworkCore.Diagnostics;
using Serilog;
using Shared.Core.GuardClauses;
using System.Data.Common;
using System.Diagnostics;

namespace DemoTest.Infrastructure;

internal sealed class QueryPerformanceInterceptor(ILogger logger) : DbCommandInterceptor
{
    private readonly ILogger _logger = logger.IsNotNull();
    private const long _slowQueryThreshold = 100; // milliseconds

    public override InterceptionResult<DbDataReader> ReaderExecuting(
        DbCommand command,
        CommandEventData eventData,
        InterceptionResult<DbDataReader> result)
    {
        Stopwatch stopwatch = Stopwatch.StartNew();

        var originalResult = base.ReaderExecuting(command, eventData, result);

        stopwatch.Stop();
        if (stopwatch.ElapsedMilliseconds > _slowQueryThreshold)
        {
            LogSlowQuery(command, stopwatch.ElapsedMilliseconds);
        }

        return originalResult;
    }


    public override ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(
        DbCommand command,
        CommandEventData eventData,
        InterceptionResult<DbDataReader> result,
        CancellationToken cancellationToken = default)
    {
        Stopwatch stopwatch = Stopwatch.StartNew();

        var originalResult = base.ReaderExecuting(command, eventData, result);

        stopwatch.Stop();
        if (stopwatch.ElapsedMilliseconds > _slowQueryThreshold)
        {

            LogSlowQuery(command, stopwatch.ElapsedMilliseconds);
        }

        return new ValueTask<InterceptionResult<DbDataReader>>(result);
    }

    /// <summary>
    /// Method to log the slow query
    /// </summary>
    /// <param name="command"></param>
    /// <param name="elapsedMilliseconds"></param>
    private void LogSlowQuery(DbCommand command, long elapsedMilliseconds)
    {
        Console.WriteLine($"Slow Query ({elapsedMilliseconds} ms):  {command.CommandText}");
        _logger.Information($"Slow Query ({elapsedMilliseconds} ms):  {command.CommandText}");
    }
}

I validated the above code and was able to find the traces getting logged into the Application Insights now.