EF Core Performance Basics: N+1, Projection, AsNoTracking and Compiled Queries

Version note: The code in this post is written for EF Core 6 and runs unchanged on EF Core 10.

Guess First: How Many SQL Commands?

The database holds 100 authors, each with 20 books. How many SQL commands does this code, which lists every author's name and book count, send to the database?

var authors = await db.Authors.ToListAsync();

foreach (var author in authors)
{
    var bookCount = await db.Books.CountAsync(b => b.AuthorId == author.Id);
    // ... print it
}

Console.WriteLine($"Commands: {BookstoreContext.CommandCount}");

The code looks innocent: two lines of queries and a loop. In this post we will measure, one by one, the most common mistakes that slow EF Core applications down. The model is a slightly extended version of the Bookstore model so far; books have a long description and reviews, and authors have awards:

public class Author
{
    public int Id { get; set; }
    public string Name { get; set; } = "";
    public List<Book> Books { get; set; } = new();
    public List<Award> Awards { get; set; } = new();
}

public class Book
{
    public int Id { get; set; }
    public string Title { get; set; } = "";
    public string Description { get; set; } = "";
    public decimal Price { get; set; }
    public int Stock { get; set; }
    public int AuthorId { get; set; }
    public Author Author { get; set; } = null!;
    public List<Review> Reviews { get; set; } = new();
}

public class Review
{
    public int Id { get; set; }
    public int Rating { get; set; }
    public string Text { get; set; } = "";
    public int BookId { get; set; }
}

public class Award
{
    public int Id { get; set; }
    public string Name { get; set; } = "";
    public int AuthorId { get; set; }
}

Do Not Optimize Without Measuring: Counting and Logging Commands

The first rule of performance: do not guess, measure. For the measurements in this post we added a very simple counter to the context. We hook LogTo up to the CommandExecuted event only and increment a counter for every SQL command:

public static int CommandCount;

protected override void OnConfiguring(DbContextOptionsBuilder options)
{
    options.UseSqlite("Data Source=bookstore.db")
        .LogTo(message => CommandCount++, new[] { RelationalEventId.CommandExecuted });
}

In a real application you look at the log instead of a counter. Writing the same event to the console shows every command together with its execution time:

options.UseSqlite("Data Source=bookstore.db")
    .LogTo(Console.WriteLine, new[] { RelationalEventId.CommandExecuted });

Finding out which code a log line came from can be hard. TagWith adds a SQL comment to the beginning of the query:

var soldOut = await db.Books
    .TagWith("Stock report: sold out books")
    .Where(b => b.Stock == 0)
    .Select(b => b.Title)
    .ToListAsync();

      Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      -- Stock report: sold out books
      
      SELECT "b"."Title"
      FROM "Books" AS "b"
      WHERE "b"."Stock" = 0

The Executed DbCommand (0ms) part tells you how long the command took in the database. When you search the log for a slow page, you find this tag directly; since the comment is part of the SQL text, it also shows up in monitoring tools on the database side. If you want to see parameter values too, there is EnableSensitiveDataLogging(), but as the name suggests, it is not a setting to leave on in production.

N+1 and the Projection Fix

The answer to the opening question:

Commands: 101

One command for the authors, then one more command for each author. This pattern is called N+1: one query fetches the list, then N more queries go out for the N items in the list. Since SQLite is a file on the same machine, 101 commands finish too fast to notice. When the database is at the other end of a network, every command is a round trip; even at 2 ms per command this page spends 200 ms just waiting. With lazy loading on, this mistake gets even sneakier, because writing author.Books.Count in the loop is enough and no query is visible in the code at all.

The fix is to ask for what you need in a single query:

var summaries = await db.Authors
    .Select(a => new AuthorSummary(a.Name, a.Books.Count))
    .ToListAsync();

Console.WriteLine($"Commands: {BookstoreContext.CommandCount}");

public record AuthorSummary(string Name, int BookCount);
public record BookListItem(int Id, string Title, decimal Price);

Commands: 1

EF Core turned a.Books.Count into a correlated subquery:

SELECT "a"."Name", (
    SELECT COUNT(*)
    FROM "Books" AS "b"
    WHERE "a"."Id" = "b"."AuthorId")
FROM "Authors" AS "a"

