Blog Post

Azure Database Support Blog
8 MIN READ

Lesson Learned #481: Query Performance Analysis Tips

Jose_Manuel_Jurado's avatar
Mar 18, 2024

When working with databases, high resource usage or a query reporting a timeout could indicate that the statistics of the tables involved in the query are not up to date, that we might be missing indexes, or that there are excessive blocking as the most common elements and possible causes of performance loss. For this reason, I would like to add in this article elements that can help us determine what might be happening with our query. 

Scenario 1: CommandTimeout and Obtaining Statistics

 

The inception point of our exploration is the creation of a stored procedure, sp_AnalyzeQueryStatistics. This procedure is designed to take a SQL query as input, specified through the @SQLQuery parameter, and dissect it to unveil the underlying schema and tables it interacts with.

 

Crafting

 

sp_AnalyzeQueryStatistics: The core functionality of this procedure leverages the sys.dm_exec_describe_first_result_set DMV. This invaluable tool provides a window into the query's anatomy, pinpointing the schema and tables entwined in its execution path.

 

 

CREATE PROCEDURE sp_AnalyzeQueryStatistics
    @SQLQuery NVARCHAR(MAX)
AS
BEGIN
    SET NOCOUNT ON;

    DECLARE @TableNames TABLE (
        SourceSchema NVARCHAR(128),
        TableName NVARCHAR(128)
    );

    INSERT INTO @TableNames (SourceSchema, TableName)
    SELECT DISTINCT
        source_schema AS SourceSchema,
        source_table AS TableName
    FROM
        sys.dm_exec_describe_first_result_set(@SQLQuery, NULL, 1) sp
		WHERE sp.error_number IS NULL AND NOT sp.source_table is NULL

    SELECT
        t.TableName,
        s.name AS StatisticName,
        STATS_DATE(s.object_id, s.stats_id) AS LastUpdated,
        sp.rows,
        sp.rows_sampled,
        sp.modification_counter
    FROM
        @TableNames AS t
    INNER JOIN
        sys.stats AS s ON s.object_id = OBJECT_ID(QUOTENAME(t.SourceSchema) + '.' + QUOTENAME(t.TableName))
    CROSS APPLY
        sys.dm_db_stats_properties(s.object_id, s.stats_id) AS sp;
END;

 

 

Diving Deeper with Table Statistics:

 

Identification is just the precursor; the crux lies in scrutinizing the statistics of these identified tables. By employing sys.stats and sys.dm_db_stats_properties, we delve into the statistical realm of each table, gleaning insights into data distribution, sampling rates, and the freshness of the statistics.

 

Informed Decision-Making:

 

This statistical audit empowers us with the knowledge to make data-driven decisions. Should the rows_sample significantly deviate from the total rows, or the statistics' last update be a for example 2 months, it's a clarion call for action—be it updating the statistics or reevaluating index strategies.

 

Scenario 2: CommandTimeout due to Missing Indexes

 

In many scenarios, a CommandTimeout exception in a .NET application can be a signal of underlying performance issues within your SQL Server database. One common cause of these timeouts is the lack of appropriate indexes that can lead to inefficient query execution plans. Identifying and implementing missing indexes can significantly enhance the performance of your database queries.

Consider a situation where a seemingly simple query like:

 

SELECT Id FROM [MSxyzTest].[_x_y_z_MS_HighCPU] WHERE TextToSearch = '23'

 

takes longer than expected to execute, resulting in a CommandTimeout exception in your .NET application when the command timeout is set to a threshold like 2 seconds. This issue might not just be a one-time occurrence but a symptom of a larger problem: the absence of an efficient search mechanism in the form of an index.

 

Identifying Missing Indexes

To address this issue, we've devised a stored procedure, sp_AnalyzeQueryIndex, which when executed against a problematic SQL query, provides insights into missing indexes that could improve query performance. 

 

 

CREATE PROCEDURE [dbo].[sp_AnalyzeQueryIndex]
    @SQLQuery NVARCHAR(MAX)
