Skip to content
Go back

Debugging Duplicate Event Processing: A 4-Day Journey Through EF Core Interceptors

TL;DR

The Bug: Domain events in EF Core integration tests were being processed twice.

The Investigation: I spent 4 days testing wild theories:

The Truth: WebApplicationFactory was registering the DbContext configuration twice, creating two interceptor instances. I only found it when I stopped assuming and started enumerating what was actually registered in the test setup.

The Fix:

  1. Made our Outbox library’s AddDbContext idempotent (check for existing interceptors before adding)
  2. Added deduplication with HashSet<Guid> instead of List<Guid>

The Lesson: Sometimes the simplest explanation (double registration) is the right one. I just won’t find it until I’ve eliminated all the complex ones. Also: stack traces can be misleading when I’m making wrong assumptions.


Introduction

This document chronicles a four-day debugging journey to track down why domain events were being processed twice in an application using the Onward library. What started as a simple “events are duplicating” bug turned into a deep dive through Entity Framework Core’s internals, dependency injection scoping, execution strategies, and ultimately led me to an unexpected culprit hiding in the test infrastructure.

Spoiler: The issue wasn’t where I thought it was. Not even close. I went through four different theories before finding the truth.

Background: The Onward Library

Onward is an implementation of the Transactional Outbox pattern for Entity Framework Core. It works by:

  1. Extracting domain events from entities during SaveChangesAsync
  2. Persisting events to an Events table within the same database transaction
  3. Processing events immediately after the transaction commits
  4. Retrying failed events via a background service

The library uses EF Core’s ISaveChangesInterceptor to hook into the save pipeline:

public class SaveChangesInterceptor<TContext> : ISaveChangesInterceptor
{
    private readonly List<Guid> _added = [];

    public override async ValueTask<InterceptionResult<int>> SavingChangesAsync(...)
    {
        // Extract domain events from entities
        var events = context.ExtractEvents();

        // Add Event entities to ChangeTracker
        context.AddToEvents(events);

        // Track which events we added
        var eventIds = GetAddedEventIds(context);
        _added.AddRange(eventIds);

        return result;
    }

    public override async ValueTask<int> SavedChangesAsync(...)
    {
        // Process all events we tracked
        foreach (var eventId in _added)
        {
            await ProcessEventAsync(eventId, context);
        }

        _added.Clear();
        return result;
    }
}

Simple, elegant, and it worked perfectly… until I noticed events were being processed twice in integration tests.

Day 1: The DbContext Lifetime Rabbit Hole

Initial Hypothesis: Transient vs Scoped DbContext

Looking at our service registration, I noticed the DbContext was registered as Transient:

services.AddDbContext<TContext>(
    optionsAction,
    contextLifetime: ServiceLifetime.Transient,  // <-- Suspicious!
    optionsLifetime: ServiceLifetime.Scoped);

Why Transient DbContext is a Bad Idea:

Using ServiceLifetime.Transient for DbContext is generally considered an anti-pattern for several reasons:

  1. Connection Pool Exhaustion - Each transient instance creates a new connection lifecycle, potentially exhausting the connection pool under load
  2. Performance Overhead - Creating and disposing DbContext instances repeatedly adds unnecessary overhead
  3. State Management Issues - Multiple DbContext instances in the same scope can lead to inconsistent views of entity state
  4. Change Tracking Conflicts - Two transient contexts might track the same entity differently
  5. Transaction Complexity - Coordinating transactions across multiple context instances becomes problematic
  6. Memory Pressure - More frequent allocations and disposals increase GC pressure

The Microsoft documentation explicitly recommends Scoped lifetime for web applications. Even though this wasn’t the cause of the bug, it was still a problem that needed fixing.

My first theory: Maybe Transient contexts are causing interceptor sharing issues.

The “Fix” That Didn’t Fix Anything

I changed the DbContext lifetime to Scoped:

services.AddDbContext<TContext>(
    optionsAction,
    contextLifetime: ServiceLifetime.Scoped,  // <-- Changed from Transient
    optionsLifetime: ServiceLifetime.Scoped);

Result: Events still duplicating. 😞

I tested my hypothesis by checking if interceptors were truly isolated per scope:

