EF core logs OperationCanceledException if CancellationToken is cancelled before query starts

[ravindUwU]

Bug description

When an already-cancelled CancellationToken is specified in a query, EF core seems to log the OperationCanceledException that is thrown when EF tries to open the connection.

It's caught with catch (Exception e), logged as "Opening connection to database '...' on server '...'", and rethrown,

efcore/src/EFCore.Relational/Storage/RelationalConnection.cs

Lines 748 to 786 in a1541cb

	private async Task OpenInternalAsync(bool errorsExpected, CancellationToken cancellationToken)
	{
	var logger = Dependencies.ConnectionLogger;
	var startTime = DateTimeOffset.UtcNow;
	var stopwatch = SharedStopwatch.StartNew();
	try
	{
	if (logger.ShouldLogConnectionOpen(startTime))
	{
	var interceptionResult
	= await logger.ConnectionOpeningAsync(this, startTime, cancellationToken).ConfigureAwait(false);
	if (!interceptionResult.IsSuppressed)
	{
	await OpenDbConnectionAsync(errorsExpected, cancellationToken).ConfigureAwait(false);
	}
	await logger.ConnectionOpenedAsync(this, startTime, stopwatch.Elapsed, cancellationToken)
	.ConfigureAwait(false);
	}
	else
	{
	await OpenDbConnectionAsync(errorsExpected, cancellationToken).ConfigureAwait(false);
	}
	}
	catch (Exception e)
	{
	await logger.ConnectionErrorAsync(
	this,
	e,
	startTime,
	stopwatch.Elapsed,
	errorsExpected,
	cancellationToken)
	.ConfigureAwait(false);
	throw;
	}

I think cancellations should be rethrown without being logged 🤔.

Your code

static async Task Main()
{
	var sp = new ServiceCollection()
		.AddDbContext<Db>()
		.AddLogging((options) => options
			.SetMinimumLevel(LogLevel.Debug)
			.AddSimpleConsole()
			.AddFilter("Microsoft.EntityFrameworkCore.Query", LogLevel.None)
			.AddFilter("Microsoft.EntityFrameworkCore.Infrastructure", LogLevel.None)
		)
		.BuildServiceProvider();

	using var scope = sp.CreateScope();
	var db = scope.ServiceProvider.GetRequiredService<Db>();

	var s = new CancellationTokenSource();
	s.Cancel();

	try
	{
		Console.WriteLine("query");
		await db.Entities.FromSqlRaw("SELECT 1 AS id").ToListAsync(s.Token);
	}
	catch (OperationCanceledException)
	{
		Console.WriteLine("cancelled; ignored");
	}
}

[Table("entity")]
class Entity
{
	[Column("id")]
	public required int Id { get; set; }
}

partial class Db(DbContextOptions<Db> options) : DbContext(options)
{
	public required DbSet<Entity> Entities { get; init; }
}

Output below. The highlighted lines are caused by the OperationCanceledException being logged by EF.

 query
 dbug: Microsoft.EntityFrameworkCore.Database.Connection[20005]
       Creating DbConnection.
 dbug: Microsoft.EntityFrameworkCore.Database.Connection[20006]
       Created DbConnection. (10ms).
 dbug: Microsoft.EntityFrameworkCore.Database.Connection[20000]
       Opening connection to database 'main' on server 'owo.db'.
-fail: Microsoft.EntityFrameworkCore.Database.Connection[20004]
-      An error occurred using the connection to database 'main' on server 'owo.db'.
 cancelled; ignored
 dbug: Microsoft.EntityFrameworkCore.Database.Connection[20007]
       Disposing connection to database 'main' on server 'owo.db'.
 dbug: Microsoft.EntityFrameworkCore.Database.Connection[20008]
       Disposed connection to database 'main' on server 'owo.db' (0ms).

Stack traces

Verbose output

EF Core version

9.0.2

Database provider

No response

Target framework

.NET 9.0.200

Operating system

No response

IDE

No response

[gran0123]

We are seeing the same issue on a Postgres instance in prod, but I can't reproduce it locally with your example code.
In production we are logging canceled user requests and whenever this db error occurs, we have an info cancel log behind from our side.

Error message from the diagnostic logger: "An error occurred using the connection to database '"xxxx"' on server '"/xxxxxxx.s.PGSQL.5432"'.". Name: Microsoft.EntityFrameworkCore.Database.Connection.ConnectionError and Type: 20004

There is nothing inside NpgsqlConnection that is calling cancellationToken.ThrowIfCancellationRequested() which I can see.

---

EF Core version
Microsoft.EntityFrameworkCore 9.0.1

Database provider
Postgres 17.2 and Npgsql.EntityFrameworkCore.PostgreSQL 9.0.3

Target framework
.NET 8.0

Operating system
macOS ARM64 Sequoia 15.3.1

IDE
Rider 2024.3.5