Logging SQL Server Query Performance with sp_query_logger

Introduction
Why Logging SQL Server Query Performance is Important
Setting Up sp_query_logger
Using sp_query_logger
Understanding the Logged Data
Conclusion

Introduction

Effective database performance tuning and troubleshooting often require detailed insights into SQL Server query execution and behavior. SQL Server provides various tools to gather and analyze this information. One particularly useful tool is a custom stored procedure, sp_query_logger, which logs detailed query statistics and execution plans. This blog will walk you through the setup and usage of sp_query_logger, highlighting its importance in troubleshooting performance issues.

Why Logging SQL Server Query Performance is Important

Query logging is essential for several reasons:
  • Identify Performance Bottlenecks: By logging query execution statistics, you can identify slow-running queries and understand their impact on overall performance.
  • Analyze Query Plans: Capturing query plans helps in understanding how SQL Server executes a query, which is crucial for optimizing performance.
  • Track Query Execution: Monitoring query execution over time helps in identifying trends and understanding how changes to the database or application affect performance.
  • Troubleshoot Issues: When users report slow performance, query logs provide the data needed to diagnose and resolve these issues quickly.

Setting Up sp_query_logger

The sp_query_logger stored procedure logs query statistics and plans into a table named query_logger. Here's how to set it up:

Create the Stored Procedure: This step creates or alters the sp_query_logger procedure, which captures and logs query performance data.

-- Create or alter the sp_query_logger procedure
if object_id('dbo.sp_query_logger') is null
    exec ('create procedure dbo.sp_query_logger as return 0;');
go

alter procedure sp_query_logger
    @dbid smallint,
    @search_string nvarchar(4000) = N'%%',
    @log_retention_days int = 2
with recompile
as
    if not exists (select * from information_schema.tables where table_name = N'query_logger')
    begin
        create table query_logger
        (
            logged_at datetime,
            dbid smallint,
            sql_handle varbinary(64),
            statement_start_offset int,
            statement_end_offset int,
            plan_generation_num bigint,
            plan_handle varbinary(64),
            query_text nvarchar(max),
            query_plan xml,
            creation_time datetime,
            last_execution_time datetime,
            total_elapsed_time bigint,
            execution_count bigint,
            last_elapsed_time bigint,
            min_elapsed_time bigint,
            max_elapsed_time bigint,
            total_rows bigint,
            last_rows bigint,
            min_rows bigint,
            max_rows bigint,
            total_worker_time bigint,
            last_worker_time bigint,
            min_worker_time bigint,
            max_worker_time bigint,
            total_physical_reads bigint,
            last_physical_reads bigint,
            min_physical_reads bigint,
            max_physical_reads bigint,
            total_logical_reads bigint,
            last_logical_reads bigint,
            min_logical_reads bigint,
            max_logical_reads bigint,
            total_logical_writes bigint,
            last_logical_writes bigint,
            min_logical_writes bigint,
            max_logical_writes bigint
        );
    end

    delete from query_logger
    where logged_at < dateadd(day, datediff(day, 0, getdate()), -@log_retention_days);

    insert into query_logger
    (
        logged_at,
        dbid,
        sql_handle,
        statement_start_offset,
        statement_end_offset,
        plan_generation_num,
        plan_handle,
        query_text,
        query_plan,
        creation_time,
        last_execution_time,
        total_elapsed_time,
        execution_count,
        last_elapsed_time,
        min_elapsed_time,
        max_elapsed_time,
        total_rows,
        last_rows,
        min_rows,
        max_rows,
        total_worker_time,
        last_worker_time,
        min_worker_time,
        max_worker_time,
        total_physical_reads,
        last_physical_reads,
        min_physical_reads,
        max_physical_reads,
        total_logical_reads,
        last_logical_reads,
        min_logical_reads,
        max_logical_reads,
        total_logical_writes,
        last_logical_writes,
        min_logical_writes,
        max_logical_writes
    )
    select
        getdate(),
        dest.dbid,
        deqs.sql_handle,
        deqs.statement_start_offset,
        deqs.statement_end_offset,
        deqs.plan_generation_num,
        deqs.plan_handle,
        dest.text,
        deqp.query_plan,
        deqs.creation_time,
        deqs.last_execution_time,
        deqs.total_elapsed_time,
        deqs.execution_count,
        deqs.last_elapsed_time,
        deqs.min_elapsed_time,
        deqs.max_elapsed_time,
        deqs.total_rows,
        deqs.last_rows,
        deqs.min_rows,
        deqs.max_rows,
        deqs.total_worker_time,
        deqs.last_worker_time,
        deqs.min_worker_time,
        deqs.max_worker_time,
        deqs.total_physical_reads,
        deqs.last_physical_reads,
        deqs.min_physical_reads,
        deqs.max_physical_reads,
        deqs.total_logical_reads,
        deqs.last_logical_reads,
        deqs.min_logical_reads,
        deqs.max_logical_reads,
        deqs.total_logical_writes,
        deqs.last_logical_writes,
        deqs.min_logical_writes,
        deqs.max_logical_writes
    from
        sys.dm_exec_query_stats deqs
        cross apply
        sys.dm_exec_sql_text(deqs.plan_handle) as dest
        cross apply
        sys.dm_exec_query_plan(deqs.plan_handle) as deqp
    where
        dest.dbid = @dbid
    and
        dest.text like @search_string;