AS
BEGIN
    SET NOCOUNT ON;

    DECLARE @TableNames TABLE (
        SourceSchema NVARCHAR(128),
        TableName NVARCHAR(128),
        ObjectId INT
    );

    INSERT INTO @TableNames (SourceSchema, TableName, ObjectId)
    SELECT DISTINCT
        source_schema AS SourceSchema,
        source_table AS TableName,
        OBJECT_ID(source_schema + '.' + source_table) AS ObjectId
    FROM
        sys.dm_exec_describe_first_result_set(@SQLQuery, NULL, 1) sp
    WHERE sp.error_number IS NULL AND NOT sp.source_table IS NULL

    SELECT
        t.TableName,
        migs.group_handle,
        migs.unique_compiles,
        migs.user_seeks,
        migs.user_scans,
        migs.last_user_seek,
        migs.last_user_scan,
        mid.statement,
        mid.equality_columns,
        mid.inequality_columns,
        mid.included_columns
    FROM
        @TableNames AS t
    INNER JOIN
        sys.dm_db_missing_index_groups mig ON mig.index_handle IN (
            SELECT index_handle
            FROM sys.dm_db_missing_index_details
            WHERE object_id = t.ObjectId
        )
    INNER JOIN
        sys.dm_db_missing_index_group_stats migs ON migs.group_handle = mig.index_group_handle
    INNER JOIN
        sys.dm_db_missing_index_details mid ON mig.index_handle = mid.index_handle
    WHERE
        mid.database_id = DB_ID();
END;

 

 

In our example, executing this stored procedure against the problematic query indicates that the table [DotNetExample].[MSxyzTest].[_x_y_z_MS_HighCPU] could benefit significantly from an index on the TextToSearch column. It reveals that the absence of this index has already resulted in 7 user seeks, which are instances where SQL Server had to perform a more resource-intensive search than would have been necessary with the right index in place.

 

Implementing the Solution

Armed with this information, database administrators can take informed action by creating the recommended index, thereby reducing the execution time of the query and avoiding CommandTimeout exceptions in the application:

 

CREATE NONCLUSTERED INDEX IX_TextToSearch
ON [MSxyzTest].[_x_y_z_MS_HighCPU] (TextToSearch);

 

By routinely analyzing your queries for missing indexes, especially those frequently resulting in CommandTimeout exceptions, you can proactively optimize your database's performance and enhance the overall responsiveness of your .NET applications.

 

C# Implementation for all scenarios:

 

 

using System;
using System.Diagnostics;
using System.Data;
using System.Threading;
using System.Threading.Tasks;
using Microsoft.Data.SqlClient;

namespace HighCPU
{
    class Program
    {
        private static string ConnectionString = "Server=tcp:myservername.database.windows.net,1433;User Id=MyUser;Password=MyPassword;Initial Catalog=MyDb;Persist Security Info=False;MultipleActiveResultSets=False;Encrypt=True;TrustServerCertificate=False;Connection Timeout=30;Pooling=true;Max Pool size=100;Min Pool Size=1;ConnectRetryCount=3;ConnectRetryInterval=10;Application Name=ConnTest";
        private static string Query = "Select Id from [MSxyzTest].[_x_y_z_MS_HighCPU] where TextToSearch = '23'";

        static async Task Main(string[] args)
        {
            SqlConnection connection = await EstablishConnectionWithRetriesAsync(3, 2000);
            if (connection == null)
            {
                Console.WriteLine("Failed to establish a database connection.");
                return;
            }

            await ExecuteQueryWithRetriesAsync(connection, 5,  1000, 100000,2,true);

            connection.Close();
        }

        private static async Task<SqlConnection> EstablishConnectionWithRetriesAsync(int maxRetries, int initialDelay)
        {
            SqlConnection connection = null;
            int retryDelay = initialDelay;

            for (int attempt = 1; attempt <= maxRetries; attempt++)
            {
                try
                {
                    connection = new SqlConnection(ConnectionString);
                    await connection.OpenAsync();
                    Console.WriteLine("Connection established successfully.");
                    return connection;
                }
                catch (SqlException ex)
                {
                    Console.WriteLine($"Failed to establish connection: {ex.Message}. Attempt {attempt} of {maxRetries}.");
                    if (attempt == maxRetries)
                    {
                        Console.WriteLine("Maximum number of connection attempts reached. The application will terminate.");
                        return null;
                    }

                    Console.WriteLine($"Waiting {retryDelay / 1000} seconds before the next connection attempt...");
                    await Task.Delay(retryDelay);

                    retryDelay *= 2;
                }
            }

            return null;
        }

