Mert Özen Further With Every Line
Database Entity Framework Core — #21

EF Core Interceptors and Events: Audit Fields and Slow Query Logging

Mert Özen Nov 5, 2026 10 min 2 views
EF Core Interceptors and Events: Audit Fields and Slow Query Logging

We fill CreatedAt and UpdatedAt automatically with a SaveChangesInterceptor, log queries over a threshold with a DbCommandInterceptor, and watch the change tracker live through SavingChanges and StateChanged events. We also see why nothing runs when you forget the async override.

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

Guess First: How Many Times Does This Interceptor Run?

The class below is a small piece that hooks into EF Core's SaveChanges process. All it does is write a line to the console:

using Microsoft.EntityFrameworkCore;
using Microsoft.EntityFrameworkCore.Diagnostics;

public class SyncOnlyInterceptor : SaveChangesInterceptor
{
    public override InterceptionResult<int> SavingChanges(
        DbContextEventData eventData, InterceptionResult<int> result)
    {
        Console.WriteLine("SavingChanges called");
        return base.SavingChanges(eventData, result);
    }
}

We registered it on the context with options.UseSqlite("Data Source=bookstore.db").AddInterceptors(new SyncOnlyInterceptor()) and save two books in two different ways:

db.Books.Add(new Book { Title = "Dune" });
Console.WriteLine("calling SaveChanges");
db.SaveChanges();

db.Books.Add(new Book { Title = "Emma" });
Console.WriteLine("calling SaveChangesAsync");
await db.SaveChangesAsync();
Console.WriteLine("done");

How many times will you see the "SavingChanges called" line? The real output on EF Core 6 and 10:

calling SaveChanges
SavingChanges called
calling SaveChangesAsync
done

Once. SaveChangesAsync calls the interceptor's async method, and since we didn't override it, nothing happened. The second book was saved, but the interceptor never knew. In an ASP.NET Core application almost everything is async, so this bug looks like the interceptor "never runs". In this post we will write interceptors properly, use them to fill audit fields automatically, catch slow queries, and look at EF Core's lighter alternative: events.

What Is an Interceptor, and Where Does It Sit?

An interceptor is a hook attached to specific points of EF Core's own workflow. EF calls your code before and after it sends a command, when it opens a connection, when it starts a transaction, or while SaveChanges runs. Think of a quality control point on a factory conveyor belt: as a product passes, you can stop and inspect it, stick a label on it, or even take it off the belt.

In EF Core 6 there are four interceptor interfaces you will use most often. ISaveChangesInterceptor hooks into saving, IDbCommandInterceptor into every command sent to the database, IDbConnectionInterceptor into a connection opening and closing, and IDbTransactionInterceptor into transactions. Each one has a base class that makes the job easier, such as SaveChangesInterceptor and DbCommandInterceptor. All the methods on these classes are empty virtual methods; you only override the moment you care about.

Registration always happens in the same place: DbContextOptionsBuilder.AddInterceptors(...). An interceptor is registered once and runs for every context created with those options.

Audit Fields with a SaveChangesInterceptor

The classic need: keep track of when each record was created and when it was last updated. Instead of writing that next to every Add call, let's mark the entities with an interface and solve it in one place:

public interface IAuditable
{
    DateTime CreatedAt { get; set; }
    DateTime? UpdatedAt { get; set; }
}

public class Book : IAuditable
{
    public int Id { get; set; }
    public string Title { get; set; } = "";
    public decimal Price { get; set; }
    public DateTime CreatedAt { get; set; }
    public DateTime? UpdatedAt { get; set; }
}
public class AuditInterceptor : SaveChangesInterceptor
{
    public override InterceptionResult<int> SavingChanges(
        DbContextEventData eventData, InterceptionResult<int> result)
    {
        StampAuditFields(eventData.Context);
        return base.SavingChanges(eventData, result);
    }

    public override ValueTask<InterceptionResult<int>> SavingChangesAsync(
        DbContextEventData eventData, InterceptionResult<int> result,
        CancellationToken cancellationToken = default)
    {
        StampAuditFields(eventData.Context);
        return base.SavingChangesAsync(eventData, result, cancellationToken);
    }

