{"id":2915,"date":"2013-08-14T17:54:25","date_gmt":"2013-08-14T16:54:25","guid":{"rendered":"http:\/\/andreas-wolter.com\/leistungseinbussen-beim-tracing-extended-event-ziele-gegen-sql-trace-unter-cpu-last\/"},"modified":"2017-11-15T11:35:09","modified_gmt":"2017-11-15T10:35:09","slug":"performance-overhead-of-tracing-with-extended-event-targets-vs-sql-trace-under-cpu-load","status":"publish","type":"post","link":"https:\/\/andreas-wolter.com\/en\/performance-overhead-of-tracing-with-extended-event-targets-vs-sql-trace-under-cpu-load\/","title":{"rendered":"Performance overhead of tracing with Extended Event targets vs SQL Trace under CPU Load"},"content":{"rendered":"\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_heading-dd5b5d60c3f2b6836a95102d0aa99a13\">\n#top .av-special-heading.av-av_heading-dd5b5d60c3f2b6836a95102d0aa99a13{\npadding-bottom:10px;\n}\nbody .av-special-heading.av-av_heading-dd5b5d60c3f2b6836a95102d0aa99a13 .av-special-heading-tag .heading-char{\nfont-size:25px;\n}\n.av-special-heading.av-av_heading-dd5b5d60c3f2b6836a95102d0aa99a13 .av-subheading{\nfont-size:15px;\n}\n<\/style>\n<div  class='av-special-heading av-av_heading-dd5b5d60c3f2b6836a95102d0aa99a13 av-special-heading-h3 blockquote modern-quote  avia-builder-el-0  el_before_av_textblock  avia-builder-el-first '><h3 class='av-special-heading-tag'  itemprop=\"headline\"  >Performance overhead of tracing with Extended Event targets vs SQL Trace under CPU Load<\/h3><div class=\"special-heading-border\"><div class=\"special-heading-inner-border\"><\/div><\/div><\/div>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>Inspired by the Blog Post \u201c<a href=\"http:\/\/www.sqlperformance.com\/2012\/10\/sql-trace\/observer-overhead-trace-extended-events\" target=\"_blank\" rel=\"noopener\">Measuring Observer Overhead of SQL Trace vs. Extended Events<\/a>\u201d by Jonathan Kehayias, I was curious to do some more benchmarking. I have already presented the results in my <a href=\"http:\/\/www.sarpedonqualitylab.com\/SQL_Master-Classes.htm\" target=\"_blank\" rel=\"noopener\">SQL Server Master-Class<\/a> workshops on XEvents as well as at the PreCon of the <a href=\"http:\/\/sqlsaturday.com\/230\/\" target=\"_blank\" rel=\"noopener\">SQLSaturday #230<\/a>. Now I am finally sharing them with you here.<!--more--><\/p>\n<p>I was interested in the following aspects, in particular:<\/p>\n<ul>\n<li>What is the Performance-overhead of an <strong>Extended Event Session itself<\/strong> \u2013 not including the processing\/dispatching for the target<\/li>\n<li>How does this compare to the old-school <strong>SQL Trace<\/strong> \u2013 again with <strong>no Target overhead<\/strong> (No File, no Profiler: no consumer at all)<\/li>\n<\/ul>\n<p>Besides that, once I had the setup ready, I decided to include <strong>all the other targets<\/strong> and some <strong>basic option-variations<\/strong>, to have a complete overview that is comparable in itself.<\/p>\n<p>I also decided for a test of <strong>a system that\u2019s already under CPU pressure<\/strong> &#8211; so <strong>the Processor Usage is almost constantly hitting 100%<\/strong>. Under these circumstances I was hoping to get the<strong> maximum impact of Extended Events as well as SQL Trace<\/strong>. (Remember: SQL Profiler is based on SQL Trace) One could think that an I\/O driven workload would be even more influenced, but that depends on the targets of Extended Events. &#8211; 4 of which only go to memory, vs. one file target (which one should put onto a non-data volume anyways). And since I also want to measure the pure overhead of the tracing technologies (without any target), this makes even more sense. Besides that, I\/O usually can be tuned quite easily by writing to an otherwise idle and fast device, whereas for CPU it is not as simple to keep the costs invisible. Keeping this in mind helps to evaluate the results presented here and bringing them into the right context.<\/p>\n<p><strong>Test Environment<\/strong><\/p>\n<p>\u201cSimple but physical\u201d<\/p>\n<p>1 Windows 2008 R2 Server with SQL Server 2012 SP1. No running services above the minimum required, to avoid side-effects. I also shut down the default trace as well as the system_health_session. The Distributed Replay-client was run locally for all tests, so yes, this has effect on the server, but it was equally for all tests. All tests have been repeated 3 times (some even more) to make sure the average\/median is valid. The server, as I already said, was physical (which comes in handy when you are running benchmarks for a total of ~50 hours): 1 Dual Core Intel Xeon with 8 GB of RAM (which was by far enough), Data Volumes and Volumes for Trace-Targets on separate Controllers.<\/p>\n<p>The workload was a mixture of mostly short (sub-second) but also several queries of several second runtime, (Ad Hoc and stored procedures) to simulate a somehow realistic decision-support-systems\u2019 load \u2013 no data changes though. The baseline workload took 00:24:24 minutes. The statistics stayed the same for all workloads cycles. The database used was AdventureWorks2012.<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p><strong>Trace-Configurations<\/strong><\/p>\n<p>I decided for a simple but not uncommon trace that typically collects a lot of data. The trace collects only 2 events:<\/p>\n<ul>\n<li>Lock acquired<\/li>\n<li>Lock released<\/li>\n<\/ul>\n<p>Filtered out: System-sessions and other databases than the one under load here.<\/p>\n<p>CollectedData:<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><ul>\n<li>Lock:Released\u00a0\u00a0 BinaryData<\/li>\n<li>Lock:Released\u00a0\u00a0 DatabaseID<\/li>\n<li>Lock:Released\u00a0\u00a0 TransactionID<\/li>\n<li>Lock:Released\u00a0\u00a0 SPID<\/li>\n<li>Lock:Released\u00a0\u00a0 ObjectID<\/li>\n<li>Lock:Released\u00a0\u00a0 Mode<\/li>\n<li>Lock:Released\u00a0\u00a0 BigintData1<\/li>\n<li>Lock:Released\u00a0\u00a0 IntegerData2<\/li>\n<li>Lock:Released\u00a0\u00a0 ObjectID2<\/li>\n<li>Lock:Released\u00a0\u00a0 Type<\/li>\n<li>Lock:Released\u00a0\u00a0 OwnerID<\/li>\n<li>Lock:Released\u00a0\u00a0 IsSystem<\/li>\n<\/ul>\n<ul>\n<li>Lock:Acquired\u00a0\u00a0 BinaryData<\/li>\n<li>Lock:Acquired\u00a0\u00a0 DatabaseID<\/li>\n<li>Lock:Acquired\u00a0\u00a0 TransactionID<\/li>\n<li>Lock:Acquired\u00a0\u00a0 SPID<\/li>\n<li>Lock:Acquired\u00a0\u00a0 Duration<\/li>\n<li>Lock:Acquired\u00a0\u00a0 ObjectID<\/li>\n<li>Lock:Acquired\u00a0\u00a0 IsSystem<\/li>\n<li>Lock:Acquired\u00a0\u00a0 Mode<\/li>\n<li>Lock:Acquired\u00a0\u00a0 BigintData1<\/li>\n<li>Lock:Acquired\u00a0\u00a0 IntegerData2<\/li>\n<li>Lock:Acquired\u00a0\u00a0 ObjectID2<\/li>\n<li>Lock:Acquired\u00a0\u00a0 Type<\/li>\n<li>Lock:Acquired\u00a0\u00a0 OwnerID<\/li>\n<\/ul>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>This gave me the advantage to have a valid test for all Extended Event Targets that are provided (only ETW-Tracing was left out) &#8211; specifically histogram and Pair Matching (I did not care about the few occasions of lock escalation on purpose).<\/p>\n<p>The following <strong>Trace technologies and -Targets<\/strong> were used:<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><ul>\n<li>XEvent Trace, Target: None<\/li>\n<li>XEvent Trace, Target: Ring Buffer<\/li>\n<li>XEvent Trace, Target: File<\/li>\n<li>XEvent Trace, Target: Counter<\/li>\n<li>XEvent Trace, Target: Histogram\n<ul>\n<li>Here I chose to filter on lock acquired and to bucketize on the lock mode<\/li>\n<\/ul>\n<\/li>\n<li>XEvent Trace, Target: Pair Matching\n<ul>\n<li>Guess, what I matched here \ud83d\ude09<\/li>\n<\/ul>\n<\/li>\n<li>SQL Trace, Target: None (I had to trick a little bit to get this to work, but I made sure, the behavior of this unsupported configuration did not distort the results: It\u2019s just a SQL Trace with no Provider processing anything, so <em>all events are<\/em> <em>lost<\/em> by nature.)<\/li>\n<li>SQL Trace, Target: File<\/li>\n<li>SQL Profiler, remotely<\/li>\n<\/ul>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>For each Extended Event Target I tested <strong>4 variations<\/strong>, based on the session options:<\/p>\n<ul>\n<li>Single event loss<\/li>\n<li>No event loss<\/li>\n<li>Multiple event loss<\/li>\n<li>Single event loss with causality tracking on<\/li>\n<\/ul>\n<p>All other options were using the defaults for these tests.<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p><img loading=\"lazy\" decoding=\"async\" class=\"alignleft size-full wp-image-2902\" src=\"http:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1306_XEventPerfComparison_sessions.png\" alt=\"\" width=\"218\" height=\"526\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1306_XEventPerfComparison_sessions.png 218w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1306_XEventPerfComparison_sessions-124x300.png 124w\" sizes=\"auto, (max-width: 218px) 100vw, 218px\" \/><\/p>\n<p>Picture: the 24 prepared traces<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p><strong>The Results<\/strong><\/p>\n<p>I measured the total time for the workload to take as well as batches per second and CPU time %.<\/p>\n<p>And here is the complete Table of Results:<\/p>\n<\/div><\/section>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_image-4c6f71f6a81eba740227c23b63f471fb\">\n.avia-image-container.av-av_image-4c6f71f6a81eba740227c23b63f471fb img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-4c6f71f6a81eba740227c23b63f471fb .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-4c6f71f6a81eba740227c23b63f471fb av-styling- avia-align-center  avia-builder-el-9  el_after_av_textblock  el_before_av_textblock '   itemprop=\"image\" itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/ImageObject\" ><div class=\"avia-image-container-inner\"><div class=\"avia-image-overlay-wrap\"><img decoding=\"async\" class='wp-image-2905 avia-img-lazy-loading-not-2905 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Avg_EvSec.png\" alt='' title='1308_XEventPerfComparison_Runtime_Avg_EvSec'  height=\"610\" width=\"697\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Avg_EvSec.png 697w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Avg_EvSec-600x525.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Avg_EvSec-300x263.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Avg_EvSec-450x394.png 450w\" sizes=\"(max-width: 697px) 100vw, 697px\" \/><\/div><\/div><\/div>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p><strong>EL<\/strong> = Event Loss. <strong>S<\/strong> = Single event loss, <strong>N<\/strong> = No event loss, <strong>M<\/strong> = Multiple event loss<\/p>\n<p><strong>CT<\/strong> = Causality Tracking On<\/p>\n<p>For the sake of saving space and time, <strong>I will focus on<\/strong> the benchmarks with the options <strong><em>single event loss<\/em> and <em>no event loss <\/em>without <em>causality tracking<\/em><\/strong>. In fact, <strong>the cost of causality tracking was less than 1% for all targets<\/strong>.<\/p>\n<p>So this is the more <strong>condensed result<\/strong>:<\/p>\n<\/div><\/section>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_image-98e3365dc5c6dc8eadecc9222ba72278\">\n.avia-image-container.av-av_image-98e3365dc5c6dc8eadecc9222ba72278 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-98e3365dc5c6dc8eadecc9222ba72278 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-98e3365dc5c6dc8eadecc9222ba72278 av-styling- avia-align-center  avia-builder-el-11  el_after_av_textblock  el_before_av_textblock '   itemprop=\"image\" itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/ImageObject\" ><div class=\"avia-image-container-inner\"><div class=\"avia-image-overlay-wrap\"><img decoding=\"async\" class='wp-image-2909 avia-img-lazy-loading-not-2909 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec.png\" alt='' title='1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec'  height=\"358\" width=\"697\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec.png 697w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec-600x308.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec-300x154.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_S_N_Avg_EvSec-450x231.png 450w\" sizes=\"(max-width: 697px) 100vw, 697px\" \/><\/div><\/div><\/div>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>What we can tell from that is: (Remember: Everything is running under High CPU Load, so that\u2019s the base of all results.)<\/p>\n<ul>\n<li>A <strong>plain XEvent Session <\/strong>itself, with no Targets, already does have a noticeable impact of ~15 % performance decrease.<\/li>\n<li>The overhead of the artificial (not supported) version <strong>plain SQL Trace<\/strong>, without the overhead of a rowset or file provider (aka target), is not too far off the Extended Events Session without the dispatching to any target (~19% versus ~15%).<\/li>\n<li>The <strong>Ring Buffer<\/strong> is the XE-Target with the greatest overhead (~40%). (!)<\/li>\n<li>The <strong>File-Target<\/strong> really does have the lowest overhead as expected, but it\u2019s still 25%.<\/li>\n<li>The differences between <strong>the Targets Counter, Histogram and Pair Matching <\/strong>are irrelevant.\n<ul>\n<li>Yes, even the simple <strong>Counter<\/strong> has a higher overhead than the File Target.<\/li>\n<li>Configuring the<strong> file target with <em>no event loss<\/em> <\/strong>adds approximately 4 times as much performance overhead.<\/li>\n<li>The difference for the other targets between <strong><em>single<\/em>, <em>multiple<\/em> and even <em>no event loss<\/em><\/strong> is mostly negligible in this scenario.<\/li>\n<li>Compared to Extended Events, the overhead through <strong>SQL Trace<\/strong> is almost \u201cbrutal\u201d: It quadruplicated the total runtime.<\/li>\n<li>And there\u2019s even more: Tracing with <strong>SQL Profiler<\/strong> is absolutely impossible for such a scenario: I filled in 21 hours, but that\u2019s actually an <u>estimate<\/u>: I stopped those test circle after around 3 hours (forgive me, but it\u2019s just a waste of time&#8230;), counted the finished events and calculated how much else it would have taken, roughly \u2013 in an actually rather optimistic manner. Profiler, as I always say, is a \u201cno go\u201d for tracing longer periods of time, especially if performance is already at stake.<\/li>\n<\/ul>\n<\/li>\n<\/ul>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>You have a nice picture of the <strong>SQL Trace Architecture<\/strong> in BOL: <a href=\"http:\/\/msdn.microsoft.com\/en-us\/library\/hh245121.aspx\" target=\"_blank\" rel=\"noopener\">msdn.microsoft.com\/en-us\/library\/hh245121.aspx<\/a><\/p>\n<p>The <strong>Extended Events Architecture<\/strong> is depicted here: <a href=\"http:\/\/msdn.microsoft.com\/en-us\/library\/bb630318%28v=sql.105%29.aspx\" target=\"_blank\" rel=\"noopener\">msdn.microsoft.com\/en-us\/library\/bb630318%28v=sql.105%29.aspx<\/a><\/p>\n<p><strong>Adding Filters<\/strong><\/p>\n<p>How does adding filters change the observer overhead?<\/p>\n<p>Now it is important to note what I actually used as a filter: The database_id \/ source_database_id. &#8211; I essentially added a filter that would never return \u201ctrue\u201d by adding a filter on database_id = 77 \u2013 since no session\/query\/lock was on this non-existing database.<\/p>\n<p>Why did I do that? \u2013 This is a totally artificial test\/benchmark. I am interested what the pure overhead of tracing is, and not what happens if a certain percentage of activity is not logged. (That might be something for a different benchmark. :-))<\/p>\n<p>This time I only focused on \u201csingle\u201d and \u201cno event loss\u201d.<\/p>\n<p><strong>The results of Filtered Tracing, without actually storing\/logging any events<\/strong> is as follows:<\/p>\n<\/div><\/section>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_image-1972030922fc478b0b1c119bffcc14e6\">\n.avia-image-container.av-av_image-1972030922fc478b0b1c119bffcc14e6 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-1972030922fc478b0b1c119bffcc14e6 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-1972030922fc478b0b1c119bffcc14e6 av-styling- avia-align-center  avia-builder-el-14  el_after_av_textblock  el_before_av_textblock '   itemprop=\"image\" itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/ImageObject\" ><div class=\"avia-image-container-inner\"><div class=\"avia-image-overlay-wrap\"><img decoding=\"async\" class='wp-image-2907 avia-img-lazy-loading-not-2907 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Filtered_Avg.png\" alt='' title='1308_XEventPerfComparison_Runtime_Filtered_Avg'  height=\"335\" width=\"380\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Filtered_Avg.png 380w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/09\/1308_XEventPerfComparison_Runtime_Filtered_Avg-300x264.png 300w\" sizes=\"(max-width: 380px) 100vw, 380px\" \/><\/div><\/div><\/div>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><ul>\n<li>As one can see, the overhead of the pure <strong>XEvent session without target<\/strong> drops from ~ 15% to 9% respectively ~ 16.5% vs. 12.5 % (no Event loss)<\/li>\n<li>The other targets do in fact show more differences in this setup:\n<ul>\n<li>The <strong>Counter Target with single event loss<\/strong> benefits most of the filter and drops from ~33.5 to 8.4 % overhead.<\/li>\n<li>Only <strong>Ring Buffer and Pair Matching<\/strong> show no difference between <em>single<\/em> and <em>no event loss.<\/em><\/li>\n<li><strong>SQL Trace <\/strong>with and without rowset provider (file) as target have\u00a0almost the same overhead \u2013 no surprise if you know the architecture. This is in fact another huge difference which counts for Extended Events, where filters get honored much sooner within the Trace.<\/li>\n<li>That the overhead of <strong>SQL Trace without target and at the same time all events being filtered out<\/strong> <strong>is actually higher<\/strong> than the overhead without target but no filtering (from the former test cycle) must be caused by the processing of for filtering out. I will not dive more into this though, since this setup is not documented and or supported. And in my eyes, \u201cSQL trace is dead\u201d anyways \ud83d\ude09 \u2013 okay, I am exaggerating a bit here, but I am also just being frank: For SQL Server 2012 there is almost no need to use it any more. \u2013 Running benchmarks using Distributed Replay is such a reason \u2013 isn\u2019t that ironic?<\/li>\n<\/ul>\n<\/li>\n<\/ul>\n<p>I did not run SQL Profiler for this Test, forgive me. You probably know why by now. \ud83d\ude09<\/p>\n<p><strong>Wait-Types for Extended Events<\/strong><\/p>\n<p>Another aspect I was interested in were the specific XEvent wait-types which would occur when running Extended Event sessions. (Wait-Statistics are often the base for performance analysis)<\/p>\n<p>In general, you will see the following:<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>When <strong>starting<\/strong> a session:<\/p>\n<p>PREEMPTIVE_XE_TARGETINIT<br \/>\nPREEMPTIVE_XE_CALLBACKEXECUTE<br \/>\nPREEMPTIVE_XE_SESSIONCOMMIT<\/p>\n<p>When <strong>stopping<\/strong> a session:<\/p>\n<p>PREEMPTIVE_XE_SESSIONCOMMIT<br \/>\nXE_BUFFERMGR_ALLPROCESSED_EVENT PREEMPTIVE_XE_CALLBACKEXECUTE<\/p>\n<p>While <strong>running<\/strong> sessions you will see:<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>XE_DISPATCHER_WAIT\u00a0 &#8211; From BOL: Occurs when a background thread that is used for Extended Events sessions is waiting for event buffers to process. &#8211; You should be able to safely ignore this unless you believe a problem is occurring with processing of events for async targets. Since this works on a queue you can have bursts of high wait times especially when no XEvent sessions are active.<\/p>\n<p>XE_TIMER_EVENT \u2013 From BOL: Used to indicate a background task is waiting for &#8220;expired&#8221; timers for internal Xevent engine work. &#8211; You should be able to safely ignore this one. Just used by the Xevent engine for internal processing of its work. If something was possibly wrong with Xevent processing you might see if this thread ever &#8220;wakes up&#8221;<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>When <strong>starting<\/strong> the <strong>File target<\/strong> you will also see:<\/p>\n<p>PREEMPTIVE_XE_TARGETINIT<\/p>\n<p>If you run a session with the <strong><em>no event loss<\/em><\/strong> option you might see:<\/p>\n<p>XE_BUFFERMGR_FREEBUF_EVENT &#8211; which by BOL means: An Extended Events session is configured for no event loss, and all buffers in the session are currently full. This can indicate that the buffers for an Extended Events session are too small, or should be partitioned.<\/p>\n<p>So, I hope this was interesting for you. You may draw more and other conclusions out of these results. Remember though: this is a very specific scenario with no CPU reserves, so the Tracing\/observer overhead has to show up \u2013 no choice but to take away (CPU) resources.<\/p>\n<\/div><\/section>\r\n\r\n<section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><p>Happy Tracing<\/p>\n<p>Andreas<\/p>\n<p>P.S.: I just discovered that my MCM and SQLSkills-class buddy Steven Ormrod also has recently blogged about the performance overhead from a SQL Trace to remote file share on production here: <a href=\"http:\/\/stevenormrod.com\/2013\/06\/remote-trace-slowing-down-server\/\" target=\"_blank\" rel=\"noopener\">stevenormrod.com\/2013\/06\/remote-trace-slowing-down-server\/<\/a><\/p>\n<\/div><\/section>\r\n\r\n<div  class='hr av-av_hr-0ff602b3e980a3377077ff3c1c834df6 hr-default  avia-builder-el-20  el_after_av_textblock  el_before_av_one_full '><span class='hr-inner '><span class=\"hr-inner-style\"><\/span><\/span><\/div>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_one_full-97c650ae075063b375f558a776c570f8\">\n#top .flex_column.av-av_one_full-97c650ae075063b375f558a776c570f8{\nmargin-top:40px;\nmargin-bottom:40px;\n}\n.flex_column.av-av_one_full-97c650ae075063b375f558a776c570f8{\nborder-radius:0px 0px 0px 0px;\npadding:0px 0px 0px 0px;\n}\n.responsive #top #wrap_all .flex_column.av-av_one_full-97c650ae075063b375f558a776c570f8{\nmargin-top:40px;\nmargin-bottom:40px;\n}\n<\/style>\n<div  class='flex_column av-av_one_full-97c650ae075063b375f558a776c570f8 av_one_full  avia-builder-el-21  el_after_av_hr  el_before_av_social_share  first flex_column_div av-zero-column-padding  '     ><section  class='av_textblock_section av-av_textblock-2de302bf1aa3cf4c9157dbe6f50ac7eb '   itemscope=\"itemscope\" itemtype=\"https:\/\/schema.org\/BlogPosting\" itemprop=\"blogPost\" ><div class='avia_textblock'  itemprop=\"text\" ><div><\/div>\n<div><\/div>\n<\/div><\/section><\/div>\r\n\r\n<div  class='av-social-sharing-box av-av_social_share-8644d330ffb238fff0cfa858c5295467 av-social-sharing-box-default  avia-builder-el-23  el_after_av_one_full  el_before_av_hr  av-social-sharing-box-fullwidth'><div class=\"av-share-box\"><h5 class='av-share-link-description av-no-toc '>Share<\/h5><ul class=\"av-share-box-list noLightbox\"><li class='av-share-link av-social-link-facebook' ><a target=\"_blank\" aria-label=\"Share on Facebook\" href=\"https:\/\/www.facebook.com\/sharer.php?u=https:\/\/andreas-wolter.com\/en\/performance-overhead-of-tracing-with-extended-event-targets-vs-sql-trace-under-cpu-load\/&#038;t=Performance%20overhead%20of%20tracing%20with%20Extended%20Event%20targets%20vs%20SQL%20Trace%20under%20CPU%20Load\" aria-hidden=\"false\" data-av_icon=\"\ue8f3\" data-av_iconfont=\"entypo-fontello\" title=\"\" data-avia-related-tooltip=\"Share on Facebook\" rel=\"noopener\"><span class='avia_hidden_link_text'>Share on Facebook<\/span><\/a><\/li><li class='av-share-link av-social-link-twitter' ><a target=\"_blank\" aria-label=\"Share on Twitter\" href=\"https:\/\/twitter.com\/share?text=Performance%20overhead%20of%20tracing%20with%20Extended%20Event%20targets%20vs%20SQL%20Trace%20under%20CPU%20Load&#038;url=https:\/\/andreas-wolter.com\/en\/?p=2915\" aria-hidden=\"false\" data-av_icon=\"\ue8f1\" data-av_iconfont=\"entypo-fontello\" title=\"\" data-avia-related-tooltip=\"Share on Twitter\" rel=\"noopener\"><span class='avia_hidden_link_text'>Share on Twitter<\/span><\/a><\/li><li class='av-share-link av-social-link-linkedin' ><a target=\"_blank\" aria-label=\"Share on LinkedIn\" href=\"https:\/\/linkedin.com\/shareArticle?mini=true&#038;title=Performance%20overhead%20of%20tracing%20with%20Extended%20Event%20targets%20vs%20SQL%20Trace%20under%20CPU%20Load&#038;url=https:\/\/andreas-wolter.com\/en\/performance-overhead-of-tracing-with-extended-event-targets-vs-sql-trace-under-cpu-load\/\" aria-hidden=\"false\" data-av_icon=\"\ue8fc\" data-av_iconfont=\"entypo-fontello\" title=\"\" data-avia-related-tooltip=\"Share on LinkedIn\" rel=\"noopener\"><span class='avia_hidden_link_text'>Share on LinkedIn<\/span><\/a><\/li><\/ul><\/div><\/div>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_hr-4474f20d2389e2e5ecf918a02da5132e\">\n#top .hr.hr-invisible.av-av_hr-4474f20d2389e2e5ecf918a02da5132e{\nheight:50px;\n}\n<\/style>\n<div  class='hr av-av_hr-4474f20d2389e2e5ecf918a02da5132e hr-invisible  avia-builder-el-24  el_after_av_social_share  el_before_av_comments_list '><span class='hr-inner '><span class=\"hr-inner-style\"><\/span><\/span><\/div>\r\n\r\n<div  class='av-buildercomment av-av_comments_list-88ce68e426f11248fa394058a3de040f  av-blog-meta-author-disabled av-blog-meta-html-info-disabled'><\/div>","protected":false},"excerpt":{"rendered":"Inspired by the Blog Post \u201cMeasuring Observer Overhead of SQL Trace vs. Extended Events\u201d by Jonathan Kehayias, I was curious to do some more benchmarking. I have already presented the results in my SQL Server Master-Class workshops on XEvents as well as at the PreCon of the SQLSaturday #230. Now I am finally sharing them [&hellip;]","protected":false},"author":4,"featured_media":2913,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[55,43,131,56],"tags":[18,19,175,182,183],"class_list":["post-2915","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-extended-events-en","category-performance","category-sql-trace-profiler","category-tracing-monitoring-en","tag-extended-events-en","tag-performance-analysis-en","tag-sql-trace_profiler-en","tag-tracing-en","tag-wait-analysis-en"],"_links":{"self":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/2915","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/users\/4"}],"replies":[{"embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/comments?post=2915"}],"version-history":[{"count":3,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/2915\/revisions"}],"predecessor-version":[{"id":3092,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/2915\/revisions\/3092"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/media\/2913"}],"wp:attachment":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/media?parent=2915"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/categories?post=2915"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/tags?post=2915"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}