none
Query Store execution time is not updated properly

    Question

  • I am using the following query to get some statistics from the database.

    SELECT 
    	query_sql_text AS TEXT, 
    	St.count_executions AS EXECUTION_COUNT, 
    	St.avg_duration AS AVG_TIME, 
    	St.last_duration AS LAST_TIME, 
    	St.last_execution_time AS LAST_EXECUTED 
    	FROM sys.query_store_runtime_stats St  
    	JOIN sys.query_store_plan AS Pl ON St.plan_id = Pl.plan_id 
    	JOIN sys.query_store_query AS Qry ON Pl.query_id = Qry.query_id 
    	JOIN sys.query_store_query_text AS Txt ON Qry.query_text_id = Txt.query_text_id 

    But, the avg_duration, last_duration values are 0 for all the DML queries almost all the time. However if I keep on executing a DML query the times are getting updated. This is not reliable at all? Why is it happening?

    I tried reducing the Statistics Collection Interval

    ALTER DATABASE AdventureWorks2014 SET QUERY_STORE (INTERVAL_LENGTH_MINUTES = 1); 

    Still no improvement.

    SELECT @@version report:

    Microsoft SQL Server 2016 (SP1) (KB3182545) - 13.0.4001.0 (X64)   Oct 28 2016 18:17:30   Copyright (c) Microsoft Corporation  Developer Edition (64-bit) on Windows Server 2016 Essentials 6.3 <X64> (Build 14393: ) 

    Other than that, I have forced parameterization.



    • Edited by Deepan94 Saturday, March 18, 2017 11:05 AM
    Saturday, March 18, 2017 8:12 AM

All replies

  • So how long is the execution time for the queries you are running? I ran this in a database called Northgale which is an inflated version of Northwind:

    ALTER DATABASE CURRENT SET QUERY_STORE = ON
    
    SELECT SUM(Freight) FROM Orders
    
    SELECT
         query_sql_text AS TEXT,
         St.count_executions AS EXECUTION_COUNT,
         St.avg_duration AS AVG_TIME,
         St.last_duration AS LAST_TIME,
         St.last_execution_time AS LAST_EXECUTED
         FROM sys.query_store_runtime_stats St
         JOIN sys.query_store_plan AS Pl ON St.plan_id = Pl.plan_id
         JOIN sys.query_store_query AS Qry ON Pl.query_id = Qry.query_id
         JOIN sys.query_store_query_text AS Txt ON Qry.query_text_id = Txt.query_text_id

    I got this output
    [code]
    TEXT                               EXECUTION_COUNT   AVG_TIME   LAST_TIME   LAST_EXECUTED
    SELECT SUM(Freight) FROM Orders   1                 1464118   1464118   2017-03-18 10:49:24.2200000 +00:00
    {/code]

    What does SELECT @@version report?

    Saturday, March 18, 2017 10:52 AM
  • SELECT @@version report:

    Microsoft SQL Server 2016 (SP1) (KB3182545) - 13.0.4001.0 (X64)   Oct 28 2016 18:17:30   Copyright (c) Microsoft Corporation  Developer Edition (64-bit) on Windows Server 2016 Essentials 6.3 <X64> (Build 14393: ) 

    Other than that, I have forced parameterization.

    Saturday, March 18, 2017 11:05 AM
  • I have a slightly newer build, 4202, but as far as I know that is only a security fix that is added. I tried to set the database in forced parameterization, but that did not really change things.

    Saturday, March 18, 2017 1:19 PM
  • But, 0 execution time is really weird. How on earth a query take no time (0 microseconds)  to execute. Are there any result caching happening ?
    Saturday, March 18, 2017 6:21 PM
  • But, 0 execution time is really weird. How on earth a query take no time (0 microseconds)  to execute. Are there any result caching happening ?

    So what query are you running? A query like "SELECT * FROM tbl WHERE pid = 123" may well take less than a millisecond to run. (And execution times below a millisecond may not be recorded.)

    Saturday, March 18, 2017 7:29 PM
  • So what query are you running? A query like "SELECT * FROM tbl WHERE pid = 123" may well take less than a millisecond to run. (And execution times below a millisecond may not be recorded.)

    Queries are fairly complicated.

    For example:

    SELECT DISTINCT p.LastName, p.FirstName FROM Person.Person AS p JOIN HumanResources.Employee AS e ON e.BusinessEntityID = p.BusinessEntityID WHERE 5000.00 IN (SELECT Bonus FROM Sales.SalesPerson AS sp WHERE e.BusinessEntityID = sp.BusinessEntityID)
    It takes around 66 milliseconds to complete (checked the statistics time). But 0 in query store. 

     
    Tuesday, March 21, 2017 4:26 AM
  • Hm, that should appear with a non-zero time. I'm afraid that I don't have any further ideas.

    Tuesday, March 21, 2017 11:02 PM