Lesson Learned #170: Connection Pooling caches IP address

Today, I had a discussion with a colleague with a very interesting situation. All points to that the IP address is part of the cached data in the connection pooling slot. 

In order to test this situation, I developed this small PowerShell Script doing a simple connection and executing "SELECT 1" command around for 10000 times.  Using connection pooling the connection will be re-use every time without opening a new port everytime. 

So, during the execution of PowerShell script, we are going to use the host file to modify the resolution of the IP address  of our Azure SQL Server servername.database.windows.net based on North Europe. 

Results using connection pooling:

• Using a fake IP we obtain errors about the connection, removing this fake IP the execution becomes successulf but if I changed the resolution of the IP again to this fake address new connections using the same connection pooling slot is still working, so the IP address has not been updated. 
• However,  without using connection pooling and repeating the same procedure without using connection pooling I have the expected behavior, everytime that I changed the IP resolution to the fake IP I got an error. 

Lesson Learned: In case of failovers or IP changes if you are using connection pooling, all points that the connection pooling slot will be used the previous IP. In order to avoid this issue, I implemented the following workaround:

• In every connection check the DNS
• if the IP is changed execute a ClearPool of the SQLConnection in order to clean this cache, with an exception if that both IPs are from the same datacenter (round-robin access), because, there is not needed to execute the clean the pool.

Enjoy!

Code:

$DatabaseServer = "servername.database.windows.net"
$Database = "DatabaseName"
$Username = "UserName"
$Password = "Password" 
$Pooling = $true
$NumberExecutions =100000
$FolderV = "C:\MyFolder\"
[string]$LocalInitialIP = ""

#-------------------------------
Function DetectIP([Parameter(Mandatory=$true, Position=0)]
                  [string] $IP)
{ 
  
  $IP=$IP.Trim()
  if(($IP -eq "40.68.37.158") -or ($IP -eq "104.40.168.105") -or ($IP -eq "52.236.184.163")) {return "WE"}

  if(($IP -eq "40.113.93.91") -or ($IP -eq "52.138.224.1") -or ($IP -eq "13.74.104.113")) {return "NE"}

  return "UNknow"

  ##See URL: https://docs.microsoft.com/en-us/azure/azure-sql/database/connectivity-architecture
}



#-------------------------------
Function DeleteFile{ 
  Param( [Parameter(Mandatory)]$FileName ) 
  try
   {
    $FileExists = Test-Path $FileNAme
    if($FileExists -eq $True)
    {
     Remove-Item -Path $FileName -Force 
    }
    return $true 
   }
  catch
  {
   return $false
  }
 }

function GiveMeSeparator
{
Param([Parameter(Mandatory=$true)]
      [System.String]$Text,
      [Parameter(Mandatory=$true)]
      [System.String]$Separator)
  try
   {
    [hashtable]$return=@{}
    $Pos = $Text.IndexOf($Separator)
    $return.Text= $Text.substring(0, $Pos) 
    $return.Remaining = $Text.substring( $Pos+1 ) 
    return $Return
   }
  catch
  {
    $return.Text= $Text
    $return.Remaining = ""
    return $Return
  }
}

#--------------------------------------------------------------
#Create a folder 
#--------------------------------------------------------------
Function CreateFolder
{ 
  Param( [Parameter(Mandatory)]$Folder ) 
  try
   {
    $FileExists = Test-Path $Folder
    if($FileExists -eq $False)
    {
     $result = New-Item $Folder -type directory 
     if($result -eq $null)
     {
      logMsg("Imposible to create the folder " + $Folder) (2)
      return $false
     }
    }
    return $true
   }
  catch
  {
   return $false
  }
 }

#--------------------------------
#Validate Param
#--------------------------------

function TestEmpty($s)
{
if ([string]::IsNullOrWhitespace($s))
  {
    return $true;
  }
else
  {
    return $false;
  }
}

Function GiveMeConnectionSource([Parameter(Mandatory=$false)][String][ref]$InitialIP)
{ 
  for ($i=1; $i -lt 10; $i++)
  {
   try
    {
      logMsg( "Connecting to the database...Attempt #" + $i) (1)
      if( TestEmpty($InitialIP) -eq $true)
       {$InitialIP = CheckDns($DatabaseServer)}
      else
      {
       [string]$OtherIP = CheckDns($DatabaseServer)
       If( $OtherIP -ne $InitialIP )
       {
         $PreviousOneDC=DetectIP($InitialIP)
         $NewOneDC = DetectIP($OtherIP)

         If($PreviousOneDC -ne $NewOneDC)
         { 
           [System.Data.SqlClient.SqlConnection]::ClearAllPools()
           logMsg("IP changed noticed. Cleaning Pools...") (1)
         }
         else
         { 
           logMsg("IP changed noticed, same DC...") (1)
         }
          
       }   
      }

      $SQLConnection = New-Object System.Data.SqlClient.SqlConnection 
      $SQLConnection.ConnectionString = "Server="+$DatabaseServer+";Database="+$Database+";User ID="+$username+";Password="+$password+";Connection Timeout=15" 
      if( $Pooling -eq $true )
        {
          $SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Pooling=True"
        } 
      else
        {
          $SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Pooling=False"
        }

      $SQLConnection.Open()
      logMsg("Connected to the database...") (1)
      return $SQLConnection
      break;
    }
  catch
   {
    logMsg("Not able to connect - Retrying the connection..." + $Error[0].Exception) (2)
    Start-Sleep -s 5

   }
  }
}

