Search code examples
sql.netentity-frameworklogginginterceptor

Database.Log not logging appended SQL from interceptor in Entity Framework


I am appending this code below successfully to the SQL Query being created from Entity Framework with an interceptor inside a Scope, but the Database.Log below, called afterwards, doesnt show the OPTION(RECOMPILE) in the query so I am not sure its even being executed.

Calling Code

  using (new OptionRecompileScope(_divisionPoolsRepository.DataContext))
            {
                divisionTeamResultsIds.AddRange(_divisionPoolsRepository.DataContext.DivisionBracketParticipants.Where(g => g.DivisionBracketParticipantPool.DivisionPoolId == divisionPoolId.Value).Select(g => g.DivisionGameTeamResultId).Distinct().ToList());
            }

OptionRecompileScope.cs

private void AddOptionRecompile(IDbCommand command)
            {
                command.CommandText += " OPTION(RECOMPILE)";
            }

The code above is from this link EF 6 Parameter Sniffing

DataContext.cs

public class DataContext : DbContext
    {
        private readonly ILogger _logger;

        public DataContext(ILogger logger)
        {
            Database.SetInitializer<DataContext>(null);

            Configuration.LazyLoadingEnabled = false;
            Configuration.ProxyCreationEnabled = false;

            _logger = logger;

            if (Config.Debugging.LogDatabase)
            {
                Database.Log = q => _logger.Debug(q);
            }
        }
}

Entire Scope Class

public class OptionRecompileScope : IDisposable
    {
        private const string QueryHintText = " OPTION(RECOMPILE)";
        private readonly OptionRecompileDbCommandInterceptor interceptor;

        public OptionRecompileScope(DbContext context)
        {
            interceptor = new OptionRecompileDbCommandInterceptor(context);
            DbInterception.Add(interceptor);
        }

        public void Dispose()
        {
            DbInterception.Remove(interceptor);
        }

        private class OptionRecompileDbCommandInterceptor : IDbCommandInterceptor
        {
            private readonly DbContext dbContext;

            internal OptionRecompileDbCommandInterceptor(DbContext dbContext)
            {
                this.dbContext = dbContext;
            }

            public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
            {
            }

            public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
            {
            }

            public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
            {
                if (ShouldIntercept(command, interceptionContext))
                {
                    AddOptionRecompile(command);
                }
            }

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

            public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
            {
                if (ShouldIntercept(command, interceptionContext))
                {
                    AddOptionRecompile(command);
                }
            }

            public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
            {
            }

            private void AddOptionRecompile(IDbCommand command)
            {
                if (!command.CommandText.EndsWith(QueryHintText))
                {
                    command.CommandText += QueryHintText;
                }
            }

            private bool ShouldIntercept(IDbCommand command, DbCommandInterceptionContext interceptionContext)
            {
                return
                    command.CommandType == CommandType.Text &&
                    command is SqlCommand &&
                    interceptionContext.DbContexts.Any(interceptionDbContext => ReferenceEquals(interceptionDbContext, dbContext));
            }
        }
    }

Solution

  • It looks like the order was the issue. I just readded it inside the OptionRecompileScope constructor and the output is correct now.

    public OptionRecompileScope(DbContext context, ILogger logger)
            {
                interceptor = new OptionRecompileDbCommandInterceptor(context);
                DbInterception.Add(interceptor);
                if (Config.Debugging.LogDatabase)
                {
                    context.Database.Log = q => logger.Debug(q);
                }
            }