[Test]
public async Task InterceptorsAreDifferentBetweenScopes()
{
    await using var scope1 = _serviceProvider.CreateAsyncScope();
    await using var scope2 = _serviceProvider.CreateAsyncScope();

    var interceptor1 = scope1.ServiceProvider
        .GetRequiredService<SaveChangesInterceptor<TestContext>>();
    var interceptor2 = scope2.ServiceProvider
        .GetRequiredService<SaveChangesInterceptor<TestContext>>();

    Assert.That(interceptor1, Is.Not.SameAs(interceptor2));
}

Result: ✅ PASSED

Different scopes got different interceptor instances. Every time.

Dead End #1

After a full day of testing DbContext lifetimes, I had:

However, I kept the change to ServiceLifetime.Scoped anyway. Even though it didn’t solve my immediate problem, using Transient for DbContext was a legitimate issue that could cause problems in production. I fixed it preemptively while I was in the area.

Time to look elsewhere.

Day 2: The EF Core Internals Deep Dive

Hypothesis 2: Transaction Lifecycle and DetectChanges

Next, I wondered if EF Core’s transaction handling was causing multiple interceptor invocations. I added extensive logging to trace the execution flow:

public override async ValueTask<InterceptionResult<int>> SavingChangesAsync(...)
{
    var depth = new StackTrace().FrameCount;
    _logger.LogWarning(
        "[ONWARD] SavingChangesAsync ENTRY - Depth: {depth}", depth);

    // ... existing logic ...

    _logger.LogWarning(
        "[ONWARD] SavingChangesAsync EXIT - Depth: {depth}", depth);
}

The Revelation: Multiple Interceptor Calls

Running the integration tests produced this output:

📝 [ONWARD] SavingChangesAsync ENTRY, Depth: 1
info: Extracted 1 events from entities
warn: Found 1 new Event entities to add to _added list
info: → Event ID: 9affe28b-e623-40f6-aa96-eb0a5eacf782
warn: _added list now contains: 1 items
📝 [ONWARD] SavingChangesAsync EXIT, Depth: 1

📝 [ONWARD] SavingChangesAsync ENTRY, Depth: 1
info: Extracted 0 events from entities    ← NO NEW DOMAIN EVENTS
warn: Found 1 new Event entities to add to _added list
info: → Event ID: 9affe28b-e623-40f6-aa96-eb0a5eacf782  ← SAME EVENT ID
warn: _added list now contains: 2 items   ← DUPLICATE!
📝 [ONWARD] SavingChangesAsync EXIT, Depth: 1

✅ [ONWARD] SavedChangesAsync ENTRY
warn: Processing 2 items...
warn: 🎯 Processing event 1/2: 9affe28b-e623-40f6-aa96-eb0a5eacf782
warn: 🎯 Processing event 2/2: 9affe28b-e623-40f6-aa96-eb0a5eacf782  ← DUPLICATE PROCESSING!
✅ [ONWARD] SavedChangesAsync EXIT

Key Observation: The interceptor was being invoked twice at the same stack depth, both times accumulating the same event ID into the _added list.

Testing With DetectChanges

I theorised that calling context.AddRange() inside the interceptor might trigger EF Core to re-run the save pipeline. I tested by disabling automatic change detection:

var autoDetectChangesEnabled = context.ChangeTracker.AutoDetectChangesEnabled;
try
{
    context.ChangeTracker.AutoDetectChangesEnabled = false;
    // ... extract and add events ...
}
finally
{
    context.ChangeTracker.AutoDetectChangesEnabled = autoDetectChangesEnabled;
}

Result: Still duplicating.

Dead End #2

I spent hours reading EF Core source code, trying to understand transaction lifecycle phases and change detection algorithms. I learnt a lot about EF Core internals, but I still couldn’t explain why the interceptor was being called twice with identical stack traces.

Current Status: Two days in, two dead ends.

Day 3: The Execution Strategy Red Herring

Hypothesis 4: NpgsqlExecutionStrategy

Looking at the stack traces, I noticed:

Call 1 & Call 2 both showed:
  Npgsql.EntityFrameworkCore.PostgreSQL.Storage.Internal.NpgsqlExecutionStrategy.ExecuteAsync

New theory: The execution strategy must be retrying SaveChangesAsync.

I pulled up the Npgsql source code to understand what was happening under the hood.

Reading the Source Code

Here’s what NpgsqlExecutionStrategy.ExecuteAsync actually does:

