How To Access SQL Generated By Entity Framework Core 3
Entity Framework Core (EF) converts expressions into SQL at runtime. In earlier versions, it was straight forward to get the SQL. In Entity Framework Core 3, you must access the SQL using ILogger. This article explains how to access the SQL generated and gives some example code to access the output of queries made behind the scenes. This article works with Entity Framework Core 3.
Note: M_icrosoft is about to release Entity Framework Core 5 soon. This version will have an easier method to get at the SQL. This is the_ interface method.
Many developers may feel uncomfortable if they do not know what SQL EF executes behind the scenes. There’s a good reason for this! Expressions may not map on to SQL very easily. You may end up executing SQL that doesn’t take advantage of indexes, or the expression may end up filtering records after the data was selected from the database. In older versions of EF you could use ToTraceString()but this no longer exists in EF Core 6.
There may even be other reasons to access the SQL. Perhaps your want to convert EF expressions to SQL. This is all possible in EF Core. Grab the full sample here.
The Basics
The key to making entity framework log SQL queries is to provide it with a logging factory:
optionsBuilder.UseLoggerFactory(_loggerFactory);
And, the factory must have a filter like so:
var loggerFactory = LoggerFactory.Create(builder => {
builder.AddFilter((category, level)
=> category == DbLoggerCategory.Database.Command.Name && level == LogLevel.Information);
});
That’s it. If you add console logging, SQL will be logged to the console when the SQL executes.
var loggerFactory = LoggerFactory.Create(builder =>
{
builder
.AddConsole((options) => { })
.AddFilter((category, level) =>
category == DbLoggerCategory.Database.Command.Name
&& level == LogLevel.Information);
});
This is an example query:
using (var ordersDbContext = new OrdersDbContext(loggerFactory))
{
var orderLines = ordersDbContext.OrderLines.Where(o => o.Id == Guid.Empty).ToList();
orderLines = ordersDbContext.OrderLines.ToList();
}
This is the console output:
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
Executed DbCommand (3ms) [Parameters=[], CommandType=’Text’, CommandTimeout=’30’]
SELECT COUNT(*) FROM “sqlite_master” WHERE “type” = ‘table’ AND “rootpage” IS NOT NULL;
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
Executed DbCommand (0ms) [Parameters=[], CommandType=’Text’, CommandTimeout=’30’]
SELECT “o”.”Id”, “o”.”Count”, “o”.”Item”
FROM “OrderLines” AS “o”
WHERE “o”.”Id” = ‘00000000-0000-0000-0000-000000000000’
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
Executed DbCommand (0ms) [Parameters=[], CommandType=’Text’, CommandTimeout=’30’]
SELECT “o”.”Id”, “o”.”Count”, “o”.”Item”
FROM “OrderLines” AS “o”
Incidentally, it looks as though the where clause is not parameterized. Is this a security hole in Entity Framework Core for SQLite?**
Here is some further documentation on this approach.
Getting More Detail
You may need more detail. Or, you may want to use EF to generate SQL for some reason. You can achieve that with this code. This is an implementation of ILogger that will allow you to hook into an action when SQL runs.
public class EntityFrameworkSqlLogger : ILogger
{
#region Fields
Action<EntityFrameworkSqlLogMessage> _logMessage;
#endregion
#region Constructor
public EntityFrameworkSqlLogger(Action<EntityFrameworkSqlLogMessage> logMessage)
{
_logMessage = logMessage;
}
#endregion
#region Implementation
public IDisposable BeginScope<TState>(TState state)
{
return default;
}
public bool IsEnabled(LogLevel logLevel)
{
return true;
}
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
if (eventId.Id != 20101)
{
//Filter messages that aren't relevant.
//There may be other types of messages that are relevant for other database platforms...
return;
}
if (state is IReadOnlyList<KeyValuePair<string, object>> keyValuePairList)
{
var entityFrameworkSqlLogMessage = new EntityFrameworkSqlLogMessage
(
eventId,
(string)keyValuePairList.FirstOrDefault(k => k.Key == "commandText").Value,
(string)keyValuePairList.FirstOrDefault(k => k.Key == "parameters").Value,
(CommandType)keyValuePairList.FirstOrDefault(k => k.Key == "commandType").Value,
(int)keyValuePairList.FirstOrDefault(k => k.Key == "commandTimeout").Value,
(string)keyValuePairList.FirstOrDefault(k => k.Key == "elapsed").Value
);
_logMessage(entityFrameworkSqlLogMessage);
}
}
#endregion
}
This is a data model of what the EF logging system sends:
public class EntityFrameworkSqlLogMessage
{
public EntityFrameworkSqlLogMessage(
EventId eventId,
string commandText,
string parameters,
CommandType commandType,
int commandTimeout,
string elapsed
)
{
EventId = eventId;
CommandText = commandText;
Parameters = parameters;
CommandType = commandType;
Elapsed = elapsed;
CommandTimeout = commandTimeout;
}
public string Elapsed { get; }
public int CommandTimeout { get; }
public EventId EventId { get; }
public string CommandText { get; }
public string Parameters { get; }
public CommandType CommandType { get; }
}
You can create a simple provider like this:
public class SingletonLoggerProvider : ILoggerProvider
{
#region Fields
ILogger _logger;
#endregion
#region Constructor
public SingletonLoggerProvider(ILogger logger)
{
_logger = logger;
}
#endregion
#region Implementation
public ILogger CreateLogger(string categoryName)
{
return _logger;
}
public void Dispose()
{
}
#endregion
}
Finally, create a logger factory and add a provider with the custom ILogger. Then, inject this into your DbContext. The callback will log to the console.
var entityFrameworkSqlLogger = new EntityFrameworkSqlLogger((m) =>
{
Console.WriteLine($"SQL Query:\r\n{m.CommandText}\r\nElapsed:{m.Elapsed} millisecods\r\n\r\n");
});
var loggerFactory = LoggerFactory.Create(builder =>
{
builder
.AddFilter((category, level) =>
category == DbLoggerCategory.Database.Command.Name
&& level == LogLevel.Information);
});
loggerFactory.AddProvider(new SingletonLoggerProvider(entityFrameworkSqlLogger));
using (var ordersDbContext = new OrdersDbContext(loggerFactory))
{
var orderLines = ordersDbContext.OrderLines.Where(o => o.Id == Guid.Empty).ToList();
orderLines = ordersDbContext.OrderLines.ToList();
}
The above allows you to capture useful information about the SQL being generated and possibly use this data within your app.
Wrap-up
I usually wouldn’t recommend implementing ILogger, but EF Core doesn’t seem to give us a suitable mechanism for getting at the SQL otherwise. This code has been tested with SQLite but is not battle-hardened. If you end up using this in your system, please hit me up on Twitter and let me know how it goes. Someone might want to extend this Github code into a Nuget at some point.
