Skip to content

[7.1] 7.1.0 regression: in-flight OpenAsync fails instantly with pool "Timeout expired" when ClearAllPools()/ClearPool() runs #4737

Description

@mdaigle

Describe the bug

In 7.1.0, with the default pool (WaitHandleDbConnectionPool, no AppContext switches set), an OpenAsync that is in flight when its pool is shut down faults immediately with:

System.InvalidOperationException: Timeout expired.  The timeout period elapsed prior to obtaining a connection from the pool.  This may have occurred because all pooled connections were in use and max pool size was reached.
   at Microsoft.Data.Common.ADP.ExceptionWithStackTrace(Exception e)

The open has waited ~0 ms (Connect Timeout = 30 s) and no pool is anywhere near Max Pool Size. On 7.0.2 and 7.0.3 the same open completes successfully.

Any SqlConnection.ClearAllPools() anywhere in the process triggers it, because ClearAllPools → DbConnectionPoolGroup.Clear → SqlConnectionFactory.QueuePoolForRelease → pool.Shutdown() runs for every pool. EF Core's EnsureDeleted() calls ClearAllPools(), so any test suite that creates a database per test hits it constantly. DbConnectionPoolGroup.Prune() takes the same QueuePoolForRelease → Shutdown() path for a drained idle pool, so (by code reading — not reproduced) production apps are exposed on the first open after an idle period.

Cause

#4302 ("…harden WaitHandleDbConnectionPool shutdown") added this to the private TryGetConnection, straight after WaitHandle.WaitAny:

if (State is not Running)
{
    ...
    Interlocked.Decrement(ref _waitCount);
    connection = null;
    return false;
}

WaitForPendingOpen interprets false as a timeout:

timeout = !TryGetConnection(next.Owner, delay, allowCreate: true, onlyOneCheckConnection: false, next.Timeout, out connection);
...
else if (timeout)
{
    next.Completion.TrySetException(ADP.ExceptionWithStackTrace(ADP.PooledOpenTimeout()));
}

The sync path survives the same race: SqlConnectionFactory.TryGetConnection sees connection is null with !connectionPool.IsRunning, sleeps and retries against the replacement pool ("We've hit the race condition, where the pool was shut down after we got it from the group"). The async pending-open path has no equivalent, so "pool shut down" surfaces as a pool timeout. Before #4302 there was no State check after WaitAny, and the in-flight request simply completed.

#4302's description says "Existing pooling behavior is unchanged until Shutdown() is invoked" — but Shutdown() is invoked by every ClearPool/ClearAllPools and by pruning.

To reproduce

16 tasks loop OpenAsync/dispose, each on its own pool, while one task calls ClearAllPools() every 5 ms. REPRO_CS = any SQL Server connection string.

using System.Collections.Concurrent;
using System.Diagnostics;
using Microsoft.Data.SqlClient;

// Repro: an async Open that is in flight on a pool when ANY SqlConnection.ClearAllPools() runs.
// Each "worker" opens and closes a connection on its own pool; a "clearer" calls ClearAllPools(), exactly like
// EF Core's EnsureDeleted(). No pool is ever near Max Pool Size.
var baseCs = Environment.GetEnvironmentVariable("REPRO_CS") ?? throw new InvalidOperationException("set REPRO_CS");
int seconds = int.Parse(args.Length > 0 ? args[0] : "20");
int workers = int.Parse(args.Length > 1 ? args[1] : "16");
bool clear = !(args.Length > 2 && args[2] == "noclear");

var asm = typeof(SqlConnection).Assembly;
Console.WriteLine($"Microsoft.Data.SqlClient {FileVersionInfo.GetVersionInfo(asm.Location).ProductVersion?.Split('+')[0]}  ({workers} workers, {seconds}s, ClearAllPools={(clear ? "on" : "OFF")})");

using var cts = new CancellationTokenSource(TimeSpan.FromSeconds(seconds));
long opens = 0, clears = 0;
var errors = new ConcurrentDictionary<string, int>();
var elapsedOfFailures = new ConcurrentBag<long>();

var workerTasks = Enumerable.Range(0, workers).Select(i => Task.Run(async () =>
{
    // One pool per worker, reused: nothing leaks, so a run with clearing OFF is a fair control.
    var cs = new SqlConnectionStringBuilder(baseCs) { ApplicationName = "repro-worker-" + i }.ConnectionString;
    while (!cts.IsCancellationRequested)
    {
        var sw = Stopwatch.StartNew();
        try
        {
            await using var c = new SqlConnection(cs);
            await c.OpenAsync();
            Interlocked.Increment(ref opens);
        }
        catch (Exception e)
        {
            elapsedOfFailures.Add(sw.ElapsedMilliseconds);
            var top = e.StackTrace?.Split('\n').FirstOrDefault()?.Trim() ?? "";
            errors.AddOrUpdate($"{e.GetType().Name}: {e.Message.Split('.')[0]} | top frame: {top}", 1, (_, n) => n + 1);
        }
    }
})).ToArray();

var clearer = Task.Run(async () =>
{
    while (clear && !cts.IsCancellationRequested)
    {
        SqlConnection.ClearAllPools();
        Interlocked.Increment(ref clears);
        await Task.Delay(5);
    }
});

await Task.WhenAll(workerTasks.Append(clearer));
Console.WriteLine($"opens ok={opens}  ClearAllPools calls={clears}  FAILED opens={errors.Values.Sum()}");
foreach (var kv in errors.OrderByDescending(k => k.Value)) Console.WriteLine($"  x{kv.Value}  {kv.Key}");
if (!elapsedOfFailures.IsEmpty)
{
    var ms = elapsedOfFailures.OrderBy(x => x).ToArray();
    Console.WriteLine($"  failed-open latency ms: min={ms[0]} median={ms[ms.Length / 2]} max={ms[^1]}   (Connect Timeout is 30000)");
}

Results (SQL Server 2022 in Docker, .NET 10, Windows 11, 10–15 s runs):

Version ClearAllPools Successful opens Failed opens Failure latency
7.0.2 on 8,404 0 —
7.0.3 on 397,362 0 —
7.1.0 on 7,051 / 666,333 / 810,677 187 / 1,154 / 1,684 min 0, median 0, max 44 ms
7.0.2 off 53,412,474 0 —
7.1.0 off 46,728,760 0 —

(Throughput varies a lot run to run; the failure count is the signal. Long runs with clearing on can also hit genuine network connect timeouts from port exhaustion — those are SqlException after ~29 s and are unrelated.)

Expected behavior

As in 7.0.x: an open in flight on a pool that gets shut down should complete, or be retried transparently against the replacement pool as the sync path does. If it must fail, not as PooledOpenTimeout — the message sends people hunting for a connection leak that does not exist.

Further technical details

Microsoft.Data.SqlClient: 7.1.0 (regression from 7.0.3)
.NET target: net10.0
SQL Server: 2022 (Linux container)
OS: Windows 11; also seen on ubuntu GitHub runners

Real-world impact

An xUnit project using EF Core with a database per test (965 tests): 0 failures in the previous 40 CI runs on 7.0.2; on 7.1.0, 4 of 5 runs fail with 1–4 tests each, a different test every time. Identical binaries apart from SqlClient: 7.0.2 0/5 failed runs, 7.1.0 4/5.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

Regression 💥Issues that are regressions introduced from earlier PRs.

Type

Projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions