Count reclaimed connections and align reclaim traces

Rebasing onto the pool instrumentation work makes two things available that
the reclaim path was missing.

The metrics seam now exists, so the sweep emits ReclaimedConnectionRequest
the way WaitHandleDbConnectionPool does. Previously the
number-of-reclaimed-connections counter always read zero under pool V2,
which made a leaking application look healthy on exactly the counter that
would have identified it.

The trace call sites also predate the new pool trace message format, so
they still used the legacy prov-prefixed form. Converted the sweep,
reclaimer and shutdown messages to match their neighbours.

Adds a parity test asserting both pool implementations report identical
counters when a leaked connection is reclaimed. It drives the sweep the
same way for both, by capping the pool at one connection, leaking it and
requesting another, so it asserts observable behaviour rather than an
internal entry point. The counters agree exactly, including a shared quirk
now pinned by the test: reclamation emits no soft disconnect, so
activeSoftConnections drifts up by one for every leaked connection.

Also makes the parked-caller test deterministic. It relied on the leaked
owner surviving until the second caller parked, but any test running in
parallel could collect it first, in which case the caller's inline sweep
succeeded and it never parked. The owner is now rooted in a GCHandle that
the test frees at the exact point it wants emancipation to become
observable. A local cannot express that: in a Debug build its stack slot
roots the object for the rest of the method even once it is assigned null.
That also removes the thread-pool headroom workaround added earlier, which
was aimed at a starvation theory the diagnostics disproved.

Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com>

Author: mdaigle

src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/ConnectionPool/ChannelDbConnectionPool.cs

@@ -788,7 +788,7 @@ public void Shutdown()
             catch (Exception ex)
             {
                 SqlClientEventSource.Log.TryPoolerTraceEvent(
-                    "<prov.DbConnectionPool.Shutdown|RES|CPOOL> {0}, Reclaimer.Dispose threw, continuing shutdown: {1}", Id, ex);
+                    "ChannelDbConnectionPool.Shutdown | INFO | {0}, Reclaimer.Dispose threw, continuing shutdown: {1}", Id, ex);
             }
 
             // Dispose the error state so its exit timer is released. Otherwise a timer scheduled
@@ -1574,7 +1574,7 @@ private async Task<DbConnectionInternal> GetInternalConnection(
         internal bool ReclaimEmancipatedConnections()
         {
             SqlClientEventSource.Log.TryPoolerTraceEvent(
-                "<prov.DbConnectionPool.ReclaimEmancipatedObjects|RES|CPOOL> {0}", Id);
+                "ChannelDbConnectionPool.ReclaimEmancipatedConnections | INFO | {0}, Sweeping for emancipated connections.", Id);
 
             List<DbConnectionInternal>? reclaimed = null;
 
@@ -1615,10 +1615,14 @@ internal bool ReclaimEmancipatedConnections()
             foreach (DbConnectionInternal connection in reclaimed)
             {
                 SqlClientEventSource.Log.TryPoolerTraceEvent(
-                    "<prov.DbConnectionPool.ReclaimEmancipatedObjects|RES|CPOOL> {0}, Connection {1}, Reclaiming.",
+                    "ChannelDbConnectionPool.ReclaimEmancipatedConnections | INFO | {0}, Connection {1}, Reclaiming.",
                     Id,
                     connection.ObjectID);
 
+                // Matches WaitHandleDbConnectionPool so the number-of-reclaimed-connections counter
+                // is meaningful under pool V2 as well; it previously always read zero here.
+                Metrics.ReclaimedConnectionRequest();
+
                 connection.DetachCurrentTransactionIfEnded();
                 DeactivateAndRouteConnection(connection);
             }

src/Microsoft.Data.SqlClient/src/Microsoft/Data/SqlClient/ConnectionPool/PoolReclaimer.cs

@@ -163,7 +163,7 @@ internal void EnterParkedWait()
                 _timer.Change(SweepInterval, Timeout.InfiniteTimeSpan);
 
                 SqlClientEventSource.Log.TryPoolerTraceEvent(
-                    "<prov.PoolReclaimer.EnterParkedWait|RES|INFO|CPOOL> {0}, sweep timer started", _pool.Id);
+                    "PoolReclaimer.EnterParkedWait | INFO | {0}, Sweep timer started.", _pool.Id);
             }
         }
 
@@ -189,7 +189,7 @@ internal void ExitParkedWait()
                 _timer.Change(Timeout.InfiniteTimeSpan, Timeout.InfiniteTimeSpan);
 
                 SqlClientEventSource.Log.TryPoolerTraceEvent(
-                    "<prov.PoolReclaimer.ExitParkedWait|RES|INFO|CPOOL> {0}, sweep timer stopped, no parked waiters", _pool.Id);
+                    "PoolReclaimer.ExitParkedWait | INFO | {0}, Sweep timer stopped, no parked waiters.", _pool.Id);
             }
         }
 
