Actual Time Statistics in Execution Plans: Elapsed CPU Time and more

execution-plan-music-video-setOne of the coolest things to come to SQL Server Management Studio in a long time might be hard to see at first: it’s tucked away in the Properties Window.

But once you see it, it might just be something that you use all the time.

SQL Server now shows Actual Elapsed CPU Time and Actual Elapsed Time (duration) for each operator in an Actual Execution Plan

For SQL Server 2016 and 2014 SP2 and higher, actual execution plans contain a bunch of new information on each operator, including how much CPU they burn, how long it takes, and how much IO is done by that operator. This was a little hard to use for a while because the information was only visible in the XML of the execution plan.

But now you can see this information with just a few clicks in the properties window of a plan. Here’s the announcement from the SSMS team.

Watch an example: Finding Actual Time Statistics in an Execution Plan

Here’s an animated gif of running a query with ‘Actual Execution Plans’ turned on, then right-clicking to see the Properties window and looking at Elapsed CPU Time (ms) and Elapsed Time (ms) for specific operators:

actual-elapsed-time-demo

Click to see a larger image

Some things to note:

  • The query took just over 8 seconds to execute. (It’s shorter in the .gif because I sped up the video)
  • The total CPU time on the index scan shows as 20+ seconds. That’s because it’s adding up the CPU time for all the threads– this query is running at MAXDOP 4. The threads were pretty evenly distributed on the index scan and the longest one took about 5.2 seconds
  • Notice how Thread 0 doesn’t accrue time? It’s the “watcher thread” that just waits for the worker threads to complete. It’s supposed to be lazy like that.
  • The threads on the Stream Aggregate operator took some time as well–  8.4 seconds on the longest thread

Wait, Kendra, those don’t add up!

No, they don’t. That’s OK! As data flows through this execution plan, multiple operators can be busy at the same time. SQL Server doesn’t have to wait for the index scan to finish before it works on the Compute Scalar and the Stream Aggregate operator – in this case, these operators are non-blocking. (Craig Freedman writes about blocking vs. non-blocking operators in this post.)

Let’s watch the same query with Live Query Statistics turned on

Here’s the same query running with Live Query Stats. You can see that the data is flowing through and that multiple operators are working at the same time.

We get a lot of cool information from this view, but we don’t get the same detail that we get for Actual Elapsed CPU Time and Actual Elapsed Time in the properties window of an actual execution plan. These two tools complement each other nicely.

live-query-execution-demo

Click to see a larger image

You can also see Actual IO Statistics

 

It’s not just about the CPUs, for each operator you can also see how many logical reads, read ahead reads, and physical reads done by that operator. And it’s all right there in the properties window now. Enjoy!

, , , , , ,

3 Responses to Actual Time Statistics in Execution Plans: Elapsed CPU Time and more

  1. Carl Thompson December 21, 2016 at 8:40 am #

    Hi Kendra,

    Thanks for the blog and providing an update regarding the Actual Time Statistics. However, even though we have SQL Server 2016 when I view the properties of the operator the Actual Time Statistics do not show in the properties pane.

    Is there a setting that needs to be enabled? Or could this b related to our compatibility level (which is 100)?

    Thanks,

    • Kendra Little December 22, 2016 at 9:16 am #

      I don’t believe database compatibility level matters. Couple things to check:

      1) Are you running the latest release of SSMS, which you updated within the last month or two? Updating SSMS is required to see it in the properties pane.

      2) Are you looking at actual execution plans? This won’t show up in estimated plans, or plans stored in SQL Server’s cache. You have to run it live with actual plans enabled.

      You can find this information in the XML of an actual plan by searching for: RunTimeInformation

      This post shows what the XML looks like: https://blogs.msdn.microsoft.com/sql_server_team/added-per-operator-level-performance-stats-for-query-processing/

Trackbacks/Pingbacks

  1. Columnstore Indexes and Computed Columns in SQL Server 2016 - by Kendra Little - December 29, 2016

    […] is an actual execution plan, so I have Actual Time Statistics, and I can see exactly how much CPU was burned to compute BirthYear for every row. Scrolling up in […]

Leave a Reply