go

Using sp_query_logger

To use sp_query_logger, execute it with the appropriate parameters. For example, to log queries from database ID 5 that match a specific search string:

execute sp_query_logger
    @dbid = 5,
    @search_string = N'%SELECT * from AUDITLOG;%',
    @log_retention_days = 3;

This setup logs detailed statistics and plans for queries that match the search string, allowing you to analyze performance issues and optimize the query or index usage. The sp_query_logger procedure can be scheduled to run a few times a day to record the execution of the SQL query in the search string, capturing insights about the SQL.

select * from query_logger;
sp-query-logger

Understanding the Logged Data

The query_logger table captures extensive information about each logged query:

Column                                                        | Description
------------------------------------------------------------- | ------------------------------------------------------------
logged_at                                                     | Timestamp when the log entry was created.
dbid                                                          | Database ID where the query was executed.
sql_handle                                                    | A unique identifier for the SQL text of the query.
statement_start_offset                                        | The starting position of the statement within the batch.
statement_end_offset                                          | The ending position of the statement within the batch.
plan_handle                                                   | A unique identifier for the query plan.
query_text                                                    | The SQL text of the query.
query_plan                                                    | The execution plan for the query in XML format.
creation_time                                                 | When the query plan was created.
last_execution_time                                           | When the query was last executed.
total_elapsed_time                                            | Total time the query has taken to execute.
execution_count                                               | Number of times the query has been executed.
min_elapsed_time                                              | Minimum execution times.
max_elapsed_time                                              | Maximum execution times.
total_rows, min_rows, max_rows                                | Row count metrics.
total_worker_time, min_worker_time, max_worker_time           | CPU time metrics.
total_physical_reads, min_physical_reads, max_physical_reads  | Disk read metrics.
total_logical_reads, min_logical_reads, max_logical_reads     | Memory read metrics.
total_logical_writes, min_logical_writes, max_logical_writes: | Memory write metrics.

Conclusion

Implementing sp_query_logger in SQL Server provides valuable insights into SQL Server query performance, helping you identify and resolve performance bottlenecks effectively. By logging query statistics and execution plans, you gain a powerful tool for database performance tuning and troubleshooting.

Related content



Rate Your Experience

: 89 : 1


Last updated in July, 2024

Online Tests
Read more

Cloud Technology
Read more

Oracle Database
Read more

MSSQL Database
Read more

PostGres Database
Read more

Linux
Read more

ASP/C#
Read more

Quick Access