public virtual async Task<TResult> ExecuteAsync<TState, TResult>(
    TState state,
    Func<DbContext, TState, CancellationToken, Task<TResult>> operation,
    Func<DbContext, TState, CancellationToken, Task<ExecutionResult<TResult>>>? verifySucceeded,
    CancellationToken cancellationToken)
{
    try
    {
        return await operation(Dependencies.CurrentContext.Context, state, cancellationToken)
            .ConfigureAwait(false);
    }
    catch (Exception ex) when (ExecutionStrategy.CallOnWrappedException(ex, NpgsqlTransientExceptionDetector.ShouldRetryOn))
    {
        throw new InvalidOperationException(
            "An exception has been raised that is likely due to a transient failure.", ex);
    }
}

And the synchronous Execute method:

public virtual TResult Execute<TState, TResult>(
    TState state,
    Func<DbContext, TState, TResult> operation,
    Func<DbContext, TState, ExecutionResult<TResult>>? verifySucceeded)
{
    try
    {
        return operation(Dependencies.CurrentContext.Context, state);
    }
    catch (Exception ex) when (ExecutionStrategy.CallOnWrappedException(ex, NpgsqlTransientExceptionDetector.ShouldRetryOn))
    {
        throw new InvalidOperationException(
            "An exception has been raised that is likely due to a transient failure.", ex);
    }
}

What this revealed:

The execution strategy is just a generic wrapper. It:

  1. Takes a delegate (operation) representing any database operation
  2. Invokes it exactly once
  3. Catches exceptions and checks if they’re transient
  4. Re-throws if they are, otherwise returns the result

It doesn’t know what operation it’s wrapping. It could be a query, a command, an update, a delete, or a SaveChangesAsync call. It doesn’t matter. It’s completely operation-agnostic.

The fact that NpgsqlExecutionStrategy.ExecuteAsync appeared in both stack traces simply meant “EF Core wrapped a database operation here”. It told me nothing about whether anything was retrying or why it was being called twice.

But that still didn’t explain why the interceptor was being called twice…

Dead End #3

After a full day investigating execution strategies:

Current Status: Three days in, three dead ends. I was exhausted and running out of ideas.

Day 4: The Breakthrough

A Wild, Desperate Theory

On the morning of day 4, completely out of obvious theories and running on pure desperation, I threw an idea at the wall - one I didn’t actually expect to be true:

What if there are TWO interceptors?

This seemed ridiculous. I’d proven that scopes don’t share interceptors. I’d proven no re-entrancy. I’d proven no retry logic. The idea that we somehow accidentally registered the interceptor type twice during configuration felt like a Hail Mary theory.

But I was out of ideas, so I tested it anyway.

The Smoking Gun

I added logging to capture ALL interceptor instances:

var context = scope.ServiceProvider.GetRequiredService<TestContext>();
var interceptors = context.GetService<IEnumerable<ISaveChangesInterceptor>>();

foreach (var interceptor in interceptors)
{
    var hash = RuntimeHelpers.GetHashCode(interceptor).ToString("X8");
    var type = interceptor.GetType().Name;
    Console.WriteLine($"Interceptor: {type} (Hash: {hash})");
}

Output:

Interceptor: SaveChangesInterceptor (Hash: 016E492A)
Interceptor: OnConnectingInterceptor (Hash: 01234ABC)
Interceptor: SaveChangesInterceptor (Hash: 02F3C7DE)  ← DUPLICATE!
Interceptor: OnConnectingInterceptor (Hash: 03456DEF)  ← DUPLICATE!

There it was. Two instances of SaveChangesInterceptor<TContext>. Two instances of OnConnectingInterceptor.

The wild theory was true. Not shared across scopes. Just… registered twice.

Finding the Root Cause

The problem was in how we set up our integration tests. At first glance, the logic seemed perfectly reasonable.

Step 1: Production Startup (Program.cs)

services.AddShoppingCartContext(() => connectionString);

Step 2: Test Setup (WebApplicationFactory)

protected override void ConfigureTestServices(IServiceCollection services)
{
    services.RemoveAll(typeof(ShoppingCartContext));
    services.RemoveAll(typeof(DbContextOptions<ShoppingCartContext>));

    services.AddShoppingCartContext(() => testConnectionString);
}

