Pages

Wednesday, December 31, 2014

Query Details Report Error

If we click on the query detail hyperlink on the Query Statistics History report or any other report with a query detail hyperlink:


We may get this error:


The error doesn’t make much sense so if we look at the SQL Server error log, we will find out that tempdb fill out:

Could not allocate space for object 'dbo.SORT temporary run storage:  142388431486976' in database 'tempdb' because the 'PRIMARY' filegroup is full. Create disk space by deleting unneeded files, dropping objects in the filegroup, adding additional files to the filegroup, or setting autogrowth on for existing files in the filegroup.

Moreover if we run SQL Server Profiler, we will find the stored procedure that the report uses:

exec snapshots.rpt_query_stats

Analyzing the T-SQL, the culprit is the subquery used to find the dense rank, it doesn’t have any "where" clause (line 29 below) so it will scan the entire snapshots.query_stats table.

 

    SELECT 
        REPLACE (REPLACE (REPLACE (REPLACE (REPLACE (REPLACE (
            LEFT (LTRIM (stmtsql.query_text), 100)
            , CHAR(9), ' '), CHAR(10), ' '), CHAR(13), ' '), '   ', ' '), '  ', ' '), '  ', ' ') AS flat_query_text, 
        t.*, 
        master.dbo.fn_varbintohexstr (t.sql_handle) AS sql_handle_str, 
        stmtsql.*
    FROM 
    (
        SELECT 
            stat.sql_handle, stat.statement_start_offset, stat.statement_end_offset, snap.source_id, 
            SUM (stat.snapshot_execution_count) AS execution_count, 
            SUM (stat.snapshot_execution_count) / (@interval_sec / 60) AS executions_per_min, 
            SUM (stat.snapshot_worker_time / 1000) AS total_cpu, 
            SUM (stat.snapshot_worker_time / 1000) / @interval_sec AS avg_cpu_per_sec, 
            SUM (stat.snapshot_worker_time / 1000.0) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_cpu_per_exec, 
            SUM (stat.snapshot_physical_reads) AS total_physical_reads, 
            SUM (stat.snapshot_physical_reads) / @interval_sec AS avg_physical_reads_per_sec, 
            SUM (stat.snapshot_physical_reads) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_physical_reads_per_exec, 
            SUM (stat.snapshot_logical_writes) AS total_logical_writes, 
            SUM (stat.snapshot_logical_writes) / @interval_sec AS avg_logical_writes_per_sec, 
            SUM (stat.snapshot_logical_writes) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_logical_writes_per_exec, 
            SUM (stat.snapshot_elapsed_time / 1000) AS total_elapsed_time, 
            SUM (stat.snapshot_elapsed_time / 1000) / @interval_sec AS avg_elapsed_time_per_sec, 
            SUM (stat.snapshot_elapsed_time / 1000.0) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_elapsed_time_per_exec, 
            COUNT(*) AS row_count, COUNT(DISTINCT plan_number) AS plan_count
        FROM
        (
            SELECT *, DENSE_RANK() OVER (ORDER BY plan_handle, creation_time) AS plan_number
            FROM snapshots.query_stats s
        ) AS stat
        INNER JOIN core.snapshots snap ON stat.snapshot_id = snap.snapshot_id
        WHERE
            snap.instance_name = @instance_name 
            AND stat.sql_handle = @sql_handle 
            AND stat.statement_start_offset = @statement_start_offset 
            AND stat.statement_end_offset = @statement_end_offset
            AND snap.snapshot_time_id BETWEEN @start_snapshot_time_id AND @end_snapshot_time_id
        GROUP BY stat.sql_handle, stat.statement_start_offset, stat.statement_end_offset, snap.source_id
    ) t
    LEFT OUTER JOIN snapshots.notable_query_text sql ON t.sql_handle = sql.sql_handle and sql.source_id = t.source_id
    OUTER APPLY snapshots.fn_get_query_text (t.source_id, t.sql_handle, t.statement_start_offset, t.statement_end_offset) AS stmtsql

Looking at the query plan, it will sort the entire snapshots.query_stats table and it will cause tempdb full if there is a large amount of rows.


