I'm using EF 6.0 with LINQ in MVC 5 project. I want to log all the SQL queries executed by the Entity Framework DbContext for debugging/performance-measurement purpose.
In Java/Hibernate, equivalent behavior can be achieved by setting the property hibernate.show_sql=true. Is it possible to have a similar behavior in Entity Framework?
Logging and Intercepting Database Operations article at MSDN is what your are looking for.
The DbContext.Database.Log property can be set to a delegate for any method that takes a string. Most commonly it is used with any TextWriter by setting it to the “Write” method of that TextWriter. All SQL generated by the current context will be logged to that writer. For example, the following code will log SQL to the console:
using (var context = new BlogContext())
{
context.Database.Log = s => System.Diagnostics.Debug.WriteLine(s);
// Your code here...
}
UPDATE 2022: Logging is now enabled by default in development in ef core. The behavior can be configured in the builder of your DB Context (enable sensitive data logging to log the query parameter values or specify events to be logged ):
services.AddDbContext<IDbContext, ApplicationDbContext>(
options => options.UseSqlServer(dbConnectionString)
.LogTo(s => System.Diagnostics.Debug.WriteLine(s))
.EnableDetailedErrors(isDebugMode)
.EnableSensitiveDataLogging(isDebugMode));
or you can use the app.settings file to define logging configuration for events of your interest
context.Database.Log = s => System.Diagnostics.Debug.WriteLine(s); then it will only log when in Debug mode. Calls to System.Diagnostics.Debug are ignored in Release mode.
[Conditional("Debug")] attribute
You can use this line to log the SQL queries to the Visual Studio "Output" window only and not to a console window, again in Debug mode only.
public class YourContext : DbContext
{
public YourContext()
{
Database.Log = sql => Debug.Write(sql);
}
}
If you've got a .NET Core setup with a logger, then EF will log its queries to whichever output you want: debug output window, console, file, etc.
You merely need to configure the 'Information' log level in your appsettings. For instance, this has EF logging to the debug output window:
"Logging": {
"PathFormat": "Logs/log-{Date}.txt",
"IncludeScopes": false,
"Debug": {
"LogLevel": {
"Default": "Information",
"System": "Information",
"Microsoft": "Information"
}
},
"Console": {
"LogLevel": {
"Default": "Information",
"System": "Warning",
"Microsoft": "Warning"
}
},
"File": {
"LogLevel": {
"Default": "Information",
"System": "Warning",
"Microsoft": "Warning"
}
},
"LogLevel": {
"Default": "Information",
"System": "Warning",
"Microsoft": "Warning"
}
}
Override OnConfiguring method in YourDbContext with the additional line:
public class YourContext : DbContext
{
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
optionsBuilder.LogTo(Console.WriteLine);
}
}
EF Core logging automatically integrates with the logging mechanisms of .NET Core. Example how it can be used to log to console:
public class SchoolContext : DbContext
{
//static LoggerFactory object
public static readonly ILoggerFactory loggerFactory = new LoggerFactory(new[] {
new ConsoleLoggerProvider((_, __) => true, true)
});
//or
// public static readonly ILoggerFactory loggerFactory = new LoggerFactory().AddConsole((_,___) => true);
public SchoolContext():base()
{
}
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
optionsBuilder.UseLoggerFactory(loggerFactory) //tie-up DbContext with LoggerFactory object
.EnableSensitiveDataLogging()
.UseSqlServer(@"Server=.\SQLEXPRESS;Database=SchoolDB;Trusted_Connection=True;");
}
public DbSet<Student> Students { get; set; }
}
If you would like to log to output window use this instead:
public static readonly ILoggerFactory loggerFactory = new LoggerFactory(new[] {
new DebugLoggerProvider()
});
https://www.entityframeworktutorial.net/efcore/logging-in-entityframework-core.aspx
If someone is using EF6.1+ there is an easy way. Check the below links for more details.
Example Code
<interceptors>
<interceptor type="System.Data.Entity.Infrastructure.Interception.DatabaseLogger, EntityFramework">
<parameters>
<parameter value="C:\Stuff\LogOutput.txt"/>
<parameter value="true" type="System.Boolean"/>
</parameters>
</interceptor>
</interceptors>
From this article
Create a factory and set the filter.
var loggerFactory = LoggerFactory.Create(builder =>
{
builder
.AddConsole((options) => { })
.AddFilter((category, level) =>
category == DbLoggerCategory.Database.Command.Name
&& level == LogLevel.Information);
});
Tell the DbContext to use the factory in the OnConfiguring method:
optionsBuilder.UseLoggerFactory(_loggerFactory);
You can use IDbCommandInterceptor too, here is a complete example:
// Created By [email protected] at 2024-11-16 14:17:52+0800
using System.ComponentModel.DataAnnotations;
using System.ComponentModel.DataAnnotations.Schema;
using System.Data.Common;
using System.Text.RegularExpressions;
using Microsoft.Data.Sqlite;
using Microsoft.EntityFrameworkCore;
using Microsoft.EntityFrameworkCore.Diagnostics;
using Newtonsoft.Json;
using NLog;
using NLog.Config;
using NLog.Targets;
const string layout = "[${date}] [${level:uppercase=true:padding=5}] [${threadid:padding=2}]" +
" [${logger}:${callsite-linenumber}] ${message:withexception=true}";
LogManager.Configuration = new LoggingConfiguration();
LogManager.Configuration.AddRuleForAllLevels(new ConsoleTarget { Layout = layout });
LogManager.Configuration = LogManager.Configuration;
var logger = LogManager.GetLogger(nameof(Program));
var db = new MyDbContext();
await db.Database.EnsureCreatedAsync();
await db.Persons.AddAsync(new Person { Name = "Alpha" });
await db.Persons.AddAsync(new Person { Name = "Beta" });
await db.SaveChangesAsync();
var persons = await db.Persons.Where(x => x.Id > 0).ToListAsync();
logger.Info("Persons: {0}", JsonConvert.SerializeObject(persons));
internal class MyDbContext : DbContext
{
public DbSet<Person> Persons { get; set; }
protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
var conn = new SqliteConnection("DataSource=:memory:");
conn.Open();
base.OnConfiguring(optionsBuilder.UseSqlite(conn).AddInterceptors(new SqlInterceptor()));
}
}
[Table("person")]
[Index(nameof(Name), IsUnique = true)]
internal class Person
{
[Column("id")] [Key] public int Id { get; set; }
[Column("name")] public string Name { get; set; }
}
internal static partial class MyObjectUtils
{
public static string PrettyPrint(this DbCommand @this)
{
var parameters = string.Join(", ",
@this.Parameters.OfType<DbParameter>().Select(x => $"{x.ParameterName}={x.Value}"));
var command = PrettySpaceRegex().Replace(@this.CommandText, " ");
return @this.Parameters.Count == 0 ? command : $"{command} [{parameters}]";
}
[GeneratedRegex(@"\s+")]
private static partial Regex PrettySpaceRegex();
}
internal class SqlInterceptor : IDbCommandInterceptor
{
private readonly Logger _logger = LogManager.GetLogger(nameof(SqlInterceptor));
public ValueTask<InterceptionResult<DbDataReader>> ReaderExecutingAsync(DbCommand command,
CommandEventData eventData, InterceptionResult<DbDataReader> result,
CancellationToken cancellationToken = new())
{
_logger.Info("[R] {0}", command.PrettyPrint());
return new ValueTask<InterceptionResult<DbDataReader>>(result);
}
public ValueTask<InterceptionResult<object>> ScalarExecutingAsync(DbCommand command, CommandEventData eventData,
InterceptionResult<object> result, CancellationToken cancellationToken = new())
{
_logger.Info("[S] {0}", command.PrettyPrint());
return new ValueTask<InterceptionResult<object>>(result);
}
public ValueTask<InterceptionResult<int>> NonQueryExecutingAsync(DbCommand command, CommandEventData eventData,
InterceptionResult<int> result, CancellationToken cancellationToken = new())
{
_logger.Info("[N] {0}", command.PrettyPrint());
return new ValueTask<InterceptionResult<int>>(result);
}
}
Example output:
[2024/11/16 14:17:12.478] [ INFO] [ 1] [SqlInterceptor:86] [N] CREATE TABLE "person" ( "id" INTEGER NOT NULL CONSTRAINT "PK_person" PRIMARY KEY AUTOINCREMENT, "name" TEXT NOT NULL );
[2024/11/16 14:17:12.504] [ INFO] [ 1] [SqlInterceptor:86] [N] CREATE UNIQUE INDEX "IX_person_name" ON "person" ("name");
[2024/11/16 14:17:12.644] [ INFO] [ 1] [SqlInterceptor:72] [R] INSERT INTO "person" ("name") VALUES (@p0) RETURNING "id"; [@p0=Alpha]
[2024/11/16 14:17:12.660] [ INFO] [ 1] [SqlInterceptor:72] [R] INSERT INTO "person" ("name") VALUES (@p0) RETURNING "id"; [@p0=Beta]
[2024/11/16 14:17:12.952] [ INFO] [ 1] [SqlInterceptor:72] [R] SELECT "p"."id", "p"."name" FROM "person" AS "p" WHERE "p"."id" > 0
[2024/11/16 14:17:13.005] [ INFO] [ 1] [Program:28] Persons: [{"Id":1,"Name":"Alpha"},{"Id":2,"Name":"Beta"}]
