Debugging Entity Framework SQL statements

Question

I am having a weird pattern of response time when using the Entity Framework for SQL communication.

This is from my web host:

This is from my local server:

It's the increase in response time I am worried about. I have narrowed the problem down to one single line in code Nop.Data > EfRepository.cs > public void Insert(T entity) > _entities.Add(entity); Yes I know this very specific for the NopCommerce, but the point is really that I am looking her for help on how to debug this.

Are there some events I can catch that display the SQL being executed? Or what other things can I do to find out more what is actually happening in the Entity Framework in that above command.

Taxidermy

Answer 1

For debugging EF queries, the easiest thing is to cast the query to ObjectQuery and use ToTraceString:

var query = myContext.MyTable
    .Where(r => r.Id == searchId)
    .Select(r => r);

Console.WriteLine(((ObjectQuery)query).ToTraceString());

This will show the underlying SQL for the query, and you can run the queries manually to debug why they are slow. Here is the MSDN link:

http://msdn.microsoft.com/en-us/library/system.data.objects.objectquery.totracestring.aspx

If you're trying to get the SQL which is run when you call SaveChanges() on your context, it's not as easy. You could take a look at EFTracingProvider:

http://blogs.msdn.com/b/jkowalski/archive/2009/06/11/tracing-and-caching-in-entity-framework-available-on-msdn-code-gallery.aspx

Or, assuming you use SQL Server, you can go directly to SQL Profiler and capture the T-SQL statements (this is my preferred approach).

Figure

Thanks, I will try the first one because the SaveChanges() call does not seem to take that much time, at least the line I wrote took alot of time. I cannot not use the Profiler (I tried) due to restrictions on the host. – Taxidermy

I found out that part of the problem was within the code regarding casting of objects to specific classes. So the problem probably was not SQL related – Taxidermy

If you are on EF Core 5+, you can do: query.ToQueryString() learn.microsoft.com/en-us/dotnet/api/… – Devinna

Answer 2

In EF6, you can also do this in the constructor of your dbcontext

Example

public BookServiceContext() : base("name=BookServiceContext")
{
    // New code:
    this.Database.Log = s => System.Diagnostics.Debug.WriteLine(s);
}

This will log to the console every SQL query EF generates. See this article for more information http://blog.oneunicorn.com/2013/05/08/ef6-sql-logging-part-1-simple-logging/

Cristobal

Answer 3

EF 7:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    base.OnConfiguring(optionsBuilder);
    optionsBuilder
        .UseSqlServer("...")
        .LogTo(Console.WriteLine, LogLevel.Information);
}

Lueck

Answer 4

Another example might be very helpful for someone.

public class MyDbContext : DbContext
{
    private readonly ILoggerFactory _loggerFactory;

    public MyDbContext(DbContextOptions<MyDbContext> options, ILoggerFactory loggerFactory) : base(options)
    {
        _loggerFactory = loggerFactory ?? throw new ArgumentNullException(nameof(loggerFactory));
    }

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        // Enable logging
        optionsBuilder.UseLoggerFactory(_loggerFactory);

        if (System.Diagnostics.Debugger.IsAttached)
            optionsBuilder.EnableSensitiveDataLogging();

        base.OnConfiguring(optionsBuilder);
    }
}

Vu

Fortunately, that's become a lot easier now. See the newer answer. – Dressing

Gert Arnold, I don't think you should write logs into the console. Also see EnableSensitiveDataLogging. The right way is to pass the logger. Then you can setup your logger whatever (sql, system, io) and wherever (file, console, db) you want to log using appsettings.json. – Vu

You don't have to log to the console, it's just an example. And sensitive data logging can be en/disabled in the optionsBuilder apart from logger factory options. – Dressing