number-of-active-connections metric goes negative, "activated multiple times?" debug assertions failing

[borland]

Describe the bug

Since upgrading from SqlClient v6.0.2 to v6.1.1, we noticed in our metrics that the number-of-active-connections started to report negative values, sometimes quite large -- e.g. -357

Rolling back to v6.0.2 removed the issue.

I am not aware of anyone noticing any other problems with the 6.1.1 upgrade at this stage.

To reproduce

I am not sure what exactly in our codebase is triggering the buggy code path; Our application is quite large and complex, it opens many SQL connections rapidly.

However, I checked out SqlClient locally, built it as part of our application's solution, and used git bisect to narrow down the commit which introduces the problem.

0322d44c7cfec424cbe33c9f48430f6ad79a8a50 is the first bad commit
commit 0322d44c7cfec424cbe33c9f48430f6ad79a8a50
Author: Malcolm Daigle <mdaigle@microsoft.com>
Date:   Wed Jan 15 10:38:24 2025 -0800

When testing this, I found the debug assertion in DeactivateConnection would fire shortly after launching the application.

Expected behavior

Metrics should not go negative, debug assertions should not fire.

Further technical details

Microsoft.Data.SqlClient version: (found on the nuget or Microsoft.Data.SqlClient.dll)
.NET target: (e.g. .NET Framework 4.7.2, .NET 6.0)
SQL Server version: (e.g. SQL Server 2022)
Operating system: (e.g. Windows Server 2022, Ubuntu 24.04, macOS 14.7.1, Docker container)

Additional context

Our hosting platform runs Linux, and my local machine is a Mac with an M4 Max. I use JetBrains Rider to build and debug with .NET 8.0.413

[borland]

Additional Info: In the process of writing this up, I noticed the PR Fix Debug Assertion in Connection Pool Due to Double Deactivation which appears not to be available in a public release yet.

I checked out the code from the main branch, and indeed the debug assertion no longer fires. However, the metrics are still broken.

As part of earlier testing, I slightly modified SqlClientMetrics.ExitActiveConnection to add a debug assertion, as follows:

internal void ExitActiveConnection()
{
    DecrementPlatformSpecificCounter(ref _activeConnections);
    Debug.Assert(Thread.VolatileRead(ref _activeConnections) >= 0, "active connections must never be negative");
}

I find that this assertion still fires, _activeConnections goes to -1 and presumably would go further negative if I let it run longer

[cheenamalhotra]

@mdaigle tagging you since this is familiar space for you.. could you please take a look?

[mdaigle]

Hi @borland, thank you for the report. I think I can see the issue. The commit you referenced adds an additional deactivation on this line: 0322d44#diff-9d38a50f1645237c63d8786c5f4b3251b91a2ecae192b899992e8cebc511d219R1808-R1811. However, at the point that that method is called, the connection has already been deactivated. This means that deactivations are getting double counted, resulting in negative active counts as transacted connections are recycled through the pool. I'll look into a fix for this that we can get backported to 6.1.

[borland]

@mdaigle that's great, thank you. If there's an interim git commit or build that I can run to test+validate, I'd be happy to

[borland]

Note for other observers: I noticed 6.1.2 had been released, so I re-tested, and the bug is still present