The counting happens in the database and only the result comes back: 100 rows, two columns. The output is the same on EF Core 6 and 10.

Only the Columns You Need: Projecting into DTOs

The book list page shows each book's id, title and price. Let's look at the difference between loading the whole entity and projecting into a DTO:

var full = db.Books.AsNoTracking().Where(b => b.Stock > 0);
var list = db.Books.Where(b => b.Stock > 0)
    .Select(b => new BookListItem(b.Id, b.Title, b.Price));

Console.WriteLine(full.ToQueryString());
Console.WriteLine(list.ToQueryString());

SELECT "b"."Id", "b"."AuthorId", "b"."Description", "b"."Price", "b"."Stock", "b"."Title"
FROM "Books" AS "b"
WHERE "b"."Stock" > 0
SELECT "b"."Id", "b"."Title", "b"."Price"
FROM "Books" AS "b"
WHERE "b"."Stock" > 0

The first query brings every column, including the 2000-character Description; the second brings only three columns. We ran each of them 20 times and saw these timings on EF Core 10:

20x full entity: 87 ms, 20x projection: 37 ms
20x full entity: 75 ms, 20x projection: 38 ms
20x full entity: 76 ms, 20x projection: 32 ms

The numbers will be different on your machine; what matters is the ratio. Here the projection is more than twice as fast, and the difference comes entirely from the data being moved. Projection has another side benefit: since the result is a DTO and not an entity, it never enters the change tracker. We discussed the design side of returning DTOs instead of entities from an API in the ASP.NET Core Web API series; this is the performance side.

Unnecessary Tracking

Sometimes you really need the whole entity but you will not change it. Default queries still register every entity in the change tracker:

using var db = new BookstoreContext();
var sw = Stopwatch.StartNew();

var tracked = await db.Books.ToListAsync();
Console.WriteLine($"Tracked: {sw.ElapsedMilliseconds} ms, entries: {db.ChangeTracker.Entries().Count()}");

db.ChangeTracker.Clear();
sw.Restart();

var readOnly = await db.Books.AsNoTracking().ToListAsync();
Console.WriteLine($"No tracking: {sw.ElapsedMilliseconds} ms, entries: {db.ChangeTracker.Entries().Count()}");

Tracked: 13 ms, entries: 2000
No tracking: 3 ms, entries: 0

The measurement is from the third round on EF Core 10; on EF Core 6 the picture is similar: between 10 and 22 ms tracked, 4 ms without tracking. The cost of tracking is not only time. A snapshot is kept for every entity, and that memory is not released until the context is disposed. The rule we saw in the change tracking post applies here too: load data you will only read with AsNoTracking(). If most of the application reads, another option is to change the default at the context level with UseQueryTrackingBehavior(QueryTrackingBehavior.NoTracking) and say AsTracking() only where you write.

Indexes and the Query Plan

However good the SQL generated by EF Core is, if the database does not have the right index, it reads the table from start to finish for every query. On SQLite you can see this with EXPLAIN QUERY PLAN. We took the SQL EF Core generates and put it in front:

var query = db.Books.Where(b => b.Title == "Book 042-07");
Console.WriteLine(query.ToQueryString());

var connection = db.Database.GetDbConnection();
await connection.OpenAsync();
using var command = connection.CreateCommand();
command.CommandText = "EXPLAIN QUERY PLAN " + query.ToQueryString();

using var reader = await command.ExecuteReaderAsync();
while (await reader.ReadAsync())
    Console.WriteLine(reader.GetString(3)); // the plan's detail column

SELECT "b"."Id", "b"."AuthorId", "b"."Description", "b"."Price", "b"."Stock", "b"."Title"
FROM "Books" AS "b"
WHERE "b"."Title" = 'Book 042-07'
SCAN b

SCAN b means the whole table is read. We add an index on Title with the Fluent API:

modelBuilder.Entity<Book>().HasIndex(b => b.Title);

The plan of the same query changes:

SEARCH b USING INDEX IX_Books_Title (Title=?)

The plan is the same on EF Core 6 and 10. With 2000 rows you do not feel the difference; with two million rows this line makes all the difference. Do not pick the columns to index by guessing; look at the WHERE, JOIN and ORDER BY parts of frequent and slow-looking queries. Every index speeds up reads but slows down every INSERT and UPDATE a little. We saw the model side of indexes in the Fluent API post; EF Core already puts an index on foreign key columns by itself.