@@ -224,7 +224,7 @@ internal void OnSweepCallback()
                 // would tear down the process. A failed sweep is not fatal to the pool, so trace it
                 // and let the next sweep try again.
                 SqlClientEventSource.Log.TryPoolerTraceEvent(
-                    "<prov.PoolReclaimer.OnSweepCallback|RES|CPOOL> {0}, sweep threw, continuing: {1}", _pool.Id, ex);
+                    "PoolReclaimer.OnSweepCallback | ERR | {0}, Sweep threw, continuing: {1}.", _pool.Id, ex);
             }
 
             lock (_lock)

src/Microsoft.Data.SqlClient/tests/UnitTests/ConnectionPool/ChannelDbConnectionPoolReclaimTimerTest.cs

@@ -5,6 +5,7 @@
 using System;
 using System.Diagnostics;
 using System.Runtime.CompilerServices;
+using System.Runtime.InteropServices;
 using System.Threading;
 using System.Threading.Tasks;
 using Microsoft.Data.Common.ConnectionString;
@@ -79,6 +80,31 @@ private static DbConnectionInternal CheckOutAndAbandonOwner(ChannelDbConnectionP
             return connection!;
         }
 
+        /// <summary>
+        /// Checks out a connection and roots its owner in a <see cref="GCHandle"/> rather than a
+        /// local. The owner stays alive until the caller frees the returned handle, which gives the
+        /// test exact control over when the connection becomes emancipated. A local cannot do this:
+        /// in a Debug build its stack slot roots the object for the rest of the enclosing method
+        /// even after it is assigned null, so the collection would never happen. The checkout runs
+        /// in its own non-inlined frame so no slot in the caller's frame ever holds the owner.
+        /// </summary>
+        [MethodImpl(MethodImplOptions.NoInlining)]
+        private static DbConnectionInternal CheckOutAndRootOwner(ChannelDbConnectionPool pool, out GCHandle ownerRoot)
+        {
+            SqlConnection owner = new();
+            ownerRoot = GCHandle.Alloc(owner);
+
+            bool completed = pool.TryGetConnection(
+                owner,
+                taskCompletionSource: null,
+                TimeoutTimer.StartNew(TimeSpan.FromSeconds(15)),
+                out DbConnectionInternal? connection);
+
+            Assert.True(completed);
+            Assert.NotNull(connection);
+            return connection!;
+        }
+
         /// <summary>
         /// Forces collection of an abandoned owner so its connection becomes emancipated.
         /// </summary>
@@ -104,26 +130,6 @@ private static void WaitFor(Func<bool> condition, string because)
             }
         }
 
-        /// <summary>
-        /// Guarantees the thread pool can start a queued work item promptly.
-        /// <see cref="ChannelDbConnectionPool.TryGetConnection"/> dispatches its async path through
-        /// <see cref="Task.Run(Action)"/>, so a test that needs a caller to actually reach its parked
-        /// wait depends on a worker being available. Other tests in this assembly block pool threads
-        /// on sockets and sync-over-async waits, and the pool's own thread injection only adds
-        /// threads at roughly one per second, which is slow enough to time this test out.
-        /// The raise is deliberately monotonic and never restored: lowering it again would pull the
-        /// floor out from under tests running in parallel with this one.
-        /// </summary>
-        private static void EnsureThreadPoolHeadroom()
-        {
-            ThreadPool.GetMinThreads(out int workerThreads, out int completionPortThreads);
-            int desired = Environment.ProcessorCount * 4;
-            if (workerThreads < desired)
-            {
-                ThreadPool.SetMinThreads(desired, completionPortThreads);
-            }
-        }
-
         #endregion
 
         /// <summary>
