0

There is this weird behavior of Query Store runtime stats that I observe at many of my servers with different scenarios that makes me not to believe these stats. Or am I wrong in something?

E.g. trivial query like this with a given query plan:

enter image description here

Stats (sys.query_store_runtime_stats) reports absolutely insane number of max_logical_io_reads at some accidental interval:

enter image description here

But table has only 27 pages allocated altogether!

I am experiencing this phenomenon with different queries cross many environments. And it's ruining my regressed query analysis.

Queries with different numbers of reads don't have different plans.

The heap table shown only updates and inserts rarely. It's just coincident I used a heap as an example. I experience this with clustered tables too.

0

2 Answers 2

7

Pathology!

This could happen to queries in ways that wouldn't impact the plans:

Additionally some selects that cause writes may trigger additional reads if there are stats updates, spills, spools, etc. Though none of those show in your plan, someone else may some along later and find this tidbit useful.

Heaps

DROP TABLE IF EXISTS dbo.el_heapo;
CREATE TABLE dbo.el_heapo ( col1 BIGINT, col2 VARCHAR(8000) DEFAULT 'A' );

INSERT dbo.el_heapo ( col1 )
SELECT TOP 1000000
       x.rn
FROM   (   SELECT     ROW_NUMBER() OVER ( ORDER BY ( SELECT 1 / 0 )) AS rn
           FROM       sys.messages AS m
           CROSS JOIN sys.messages AS m2 ) AS x;

Run a simple query:

SELECT COUNT_BIG(*)
FROM   dbo.el_heapo;

Table 'el_heapo'. Scan count 1, logical reads 2718 
CPU time = 62 ms,  elapsed time = 62 ms.

Look at the table: No forwarded fetches.

SELECT OBJECT_NAME(ddips.object_id) AS TableName, 
       ddips.index_type_desc, 
       ddips.forwarded_record_count
FROM   sys.dm_db_index_physical_stats(DB_ID(), 
                                      OBJECT_ID('dbo.el_heapo'), 
                                      0, 
                                      NULL, 
                                      'DETAILED') AS ddips;

Cause some forwarded fetches:

UPDATE dbo.el_heapo
SET    col2 = REPLICATE('Z', 1000)
WHERE  col1 % 3 = 0;

If you run the count and forwarded fetch query again, you should see:

~330k forwarded fetches

Table 'el_heapo'. Scan count 1, logical reads 380564
 SQL Server Execution Times:
   CPU time = 359 ms,  elapsed time = 360 ms.

But the execution plan will be the same.

Indexes

Create a dummy table do I don't mess up my real Users table:

SELECT *
INTO dbo.TempUsers
FROM StackOverflow2013.dbo.Users AS u;

CREATE UNIQUE CLUSTERED INDEX c ON dbo.TempUsers(Id);

Check on the table size:

SELECT   TOP 2147483647 
         s.name AS schema_name,
         OBJECT_NAME(ps.object_id) AS table_name,         
         i.name AS index_name,
         ps.row_count,
         ps.in_row_used_page_count,
         (ps.reserved_page_count * 8. / 1024.) AS reserved_MB,
         (ps.lob_reserved_page_count * 8. / 1024.) AS reserved_LOB_MB,
         (ps.row_overflow_reserved_page_count * 8. / 1024.) AS reserved_row_overflow_MB
FROM     sys.dm_db_partition_stats AS ps
JOIN     sys.objects AS so
    ON  ps.object_id = so.object_id
    AND so.is_ms_shipped = 0
    AND so.type <> 'TF'
JOIN     sys.schemas AS s
    ON s.schema_id = so.schema_id
JOIN sys.indexes AS i
    ON ps.object_id = i.object_id
    AND ps.index_id = i.index_id
ORDER BY ps.object_id, ps.index_id, ps.partition_number

Should be 44,450 pages and 348MB.

Simple query:

SELECT COUNT(*)
FROM dbo.TempUsers AS tu

Table 'TempUsers'. Scan count 1, logical reads 44439
   CPU time = 219 ms,  elapsed time = 229 ms.

Update the DisplayName column to be the max length (nvarchar 40):

UPDATE t
SET t.DisplayName = t.DisplayName + REPLICATE('A', 40 - (DATALENGTH(t.DisplayName) / 2))
FROM dbo.TempUsers AS t

Now the table is much larger:

88,392 pages, 691MB.

Query results:

Table 'TempUsers'. Scan count 1, logical reads 88381
   CPU time = 250 ms,  elapsed time = 245 ms.
2
  • As mentioned this not an unique case I see this many times while analysing Query Store reports. Index / table rebuild wouldn't reflect in query store stats of a given query. Maybe I should report it to Microsoft as an bug.
    – jericzech
    Commented Sep 3, 2019 at 22:05
  • @jerik1 if you rebuild the table or indexes, you would fix the problems in both of the scenarios I presented, which would make reads go "back to normal". But sure, open a case with Microsoft. Commented Sep 3, 2019 at 22:06
3

One possible explanation for what you're seeing is that the query with high logical reads got a RID lookup plan (assuming there is a nonclustered index on the heap). This could quickly result in "logical reads" exceeding the total number of pages in the table, depending on how many rows were returned.

You should join to sys.query_store_plan to see if there are different plan_ids for that query_id.

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.