Lesson Learned #454:Optimizing Connection Pooling for Application Workloads: Active Connections
This article is contributed. See the original author and article here.
A few days ago, a customer asked us to find out details about the active connections of a connection pooling, how many connection poolings their application has, etc. In this article, I would like to share the lessons learned to see these details.
As our customer is using .NET Core, we will rely on the following article to gather all this information Event counters in SqlClient – ADO.NET Provider for SQL Server | Microsoft Learn
We will continue with the same script that we are using in the previous article Lesson Learned #453:Optimizing Connection Pooling for Application Workloads: A single journey – Microsoft Community Hub, and once the link is implemented Event counters in SqlClient – ADO.NET Provider for SQL Server | Microsoft Learn, we will see what information we obtain.
Once we executed our application we started seeing the following information:
2023-11-26 09:38:18.998: Actual active connections currently made to servers 0
2023-11-26 09:38:19.143: Active connections retrieved from the connection pool 0
2023-11-26 09:38:19.167: Number of connections not using connection pooling 0
2023-11-26 09:38:19.176: Number of connections managed by the connection pool 0
2023-11-26 09:38:19.181: Number of active unique connection strings 1
2023-11-26 09:38:19.234: Number of unique connection strings waiting for pruning 0
2023-11-26 09:38:19.236: Number of active connection pools 1
2023-11-26 09:38:19.239: Number of inactive connection pools 0
2023-11-26 09:38:19.242: Number of active connections 0
2023-11-26 09:38:19.245: Number of ready connections in the connection pool 0
2023-11-26 09:38:19.272: Number of connections currently waiting to be ready 0
As our application is using a single connection string and using a single connection pooler, the details that appear below are stable and understandable. But let’s make a couple of changes to the code to see how the numbers change.
Our first change will be to open 100 connections and once we reach those 100, we will close and reopen them to see how the counters fluctuat. The details we observe while our application is running indicate that connections are being opened but not closed. Which is expected.
2023-11-26 09:49:01.606: Actual active connections currently made to servers 13
2023-11-26 09:49:01.606: Active connections retrieved from the connection pool 13
2023-11-26 09:49:01.607: Number of connections not using connection pooling 0
2023-11-26 09:49:01.607: Number of connections managed by the connection pool 13
2023-11-26 09:49:01.608: Number of active unique connection strings 1
2023-11-26 09:49:01.608: Number of unique connection strings waiting for pruning 0
2023-11-26 09:49:01.609: Number of active connection pools 1
2023-11-26 09:49:01.609: Number of inactive connection pools 0
2023-11-26 09:49:01.610: Number of active connections 13
2023-11-26 09:49:01.610: Number of ready connections in the connection pool 0
2023-11-26 09:49:01.611: Number of connections currently waiting to be ready 0
But as we keep closing and opening new ones, we start to see how our connection pooling is functioning
2023-11-26 09:50:08.600: Actual active connections currently made to servers 58
2023-11-26 09:50:08.601: Active connections retrieved from the connection pool 50
2023-11-26 09:50:08.601: Number of connections not using connection pooling 0
2023-11-26 09:50:08.602: Number of connections managed by the connection pool 58
2023-11-26 09:50:08.602: Number of active unique connection strings 1
2023-11-26 09:50:08.603: Number of unique connection strings waiting for pruning 0
2023-11-26 09:50:08.603: Number of active connection pools 1
2023-11-26 09:50:08.604: Number of inactive connection pools 0
2023-11-26 09:50:08.604: Number of active connections 50
2023-11-26 09:50:08.605: Number of ready connections in the connection pool 8
2023-11-26 09:50:08.605: Number of connections currently waiting to be ready 0
In the following example, we can see how once we have reached our 100 connections, the connection pooler is serving our application the necessary connection.
2023-11-26 09:53:27.602: Actual active connections currently made to servers 100
2023-11-26 09:53:27.602: Active connections retrieved from the connection pool 92
2023-11-26 09:53:27.603: Number of connections not using connection pooling 0
2023-11-26 09:53:27.603: Number of connections managed by the connection pool 100
2023-11-26 09:53:27.604: Number of active unique connection strings 1
2023-11-26 09:53:27.604: Number of unique connection strings waiting for pruning 0
2023-11-26 09:53:27.605: Number of active connection pools 1
2023-11-26 09:53:27.606: Number of inactive connection pools 0
2023-11-26 09:53:27.606: Number of active connections 92
2023-11-26 09:53:27.606: Number of ready connections in the connection pool 8
2023-11-26 09:53:27.607: Number of connections currently waiting to be ready 0
Let’s review the counters:
Actual active connections currently made to servers (100): This indicates the total number of active connections that have been established with the servers at the given timestamp. In this case, there are 100 active connections.
Active connections retrieved from the connection pool (92): This shows the number of connections that have been taken from the connection pool and are currently in use. Here, 92 out of the 100 active connections are being used from the pool.
Number of connections not using connection pooling (0): This counter shows how many connections are made directly, bypassing the connection pool. A value of 0 means all connections are utilizing the connection pooling mechanism.
Number of connections managed by the connection pool (100): This is the total number of connections, both active and idle, that are managed by the connection pool. In this example, there are 100 connections in the pool.
Number of active unique connection strings (1): This indicates the number of unique connection strings that are currently active. A value of 1 suggests that all connections are using the same connection string.
Number of unique connection strings waiting for pruning (0): This shows how many unique connection strings are inactive and are candidates for removal or pruning from the pool. A value of 0 indicates no pruning is needed.
Number of active connection pools (1): Represents the total number of active connection pools. In this case, there is just one connection pool being used.
Number of inactive connection pools (0): This counter displays the number of connection pools that are not currently in use. A value of 0 indicates that all connection pools are active.
Number of active connections (92): Similar to the second counter, this shows the number of connections currently in use from the pool, which is 92.
Number of ready connections in the connection pool (8): This indicates the number of connections that are in the pool, available, and ready to be used. Here, there are 8 connections ready for use.
Number of connections currently waiting to be ready (0): This shows the number of connections that are in the process of being prepared for use. A value of 0 suggests that there are no connections waiting to be made ready.
These counters provide a comprehensive view of how the connection pooling is performing, indicating the efficiency, usage patterns, and current state of the connections managed by the Microsoft.Data.SqlClient.
One thing, that pay my attention is Number of unique connection strings waiting for pruning This means that if there have been no recent accesses to the connection pooler, we might find that if there have been no connections for a certain period, the connection pooler will be eliminated, and the first connection that is made will take some time (seconds) to be recreated, for example, in the night when we might not have active workload:
Idle Connection Removal: Connections are removed from the pool after being idle for approximately 4-8 minutes, or if a severed connection with the server is detected.
Minimum Pool Size: If the
Min Pool Sizeis not specified or set to zero in the connection string, the connections in the pool will be closed after a period of inactivity. However, ifMin Pool Sizeis greater than zero, the connection pool is not destroyed until theAppDomainis unloaded and the process ends. This implies that as long as the minimum pool size is maintained, the pool itself remains active.
We could observe in Microsoft.Data.SqlClient in the file SqlClient-mainSqlClient-mainsrcMicrosoft.Data.SqlClientsrcMicrosoftDataProviderBaseDbConnectionPoolGroup.cs useful information about it:
Line 50: private const int PoolGroupStateDisabled = 4; // factory pool entry pruning method
Line 268: // Empty pool during pruning indicates zero or low activity, but
Line 293: // must be pruning thread to change state and no connections
Line 294: // otherwise pruning thread risks making entry disabled soon after user calls ClearPool
These parameters work together to manage the lifecycle of connection pools and their resources efficiently, balancing the need for ready connections with system resource optimization. The actual removal of an entire connection pool (and its associated resources) depends on these settings and the application’s runtime behavior. The documentation does not specify a fixed interval for the complete removal of an entire connection pool, as it is contingent on these dynamic factors.
To conclude this article, I would like to conduct a test to see if each time I request a connection and change something in the connection string, it creates a new connection pooling.
For this, I have modified the code so that half of the connections receive a clearpool. As we could see new inactive connection pools shows.
2023-11-26 10:34:18.564: Actual active connections currently made to servers 16
2023-11-26 10:34:18.565: Active connections retrieved from the connection pool 11
2023-11-26 10:34:18.566: Number of connections not using connection pooling 0
2023-11-26 10:34:18.566: Number of connections managed by the connection pool 16
2023-11-26 10:34:18.567: Number of active unique connection strings 99
2023-11-26 10:34:18.567: Number of unique connection strings waiting for pruning 0
2023-11-26 10:34:18.568: Number of active connection pools 55
2023-11-26 10:34:18.568: Number of inactive connection pools 150
2023-11-26 10:34:18.569: Number of active connections 11
2023-11-26 10:34:18.569: Number of ready connections in the connection pool 5
2023-11-26 10:34:18.570: Number of connections currently waiting to be ready 0
Source code
using System;
using Microsoft.Data.SqlClient;
using System.Threading;
using System.IO;
using System.Diagnostics;
namespace HealthCheck
{
class ClsCheck
{
const string LogFolder = "c:tempMydata";
const string LogFilePath = LogFolder + "logCheck.log";
public void Main(Boolean bSingle=true, Boolean bDifferentConnectionString=false)
{
int lMaxConn = 100;
int lMinConn = 0;
if(bSingle)
{
lMaxConn = 1;
lMinConn = 1;
}
string connectionString = "Server=tcp:servername.database.windows.net,1433;User Id=username@microsoft.com;Password=Pwd!;Initial Catalog=test;Persist Security Info=False;MultipleActiveResultSets=False;Encrypt=True;TrustServerCertificate=False;Connection Timeout=5;Pooling=true;Max Pool size=" + lMaxConn.ToString() + ";Min Pool Size=" + lMinConn.ToString() + ";ConnectRetryCount=3;ConnectRetryInterval=10;Authentication=Active Directory Password;PoolBlockingPeriod=NeverBlock;Connection Lifetime=5;Application Name=ConnTest";
Stopwatch stopWatch = new Stopwatch();
SqlConnection[] oConnection = new SqlConnection[lMaxConn];
int lActivePool = -1;
string sConnectionStringDummy = connectionString;
DeleteDirectoryIfExists(LogFolder);
ClsEvents.EventCounterListener oClsEvents = new ClsEvents.EventCounterListener();
//ClsEvents.SqlClientListener olistener = new ClsEvents.SqlClientListener();
while (true)
{
if (bSingle)
{
lActivePool = 0;
sConnectionStringDummy = connectionString;
}
else
{
lActivePool++;
if (lActivePool == (lMaxConn-1))
{
lActivePool = 0;
for (int i = 0; i = 5)
{
Log($"Maximum number of retries reached. Error: " + ex.Message);
break;
}
Log($"Error connecting to the database. Retrying in " + retries + " seconds...");
Thread.Sleep(retries * 1000);
}
}
return connection;
}
static void Log(string message)
{
var ahora = DateTime.Now;
string logMessage = $"{ahora.ToString("yyyy-MM-dd HH:mm:ss.fff")}: {message}";
//Console.WriteLine(logMessage);
try
{
using (FileStream stream = new FileStream(LogFilePath, FileMode.Append, FileAccess.Write, FileShare.ReadWrite))
{
using (StreamWriter writer = new StreamWriter(stream))
{
writer.WriteLine(logMessage);
}
}
}
catch (IOException ex)
{
Console.WriteLine($"Error writing in the log file: {ex.Message}");
}
}
static void ExecuteQuery(SqlConnection connection)
{
int retries = 0;
while (true)
{
try
{
using (SqlCommand command = new SqlCommand("SELECT 1", connection))
{
command.CommandTimeout = 5;
object result = command.ExecuteScalar();
}
break;
}
catch (Exception ex)
{
retries++;
if (retries >= 5)
{
Log($"Maximum number of retries reached. Error: " + ex.Message);
break;
}
Log($"Error executing the query. Retrying in " + retries + " seconds...");
Thread.Sleep(retries * 1000);
}
}
}
static void LogExecutionTime(Stopwatch stopWatch, string action)
{
stopWatch.Stop();
TimeSpan ts = stopWatch.Elapsed;
string elapsedTime = String.Format("{0:00}:{1:00}:{2:00}.{3:00}",
ts.Hours, ts.Minutes, ts.Seconds,
ts.Milliseconds / 10);
Log($"{action} - {elapsedTime}");
stopWatch.Reset();
}
public static void DeleteDirectoryIfExists(string path)
{
try
{
if (Directory.Exists(path))
{
Directory.Delete(path, true);
}
Directory.CreateDirectory(path);
}
catch (Exception ex)
{
Console.WriteLine($"Error deleting the folder: {ex.Message}");
}
}
}
}
Enjoy!
Recent Comments