    private static void StampAuditFields(DbContext? context)
    {
        if (context is null)
            return;

        var now = DateTime.UtcNow;
        foreach (var entry in context.ChangeTracker.Entries<IAuditable>())
        {
            if (entry.State == EntityState.Added)
            {
                entry.Entity.CreatedAt = now;
            }
            else if (entry.State == EntityState.Modified)
            {
                entry.Entity.UpdatedAt = now;
                // CreatedAt is written once and never updated afterwards
                entry.Property(e => e.CreatedAt).IsModified = false;
            }
        }
    }
}

We overrode both the sync and the async method and put the real work in a shared method. SavingChanges is called right before EF turns the changes into SQL, so the values you write to the entities here end up in the INSERT and UPDATE. ChangeTracker.Entries<IAuditable>() runs DetectChanges itself, so the states are current. eventData.Context is nullable because the same event data type is also used in scenarios without a context; don't skip the check.

Let's register it on the context and try it:

public class BookstoreContext : DbContext
{
    public DbSet<Book> Books => Set<Book>();

    protected override void OnConfiguring(DbContextOptionsBuilder options)
        => options.UseSqlite("Data Source=bookstore.db")
                  .AddInterceptors(new AuditInterceptor())
                  .LogTo(Console.WriteLine, new[] { RelationalEventId.CommandExecuted });
}
var book = new Book { Title = "Dune", Price = 18.50m };
db.Books.Add(book);
await db.SaveChangesAsync();
Console.WriteLine($"CreatedAt: {book.CreatedAt:O}, UpdatedAt: {book.UpdatedAt?.ToString("O") ?? "null"}");

book.Price = 16.00m;
book.CreatedAt = DateTime.MinValue; // let's try to overwrite it by mistake
db.SaveChanges();
db.ChangeTracker.Clear();

var fresh = await db.Books.SingleAsync();
Console.WriteLine($"CreatedAt: {fresh.CreatedAt:O}, UpdatedAt: {fresh.UpdatedAt?.ToString("O") ?? "null"}");

The output on EF Core 10:

CreatedAt: 2026-11-03T21:57:49.5267920Z, UpdatedAt: null
CreatedAt: 2026-11-03T21:57:49.5267920, UpdatedAt: 2026-11-03T21:57:49.5537210

The SQL sent for the update shows that our attempt to overwrite CreatedAt never reached the database:

UPDATE "Books" SET "Price" = @p0, "UpdatedAt" = @p1
WHERE "Id" = @p2
RETURNING 1;

We saved once async and once sync, and the interceptor ran on both paths. Also notice that the Z disappeared on the second line; we will come back to that in the pitfalls.

Stepping In and Stopping: InterceptionResult

What sets an interceptor apart from an event is that it can change the flow instead of only watching. The InterceptionResult<int> returned from SavingChanges is how you tell EF "carry on" or "I handled this, here is the result". For example, an application in maintenance mode should write nothing:

public class ReadOnlyInterceptor : SaveChangesInterceptor
{
    public override InterceptionResult<int> SavingChanges(
        DbContextEventData eventData, InterceptionResult<int> result)
        => InterceptionResult<int>.SuppressWithResult(0);

    public override ValueTask<InterceptionResult<int>> SavingChangesAsync(
        DbContextEventData eventData, InterceptionResult<int> result,
        CancellationToken cancellationToken = default)
        => ValueTask.FromResult(InterceptionResult<int>.SuppressWithResult(0));
}
var book = new Book { Title = "Dune" };
db.Books.Add(book);
var saved = await db.SaveChangesAsync();
Console.WriteLine($"saved: {saved}, state: {db.Entry(book).State}, rows: {await db.Books.AsNoTracking().CountAsync()}");

The output is saved: 0, state: Added, rows: 0. No command went to the database, SaveChangesAsync returned 0, and the entity is still waiting in the Added state. In real life you would more likely throw an exception, but this example shows the power an interceptor holds. Command interceptors work the same way: inside ReaderExecuting you can change command.CommandText, or return a result without sending the command at all.

Catching Slow Queries with a DbCommandInterceptor

One of the most useful interceptors in production is a simple class that logs queries exceeding a given duration:

using System.Data.Common;

