{"id":1049,"date":"2016-01-21T09:00:32","date_gmt":"2016-01-21T17:00:32","guid":{"rendered":"http:\/\/3.209.169.194\/blogs\/glenn\/?p=1049"},"modified":"2017-04-13T12:28:51","modified_gmt":"2017-04-13T19:28:51","slug":"sql-server-diagnostic-information-queries-detailed-day-21","status":"publish","type":"post","link":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/","title":{"rendered":"SQL Server Diagnostic Information Queries Detailed, Day 21"},"content":{"rendered":"

For Day 21 of this series, we start out with Query #48<\/strong>, which is SP Avg Elapsed Time. This query retrieves information from the sys.procedures<\/a> object catalog view and the sys.dm_exec_procedure_stats<\/a> dynamic management view about the cached stored procedures that have the highest average elapsed time in the current database. Query #48 is shown in Figure 1.<\/p>\n

\n
\n
   1:<\/span> -- Top Cached SPs By Avg Elapsed Time (Query 48) (SP Avg Elapsed Time)<\/span><\/pre>\n
<\/p>\n
   2:<\/span> SELECT<\/span> TOP<\/span>(25) p.name AS<\/span> [SP Name], qs.min_elapsed_time, qs.total_elapsed_time\/qs.execution_count AS<\/span> [avg_elapsed_time], <\/pre>\n
<\/p>\n
   3:<\/span> qs.max_elapsed_time, qs.last_elapsed_time, qs.total_elapsed_time, qs.execution_count, <\/pre>\n
<\/p>\n
   4:<\/span> ISNULL(qs.execution_count\/DATEDIFF(Minute<\/span>, qs.cached_time, GETDATE()), 0) AS<\/span> [Calls\/Minute<\/span>], <\/pre>\n
<\/p>\n
   5:<\/span> qs.total_worker_time\/qs.execution_count AS<\/span> [AvgWorkerTime], <\/pre>\n
<\/p>\n
   6:<\/span> qs.total_worker_time AS<\/span> [TotalWorkerTime], qs.cached_time<\/pre>\n
<\/p>\n
   7:<\/span> FROM<\/span> sys.procedures AS<\/span> p WITH<\/span> (NOLOCK)<\/pre>\n
<\/p>\n
   8:<\/span> INNER<\/span> JOIN<\/span> sys.dm_exec_procedure_stats AS<\/span> qs WITH<\/span> (NOLOCK)<\/pre>\n
<\/p>\n
   9:<\/span> ON<\/span> p.[object_id] = qs.[object_id]<\/pre>\n
<\/p>\n
  10:<\/span> WHERE<\/span> qs.database_id = DB_ID()<\/pre>\n
<\/p>\n
  11:<\/span> ORDER<\/span> BY<\/span> avg_elapsed_time DESC<\/span> OPTION<\/span> (RECOMPILE);<\/pre>\n
<\/p>\n
  12:<\/span>  <\/pre>\n
<\/p>\n
  13:<\/span> -- This helps you find high average elapsed time cached stored procedures that<\/span><\/pre>\n
<\/p>\n
  14:<\/span> -- may be easy to<\/span> optimize with<\/span> standard query tuning techniques<\/pre>\n
<\/div>\n<\/div>\n
Figure 1: Query #48 SP Avg Elapsed Time<\/strong><\/p>\n
This query gives you a chance to look like a super hero<\/strong>. It shows you the cached stored procedures that have the highest average elapsed time in the current database. This basically gives you a list of stored procedures to look at much more closely, to see if you can do any query optimization or index tuning to make them dramatically faster. If you are able to do your DBA magic and make a long-running stored procedure run much, much faster, people are going to notice, and perhaps think you are some sort of evil genius.<\/p>\n
 <\/p>\n
Query #49<\/strong> is SP Worker Time. This query retrieves information from the sys.procedures<\/a> object catalog view and the sys.dm_exec_procedure_stats<\/a> dynamic management view about the cached stored procedures that have the highest cumulative worker time in the current database. Query #49 is shown in Figure 2.<\/p>\n
\n
\n
   1:<\/span> -- Top Cached SPs By Total Worker time. Worker time relates to CPU cost  (Query 49) (SP Worker Time)<\/span><\/pre>\n
<\/p>\n
   2:<\/span> SELECT<\/span> TOP<\/span>(25) p.name AS<\/span> [SP Name], qs.total_worker_time AS<\/span> [TotalWorkerTime], <\/pre>\n
<\/p>\n
   3:<\/span> qs.total_worker_time\/qs.execution_count AS<\/span> [AvgWorkerTime], qs.execution_count, <\/pre>\n
<\/p>\n
   4:<\/span> ISNULL(qs.execution_count\/DATEDIFF(Minute<\/span>, qs.cached_time, GETDATE()), 0) AS<\/span> [Calls\/Minute<\/span>],<\/pre>\n
<\/p>\n
   5:<\/span> qs.total_elapsed_time, qs.total_elapsed_time\/qs.execution_count <\/pre>\n
<\/p>\n
   6:<\/span> AS<\/span> [avg_elapsed_time], qs.cached_time<\/pre>\n
<\/p>\n
   7:<\/span> FROM<\/span> sys.procedures AS<\/span> p WITH<\/span> (NOLOCK)<\/pre>\n
<\/p>\n
   8:<\/span> INNER<\/span> JOIN<\/span> sys.dm_exec_procedure_stats AS<\/span> qs WITH<\/span> (NOLOCK)<\/pre>\n
<\/p>\n
   9:<\/span> ON<\/span> p.[object_id] = qs.[object_id]<\/pre>\n
<\/p>\n
  10:<\/span> WHERE<\/span> qs.database_id = DB_ID()<\/pre>\n
<\/p>\n
  11:<\/span> ORDER<\/span> BY<\/span> qs.total_worker_time DESC<\/span> OPTION<\/span> (RECOMPILE);<\/pre>\n
<\/p>\n
  12:<\/span>  <\/pre>\n
<\/p>\n
  13:<\/span> -- This helps you find the most expensive cached stored procedures from a CPU perspective<\/span><\/pre>\n
<\/p>\n
  14:<\/span> -- You should look at<\/span> this if<\/span> you see signs of<\/span> CPU pressure<\/pre>\n
<\/div>\n<\/div>\n
Figure 2: Query #49 SP Worker Time<\/strong><\/p>\n
This query shows you which cached stored procedures have the highest cumulative total worker time in the current database. Worker time means CPU cost. If your instance or server is under CPU pressure, than looking at the stored procedures that show up at the top of this diagnostic query should be a high priority. Even if you are not under sustained CPU pressure, keeping an eye on the top offenders on this query is a good idea. Quite often, you will find the same stored procedures showing up on several of these different \u201cTop SP cost\u201d queries, which means that the SP in question is expensive from multiple perspectives.<\/p>\n","protected":false},"excerpt":{"rendered":"
For Day 21 of this series, we start out with Query #48, which is SP Avg Elapsed Time. This query retrieves information from the sys.procedures object catalog view and the sys.dm_exec_procedure_stats dynamic management view about the cached stored procedures that have the highest average elapsed time in the current database. Query #48 is shown in […]<\/p>\n","protected":false},"author":7,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[273],"tags":[272],"class_list":["post-1049","post","type-post","status-publish","format-standard","hentry","category-dmv-diagnostic-queries-detailed","tag-dmv-diagnostic-queries-detailed"],"yoast_head":"\nSQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry<\/title>\n<meta name=\"robots\" content=\"index, follow, max-snippet:-1, max-image-preview:large, max-video-preview:-1\" \/>\n<link rel=\"canonical\" href=\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"SQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry\" \/>\n<meta property=\"og:description\" content=\"For Day 21 of this series, we start out with Query #48, which is SP Avg Elapsed Time. This query retrieves information from the sys.procedures object catalog view and the sys.dm_exec_procedure_stats dynamic management view about the cached stored procedures that have the highest average elapsed time in the current database. Query #48 is shown in […]\" \/>\n<meta property=\"og:url\" content=\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/\" \/>\n<meta property=\"og:site_name\" content=\"Glenn Berry\" \/>\n<meta property=\"article:published_time\" content=\"2016-01-21T17:00:32+00:00\" \/>\n<meta property=\"article:modified_time\" content=\"2017-04-13T19:28:51+00:00\" \/>\n<meta name=\"author\" content=\"Glenn Berry\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Glenn Berry\" \/>\n\t<meta name=\"twitter:label2\" content=\"Est. reading time\" \/>\n\t<meta name=\"twitter:data2\" content=\"3 minutes\" \/>\n<script type=\"application\/ld+json\" class=\"yoast-schema-graph\">{\"@context\":\"https:\/\/schema.org\",\"@graph\":[{\"@type\":\"WebPage\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/\",\"name\":\"SQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry\",\"isPartOf\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/#website\"},\"datePublished\":\"2016-01-21T17:00:32+00:00\",\"dateModified\":\"2017-04-13T19:28:51+00:00\",\"author\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/57a8972435106bac7970692fcf5edfa7\"},\"breadcrumb\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"SQL Server Diagnostic Information Queries Detailed, Day 21\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/#website\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/\",\"name\":\"Glenn Berry\",\"description\":\"Semi-random musings about SQL Server performance\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/?s={search_term_string}\"},\"query-input\":{\"@type\":\"PropertyValueSpecification\",\"valueRequired\":true,\"valueName\":\"search_term_string\"}}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/57a8972435106bac7970692fcf5edfa7\",\"name\":\"Glenn Berry\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/image\/\",\"url\":\"https:\/\/secure.gravatar.com\/avatar\/64bdac8830f25f2f8cc780f8a1286c66ff1182218009271e7a953639596f7e25?s=96&d=mm&r=g\",\"contentUrl\":\"https:\/\/secure.gravatar.com\/avatar\/64bdac8830f25f2f8cc780f8a1286c66ff1182218009271e7a953639596f7e25?s=96&d=mm&r=g\",\"caption\":\"Glenn Berry\"},\"sameAs\":[\"https:\/\/www.sqlskills.com\/blogs\/glenn\/\"],\"url\":\"https:\/\/www.sqlskills.com\/blogs\/glenn\/author\/glenn\/\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"SQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry","robots":{"index":"index","follow":"follow","max-snippet":"max-snippet:-1","max-image-preview":"max-image-preview:large","max-video-preview":"max-video-preview:-1"},"canonical":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/","og_locale":"en_US","og_type":"article","og_title":"SQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry","og_description":"For Day 21 of this series, we start out with Query #48, which is SP Avg Elapsed Time. This query retrieves information from the sys.procedures object catalog view and the sys.dm_exec_procedure_stats dynamic management view about the cached stored procedures that have the highest average elapsed time in the current database. Query #48 is shown in […]","og_url":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/","og_site_name":"Glenn Berry","article_published_time":"2016-01-21T17:00:32+00:00","article_modified_time":"2017-04-13T19:28:51+00:00","author":"Glenn Berry","twitter_misc":{"Written by":"Glenn Berry","Est. reading time":"3 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"WebPage","@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/","url":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/","name":"SQL Server Diagnostic Information Queries Detailed, Day 21 - Glenn Berry","isPartOf":{"@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/#website"},"datePublished":"2016-01-21T17:00:32+00:00","dateModified":"2017-04-13T19:28:51+00:00","author":{"@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/57a8972435106bac7970692fcf5edfa7"},"breadcrumb":{"@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/sql-server-diagnostic-information-queries-detailed-day-21\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/www.sqlskills.com\/blogs\/glenn\/"},{"@type":"ListItem","position":2,"name":"SQL Server Diagnostic Information Queries Detailed, Day 21"}]},{"@type":"WebSite","@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/#website","url":"https:\/\/www.sqlskills.com\/blogs\/glenn\/","name":"Glenn Berry","description":"Semi-random musings about SQL Server performance","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/www.sqlskills.com\/blogs\/glenn\/?s={search_term_string}"},"query-input":{"@type":"PropertyValueSpecification","valueRequired":true,"valueName":"search_term_string"}}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/57a8972435106bac7970692fcf5edfa7","name":"Glenn Berry","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/www.sqlskills.com\/blogs\/glenn\/#\/schema\/person\/image\/","url":"https:\/\/secure.gravatar.com\/avatar\/64bdac8830f25f2f8cc780f8a1286c66ff1182218009271e7a953639596f7e25?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/64bdac8830f25f2f8cc780f8a1286c66ff1182218009271e7a953639596f7e25?s=96&d=mm&r=g","caption":"Glenn Berry"},"sameAs":["https:\/\/www.sqlskills.com\/blogs\/glenn\/"],"url":"https:\/\/www.sqlskills.com\/blogs\/glenn\/author\/glenn\/"}]}},"_links":{"self":[{"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/posts\/1049","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/users\/7"}],"replies":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/comments?post=1049"}],"version-history":[{"count":0,"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/posts\/1049\/revisions"}],"wp:attachment":[{"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/media?parent=1049"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/categories?post=1049"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/glenn\/wp-json\/wp\/v2\/tags?post=1049"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}