The workaround is to add "join" and the "where" clause (line 32 above) inside the subquery (line 31 below) to limit the number of rows.

 
    SELECT 
        REPLACE (REPLACE (REPLACE (REPLACE (REPLACE (REPLACE (
            LEFT (LTRIM (stmtsql.query_text), 100)
            , CHAR(9), ' '), CHAR(10), ' '), CHAR(13), ' '), '   ', ' '), '  ', ' '), '  ', ' ') AS flat_query_text, 
        t.*, 
        master.dbo.fn_varbintohexstr (t.sql_handle) AS sql_handle_str, 
        stmtsql.*
    FROM 
    (
        SELECT 
            stat.sql_handle, stat.statement_start_offset, stat.statement_end_offset, stat.source_id, 
            SUM (stat.snapshot_execution_count) AS execution_count, 
            SUM (stat.snapshot_execution_count) / (@interval_sec / 60) AS executions_per_min, 
            SUM (stat.snapshot_worker_time / 1000) AS total_cpu, 
            SUM (stat.snapshot_worker_time / 1000) / @interval_sec AS avg_cpu_per_sec, 
            SUM (stat.snapshot_worker_time / 1000.0) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_cpu_per_exec, 
            SUM (stat.snapshot_physical_reads) AS total_physical_reads, 
            SUM (stat.snapshot_physical_reads) / @interval_sec AS avg_physical_reads_per_sec, 
            SUM (stat.snapshot_physical_reads) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_physical_reads_per_exec, 
            SUM (stat.snapshot_logical_writes) AS total_logical_writes, 
            SUM (stat.snapshot_logical_writes) / @interval_sec AS avg_logical_writes_per_sec, 
            SUM (stat.snapshot_logical_writes) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_logical_writes_per_exec, 
            SUM (stat.snapshot_elapsed_time / 1000) AS total_elapsed_time, 
            SUM (stat.snapshot_elapsed_time / 1000) / @interval_sec AS avg_elapsed_time_per_sec, 
            SUM (stat.snapshot_elapsed_time / 1000.0) / CASE SUM (stat.snapshot_execution_count) WHEN 0 THEN 1 ELSE SUM (stat.snapshot_execution_count) END AS avg_elapsed_time_per_exec, 
            COUNT(*) AS row_count, COUNT(DISTINCT plan_number) AS plan_count
        FROM
        (
            SELECT s.*, snap.source_id, DENSE_RANK() OVER (ORDER BY plan_handle, creation_time) AS plan_number
            FROM snapshots.query_stats s
            INNER JOIN core.snapshots snap ON s.snapshot_id = snap.snapshot_id
            WHERE
               snap.instance_name = @instance_name 
               AND s.sql_handle = @sql_handle 
               AND s.statement_start_offset = @statement_start_offset 
               AND s.statement_end_offset = @statement_end_offset
               AND snap.snapshot_time_id BETWEEN @start_snapshot_time_id AND @end_snapshot_time_id
        ) AS stat
        --move this filter to the inner subquery above to avoid a large table scan and spill to tempdb
  --INNER JOIN core.snapshots snap ON stat.snapshot_id = snap.snapshot_id
        --WHERE
        --    snap.instance_name = @instance_name 
        --    AND stat.sql_handle = @sql_handle 
        --    AND stat.statement_start_offset = @statement_start_offset 
        --    AND stat.statement_end_offset = @statement_end_offset
        --    AND snap.snapshot_time_id BETWEEN @start_snapshot_time_id AND @end_snapshot_time_id
        GROUP BY stat.sql_handle, stat.statement_start_offset, stat.statement_end_offset, stat.source_id
    ) t
    LEFT OUTER JOIN snapshots.notable_query_text sql ON t.sql_handle = sql.sql_handle and sql.source_id = t.source_id
    OUTER APPLY snapshots.fn_get_query_text (t.source_id, t.sql_handle, t.statement_start_offset, t.statement_end_offset) AS stmtsql

Thus it will produce a most efficient query plan

 
Here it is the Connect item link
 

No comments:

Post a Comment