#--------------------------------
#Check DNS
#--------------------------------
function CheckDns($sReviewServer)
{
try
 {
    $IpAddress = [System.Net.Dns]::GetHostAddresses($sReviewServer)
    foreach ($Address in $IpAddress)
    {
        $sAddress = $sAddress + $Address.IpAddressToString + " ";
    }
    logMsg("ServerName:" + $sReviewServer + " has the following IP:" + $sAddress) (1)
    return $sAddress
    break;
 }
  catch
 {
  logMsg("Imposible to resolve the name - Error: " + $Error[0].Exception) (2)
  return ""
 }
}

#--------------------------------
#Log the operations
#--------------------------------
function logMsg
{
    Param
    (
         [Parameter(Mandatory=$true, Position=0)]
         [string] $msg,
         [Parameter(Mandatory=$false, Position=1)]
         [int] $Color
    )
  try
   {
    $Fecha = Get-Date -format "yyyy-MM-dd HH:mm:ss"
    $msg = $Fecha + " " + $msg
    Write-Output $msg | Out-File -FilePath $LogFile -Append
    $Colores="White"
    $BackGround = 
    If($Color -eq 1 )
     {
      $Colores ="Cyan"
     }
    If($Color -eq 3 )
     {
      $Colores ="Yellow"
     }

     if($Color -eq 2)
      {
        Write-Host -ForegroundColor White -BackgroundColor Red $msg 
      } 
     else 
      {
        Write-Host -ForegroundColor $Colores $msg 
      } 


   }
  catch
  {
    Write-Host $msg 
  }
}



cls


  $sw = [diagnostics.stopwatch]::StartNew()


  logMsg("Creating the folder " + $FolderV) (1)
   $result = CreateFolder($FolderV) 
   If( $result -eq $false)
    { 
     logMsg("Was not possible to create the folder") (2)
     exit;
    }
logMsg("Created the folder " + $FolderV) (1)

$LogFile = $FolderV + "Results.Log"    #Logging the operations.

logMsg("Deleting Log File") (1)
   $result = DeleteFile($LogFile) #Delete Log file
logMsg("Deleted Log File") (1)

$query = @("SELECT 1")

$LocalInitialIP = CheckDns($DatabaseServer)

  for ($i=0; $i -lt $NumberExecutions; $i++)
  {
   try
    {

      $SQLConnectionSource = GiveMeConnectionSource([ref]$LocalInitialIP) #Connecting to the database.
      if($SQLConnectionSource -eq $null)
      { 
        logMsg("It is not possible to connect to the database") (2)
      }
      else
      {
       
       $SQLConnectionSource.StatisticsEnabled = 1 
       $command = New-Object -TypeName System.Data.SqlClient.SqlCommand
       $command.CommandTimeout = 60
       $command.Connection=$SQLConnectionSource
                  
         for ($iQuery=0; $iQuery -lt $query.Count; $iQuery++) 
         {
           $start = get-date
             $command.CommandText = $query[$iQuery]
             $command.ExecuteNonQuery() | Out-Null 
           $end = get-date
           $data = $SQLConnectionSource.RetrieveStatistics()
           logMsg("-------------------------")
           logMsg("Query                 :  " + $query[$iQuery]) 
           logMsg("Iteration             :  " +$i) 
           logMsg("Time required (ms)    :  " +(New-TimeSpan -Start $start -End $end).TotalMilliseconds) 
           logMsg("NetworkServerTime (ms):  " +$data.NetworkServerTime) 
           logMsg("Execution Time (ms)   :  " +$data.ExecutionTime) 
           logMsg("Connection Time       :  " +$data.ConnectionTime) 
           logMsg("ServerRoundTrips      :  " +$data.ServerRoundtrips) 
           logMsg("-------------------------")
          }
          $SQLConnectionSource.Close()

      }
    }
    catch
   {
    logMsg( "You're WRONG") (2)
    logMsg($Error[0].Exception) (2)
   }
   
}
logMsg("Time spent (ms) Procces :  " +$sw.elapsed) (2)
logMsg("Review: https://docs.microsoft.com/en-us/dotnet/framework/data/adonet/sql/provider-statistics-for-sql-server") (2)