With the help of the SET STATISTICS TIME ON statement, we can easily report the execution time statistics of a query. In this article, we will learn how to report the query execution time statistics through this statement.
Introduction
In today’s world, users have the most natural right to want database applications to run at top speed. Therefore, our queries need to be processed by databases as fast as possible. In order to solve this problem, our queries must work as fast as possible. At this point, measuring the key metrics of the queries always helps to understand their performance behaviors. In this context, the SET STATISTICS TIME ON statement offers a very short but very useful report about the execution time statistics of a query.
Measuring Time Statistics of a Query
The SET STATISTICS TIME ON statement returns a text report and this report includes how long it is taken by the query compilation and execution time of a query. To enable this option for any query we need to execute the SET STATISTICS TIME ON command before the execution of the query so that the execution time report will appear in the message of the query result panel until we turn off this option. All values of the report are shown in milliseconds type and its syntax like as below:
|
1 |
SET STATISTICS TIME { ON | OFF } |
In the following example, we will enable the time statistics before executing the select statement and the report will be shown in the message tab.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 |
SET STATISTICS TIME ON; GO SELECT soh.[SalesPersonID], p.[FirstName] + ' ' + COALESCE(p.[MiddleName], '') + ' ' + p.[LastName] AS [FullName], e.[JobTitle], st.[Name] AS [SalesTerritory], soh.[SubTotal], YEAR(DATEADD(m, 6, soh.[OrderDate])) AS [FiscalYear] FROM [Sales].[SalesPerson] sp INNER JOIN [Sales].[SalesOrderHeader] soh ON sp.[BusinessEntityID] = soh.[SalesPersonID] INNER JOIN [Sales].[SalesTerritory] st ON sp.[TerritoryID] = st.[TerritoryID] INNER JOIN [HumanResources].[Employee] e ON soh.[SalesPersonID] = e.[BusinessEntityID] INNER JOIN [Person].[Person] p ON p.[BusinessEntityID] = sp.[BusinessEntityID]; GO |
To turn time statistics off, we need to set it to OFF.
|
1 |
SET STATISTICS TIME OFF; |
- Tip: You can use the Statistics Parser website to make your reports fancier
Parse and Compile Time
When we want to execute a query on SQL Server, it needs to parse the query to validate its syntax and then the query optimizer compiles the query in order to generate an optimal query plan. How much time was spent in these two phases is shown in the parse and compile time section of the report. In this part of the report CPU time indicates the time that how long it takes to parse and compile on CPU. The elapsed time indicates the total time that is spent to parse and compile the query and it also includes the CPU time. At the same time, we can see the same value in the CompileTime attribute of the select operator of the query plan.
When we execute the same query the second time, most likely we will see this time statistics as zero. This situation describes that the query optimizer does not consume any time to compile or parse the query because the execution plan of the query is stored in the plan cache and has been reused by the query optimizer.
However, the CompileTime attribute still continues to show 32 milliseconds because this select operator attribute value indicates the time elapsed in the last compilation of the query plan.
Execution Times
In the Execution Times section of the SET STATISTICS TIME ON statement output, we can find out the time taken by the SQL server to complete the execution of the compiled query plan. The CPU time indicates the total time that is spent by the CPU(s). The elapsed time is the total time to complete the execution of the query. This elapsed time includes all I/O operations time, wait times, and the time is taken to transfer the resultset to the client. Now let’s prove this working mechanism. Firstly, we enable the actual execution plan and run the following query.
|
1 2 3 4 5 6 |
SET STATISTICS TIME ON; GO SELECT * FROM sales.Store INNER JOIN sales.Customer ON sales.Store.BusinessEntityID = sales.Customer.StoreID INNER JOIN sales.SalesOrderHeader ON sales.Customer.CustomerID = sales.SalesOrderHeader.CustomerID INNER JOIN sales.SalesOrderDetail ON sales.SalesOrderHeader.SalesOrderID = sales.SalesOrderDetail.SalesOrderID |
Query optimizer finds the query plan in the plan cache for this reason the parse and compiles time statistics display zero. The report shows that the query has been completed in 3823 milliseconds and 562 milliseconds are consumed in the CPU. Under the WaitStats property of the select operator, we can find out which wait type caused the slowing down of the query. For the example query, the ASYNC_NETWORK_IO waittype is displayed.
To eliminate this problem on the SQL Server Management Studio (SSMS), we can check the Discard results after the execution option so that SSMS does not have to show the result of the query in a grid.
We will open a new query tab and execute the same query.
As a result, we have demonstrated that the resource waiting times are added to the elapsed time.
In some cases, we can see that the CPU time is bigger than elapsed time. Such as, we can observe this type of situation when we run the following query.
|
1 2 3 4 5 6 7 8 9 |
SET STATISTICS TIME ON GO SELECT ProductID,SUM(LineTotal) AS TotalsOfLine , SUM(UnitPrice) AS TotalsOfPrice, SUM(UnitPriceDiscount) AS TotalsOfDiscount FROM Sales.SalesOrderDetail SOrderDet INNER JOIN Sales.SalesOrderHeader SalesOr ON SOrderDet.SalesOrderID = SalesOr.SalesOrderID WHERE PurchaseOrderNumber LIKE 'PO%' GROUP BY ProductID |
In the select operator of the execution plan of this query, we can see a Degree of Parallelism attribute and this attribute indicates how many separate CPUs were running during the execution of the query. That’s why the CPU time is bigger than the elapsed time. Another attribute that is related to parallel query processing is ThreadStat. ThreadStat shows us how many threads were reserved and used by the query.
Conclusion
In this article, we have learned how to use the SET STATISTICS TIME ON statement and how to interpret its result along with a query.
Most of his career has been focused on SQL Server Database Administration and Development. His current interests are in database administration and Business Intelligence. You can find him on LinkedIn.
View all posts by Esat Erkec
- SQL Performance Tuning tips for newbies - April 15, 2024
- SQL Unit Testing reference guide for beginners - August 11, 2023
- SQL Cheat Sheet for Newbies - February 21, 2023