The logic seemed sound: when you call AddDbContext, you’re registering two main services: the DbContext and its DbContextOptions. So to replace them with our TestContainer, we remove those two types and re-register with test configuration. Clean. Simple. Right?

Wrong.

The Hidden Service

When I dug into EF Core’s AddDbContext implementation, I discovered it registers a third service that’s completely invisible to casual inspection:

IDbContextOptionsConfiguration<ShoppingCartContext>

This is an internal service that EF Core uses to wrap your options lambda. When DbContextOptions are resolved, EF Core internally iterates through all registered IDbContextOptionsConfiguration<TContext> instances and calls them. This is where the interceptors get added.

Here’s the problem:

  1. Production startup calls AddDbContext, which registers IDbContextOptionsConfiguration<ShoppingCartContext> (v1)
  2. Test setup removes DbContext and DbContextOptions types (but NOT the configuration)
  3. Test setup calls AddDbContext again, which registers a SECOND IDbContextOptionsConfiguration<ShoppingCartContext> (v2)
  4. Now there are TWO configurations in the service collection
  5. When DbContextOptions are resolved, both configurations execute
  6. Both add their own instances of the interceptors
  7. Result: duplicate interceptors, duplicate event processing

The removal looked like it worked because we removed the visible services. But the hidden configuration service lingered in the container, waiting to cause trouble.

Why This Was So Hard to Find

For more technical details, see Appendix A: How EF Core’s AddDbContext Works.

The Solution

Approach 1: Prevent Double Registration

I recommended fixing this in the Onward library by making the interceptor registration idempotent:

void OptionsActionOverride(IServiceProvider sp, DbContextOptionsBuilder builder)
{
    // Let the caller configure the database provider
    optionsAction(sp, builder);

    // Check for existing interceptors before adding
    var existingInterceptors = builder.Options.Extensions
        .OfType<CoreOptionsExtension>()
        .SelectMany(e => e.Interceptors ?? [])
        .ToList();

    AddIfNotExists<SaveChangesInterceptor<TContext>>();
    AddIfNotExists<OnConnectingInterceptor>();

    void AddIfNotExists<TInterceptor>() where TInterceptor : IInterceptor
    {
        if (!existingInterceptors.OfType<TInterceptor>().Any())
        {
            builder.AddInterceptors(sp.GetRequiredService<TInterceptor>());
        }
    }
}

What This Does:

  1. Inspects the DbContextOptionsBuilder to see what interceptors are already registered
  2. Only adds an interceptor if one of that type doesn’t already exist
  3. Makes Onward’s AddDbContext idempotent - safe to call multiple times

Approach 2: Use HashSet for Deduplication (Defensive)

Even with the configuration fix, I added defensive deduplication to make the interceptor resilient to configuration mistakes:

public class SaveChangesInterceptor<TContext> : ISaveChangesInterceptor
{
    private readonly HashSet<Guid> _added = [];  // ← Changed from List<Guid>

    private List<Guid> GetAddedEventIds(DbContext context)
    {
        return context.ChangeTracker.Entries()
            .Where(x => x.Entity.GetType() == typeof(Event) && x.State == EntityState.Added)
            .Select(entry => ((Event)entry.Entity).Id)
            .ToList();
    }
}

The HashSet<Guid> automatically prevents duplicates when items are added to it. No extra filtering needed.

Why both solutions?

What I Learned

The 7 Key Lessons

LessonWhat HappenedTakeaway
🎯 Stack Traces Can Be MisleadingTwo instances, one call each ≠ one instance, two callsLog instance identity (hashes) in addition to stack traces
🔬 Verify Your HypothesesTested 4 theories; only testing revealed the truthDon’t stop at plausible. Test thoroughly
⚠️ Don’t Assume Extension MethodsAddDbContext hides IDbContextOptionsConfiguration<TContext>; RemoveAll won’t touch itUnderstand what framework methods actually register
📦 NuGet Packages Need IdempotencyBug only appeared in consuming apps, not Onward’s testsDesign extensions to be callable multiple times safely
🧪 Test Infrastructure Deserves ScrutinyDebugged library for days; issue was in test setupTreat test infrastructure as production code
🛡️ EF Core Doesn’t Prevent DuplicatesMultiple interceptors of same type allowed by designPrevent registration or implement deduplication
🧠 Step Back When StuckBreakthrough came on day 4 with fresh perspectiveExhaustion clouds judgment; stepping back helps