        private static async Task ExecuteQueryWithRetriesAsync(SqlConnection connection, int maxRetries, int initialDelay, int CancellationTokenTimeout, int CommandSQLTimeout, Boolean bReviewQuery = false)
        {
            int retryDelay = initialDelay;

            for (int attempt = 1; attempt <= maxRetries; attempt++)
            {
                using (var cts = new CancellationTokenSource())
                {
                    cts.CancelAfter(CancellationTokenTimeout*attempt); // Set CancellationToken timeout to 10 seconds

                    try
                    {
                        using (SqlCommand command = new SqlCommand(Query, connection))
                        {
                            command.CommandTimeout = CommandSQLTimeout*attempt; // Set CommandTimeout to 15 seconds

                            Stopwatch stopwatch = Stopwatch.StartNew();

                            await command.ExecuteNonQueryAsync(cts.Token);

                            stopwatch.Stop();
                            Console.WriteLine($"Query executed successfully in {stopwatch.ElapsedMilliseconds} milliseconds.");

                            return;
                        }
                    }
                    catch (TaskCanceledException)
                    {
                        Console.WriteLine($"Query execution was canceled by the CancellationToken. Attempt {attempt} of {maxRetries}.");
                    }
                    catch (SqlException ex) when (ex.Number == -2)
                    {
                        Console.WriteLine($"Query execution was canceled due to CommandTimeout. Attempt {attempt} of {maxRetries}.");
                        if (bReviewQuery)
                        { 
                            await ReviewQuery(); //Review query stuff
                        }
                    }
                    catch (SqlException ex) when (ex.Number == 207 || ex.Number == 208 || ex.Number == 2627)
                    {
                        Console.WriteLine($"SQL error preventing retries: {ex.Message}");
                        return;
                    }
                    catch (Exception ex)
                    {
                        Console.WriteLine($"An exception occurred: {ex.Message}");
                        return;
                    }

                    Console.WriteLine($"Waiting {retryDelay / 1000} seconds before the next query attempt...");
                    await Task.Delay(retryDelay);

                    retryDelay *= 2;
                }
            }
        }

        /*-----------------------------------------------------------------------
         This function will connect again to the database and run two functions:
           -- ReviewQueryWithRetriesAsync that will obtain the statistics associated with the tables involved in the query.
           -- AnalyzeMissingIndexesAsync that will obtain the missing indexes associated with the tables involved in the query
         -----------------------------------------------------------------------*/
        private static async Task ReviewQuery()
        {
            SqlConnection connection = await EstablishConnectionWithRetriesAsync(3, 2000);
            if (connection == null)
            {
                Console.WriteLine("Review Query - Failed to establish a database connection.");
                return;
            }

            await ReviewQueryWithRetriesAsync(connection, 5, 1000, 10000, 15); //Review statistics
            await AnalyzeMissingIndexesAsync(connection, 5, 1000, 10000, 15); //Review missing indexes

            connection.Close();
        }
        /*-----------------------------------------------------------------------
         ReviewQueryWithRetriesAsync that will obtain the statistics associated with the tables involved in the query.
         -----------------------------------------------------------------------*/

        private static async Task ReviewQueryWithRetriesAsync(SqlConnection connection, int maxRetries, int initialDelay, int CancellationTokenTimeout, int CommandSQLTimeout, Boolean bReviewQuery = false)
        {
            int retryDelay = initialDelay;

            for (int attempt = 1; attempt <= maxRetries; attempt++)
            {
                using (var cts = new CancellationTokenSource())
                {
                    cts.CancelAfter(CancellationTokenTimeout * attempt); // Set CancellationToken timeout to 10 seconds

                    try
                    {
                        using (SqlCommand command = new SqlCommand("sp_AnalyzeQueryStatistics", connection))
                        {
                            command.CommandTimeout = CommandSQLTimeout * attempt; // Set CommandTimeout to 15 seconds
                            command.CommandType = CommandType.StoredProcedure;

                            Stopwatch stopwatch = Stopwatch.StartNew();
                            command.Parameters.Add(new SqlParameter("@SQLQuery", SqlDbType.NVarChar, -1));
                            command.Parameters["@SQLQuery"].Value = Query;

                            using (SqlDataReader reader = await command.ExecuteReaderAsync())
                            {
                                while (await reader.ReadAsync())
                                {
                                    Console.WriteLine("TableName: " + reader["TableName"].ToString());
                                    Console.WriteLine("StatisticName: " + reader["StatisticName"].ToString());
                                    Console.WriteLine("LastUpdated: " + reader["LastUpdated"].ToString());
                                    Console.WriteLine("Rows: " + reader["Rows"].ToString());
                                    Console.WriteLine("RowsSampled: " + reader["Rows_Sampled"].ToString());
                                    Console.WriteLine("ModificationCounter: " + reader["Modification_Counter"].ToString());
                                    Console.WriteLine("-----------------------------------");
                                }
                            }

                            stopwatch.Stop();
                            Console.WriteLine($"Query executed successfully in {stopwatch.ElapsedMilliseconds} milliseconds.");

                            return;
                        }
                    }
                    catch (TaskCanceledException)
                    {
                        Console.WriteLine($"Query execution was canceled by the CancellationToken. Attempt {attempt} of {maxRetries}.");
                    }
                    catch (SqlException ex) when (ex.Number == -2)
                    {
                        Console.WriteLine($"Query execution was canceled due to CommandTimeout. Attempt {attempt} of {maxRetries}.");
                        if (bReviewQuery)
                        { }
                    }
                    catch (SqlException ex) when (ex.Number == 207 || ex.Number == 208 || ex.Number == 2627)
                    {
                        Console.WriteLine($"SQL error preventing retries: {ex.Message}");
                        return;
                    }
                    catch (Exception ex)
                    {
                        Console.WriteLine($"An exception occurred: {ex.Message}");
                        return;
                    }

                    Console.WriteLine($"Waiting {retryDelay / 1000} seconds before the next query attempt...");
                    await Task.Delay(retryDelay);

                    retryDelay *= 2;
                }
            }
        }

