Warning: Constant WP_TEMP_DIR already defined in /var/www/html/blogs/joe/wp-config.php on line 93

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902

Warning: Cannot modify header information - headers already sent by (output started at /var/www/html/blogs/joe/wp-config.php:93) in /var/www/html/blogs/joe/wp-includes/rest-api/class-wp-rest-server.php on line 1902
{"id":519,"date":"2011-11-01T07:56:00","date_gmt":"2011-11-01T07:56:00","guid":{"rendered":"\/blogs\/joe\/post\/Observer-overhead-e28093-the-perils-of-too-much-tracing.aspx"},"modified":"2011-11-01T07:56:00","modified_gmt":"2011-11-01T07:56:00","slug":"observer-overhead-the-perils-of-too-much-tracing","status":"publish","type":"post","link":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/","title":{"rendered":"Observer overhead \u2013 the perils of too much tracing"},"content":{"rendered":"

\nWhile it’s good to keep an eye on your SQL Server instances – it’s a balancing act.  <\/span>On one side you want to be sure that you are monitoring critical areas and pulling enough information to perform root cause analysis on anything out-of-the-norm. But on the other side, if you pull an excessive amount of information (or redundant information), your monitoring could end up being the cause of the problems you were looking to prevent. <\/font><\/font>\n<\/p>\n

\nLet’s get specific.<\/font>   <\/font><\/span><\/font>\n<\/p>\n

\nImagine your HR department has an application that executes the following query several times per minute:<\/font><\/font>\n<\/p>\n

\nSELECT  <\/span>JobCandidateID, [Edu.Level], [Edu.StartDate], [Edu.EndDate], [Edu.Degree],[Edu.Major], [Edu.Minor], [Edu.GPA], [Edu.GPAScale], [Edu.School], [Edu.Loc.CountryRegion], [Edu.Loc.State], [Edu.Loc.City]<\/font><\/font>\n<\/p>\n

\nFROM HumanResources.vJobCandidateEducation;<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nThis is a simple, but important query for the department, and typically the query finishes executing in 10 milliseconds on the production system.<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nNow imagine that you get a call from the HR department that all queries seem to be running slowly.  <\/span>They send you the aforementioned query and you execute it, seeing that indeed it is running in 31 milliseconds instead of the normal 10 milliseconds.<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nThe HR team is still getting work done, just more slowly now.  <\/span>Since workloads were still coming through, you decide to check out what the tasks are waiting on by querying sys.dm_os_waiting_tasks.  <\/span>Right away you see something unusual:<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\n\"clip_image002\"<\/a><\/span>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\n<\/font><\/font><\/span>\n<\/p>\n

\n<\/font><\/font><\/span>\n<\/p>\n

\nThere are five waiting requests on TRACEWRITE and one on ASYNC_NETWORK_IO.<\/font><\/font><\/span>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nYou saw this wait type before related to SQL Trace – but why would there be five of these wait types across different sessions?   <\/span><\/font><\/font>\n<\/p>\n

\n<\/span><\/font><\/font>\n<\/p>\n

\n<\/span>Perhaps you have multiple DBA and Developers in your environment with the permission to launch SQL Profiler traces.  <\/span>Even though the intention was good, by virtue of what events you are monitoring and the throughput of activity on the monitored SQL Server instance, you could be hurting the performance of the SQL Server instance.<\/font>  <\/font><\/span><\/font>Another source of these waits could be spawned from third party monitoring software packages (again with good intentions) – and for whatever reason something was misconfigured or there is redundant tracing due to lack of communication or centralized documentation. <\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font>\n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nSo to wrap up this story, you decide to query sys.traces and find the reader_spid for each trace running against the SQL Server instance:<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nSELECT path, buffer_count, reader_spid, start_time, last_event_time<\/font><\/font>\n<\/p>\n

\nFROM sys.traces<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nThis returns:<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\n\"clip_image003\"<\/a><\/span>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nYou already saw the waiting session ids in sys.dm_os_waiting_tasks – but now you know this is trace related having been surfaced in sys.traces. You look up the spid connection information in other DMVs and you notify them about the issue and have them shut down the traces.  <\/span>After doing this, you see the TRACEWRITE waiting tasks disappear and you retest the original query, finding that it has returned down to 10 ms.<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n<\/font><\/font>\n<\/p>\n

\nAs a postscript, one of the virtues of Extended Events versus SQL Profiler is that Extended Events are significantly more lightweight.  <\/span>And while I haven’t tested the overhead of excessive tracing using Extended Events, I imagine that as people move to this method, they will need to work a little harder to cause “observer overhead” problems like this – but I’m sure people will find a way.<\/font><\/font>\n<\/p>\n

\n \n<\/p>\n

\n** Oh – and a post-postscript.  If you have a chance, don't take my word for it, test this out (in a test environment) for yourself.  Pick a query and measure the "before" performance via SET STATISTICS TIME.  Get a few samplings and make note of your average.  Then spin up multiple SQL Profiler sessions.  Prior to the blog, 5 sessions did the trick, with varying overlapping events being tracked.  Then measure the SET STATISTICS TIME and compare.  Your impact will vary based on your specifications. **<\/p>\n","protected":false},"excerpt":{"rendered":"

While it’s good to keep an eye on your SQL Server instances – it’s a balancing act.  On one side you want to be sure that you are monitoring critical areas and pulling enough information to perform root cause analysis on anything out-of-the-norm. But on the other side, if you pull an excessive amount of […]<\/p>\n","protected":false},"author":7,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[28],"tags":[],"class_list":["post-519","post","type-post","status-publish","format-standard","hentry","category-performance"],"yoast_head":"\nObserver overhead \u2013 the perils of too much tracing - Joe Sack<\/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\/joe\/observer-overhead-the-perils-of-too-much-tracing\/\" \/>\n<meta property=\"og:locale\" content=\"en_US\" \/>\n<meta property=\"og:type\" content=\"article\" \/>\n<meta property=\"og:title\" content=\"Observer overhead \u2013 the perils of too much tracing - Joe Sack\" \/>\n<meta property=\"og:description\" content=\"While it’s good to keep an eye on your SQL Server instances – it’s a balancing act.  On one side you want to be sure that you are monitoring critical areas and pulling enough information to perform root cause analysis on anything out-of-the-norm. But on the other side, if you pull an excessive amount of […]\" \/>\n<meta property=\"og:url\" content=\"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/\" \/>\n<meta property=\"og:site_name\" content=\"Joe Sack\" \/>\n<meta property=\"article:published_time\" content=\"2011-11-01T07:56:00+00:00\" \/>\n<meta name=\"author\" content=\"Joseph Sack\" \/>\n<meta name=\"twitter:label1\" content=\"Written by\" \/>\n\t<meta name=\"twitter:data1\" content=\"Joseph Sack\" \/>\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\/joe\/observer-overhead-the-perils-of-too-much-tracing\/\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/\",\"name\":\"Observer overhead \u2013 the perils of too much tracing - Joe Sack\",\"isPartOf\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/#website\"},\"datePublished\":\"2011-11-01T07:56:00+00:00\",\"dateModified\":\"2011-11-01T07:56:00+00:00\",\"author\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/533eb0113a15fb5a6e8067a49e4ae648\"},\"breadcrumb\":{\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/#breadcrumb\"},\"inLanguage\":\"en-US\",\"potentialAction\":[{\"@type\":\"ReadAction\",\"target\":[\"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/\"]}]},{\"@type\":\"BreadcrumbList\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/#breadcrumb\",\"itemListElement\":[{\"@type\":\"ListItem\",\"position\":1,\"name\":\"Home\",\"item\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/\"},{\"@type\":\"ListItem\",\"position\":2,\"name\":\"Performance\",\"item\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/category\/performance\/\"},{\"@type\":\"ListItem\",\"position\":3,\"name\":\"Observer overhead \u2013 the perils of too much tracing\"}]},{\"@type\":\"WebSite\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/#website\",\"url\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/\",\"name\":\"Joe Sack\",\"description\":\"SQL Server Performance Tuning, High Availability and Disaster Recovery Blog\",\"potentialAction\":[{\"@type\":\"SearchAction\",\"target\":{\"@type\":\"EntryPoint\",\"urlTemplate\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/?s={search_term_string}\"},\"query-input\":\"required name=search_term_string\"}],\"inLanguage\":\"en-US\"},{\"@type\":\"Person\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/533eb0113a15fb5a6e8067a49e4ae648\",\"name\":\"Joseph Sack\",\"image\":{\"@type\":\"ImageObject\",\"inLanguage\":\"en-US\",\"@id\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/image\/\",\"url\":\"https:\/\/secure.gravatar.com\/avatar\/a4b39a7719a6bfff1add3ec00527810734579ee114d6d983e8e68f937b77be96?s=96&d=mm&r=g\",\"contentUrl\":\"https:\/\/secure.gravatar.com\/avatar\/a4b39a7719a6bfff1add3ec00527810734579ee114d6d983e8e68f937b77be96?s=96&d=mm&r=g\",\"caption\":\"Joseph Sack\"},\"description\":\"Joe Sack is a Principal Consultant with SQLskills. He has worked as a SQL Server professional since 1997 and has supported and developed for SQL Server environments in financial services, IT consulting, manufacturing, retail and the real estate industry. Prior to joining SQLskills he worked at Microsoft as a Premier Field Engineer supporting very large enterprise customer environments. He was responsible for providing deep SQL Server advisory services, training, troubleshooting and ongoing solutions guidance. His areas of expertise include performance tuning, scalability, T-SQL development and high-availability. In 2006 Joe earned the \u201cMicrosoft Certified Master: SQL Server 2005\u201d certification and in 2008 he earned the \u201cMicrosoft Certified Master: SQL Server 2008\u201d certification. In 2009 he took over responsibility for the entire SQL Server Microsoft Certified Master program and held that post until 2011. He was given the SQL Server MVP award in 2013.\",\"sameAs\":[\"http:\/\/3.209.169.194\/blogs\/joe\",\"https:\/\/twitter.com\/https:\/\/twitter.com\/josephsack\"],\"url\":\"https:\/\/www.sqlskills.com\/blogs\/joe\/author\/joe\/\"}]}<\/script>\n<!-- \/ Yoast SEO plugin. -->","yoast_head_json":{"title":"Observer overhead \u2013 the perils of too much tracing - Joe Sack","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\/joe\/observer-overhead-the-perils-of-too-much-tracing\/","og_locale":"en_US","og_type":"article","og_title":"Observer overhead \u2013 the perils of too much tracing - Joe Sack","og_description":"While it’s good to keep an eye on your SQL Server instances – it’s a balancing act.  On one side you want to be sure that you are monitoring critical areas and pulling enough information to perform root cause analysis on anything out-of-the-norm. But on the other side, if you pull an excessive amount of […]","og_url":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/","og_site_name":"Joe Sack","article_published_time":"2011-11-01T07:56:00+00:00","author":"Joseph Sack","twitter_misc":{"Written by":"Joseph Sack","Est. reading time":"3 minutes"},"schema":{"@context":"https:\/\/schema.org","@graph":[{"@type":"WebPage","@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/","url":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/","name":"Observer overhead \u2013 the perils of too much tracing - Joe Sack","isPartOf":{"@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/#website"},"datePublished":"2011-11-01T07:56:00+00:00","dateModified":"2011-11-01T07:56:00+00:00","author":{"@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/533eb0113a15fb5a6e8067a49e4ae648"},"breadcrumb":{"@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/#breadcrumb"},"inLanguage":"en-US","potentialAction":[{"@type":"ReadAction","target":["https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/"]}]},{"@type":"BreadcrumbList","@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/observer-overhead-the-perils-of-too-much-tracing\/#breadcrumb","itemListElement":[{"@type":"ListItem","position":1,"name":"Home","item":"https:\/\/www.sqlskills.com\/blogs\/joe\/"},{"@type":"ListItem","position":2,"name":"Performance","item":"https:\/\/www.sqlskills.com\/blogs\/joe\/category\/performance\/"},{"@type":"ListItem","position":3,"name":"Observer overhead \u2013 the perils of too much tracing"}]},{"@type":"WebSite","@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/#website","url":"https:\/\/www.sqlskills.com\/blogs\/joe\/","name":"Joe Sack","description":"SQL Server Performance Tuning, High Availability and Disaster Recovery Blog","potentialAction":[{"@type":"SearchAction","target":{"@type":"EntryPoint","urlTemplate":"https:\/\/www.sqlskills.com\/blogs\/joe\/?s={search_term_string}"},"query-input":"required name=search_term_string"}],"inLanguage":"en-US"},{"@type":"Person","@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/533eb0113a15fb5a6e8067a49e4ae648","name":"Joseph Sack","image":{"@type":"ImageObject","inLanguage":"en-US","@id":"https:\/\/www.sqlskills.com\/blogs\/joe\/#\/schema\/person\/image\/","url":"https:\/\/secure.gravatar.com\/avatar\/a4b39a7719a6bfff1add3ec00527810734579ee114d6d983e8e68f937b77be96?s=96&d=mm&r=g","contentUrl":"https:\/\/secure.gravatar.com\/avatar\/a4b39a7719a6bfff1add3ec00527810734579ee114d6d983e8e68f937b77be96?s=96&d=mm&r=g","caption":"Joseph Sack"},"description":"Joe Sack is a Principal Consultant with SQLskills. He has worked as a SQL Server professional since 1997 and has supported and developed for SQL Server environments in financial services, IT consulting, manufacturing, retail and the real estate industry. Prior to joining SQLskills he worked at Microsoft as a Premier Field Engineer supporting very large enterprise customer environments. He was responsible for providing deep SQL Server advisory services, training, troubleshooting and ongoing solutions guidance. His areas of expertise include performance tuning, scalability, T-SQL development and high-availability. In 2006 Joe earned the \u201cMicrosoft Certified Master: SQL Server 2005\u201d certification and in 2008 he earned the \u201cMicrosoft Certified Master: SQL Server 2008\u201d certification. In 2009 he took over responsibility for the entire SQL Server Microsoft Certified Master program and held that post until 2011. He was given the SQL Server MVP award in 2013.","sameAs":["http:\/\/3.209.169.194\/blogs\/joe","https:\/\/twitter.com\/https:\/\/twitter.com\/josephsack"],"url":"https:\/\/www.sqlskills.com\/blogs\/joe\/author\/joe\/"}]}},"_links":{"self":[{"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/posts\/519","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/users\/7"}],"replies":[{"embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/comments?post=519"}],"version-history":[{"count":0,"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/posts\/519\/revisions"}],"wp:attachment":[{"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/media?parent=519"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/categories?post=519"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.sqlskills.com\/blogs\/joe\/wp-json\/wp\/v2\/tags?post=519"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}