This post has been republished via RSS; it originally appeared at: New blog articles in Microsoft Community Hub.
Today, I worked on a service request that our customer asks about:
- How to know the connection time invested to connect to the database in Azure SQL Database and Azure SQL Managed Instance.
- How to know the time invested running a real queries to know the latency of the network, roundtrips and execution time.
Following, I would like to share a small PowerShell Script that giving some parameters your could know by your own these numbers. All this information is based on this article
1) Download the code from below.
#Licensed under the MIT license.
#Azure Connection and Execution Time Spent
#THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
#FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
#WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
#------------------------------------------------------------------------------
#About this PowerShell Script
#-------------------------------------------------------------------------------
Param($DatabaseServer = "ServerName.database.windows.net",
$Database = "DBName",
$Username = "UserName",
$passwordSecure = "Password" ,
$NumberExecutions ="10",
$Port="1433",
$LogFile="c:\temp\Details.log")
#-------------------------------
#Delete the file
#-------------------------------
Function DeleteFile{
Param( [Parameter(Mandatory)]$FileName )
try
{
logMsg("Checking if the file..." + $FileName + " exists.") -SaveFile $false
if( FileExist($FileName))
{
logMsg("Removing the file..." + $FileName) -SaveFile $false
$Null = Remove-Item -Path $FileName -Force
logMsg("Removed the file..." + $FileName) -SaveFile $false
}
return $true
}
catch
{
logMsg("Remove the file..." + $FileName + " - " + $Error[0].Exception) (2)
return $false
}
}
#-----------------------------------------------------------
# Identify if the value is empty or not
#-----------------------------------------------------------
function TestEmpty($s)
{
if ([string]::IsNullOrWhitespace($s))
{
return $true;
}
else
{
return $false;
}
}
#-------------------------------
#File Exists
#-------------------------------
Function FileExist{
Param( [Parameter(Mandatory)]$FileName )
try
{
$return=$false
$FileExists = Test-Path $FileName
if($FileExists -eq $True)
{
$return=$true
}
return $return
}
catch
{
return $false
}
}
#--------------------------------
#Obtain the DNS details resolution.
#--------------------------------
function CheckDns($sReviewServer)
{
try
{
$IpAddress = [System.Net.Dns]::GetHostAddresses($sReviewServer)
foreach ($Address in $IpAddress)
{
$sAddress = $sAddress + $Address.IpAddressToString + " ";
}
return $sAddress
break;
}
catch
{
return ""
}
}
#----------------------------------------------------------------
#Function to connect to the database using a retry-logic
#----------------------------------------------------------------
Function GiveMeConnectionSource()
{
$lNumRetries=10
for ($i=1; $i -le $lNumRetries; $i++)
{
try
{
logMsg( "-------------------------------------- " + "Connecting Attempt #" + $i + " of " + $lNumRetries.ToString() + " - IP:" + $(CheckDns($DatabaseServer)) + " ----------------------------------") (3)
$SQLConnection = New-Object System.Data.SqlClient.SqlConnection
$SQLConnection.ConnectionString = "data source=tcp:"+$DatabaseServer +"," + $Port
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Initial Catalog="+$Database
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Connection Timeout=30"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";User ID="+ $Username
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Password="+ $password
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Application Name=Test SQLCLIENT Connection"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Persist Security Info=False"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";ConnectRetryInterval=3"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";ConnectRetryInterval=10"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Max Pool Size=100"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Min Pool Size=1"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";MultipleActiveResultSets=False"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Pooling=True"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";Encrypt=True"
$SQLConnection.ConnectionString = $SQLConnection.ConnectionString + ";TrustServerCertificate=False"
$start = get-date
$SQLConnection.Open()
$end = get-date
##$sAdditionalInformation = " - ID:" + $SQLConnection.ClientConnectionId.ToString() ##+ " -- HostName: " + $SQLConnection.WorkstationId + " Server Version:" + $SQLConnection.ServerVersion
$lDiff=(New-TimeSpan -Start $start -End $end).TotalMilliseconds
$LatencyAndOthers.ConnectionsDone_Number_Success = $LatencyAndOthers.ConnectionsDone_Number_Success+1
$LatencyAndOthers.ConnectionsDone_MS = $LatencyAndOthers.ConnectionsDone_MS+$lDiff
logMsg("Connected (ms): " + $lDiff.ToString() ) (3)
logMsg("Conn.Failed : " + $LatencyAndOthers.ConnectionsDone_Number_Failed.ToString()) (3)
logMsg("Conn.Success : " + $LatencyAndOthers.ConnectionsDone_Number_Success.ToString()) (3)
logMsg("Conn.(ms) : " + ($LatencyAndOthers.ConnectionsDone_MS / $LatencyAndOthers.ConnectionsDone_Number_Success).ToString()) (3)
return $SQLConnection
break;
}
catch
{
$LatencyAndOthers.ConnectionsDone_Number_Failed = $LatencyAndOthers.ConnectionsDone_Number_Failed +1
logMsg("Not able to connect - Retrying the connection..." + $Error[0].Exception.ErrorRecord + "-" + $Error[0].Exception.ToString().Replace("\t"," ").Replace("\n"," ").Replace("\r"," ").Replace("\r\n","").Trim()) (2)
$WaitTime = (5*($i+1))
logMsg("Waiting for next retry in " + $WaitTime.ToString() + " seconds ..") -SaveFile $false
Start-Sleep -s $WaitTime
[System.Data.SqlClient.SqlConnection]::ClearAllPools()
}
}
}
#--------------------------------
#Verify if the value is able to convert to integer
#--------------------------------
Function IsInteger([string]$vInteger)
{
Try
{
$null = [convert]::ToInt32($vInteger)
return $True
}
Catch
{
return $False
}
}
#--------------------------------
#Log the operations
#--------------------------------
function logMsg
{
Param
(
[Parameter(Mandatory=$false, Position=0)]
[string] $msg,
[Parameter(Mandatory=$false, Position=1)]
[int] $Color,
[Parameter(Mandatory=$false, Position=2)]
[boolean] $Show=$true,
[Parameter(Mandatory=$false, Position=3)]
[boolean] $ShowDate=$true,
[Parameter(Mandatory=$false, Position=4)]
[boolean] $SaveFile=$true
)
try
{
if($ShowDate -eq $true)
{
$msg = (Get-Date -format "yyyy-MM-dd HH:mm:ss.fff") + " " + $msg
}
If($SaveFile -eq $true)
{
Write-Output $msg | Out-File -FilePath $LogFile -Append
}
if($Show -eq $true)
{
$Colores="White"
If($Color -eq 1 ) {$Colores ="Cyan"}
elseIf($Color -eq 3 ) {$Colores ="Yellow"}
elseIf($Color -eq 4 ) {$Colores ="Green"}
elseIf($Color -eq 5 ) {$Colores ="Magenta"}
If($Color -eq 2)
{
Write-Host -ForegroundColor White -BackgroundColor Red $msg
}
else
{
Write-Host -ForegroundColor $Colores $msg
}
}
}
catch
{
Write-Host $msg
}
}
Class LatencyAndOthers #Class to manage the connection latency
{
[long]$ConnectionsDone_MS = 0
[long]$ConnectionsDone_Number_Success = 0
[long]$ConnectionsDone_Number_Failed = 0
[long]$ExecutionsDone_MS = 0
[long]$ExecutionsDone_Number_Success = 0
[long]$ExecutionsDone_Number_Failed = 0
}
Class QueryText #Query Text
{
[string]$Text = ""
[boolean]$ExecuteNonQuery = $false
[boolean]$ExecuteReader = $false
[boolean]$ExecuteScalar = $false
[int]$CommandTimeout=30
}
$LatencyAndOthers = [LatencyAndOthers]::new()
$Query = [QueryText]::new()
[System.Collections.ArrayList]$IPArrayConnection = @()
[System.Collections.ArrayList]$Query = @()
[System.Collections.ArrayList]$CommandArray = @()
[System.Collections.ArrayList]$QueryMetrics = @()
cls
if (TestEmpty($DatabaseServer))
{ $DatabaseServer = read-host -Prompt "Please enter a Server Name" }
if (TestEmpty($DatabaseServer))
{
logMsg ("Server Name is empty. Closing the application.")
exit;
}
if (TestEmpty($Database))
{ $Database = read-host -Prompt "Please enter a Database Name" }
if (TestEmpty($Database))
{
logMsg ("DatabaseName is empty. Closing the application.")
exit;
}
if (TestEmpty($Port))
{ $Port = read-host -Prompt "Please enter the port number, for example, 1433 " }
if (TestEmpty($Port))
{
logMsg ("Port is empty. Closing the application.")
exit;
}
if (TestEmpty($Username))
{ $Username = read-host -Prompt "Please enter a User Name" }
if (TestEmpty($Username))
{
logMsg ("User Name is empty. Closing the application.")
exit;
}
if (TestEmpty($passwordSecure))
{
$passwordSecure = read-host -Prompt "Please enter a password" -assecurestring
$password = [Runtime.InteropServices.Marshal]::PtrToStringAuto([Runtime.InteropServices.Marshal]::SecureStringToBSTR($passwordSecure))
}
else
{$password = $passwordSecure}
if (TestEmpty($Password))
{
logMsg ("Password is empty. Closing the application.")
exit;
}
if (TestEmpty($NumberExecutions))
{
$NumberExecutions = read-host -Prompt "Please enter the number of test to run (1-2000) - Leave this field empty and press enter for default value 10."
}
if (TestEmpty($NumberExecutions))
{
$NumberExecutions="10"
}
if( -not (IsInteger([string]$NumberExecutions)))
{
logMsg("Please, specify a correct number of process to run, the value is not integer") (2)
exit;
}
$IntegerNumberExecutions = [int]::Parse($NumberExecutions)
if($integerNumberExecutions -lt 1 -or $integerNumberExecutions -gt 20000)
{
logMsg("Please, specify a correct number of process to run, it is a value between 1 and 2000") (2)
exit;
}
$QueryTmp = [QueryText]::new()
$QueryTmp.Text = "SELECT 1"
$QueryTmp.ExecuteScalar=$true
$Null = $Query.Add($QueryTmp)
if(TestEmpty($LogFile))
{
$FileBrowserAnalysis = New-Object System.Windows.Forms.SaveFileDialog -Property @{
InitialDirectory = [Environment]::GetFolderPath("Desktop")
Title = 'Please choose the Log File to save the content of this process'
Filter = 'Log File to save the content (*.*)|*.*'}
$null = $FileBrowserAnalysis.ShowDialog()
$LogFile = $FileBrowserAnalysis.FileName
if(TestEmpty($LogFile))
{
logMsg -msg "File log was not selected" -Color 2 -bSaveOnFile $false
exit;
}
}
$Null = DeleteFile($LogFile)
logMsg( "Details DB Connection: " + $DatabaseServer + " - DB: " + $Database + " HostName:" + $env:computername )
foreach($Tmp in $Query) ##Create the same number of command that queries that we need.
{
$QueryMetricTmp = [LatencyAndOthers]::new()
$Null = $QueryMetrics.add($QueryMetricTmp)
$command = New-Object -TypeName System.Data.SqlClient.SqlCommand
$command.CommandTimeout = $Tmp.CommandTimeout
$command.CommandText = $Tmp.Text
$command.Prepare()
$Null = $CommandArray.Add($command)
}
$QueryCount = $query.Count
$bShowQuery = $true
$sw = [diagnostics.stopwatch]::StartNew() ##Take the time.
for ($i=1; $i -le $IntegerNumberExecutions; $i++) ##For every number of process open a new connection and close it at the end.
{
try
{
$Null = $IPArrayConnection.Add($(GiveMeConnectionSource)) #Connecting to the database.
if($IPArrayConnection[$i-1] -eq $null)
{
LogMsg("Not able to connect. Closing the application...") (2)
exit;
}
for ($iQuery=0; $iQuery -lt $QueryCount; $iQuery++) #for Every query run it.
{
$CommandArray[$iQuery].Connection = $IPArrayConnection[$i-1]
Try
{
$lDiff=0
LogMsg( "----------------------- Query Iteration:" + $i + " Query " + ($iQuery+1).ToString() + "/" + $QueryCount + " ---------------------------------------------------------" )
if($bShowQuery -eq $true) ##There is not needed to report the same and unique query multiple time and also we're saving time.
{
LogMsg( $query[$iQuery].Text )
if( $query[$iQuery].ExecuteNonQuery -eq $true )
{
LogMsg( "Type command: ExecuteNonQuery")
}
if( $query[$iQuery].ExecuteScalar -eq $true )
{
LogMsg( "Type command: ExecuteScalar")
}
if( $query[$iQuery].ExecuteReader -eq $true )
{
LogMsg( "Type command: ExecuteReader")
}
$bShowQuery=(-not ($QueryCount -eq 1))
}
$start = get-date
$IPArrayConnection[$i-1].StatisticsEnabled = 1
if( $query[$iQuery].ExecuteNonQuery -eq $true ) { $Null = $CommandArray[$iQuery].ExecuteNonQuery() }
if( $query[$iQuery].ExecuteScalar -eq $true ) { $Null = $CommandArray[$iQuery].ExecuteScalar() }
if( $query[$iQuery].ExecuteReader -eq $true ) { $Null = $CommandArray[$iQuery].ExecuteReader() }
$data = $IPArrayConnection[$i-1].RetrieveStatistics()
$Null = $IPArrayConnection[$i-1].StatisticsEnabled = 0
$Null = $IPArrayConnection[$i-1].ResetStatistics()
$end = get-date
$lDiff=(New-TimeSpan -Start $start -End $end).TotalMilliseconds
$QueryMetrics[$iQuery].ExecutionsDone_Number_Success = $QueryMetrics[$iQuery].ExecutionsDone_Number_Success+1
$QueryMetrics[$iQuery].ExecutionsDone_MS = $QueryMetrics[$iQuery].ExecutionsDone_MS+$lDiff
$LatencyAndOthers.ExecutionsDone_Number_Success = $LatencyAndOthers.ExecutionsDone_Number_Success+1
$LatencyAndOthers.ExecutionsDone_MS = $LatencyAndOthers.ExecutionsDone_MS+$lDiff
LogMsg( "Time required (ms) : " + $lDiff.ToString())
}
catch
{
$LatencyAndOthers.ExecutionsDone_Number_Failed = $LatencyAndOthers.ExecutionsDone_Number_Failed+1
$QueryMetrics[$iQuery].ExecutionsDone_Number_Failed = $QueryMetrics[$iQuery].ExecutionsDone_Number_Failed+1
LogMsg( "Error: " + $Error[0].Exception) (2)
}
LogMsg( "NetworkServerTime (ms): " +$data.NetworkServerTime )
LogMsg( "Execution Time (ms) : " +$data.ExecutionTime)
LogMsg( "ServerRoundTrips : " +$data.ServerRoundtrips)
LogMsg( "SelectRows : " +$data.SelectRows)
##LogMsg( "BytesSent : " +$data.BytesSent)
##LogMsg( "BytesReceived : " +$data.BytesReceived)
##LogMsg( "Connection Time (ms) : " +$data.ConnectionTime)
##LogMsg( "BuffersReceived : " +$data.BuffersReceived)
##LogMsg( "SelectCount : " +$data.SelectCount)
logMsg( "Query Commands Failed : " + $QueryMetrics[$iQuery].ExecutionsDone_Number_Failed.ToString())
logMsg( "Query Commands Success: " + $QueryMetrics[$iQuery].ExecutionsDone_Number_Success.ToString())
logMsg( "Query Commands ms : " + ($QueryMetrics[$iQuery].ExecutionsDone_MS / $QueryMetrics[$iQuery].ExecutionsDone_Number_Success).ToString())
logMsg( "Total Commands Failed : " + $LatencyAndOthers.ExecutionsDone_Number_Failed.ToString())
logMsg( "Total Commands Success: " + $LatencyAndOthers.ExecutionsDone_Number_Success.ToString())
logMsg( "Total Commands ms : " + ($LatencyAndOthers.ExecutionsDone_MS / $LatencyAndOthers.ExecutionsDone_Number_Success).ToString())
}
$IPArrayConnection[$i-1].Close() ##Close the connection.
}
catch
{
LogMsg( "Error: " + $Error[0].Exception) (2)
}
}
logMsg("-------------------------------------- SUMMARY -----------------------------------------------------------------")
logMsg("Total Connections Failed : " + $LatencyAndOthers.ConnectionsDone_Number_Failed.ToString())
logMsg("Total Connections Success: " + $LatencyAndOthers.ConnectionsDone_Number_Success.ToString())
logMsg("Total Connections Avg ms : " + ($LatencyAndOthers.ConnectionsDone_MS / $LatencyAndOthers.ConnectionsDone_Number_Success).ToString())
LogMsg("Total Number Executions : " + $IntegerNumberExecutions)
LogMsg("Total Number Queries : " + $QueryCount)
LogMsg("Total Number Process : " + ($IntegerNumberExecutions*$query.Count))
logMsg("Total Commands Failed : " + $LatencyAndOthers.ExecutionsDone_Number_Failed.ToString())
logMsg("Total Commands Success : " + $LatencyAndOthers.ExecutionsDone_Number_Success.ToString())
logMsg("Total Commands ms : " + ($LatencyAndOthers.ExecutionsDone_MS / $LatencyAndOthers.ExecutionsDone_Number_Success).ToString())
$i=0
LogMsg("------------------- Queries Summary -------------------------------")
foreach($Tmp in $Query) ##Create the same number of command that queries that we need.
{
LogMsg("Query # : " + $Tmp.Text)
logMsg("Total Commands Failed : " + $QueryMetrics[$i].ExecutionsDone_Number_Failed.ToString())
logMsg("Total Commands Success: " + $QueryMetrics[$i].ExecutionsDone_Number_Success.ToString())
logMsg("Total Commands ms : " + ($QueryMetrics[$i].ExecutionsDone_MS / $QueryMetrics[$i].ExecutionsDone_Number_Success).ToString())
$i=$i+1
}
LogMsg( "Review: https://docs.microsoft.com/en-us/dotnet/framework/data/adonet/sql/provider-statistics-for-sql-server")
LogMsg("Time spent (ms) Procces : " +$sw.elapsed)
logMsg("-------------------------------------- SUMMARY -----------------------------------------------------------------")
Remove-Variable passwordSecure
Remove-Variable password
2) Configure the value of the following parameters:
- $DatabaseServer, will be the server name to connect, for example, "eeo1c8uk2i.database.windows.net"
- $Database, will be the database name to connect, for example, "myDB"
- $Username, will be the user to connect
- $passwordSecure, will be the password.
- $NumberExecutions, number of times to connect to the database and run the queries, for example, "10".
- $Port, port of the server to connect, for example, "1433"
- $LogFile, location and file name where the PowerShell Script will save the content, for example, "c:\temp\salida.log"
If you don't leave empty/blank these values, PowerShell Script will ask for.
3) Specify the value of the following parameters:
- Add the query or queries that you want to execute, for every, query, you need to specify, text and type (I suggested to enable only ExecuteNonQuery=$true.
$QueryTmp = [QueryText]::new()
$QueryTmp.Text = "SELECT 1"
$QueryTmp.ExecuteScalar=$true
$Null = $Query.Add($QueryTmp)
$QueryTmp = [QueryText]::new()
$QueryTmp.Text = "SELECT count(Id) FROM PerformanceVarcharNVarchar Where TextToSearch = N'Test Search ' + CONVERT(nvarchar(200),RAND()*(2000000-10000)+10000) OPTION (MAXDOP 1)"
$QueryTmp.ExecuteNonQuery=$true
$Null = $Query.Add($QueryTmp)
4) Execute the process and open the log file.
- Once the process has been finished, you are going to have the following details:
2022-10-14 18:44:14.356 Details DB Connection: ServerName.database.windows.net - DB: DBName HostName: ServerNameFromThePowerShellWasExecute.
2022-10-14 18:44:14.686 -------------------------------------- Connecting Attempt #1 of 10 - IP:(IP of ServerName)---------------------
2022-10-14 18:44:14.702 Connected (ms): 0 --> Time taken to connect.
2022-10-14 18:44:14.710 Conn.Failed : 0 --> Number of connections failed.
2022-10-14 18:44:14.714 Conn.Success : 1 --> Number of success connections.
2022-10-14 18:44:14.720 Conn.(ms) : 0 --> Average in ms for all the success connections established.
2022-10-14 18:44:14.724 ----------------------- Query Iteration:1 Query 1/2 ---------------------------------------------------------
2022-10-14 18:44:14.727 SELECT 1
2022-10-14 18:44:14.733 Type command: ExecuteScalar
2022-10-14 18:44:14.785 Time required (ms) : 37,1966 --> Time to complete the connection and retrieve the data.
2022-10-14 18:44:14.789 NetworkServerTime (ms): 36 --> Network Time.
2022-10-14 18:44:14.792 Execution Time (ms) : 36 --> Execution Time.
2022-10-14 18:44:14.795 ServerRoundTrips : 1 --> ServerRoundTrips.
2022-10-14 18:44:14.799 SelectRows : 1 --> Rows Number returned.
2022-10-14 18:44:14.803 Query Commands Failed : 0 --> Number of executions failed for this query
2022-10-14 18:44:14.806 Query Commands Success: 1 --> Number of success executions for this query.
2022-10-14 18:44:14.810 Query Commands ms : 37 --> Average in ms of success executions for this query.
2022-10-14 18:44:14.814 Total Commands Failed : 0 --> Number of executions failed for all queries
2022-10-14 18:44:14.818 Total Commands Success: 1 --> Number of success executions for all queries
2022-10-14 18:44:14.822 Total Commands ms : 37 --> Average in ms of success executions for all queries
2022-10-14 18:44:20.232 -------------------------------------- SUMMARY -----------------------------------------------------------------
2022-10-14 18:44:20.250 Total Connections Failed : 0
2022-10-14 18:44:20.261 Total Connections Success: 10
2022-10-14 18:44:20.266 Total Connections Avg ms : 0,5
2022-10-14 18:44:20.273 Total Number Executions : 10
2022-10-14 18:44:20.279 Total Number Queries : 2
2022-10-14 18:44:20.285 Total Number Process : 20
2022-10-14 18:44:20.291 Total Commands Failed : 0
2022-10-14 18:44:20.296 Total Commands Success : 20
2022-10-14 18:44:20.313 Total Commands ms : 184,25
2022-10-14 18:44:20.320 ------------------- Queries Summary -------------------------------
2022-10-14 18:44:20.326 Query # : SELECT 1
2022-10-14 18:44:20.332 Total Commands Failed : 0
2022-10-14 18:44:20.339 Total Commands Success: 10
2022-10-14 18:44:20.345 Total Commands ms : 36,5
2022-10-14 18:44:20.393 Review: https://docs.microsoft.com/en-us/dotnet/framework/data/adonet/sql/provider-statistics-for-sql-server
2022-10-14 18:44:20.401 Time spent (ms) Procces : 00:00:06.0379143
2022-10-14 18:44:20.409 -------------------------------------- SUMMARY -----------------------------------------------------------------
Enjoy!