public class SlowQueryInterceptor : DbCommandInterceptor
{
    private readonly TimeSpan _threshold;

    public SlowQueryInterceptor(TimeSpan threshold) => _threshold = threshold;

    public override DbDataReader ReaderExecuted(
        DbCommand command, CommandExecutedEventData eventData, DbDataReader result)
    {
        Report(command, eventData);
        return base.ReaderExecuted(command, eventData, result);
    }

    public override ValueTask<DbDataReader> ReaderExecutedAsync(
        DbCommand command, CommandExecutedEventData eventData, DbDataReader result,
        CancellationToken cancellationToken = default)
    {
        Report(command, eventData);
        return base.ReaderExecutedAsync(command, eventData, result, cancellationToken);
    }

    private void Report(DbCommand command, CommandExecutedEventData eventData)
    {
        if (eventData.Duration > _threshold)
            Console.WriteLine($"SLOW ({eventData.Duration.TotalMilliseconds:F0} ms): {command.CommandText}");
    }
}

ReaderExecuted is called after every command that returns results, and eventData.Duration tells you how long the command took. For commands that return no results there is NonQueryExecuted, and for those returning a single value, ScalarExecuted. To try it, let's add 10,000 books and write a deliberately expensive query:

// options.AddInterceptors(new SlowQueryInterceptor(TimeSpan.FromMilliseconds(100)))
db.Books.AddRange(Enumerable.Range(1, 10_000).Select(i => new Book { Title = $"Book {i}" }));
await db.SaveChangesAsync();

var first = await db.Books.TagWith("Single book").FirstAsync(b => b.Id == 42);

var pairs = await db.Books
    .TagWith("Cross join report")
    .SelectMany(a => db.Books, (a, b) => new { a.Id, Other = b.Id })
    .CountAsync(x => x.Id < x.Other);

The output on my machine with EF Core 10 (on EF Core 6 the duration was 179 ms, the SQL is the same):

SLOW (172 ms): -- Cross join report

SELECT COUNT(*)
FROM "Books" AS "b"
CROSS JOIN "Books" AS "b0"
WHERE "b"."Id" < "b0"."Id"

The query fetching a single book stayed under the threshold, so it wasn't logged. The tag we gave with TagWith was added to the start of the SQL as a comment, and in the log it immediately shows where in the code the query came from. In production, this pair is the cheapest answer to "which screen is slow?".

Registering with Dependency Injection

In ASP.NET Core you register the context with AddDbContext instead of OnConfiguring. So that the interceptor itself can take dependencies, the cleanest way is to put it in the container and resolve it from there:

using Microsoft.Extensions.DependencyInjection;

var services = new ServiceCollection();
services.AddSingleton<AuditInterceptor>();
services.AddDbContext<BookstoreContext>((sp, options) =>
    options.UseSqlite("Data Source=bookstore.db")
           .AddInterceptors(sp.GetRequiredService<AuditInterceptor>()));

The (sp, options) overload of AddDbContext gives you access to the service provider while building the options. The context itself must have a constructor that takes DbContextOptions<BookstoreContext>. Notice that we registered the interceptor as a singleton: the same instance will serve the contexts of every request. We covered the rest of the ASP.NET Core integration in detail in an earlier post and in the ASP.NET Core Web API series.

Events: A Lighter Hook

Not every need calls for an interceptor. If all you want is "something happened, let me know", the events on DbContext and the change tracker are enough:

public class BookstoreContext : DbContext
{
    public DbSet<Book> Books => Set<Book>();

    public BookstoreContext()
    {
        SavingChanges += (sender, e) =>
            Console.WriteLine($"SavingChanges: {ChangeTracker.Entries().Count(x => x.State != EntityState.Unchanged)} pending");
        SavedChanges += (sender, e) =>
            Console.WriteLine($"SavedChanges: {e.EntitiesSavedCount} saved");
        SaveChangesFailed += (sender, e) =>
            Console.WriteLine($"SaveChangesFailed: {e.Exception.GetType().Name}");

        ChangeTracker.Tracked += (sender, e) =>
            Console.WriteLine($"Tracked: {((Book)e.Entry.Entity).Title ?? "(no title)"} (from query: {e.FromQuery})");
        ChangeTracker.StateChanged += (sender, e) =>
            Console.WriteLine($"StateChanged: {((Book)e.Entry.Entity).Title} {e.OldState} -> {e.NewState}");
    }

