An EF Core race condition that only showed up after the switch to Azure

A few months ago, I faced one of those head-scratching problems. Something happened in production that shouldn't happen: a record got closed that nobody closed. Unfortunately, it happened on a critical path in the system, so we needed a fast fix.

Nothing in the error logs. No leads in other log levels either. No recent code change that could explain it. It got me thinking about a recent issue we had: code that had worked fine for years broke after we switched to Azure. My first suspect was a race condition between overlapping Hangfire jobs, but I disproved it: we turned off the second Hangfire server, and the issue persisted. I did notice it happened mostly during rush hours in production.

📝 Note: The real system isn't a warehouse. I changed the domain and names, but the mechanics are exactly the same. The full reproduction is on GitHub.

The setup

For this article, I moved the problem to a warehouse that picks orders in batches. One pick list, one walk through the warehouse, can serve several orders, so pick lists and orders are linked through a link table:

public class PickList
{
    public int Id { get; set; }
    public required string Status { get; set; }
    public List<PickListOrder> Orders { get; } = [];
}

public class PickListOrder // link row
{
    public int PickListId { get; set; }
    public int OrderId { get; set; }
}

When an order ships, the open pick lists that served only that order get closed. A pick list shared with another order stays open until that order ships too.

In our case, shipping order A closed order B's brand-new pick list.

Logging

For this project, a new deployment isn't as straightforward as pushing a button and waiting a few minutes, so we couldn't just try things in production. We needed proof before changing any logic.

Logging was the first thing that could help without breaking anything else. We added a log line before and after every place in the code that closes a pick list, including the pick list, the order it was closed for, and both statuses.

When it happened again, the logs narrowed it down to one place: the code that ships orders closed the pick list. So that was where I started looking.

The query

When an order ships, this query decides which pick lists get closed:

var pickLists = db.PickLists
    .Where(p => p.Status == "Open" && p.Orders.All(o => o.OrderId == orderId))
    .ToList();

foreach (var pickList in pickLists)
    pickList.Status = "Closed";

When I was reading the code, this line didn't catch my attention. It reads exactly like the rule: close the open pick lists whose orders are all this order. A pick list shared with order C doesn't match, which is what we want.

But All() on an empty collection returns true. It's even in the documentation: "…or if the sequence is empty". With no links, nothing breaks the condition, so a pick list without any orders matches every order.