@@ -284,14 +290,14 @@ public void Shutdown_DisposesReclaimer()
         [Fact]
         public async Task ParkedCaller_IsWokenBySweep_WhenConnectionIsEmancipatedAfterParking()
         {
-            EnsureThreadPoolHeadroom();
-
             var fakeTime = new FakeTimeProvider();
             var pool = ConstructPool(maxPoolSize: 1, timeProvider: fakeTime);
 
-            // Occupy the pool's only slot and abandon the owner. The connection is not yet
-            // collected, so it is not yet emancipated.
-            DbConnectionInternal leaked = CheckOutAndAbandonOwner(pool);
+            // Occupy the pool's only slot. The owner is deliberately kept rooted until after the
+            // second caller has parked: a collection triggered by a test running in parallel would
+            // otherwise emancipate it early, letting the second caller's inline sweep succeed so it
+            // never parks and the case under test never arises.
+            DbConnectionInternal leaked = CheckOutAndRootOwner(pool, out GCHandle leakedOwnerRoot);
             Assert.Equal(1, pool.Count);
 
             // A second caller finds the pool exhausted and parks. Its inline sweep runs before the
@@ -313,6 +319,7 @@ public async Task ParkedCaller_IsWokenBySweep_WhenConnectionIsEmancipatedAfterPa
 
             // Only now does the abandoned owner become collectable, which is precisely the case the
             // caller's own inline sweep cannot cover.
+            leakedOwnerRoot.Free();
             CollectAbandonedOwners();
             Assert.True(leaked.IsEmancipated);
 

src/Microsoft.Data.SqlClient/tests/UnitTests/ConnectionPool/DbConnectionPoolInstrumentationTest.cs

@@ -6,6 +6,7 @@
 using System.Collections.Generic;
 using System.Data.Common;
 using System.Linq;
+using System.Runtime.CompilerServices;
 using System.Threading;
 using System.Transactions;
 using Microsoft.Data.Common;
@@ -413,6 +414,85 @@ public void TransactionRollback_ReleasingParkedConnection_KeepsActiveConnectionC
                 activeConnections: 0);
         }
 
+        /// <summary>
+        /// Verifies that a connection whose owner was collected without being closed is reclaimed
+        /// and counted, in both pool implementations.
+        /// </summary>
+        /// <remarks>
+        /// The sweep is triggered the same way for both pools rather than by calling their internal
+        /// reclaim methods: the pool is capped at a single connection, that connection is leaked,
+        /// and a second caller then requests one. Each implementation reaches its own reclaim path
+        /// from that saturated request, so the test asserts observable behavior rather than a
+        /// specific internal entry point.
+        /// </remarks>
+        [Theory]
+        [InlineData(PoolImplementation.WaitHandle)]
+        [InlineData(PoolImplementation.Channel)]
+        public void EmancipatedConnection_IsReclaimedAndCounted(PoolImplementation implementation)
+        {
+            // Arrange
+            FakeSqlClientMetrics metrics = new();
+            IDbConnectionPool pool = ConstructPool(
+                implementation,
+                metrics,
+                new SuccessfulSqlConnectionFactory(metrics),
+                maxPoolSize: 1);
+
+            DbConnectionInternal leaked = CheckOutAndAbandonOwner(pool);
+            AssertCounters(
+                metrics,
+                hardConnects: 1,
+                softConnects: 1,
+                pooledConnections: 1,
+                activeConnections: 1);
+
+            // The owner is only collectable now that the helper's frame has been popped.
+            GC.Collect();
+            GC.WaitForPendingFinalizers();
+            GC.Collect();
+            Assert.True(leaked.IsEmancipated);
+
+            // Act - the pool's only slot is occupied by a connection nobody can return, so this
+            // request can only be served by reclaiming it.
+            Assert.True(pool.TryGetConnection(
+                new SqlConnection(),
+                null,
+                TimeoutTimer.StartNew(TimeSpan.FromSeconds(15)),
+                out DbConnectionInternal? reclaimed));
+
+            // Assert - the same physical connection was handed out again, with no second connect.
+            // softDisconnects stays at zero: reclamation never balances the leaked checkout, so
+            // activeSoftConnections drifts up by one per leaked connection. That is long-standing
+            // WaitHandle behavior, asserted here to pin the two implementations to the same numbers.
+            Assert.Same(leaked, reclaimed);
+            AssertCounters(
+                metrics,
+                hardConnects: 1,
+                softConnects: 2,
+                softDisconnects: 0,
+                pooledConnections: 1,
+                reclaimedConnections: 1,
+                activeConnections: 1);
+        }
+
+        /// <summary>
+        /// Checks out a connection and drops the only reference to its owner. Kept in its own
+        /// non-inlined method so the owner becomes collectable as soon as this frame is popped; a
+        /// local in the calling test would stay rooted until the end of that method in a debug build.
+        /// </summary>
+        [MethodImpl(MethodImplOptions.NoInlining)]
+        private static DbConnectionInternal CheckOutAndAbandonOwner(IDbConnectionPool pool)
+        {
+            SqlConnection owner = new();
+            Assert.True(pool.TryGetConnection(
+                owner,
+                null,
+                TimeoutTimer.StartNew(TimeSpan.FromSeconds(15)),
+                out DbConnectionInternal? connection));
+            Assert.NotNull(connection);
+            return connection!;
+        }
+
         #region Test classes
 
         /// <summary>