For EF Core Users

Interceptor scoping works correctly - If using scoped interceptors with scoped DbContexts, each scope gets its own instance. Both Scoped and Transient context lifetimes work correctly.

EF Core doesn’t call interceptors multiple times - Modifying the ChangeTracker during SavingChangesAsync does NOT cause the interceptor to be called multiple times. If you see duplicate processing, you likely have multiple interceptor instances registered.

Be careful with AddDbContext - Calling it multiple times doesn’t replace previous configurations, it appends to them. No deduplication happens automatically.

Implement defensive deduplication - Even after fixing the root cause, make your interceptors resilient to duplicate registrations with logic like HashSet<T> and ID checking.

Quick Reference: “My Interceptor is Being Called Twice!”

If you’re debugging duplicate event processing in EF Core, use this checklist:

Step 1: Verify Multiple Instances

var interceptors = dbContext.GetService<IEnumerable<ISaveChangesInterceptor>>();
foreach (var i in interceptors)
{
    Console.WriteLine($"{i.GetType().Name}: {RuntimeHelpers.GetHashCode(i):X8}");
}
// Do you see the same type twice with different hashes?

Step 2: Check for Double Registration

Step 3: Make Registration Idempotent Check if interceptors are already registered before adding:

var existingInterceptors = builder.Options.Extensions
    .OfType<CoreOptionsExtension>()
    .SelectMany(e => e.Interceptors ?? [])
    .ToList();

if (!existingInterceptors.OfType<MyInterceptor>().Any())
{
    builder.AddInterceptors(sp.GetRequiredService<MyInterceptor>());
}

Appendices

Appendix A: How EF Core’s AddDbContext Works

When you call AddDbContext, it registers three main services:

  1. DbContext - The context itself (obvious)
  2. DbContextOptions - The options (obvious)
  3. IDbContextOptionsConfiguration - The configuration wrapper (hidden!)

The third one is internal. It stores your optionsAction lambda and gets called when DbContextOptions are resolved:

// In EF Core source (simplified)
foreach (var configuration in applicationServiceProvider
    .GetServices<IDbContextOptionsConfiguration<TContext>>())
{
    configuration.Configure(applicationServiceProvider, builder);
    // Your lambda runs here!
}

The Problem: RemoveAll doesn’t remove IDbContextOptionsConfiguration<TContext>.

So if you do this:

services.RemoveAll(typeof(DbContext<TContext>));
services.RemoveAll(typeof(DbContextOptions<TContext>));
services.AddDbContext<TContext>(...);  // Registers AGAIN

You end up with:

Result: Your optionsAction runs twice, calling AddInterceptors twice.

Appendix B: Full EF Core Call Chain

If you want to understand exactly what happens, here’s the call chain when AddDbContext registers interceptors:

AddDbContext<TContext>(optionsAction)

AddCoreServices<TContext>()

ConfigureDbContext<TContext>(optionsAction)  // ← Uses services.Add()
  ↓ (later, when DbContextOptions are resolved)
CreateDbContextOptions<TContext>()

for each IDbContextOptionsConfiguration<TContext>:
    configuration.Configure(sp, builder)

    optionsAction(sp, builder)  // YOUR LAMBDA RUNS HERE

    builder.AddInterceptors()   // If you added them here

    CoreOptionsExtension.WithInterceptors()  // CONCATENATES to existing list!

The key insight: WithInterceptors() doesn’t replace, it concatenates. Multiple configurations = multiple adds = multiple interceptor instances.

Conclusion

This investigation taught me more about Entity Framework Core’s internals than I ever intended to learn. I explored dependency injection scoping, DbContext options caching, change tracking, transaction lifecycle, and execution strategies.

All of which turned out to be red herrings.

The actual bug? A simple double registration in test setup code.

The lesson: Sometimes the simplest explanation is the right one. But I won’t know that until I’ve eliminated all the complex ones. And sometimes that takes four days, three dead ends, and one desperate wild theory.

Happy debugging!


Have you encountered a similar issue with EF Core? I’d love to hear about it. Feel free to connect with me on LinkedIn.


Share this post on:

Next Post
How I Became the Impostor: Breaking Free from Toxic Environments and Self-Fulfilling Prophecies