💡 Tip: Search your code for .All( on navigation collections. Each one is true for an entity whose collection is still empty, so each is worth a second look.

Can a pick list exist without its orders? Not once it's saved. The pick list and its links are saved together in one SaveChanges(), which EF runs in one transaction. So nobody should ever see one without the other. Unless they read data that isn't committed yet.

The transaction

Deep in our persistence layer there is a base class, written years ago, that starts every transaction with the following code:

context.Database.BeginTransaction(IsolationLevel.ReadUncommitted);

READ UNCOMMITTED means dirty reads. The transaction sees rows that other sessions have written but not committed yet. The shipping code ran inside one of these transactions.

EF saves a new pick list with its link in two commands, because the link needs the pick list's generated id:

1. INSERT the pick list and read back its id.
2. INSERT the link row with that id.

Same transaction, but two round trips to the database. Between them, the pick list exists with zero orders. A dirty read at that moment sees exactly that, and All() matches it. Either one alone would have been fine.

It also explained why it started after the move. We still ran SQL Server with the same database settings, just on an Azure VM instead of a server in a hosted data center. The gap isn't only the network round trip; it also includes the work on the web server between the two commands, and that needs CPU time. I never measured it, but round trips in Azure are likely longer than before, and I suspect thread scheduling plays a part too: the earlier bug I mentioned at the start came down to how threads were scheduled there. During rush hours, more requests compete for the CPU and the network, so the gap gets longer and more requests land in it.

The original intent of that base class was most likely reads that never block: READ UNCOMMITTED, or NOLOCK on every query, was a common way to avoid blocking in older SQL Server codebases. SQL Server 2005 added a safer way, read committed snapshot isolation (RCSI), but turning it on changes every read in the database, so this base class never changed.

How RCSI works

When a row is updated or deleted, SQL Server first copies the old version into a version store (in tempdb, or in the database itself with accelerated database recovery). Readers take no locks on the rows. Each statement reads the data as it was committed when the statement started, using the old versions where needed. The cost is extra storage and a bit more work on every write.

Reproducing it

I couldn't reproduce it locally. I have a fairly fast machine, and the app on it had exactly one user: me. The gap was tiny, and the other request would have to land exactly inside it. Sometimes strong hardware is a disadvantage :D.

So I decided to make the gap bigger instead. EF Core command interceptors run around every command EF sends, so one of them can wait right after the pick list INSERT, while the transaction is still open:

public sealed class DelayAfterCommandInterceptor(string commandTextFragment, TimeSpan delay)
    : DbCommandInterceptor
{
    public override async ValueTask<DbDataReader> ReaderExecutedAsync(
        DbCommand command, CommandExecutedEventData eventData, DbDataReader result,
        CancellationToken cancellationToken = default)
    {
        if (command.CommandText.Contains(commandTextFragment, StringComparison.Ordinal))
            await Task.Delay(delay, cancellationToken);
        return result;
    }
}

This is a shortened version of the one in the repository, which also logs every command it sees. It only overrides the async method. If your code calls SaveChanges(), override ReaderExecuted the same way.

I registered it in debug builds only, for the insert I suspected:

#if DEBUG
optionsBuilder.AddInterceptors(
    new DelayAfterCommandInterceptor("INSERT INTO [PickLists]", TimeSpan.FromSeconds(2)));
#endif

That turns the tiny gap into a two-second one, and then it reproduces every time. This is the data in the repro when the race starts:

Order B gets pick list 3 while order A ships:

[ 0.04s] create ran: INSERT INTO [PickLists] ([Status])
[ 0.04s] create pausing 2.0s, transaction still open
[ 0.05s] ship   shipping order A, ReadUncommitted transaction, closing pick lists that served only A (All())
[ 0.19s] ship   found pick list(s) 1, 3
[ 2.05s] create ran: INSERT INTO [PickListOrders] ([OrderId], [PickListId])
[ 2.05s] create committed
[ 2.06s] check  order B's pick list 3 is Closed   <-- CLOSED BY SHIPPING ORDER A

Pick list 2 stays open, as it should. Pick list 3, caught between its two inserts, gets closed.

Fix

With a repro that fails every time, I could test the fixes instead of guessing. Measured on SQL Server 2022 with EF Core 10:

Query	Isolation	RCSI	Result
All()	Read uncommitted	off	❌ closes B's pick list
Any() && All()	Read uncommitted	off	✅ correct (the quick fix)
All()	Read committed	off	✅ correct, but waits 2.0 s
All()	Read committed	on	✅ correct, no waiting
All()	Read uncommitted	on	❌ closes B's pick list

 var pickLists = db.PickLists
-    .Where(p => p.Status == "Open" && p.Orders.All(o => o.OrderId == orderId))
+    .Where(p => p.Status == "Open" && p.Orders.Any() && p.Orders.All(o => o.OrderId == orderId))
     .ToList();

The second row is what we shipped: an empty collection can't match any more. It was small and safe, but the dirty read is still there and still sees half-saved data.

Without the dirty read, the bug is gone. Plain READ COMMITTED waits for the other transaction to commit, two seconds here; with RCSI turned on it doesn't wait at all. RCSI alone doesn't help, though: an explicit READ UNCOMMITTED, or a NOLOCK hint, overrides it.

Changing the isolation level in that base class changes every transaction in the application, so it's a separate change with a possibly huge impact on the legacy parts. Code that has read without waiting for years would suddenly wait on writers, or with RCSI read different data than before, and it's hard to tell which parts depend on the old behavior.

EF turns RCSI on

While building the repro, my "RCSI off" scenarios didn't block when they should have. It turned out that when EF Core creates a database with EnsureCreated() or migrations, it also runs ALTER DATABASE ... SET READ_COMMITTED_SNAPSHOT ON (except on Azure SQL Database, where it's on by default anyway). On SQL Server, a database created with a plain CREATE DATABASE has it off.

⚠️ Watch out: a local database created by EF can behave differently from production in anything that involves locks. If you're chasing a locking bug, check both sides first:

SELECT name, is_read_committed_snapshot_on FROM sys.databases;

Try it

pbednarcik / blog-examples

Companion code for blog posts: small examples and runnable repros.

It needs the .NET 10 SDK and a SQL Server where you can create a database. By default, it connects to the local default instance with Windows authentication; set REPRO_CONNECTION to a connection string to use another server. Every scenario drops and recreates a database called DirtyReadRepro.

git clone https://github.com/pbednarcik/blog-examples.git
cd blog-examples/ef-dirty-read-race
dotnet run

That runs all five scenarios and prints a summary of the results behind the Fix table. To run just one, for example, the bug itself:

dotnet run -- all ru rcsi-off

Have you hit a bug that only showed up after moving to the cloud? What was it, and how did you find it?

Thanks for reading.

I used AI to help edit this article.