AsSplitQuery: Against the Cartesian Explosion

In the post on loading related data we discussed single queries and split queries. Let's measure here. We load authors together with both their books and their awards:

var authors = await db.Authors
    .AsNoTracking()
    .Include(a => a.Books)
    .Include(a => a.Awards)
    .ToListAsync();

var authors = await db.Authors
    .AsNoTracking()
    .Include(a => a.Books)
    .Include(a => a.Awards)
    .AsSplitQuery()
    .ToListAsync();

Because the single query puts both collections into the same JOIN, it returns every combination of 20 books and 3 awards for each author: 6000 rows for 100 authors. The split query brings 100 authors, 2000 books and 300 awards with three separate queries. What we measured on EF Core 10:

Single query: 1 command(s), 18 ms
Split query:  3 command(s), 8 ms
Single query: 1 command(s), 19 ms
Split query:  3 command(s), 9 ms

Here the split query won, but that is not always the case. A split query means three round trips, and if the data changes between them the results can be inconsistent. The rule: if the row count of the single query explodes with the product of the collections, switch to split; otherwise stay with a single query.

Compiled Queries

EF Core puts every LINQ query through a compilation step to translate it into SQL. The result is cached, but EF Core still has to take the expression tree and look it up in the cache on every call. For small queries that run thousands of times per second, you can skip this step too:

public static class Queries
{
    public static readonly Func<BookstoreContext, string, Task<Book?>> BookByTitle =
        EF.CompileAsyncQuery((BookstoreContext db, string title) =>
            db.Books.AsNoTracking().FirstOrDefault(b => b.Title == title));
}

A compiled query is called like an ordinary delegate that takes the context and the parameter:

var dune = await Queries.BookByTitle(db2, "Book 042-07");

We ran the same query 5000 times normally and 5000 times compiled. The results after the warm-up round:

5000x regular: 205 ms, 5000x compiled: 106 ms
5000x regular: 170 ms, 5000x compiled: 107 ms

That is roughly from 34 microseconds to 21 microseconds per query. EF Core 6 shows the same picture: 170 ms against 100 ms. As a percentage it looks big, but the absolute value is small. If the query takes 5 ms in the database, this gain disappears in the noise. Save compiled queries for hot spots where you actually see query compilation in a profiler. Compiled queries also need a fixed LINQ shape; Where clauses added conditionally do not work here.

Common Pitfalls

IEnumerable instead of IQueryable. When a method returns IEnumerable<Book> and the caller adds a Where on top, the filter runs in memory. This trap from the LINQ post is the quietest of all performance problems: the whole table comes over, then gets thrown away.

Lists without paging. ToListAsync() brings 50 rows today and 500 thousand two years from now. Every endpoint that returns a list should have Skip/Take and an upper limit.

Measuring in the wrong place. Measurements taken in a Debug build, on the first call and against an empty database are misleading. The first call also includes building the model and compiling the query; that is why the first rounds above were always slower. Decide by measuring several rounds with data close to the real volume.

Trying to solve everything with pooling and compiled queries. These two are the last knobs to turn. First fix the number of queries, the amount of data moved and the indexes. That is where most problems are.

A Small Experiment

★☆☆ Add TagWith("Author list") to the N+1 example and write the log to the console. See the tag on each of the 101 commands, then see it on the single command in the projection version.

★★☆ Write a projection that fetches the 20 cheapest books with their prices, and sort with OrderBy(b => b.Price). In the EF Core 6 project you will get a NotSupportedException saying SQLite does not support decimal in ORDER BY; read the message and apply one of the two ways it suggests. Run the same query in the EF Core 10 project and see the difference.

★★★ Write a query that filters the Review table by BookId and Rating and look at the EXPLAIN QUERY PLAN output. Then add a composite index with HasIndex(r => new { r.BookId, r.Rating }) and compare how the plan changes.

Part of performance is never fetching unnecessary rows in the first place. Filtering out deleted records or another customer's data by hand in every query is both tiring and risky. In the next post we will see how to build soft delete and multi-tenancy into the model with global query filters.