        /*-----------------------------------------------------------------------
         AnalyzeMissingIndexesAsync that will obtain the missing indexes associated with the tables involved in the query
         -----------------------------------------------------------------------*/

        private static async Task AnalyzeMissingIndexesAsync(SqlConnection connection, int maxRetries, int initialDelay, int cancellationTokenTimeout, int commandSqlTimeout)
        {
            int retryDelay = initialDelay;

            for (int attempt = 1; attempt <= maxRetries; attempt++)
            {
                using (var cts = new CancellationTokenSource())
                {
                    cts.CancelAfter(cancellationTokenTimeout * attempt); // Set CancellationToken timeout

                    try
                    {
                        using (SqlCommand command = new SqlCommand("sp_AnalyzeQueryIndex", connection))
                        {
                            command.CommandTimeout = commandSqlTimeout * attempt; // Set CommandTimeout
                            command.CommandType = CommandType.StoredProcedure;

                            Stopwatch stopwatch = Stopwatch.StartNew();
                            command.Parameters.Add(new SqlParameter("@SQLQuery", SqlDbType.NVarChar, -1));
                            command.Parameters["@SQLQuery"].Value = Query; // Make sure you have a variable Query that contains the SQL query you want to analyze

                            using (SqlDataReader reader = await command.ExecuteReaderAsync(cts.Token))
                            {
                                while (await reader.ReadAsync(cts.Token))
                                {
                                    Console.WriteLine("TableName: " + reader["TableName"].ToString());
                                    Console.WriteLine("GroupHandle: " + reader["group_handle"].ToString());
                                    Console.WriteLine("UniqueCompiles: " + reader["unique_compiles"].ToString());
                                    Console.WriteLine("UserSeeks: " + reader["user_seeks"].ToString());
                                    Console.WriteLine("UserScans: " + reader["user_scans"].ToString());
                                    Console.WriteLine("LastUserSeek: " + reader["last_user_seek"].ToString());
                                    Console.WriteLine("Statement: " + reader["statement"].ToString());
                                    Console.WriteLine("EqualityColumns: " + reader["equality_columns"].ToString());
                                    Console.WriteLine("InequalityColumns: " + reader["inequality_columns"].ToString());
                                    Console.WriteLine("IncludedColumns: " + reader["included_columns"].ToString());
                                    Console.WriteLine("-----------------------------------");
                                }
                            }

                            stopwatch.Stop();
                            Console.WriteLine($"Query executed successfully in {stopwatch.ElapsedMilliseconds} milliseconds.");

                            return;
                        }
                    }
                    catch (TaskCanceledException)
                    {
                        Console.WriteLine($"Query execution was canceled by the CancellationToken. Attempt {attempt} of {maxRetries}.");
                    }
                    catch (SqlException ex) when (ex.Number == -2)
                    {
                        Console.WriteLine($"Query execution was canceled due to CommandTimeout. Attempt {attempt} of {maxRetries}.");
                    }
                    catch (SqlException ex) when (ex.Number == 207 || ex.Number == 208 || ex.Number == 2627)
                    {
                        Console.WriteLine($"SQL error preventing retries: {ex.Message}");
                        return;
                    }
                    catch (Exception ex)
                    {
                        Console.WriteLine($"An exception occurred: {ex.Message}");
                        return;
                    }

                    Console.WriteLine($"Waiting {retryDelay / 1000} seconds before the next attempt...");
                    await Task.Delay(retryDelay, cts.Token);

                    retryDelay *= 2;
                }
            }
        }

    }
}

 

 

Updated Mar 19, 2024
Version 4.0
No CommentsBe the first to comment