    protected override void OnConfiguring(DbContextOptionsBuilder options)
        => options.UseSqlite("Data Source=bookstore.db");
}

Let's add a book, then read it and change its price, and finally break the save on purpose with a book whose Title is null:

db.Books.Add(new Book { Title = "Dune", Price = 18.50m });
await db.SaveChangesAsync();

db.ChangeTracker.Clear();
var dune = await db.Books.SingleAsync();
dune.Price = 16.00m;
await db.SaveChangesAsync();

db.Books.Add(new Book { Title = null!, Price = 9.99m });
try { await db.SaveChangesAsync(); }
catch (DbUpdateException ex) { Console.WriteLine(ex.InnerException?.Message); }

The same output on EF Core 6 and 10 (I separated the three parts with blank lines for readability):

Tracked: Dune (from query: False)
SavingChanges: 1 pending
StateChanged: Dune Added -> Unchanged
SavedChanges: 1 saved

Tracked: Dune (from query: True)
StateChanged: Dune Unchanged -> Modified
SavingChanges: 1 pending
StateChanged: Dune Modified -> Unchanged
SavedChanges: 1 saved

Tracked: (no title) (from query: False)
SavingChanges: 1 pending
SaveChangesFailed: DbUpdateException
SQLite Error 19: 'NOT NULL constraint failed: Books.Title'.

Here you can watch live the state transitions we saw in the change tracking post. Tracked marks the moment an entity is first tracked, and FromQuery tells you whether it came from a query or from Add. StateChanged fires only when the state of an already tracked entity changes.

Choosing between them comes down to a simple question. If you need to change or stop the flow, or set up shared behavior across many contexts, use an interceptor. If you want to watch, log or collect metrics for what happens on a specific context instance, use an event. Events are bound to the instance, interceptors to the options.

Common Pitfalls

The first is the pitfall from the start of the post: sync and async methods are separate. Write SavingChanges and forget SavingChangesAsync, and the interceptor won't run for async saves. The same goes for ReaderExecuted and ReaderExecutedAsync. Make the rule a habit: write a shared method and call it from both.

The second is the shared instance. The object you pass to AddInterceptors is shared by every context created with those options; when you register it as a singleton in DI, every request uses the same object. If you keep a field like "the current user" or "records changed in this request" inside the interceptor, different threads will overwrite each other's data. Write interceptors stateless; reach context-specific information through eventData.Context.

The third: anything that bypasses SaveChanges bypasses the interceptor too. An UPDATE sent with ExecuteSqlRaw doesn't call SavingChanges, and UpdatedAt isn't written. The same applies to ExecuteUpdate/ExecuteDelete, which arrived in EF Core 7; we will see them in the version posts. If your audit rule must be airtight, know the code that uses these paths, or move the rule to the database side.

The fourth is about time. In the output, the first CreatedAt ended with Z, but the one read from the database didn't. SQLite stores a DateTime as text and doesn't write the DateTimeKind; when you read it back, Kind is Unspecified. You know the value is UTC, but the code doesn't. You can fix this with a value converter or with DateTime.SpecifyKind when reading. We will cover the changes EF Core 10 made to date behavior on SQLite in its version post.

A Small Experiment

★☆☆ Delete the SavingChangesAsync override from AuditInterceptor, run the code from the post again and look at the CreatedAt value on the first line. Then put the override back.

★★☆ Add string? UpdatedBy to IAuditable. Give the interceptor a "current user" provider of type Func<string> through its constructor and write that value on Modified records. Think about why reading from the provider on every call matters, instead of keeping the user name in a field inside the interceptor.

★★★ Write a DbConnectionInterceptor and log the ConnectionOpened and ConnectionClosed moments. Run a single query first, then two SaveChanges calls inside Database.BeginTransaction(), and compare how many times the connection opens and closes.

In this post we extended EF Core's behavior with our own code. But how do we make sure the interceptor, the value converter or the query we wrote actually works correctly? In the next post we talk about writing tests with EF Core, realistic tests with SQLite in-memory, and the pitfalls of the InMemory provider.