{"id":1853,"date":"2017-02-03T14:28:51","date_gmt":"2017-02-03T13:28:51","guid":{"rendered":"http:\/\/andreas-wolter.com\/?p=1853\/"},"modified":"2017-12-01T17:06:35","modified_gmt":"2017-12-01T16:06:35","slug":"where-is-that-preemptive-wait-coming-from","status":"publish","type":"post","link":"https:\/\/andreas-wolter.com\/en\/where-is-that-preemptive-wait-coming-from\/","title":{"rendered":"Where is that Preemptive Wait coming from?"},"content":{"rendered":"\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_heading-bc77ff5c0dcabbcbdd4d3f9c603d2361\">\n#top .av-special-heading.av-av_heading-bc77ff5c0dcabbcbdd4d3f9c603d2361{\npadding-bottom:10px;\n}\nbody .av-special-heading.av-av_heading-bc77ff5c0dcabbcbdd4d3f9c603d2361 .av-special-heading-tag .heading-char{\nfont-size:25px;\n}\n.av-special-heading.av-av_heading-bc77ff5c0dcabbcbdd4d3f9c603d2361 .av-subheading{\nfont-size:15px;\n}\n<\/style>\n<div  class='av-special-heading av-av_heading-bc77ff5c0dcabbcbdd4d3f9c603d2361 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\"  >Where is that Preemptive Wait coming from?<\/h3><div class='av-subheading av-subheading_below'><p>Database Ownership and Performance: a journey through SQL Server internals with XEvents, Windbg and Wireshark<\/p>\n<\/div><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>In this article I will bring together several techniques for troubleshooting a performance- and security-related \u201cphenomenon\u201d I recently noticed when doing some tests with Natively Compiled Stored Procedures.<!--more--><\/p>\n<p><strong>Background:<\/strong> In SQL Server 2014, <a href=\"https:\/\/msdn.microsoft.com\/en-us\/library\/dn133184.aspx\" target=\"_blank\" rel=\"noopener\">Natively Compiled Stored Procedures<\/a> did not support EXECUTE AS CALLER but EXECUTE AS \u201cSpecificUser\u201d was required. This user could be specified with \u201cUsername\u201d, \u201cSelf\u201d or simply \u201cOwner\u201d \u2013 in which case the owner of the procedure usually reverts to the schema owner, which mostly reverts to the Database Owner altogether.<\/p>\n<p><strong>The phenomenon<\/strong> I encountered was that I noticed some pretty strange <strong>long execution times<\/strong> when running a workload consisting of a <strong>very basic stored procedure<\/strong> that does nothing more than insert one row of data into a small, unspectacular table.<\/p>\n<p>The insert itself should run less than a second for 1000 rows, but I could see up to 5 seconds. The body of the procedure looks like this:<\/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-a5134770d2bcbe205057ebc3ecd2246f\">\n.avia-image-container.av-av_image-a5134770d2bcbe205057ebc3ecd2246f img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-a5134770d2bcbe205057ebc3ecd2246f .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-a5134770d2bcbe205057ebc3ecd2246f av-styling- avia-align-center  avia-builder-el-2  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-1854 avia-img-lazy-loading-not-1854 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/01_Procedure.png\" alt='' title='01_Procedure'  height=\"134\" width=\"317\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/01_Procedure.png 317w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/01_Procedure-300x127.png 300w\" sizes=\"(max-width: 317px) 100vw, 317px\" \/><\/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>The analysis: <\/strong>Since neither the query plan nor \u201cShow Statistics ON\u201d showed anything unusual, I took a step back and started a top-down-analysis with the <strong><em>Waits and Queues Methodology<\/em><\/strong> (which, if you are new in this area, has been a proven methodology for performance analysis for over a decade and is explained for SQL Server probably for the first time in detail here: <a href=\"https:\/\/technet.microsoft.com\/en-us\/library\/cc966413.aspx\" target=\"_blank\" rel=\"noopener\">SQL Server 2005 Performance Tuning using the Waits and Queues<\/a>) Using the new <strong>session-level waits<\/strong>-DMV in SQL Server 2016 (sys.dm_exec_session_wait_stats), I saw the following distribution of waits:<\/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-beab4b84a3745390eeb26bff9ff4edb3\">\n.avia-image-container.av-av_image-beab4b84a3745390eeb26bff9ff4edb3 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-beab4b84a3745390eeb26bff9ff4edb3 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-beab4b84a3745390eeb26bff9ff4edb3 av-styling- avia-align-center  avia-builder-el-4  el_after_av_textblock  el_before_av_image '   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-1856 avia-img-lazy-loading-not-1856 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/02_Stats.png\" alt='' title='02_Stats'  height=\"214\" width=\"656\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/02_Stats.png 656w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/02_Stats-600x196.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/02_Stats-300x98.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/08\/02_Stats-450x147.png 450w\" sizes=\"(max-width: 656px) 100vw, 656px\" \/><\/div><\/div><\/div>\r\n\r\n\n<style type=\"text\/css\" data-created_by=\"avia_inline_auto\" id=\"style-css-av-av_image-d08e3dc736d92fb048d4e024b21be47c\">\n.avia-image-container.av-av_image-d08e3dc736d92fb048d4e024b21be47c img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-d08e3dc736d92fb048d4e024b21be47c .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-d08e3dc736d92fb048d4e024b21be47c av-styling- avia-align-center  avia-builder-el-5  el_after_av_image  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-4977 avia-img-lazy-loading-not-4977 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD.png\" alt='' title='1702_WaitsDMV_withCMEMTHREAD'  height=\"367\" width=\"1165\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD.png 1165w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-600x189.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-300x95.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-768x242.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-1030x324.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-705x222.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_withCMEMTHREAD-450x142.png 450w\" sizes=\"(max-width: 1165px) 100vw, 1165px\" \/><\/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>From this list, Latch-contention, blocking and some waiting for IO is to be expected with a very concurrent workload (50 threads trying to insert on the last page). The wait-types marked red are the ones that caught my attention. As Preemptive waits are a quite different beast, and I initially thought maybe there was some authentication issue with the client, I decided to take a look at the CMEMTHREAD.<\/p>\n<p>The <strong>CMEMTHREAD<\/strong> is an indicator that many threads are contending simultaneously for a thread-safe memory object. Now since we are running a highly concurrent workload, I could just leave it at that, but remember: \u201cNever make quick decisions by confusing symptom with cause\u201d. Keep looking for the real cause. (A good article by Paul Randal on exactly this issue: \u201c<a href=\"https:\/\/sqlperformance.com\/2014\/02\/sql-performance\/knee-jerk-performance-troubleshooting\" target=\"_blank\" rel=\"noopener\">Avoiding Knee-Jerk Performance Troubleshooting<\/a>\u201d)<\/p>\n<p>So, the question is, which memory object is so special here.<\/p>\n<p>Time for <strong>Extended Events<\/strong> One of the niftiest features of extended events is that you can get a full stack dump of just a single thread, using the Action \u201csqlserver.create_dump_single_thread\u201d. Similarly, using \u201cpackage0.callstack\u201d you can get a callstack of the last 16 frames. You can analyze the outcome with <strong>Windbg<\/strong>. \u2013 Or, using Trace Flag 3656, you can even query the Extended Event targets directly with XQuery from within Management Studio and the callstack will be materialized, provided you have loaded the correct symbols. (Nothing you should do on a production Server!) (An example how to do that can be found here: <a href=\"https:\/\/blogs.msdn.microsoft.com\/sqlcat\/2010\/05\/11\/resolving-dtc-related-waits-and-tuning-scalability-of-dtc\/\" target=\"_blank\" rel=\"noopener\">Resolving DTC Related Waits and Tuning Scalability of DTC<\/a>)<\/p>\n<p>With the dump opened in Windbg the following function calls inside the SQL Server engine can be seen:<\/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-8970399a3b538f50f4e759c343336c50\">\n.avia-image-container.av-av_image-8970399a3b538f50f4e759c343336c50 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-8970399a3b538f50f4e759c343336c50 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-8970399a3b538f50f4e759c343336c50 av-styling- avia-align-center  avia-builder-el-7  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-4969 avia-img-lazy-loading-not-4969 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ.png\" alt='' title='1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ'  height=\"858\" width=\"1045\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ.png 1045w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-600x493.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-300x246.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-768x631.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-1030x846.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-705x579.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_Windbg_CMEMTHREAD_GetNtGroupsViaAuthZ-450x369.png 450w\" sizes=\"(max-width: 1045px) 100vw, 1045px\" \/><\/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>The <strong>Stack dump<\/strong> rings a bell. Right before allocating the memory (CMemThread::Alloc (red), several functions with very familiar names were called (orange):<\/p>\n<p>sqllang!CWindowsSecurityPrimaryInfo::GetNtGroupsViaAuthZ<br \/>\nsqllang!CreateLoginToken<br \/>\nsqllang!CreateLoginTokenForImpersonation<\/p>\n<p>And those in turn must have been caused by the sqllang!CAutoExecuteAsContext::Set, sqllang!CMsqlExecContext::FExecute and so on (green). At this point I pretty much knew where to look. But just to show you an example of how this can be done without even touching Windbg, here is an (accumulated and commented) result from the Extended Event <strong><em>callstack-Action<\/em><\/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-0c919b1f0322ff7cb1ea6888066ff4c4\">\n.avia-image-container.av-av_image-0c919b1f0322ff7cb1ea6888066ff4c4 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-0c919b1f0322ff7cb1ea6888066ff4c4 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-0c919b1f0322ff7cb1ea6888066ff4c4 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-4971 avia-img-lazy-loading-not-4971 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack.png\" alt='' title='1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack'  height=\"1016\" width=\"1283\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack.png 1283w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-600x475.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-300x238.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-768x608.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-1030x816.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-705x558.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_Callstack_XEvent_PREEMPTIVE_OS_LOOKUPACCOUNTSID_edited_2ndstack-450x356.png 450w\" sizes=\"(max-width: 1283px) 100vw, 1283px\" \/><\/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>This callstack results from the <strong>PREEMPTIVE_OS_LOOKUPACCOUNTSID Wait-Type<\/strong>, which I noticed would happen exactly once per procedure call. When analyzing different callstacks together I could draw the conclusion that <strong>the following function calls lead to the respective Wait-Types<\/strong>:<\/p>\n<p>sqllang.dll!LookupAccountNameInternal -> PREEMPTIVE_OS_LOOKUPACCOUNTSID<br \/>\nsqllang.dll!CWindowsSecurityPrimaryInfo::GetNtGroupsViaAuthZ -> PREEMPTIVE_OS_AUTHZINITIALIZERESOURCEMANAGER<br \/>\nsqllang.dll!CWindowsSecurityPrimaryInfo::Init -> PREEMPTIVE_OS_AUTHORIZATIONOPS<\/p>\n<p>The Preemptive Waits read from the Extended Events file-target can be ordered in their occurrence (from top to bottom), leading to the following picture:<\/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-5aa6a2b00d5a74e14a7c4643dfb8937a\">\n.avia-image-container.av-av_image-5aa6a2b00d5a74e14a7c4643dfb8937a img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-5aa6a2b00d5a74e14a7c4643dfb8937a .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-5aa6a2b00d5a74e14a7c4643dfb8937a 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-4979 avia-img-lazy-loading-not-4979 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder.png\" alt='' title='1702_WaitsPreemptive_XEvents_inOrder'  height=\"957\" width=\"933\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder.png 933w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-600x615.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-292x300.png 292w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-768x788.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-36x36.png 36w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-687x705.png 687w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsPreemptive_XEvents_inOrder-450x462.png 450w\" sizes=\"(max-width: 933px) 100vw, 933px\" \/><\/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>The hereunreadable callstack for the call to AUTHORIZATIONOPS (undocumented) at the bottom.<\/p>\n<p><strong>First outcome:<\/strong><\/p>\n<p>From those calls one can deduct that not the client is authenticating at SQL Server, but actually the procedure call itself causes Windows API calls (<a href=\"https:\/\/msdn.microsoft.com\/en-us\/library\/windows\/desktop\/aa379166(v=vs.85).aspx\" target=\"_blank\" rel=\"noopener\">LOOKUPACCOUNTSID<\/a>, <a href=\"https:\/\/msdn.microsoft.com\/en-us\/library\/windows\/desktop\/aa376313(v=vs.85).aspx\" target=\"_blank\" rel=\"noopener\">AUTHZINITIALIZERESOURCEMANAGER<\/a>) for authentication purposes. Now at the very latest it\u2019s time to check the ownership-chain for the stored procedure. So I checked the header of the proc, and indeed, just as I expected it contained a <strong>\u201cWITH EXECUTE AS OWNER\u201d<\/strong>. That alone can\u2019t be it, so the question is, who is the owner. I already suspected it and there it was: <strong>The database was owned by a <u>LOCAL Windows account<\/u>. <\/strong>Now, that is rare, but it all makes sense now: For every execution of the procedure, the ownership had to be verified \u2013 and since it is a Windows-Account, it had to go out of SQL Server OS, using a <em>Preemptive call<\/em> to Windows, wait, and continue only after Windows returns control of this thread back to SQL Server.<\/p>\n<p><strong>Testing the improvement options:<\/strong> Now, obviously, I did not stop here but rather made some more tests. Based on the fact that there are possible types of owner for objects within SQL Server, I compared the execution times (and waits) between those <strong>3 possible Database owner-types:<\/strong><\/p>\n<ol>\n<li><strong>SQL Account<\/strong><\/li>\n<li><strong>Windows DomainAccount<\/strong><\/li>\n<li><strong>Local Windows Account<\/strong><\/li>\n<\/ol>\n<p>&#8211; I did also test with Admin vs. non-Admin and NTLM vs. Kerberos but saw no difference.<\/p>\n<p>So here is the <strong>result of the Performance-Comparison with different Database-\/Procedure-Owners:<\/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-936ae9c25b1f15b27994896fd4cb1a98\">\n.avia-image-container.av-av_image-936ae9c25b1f15b27994896fd4cb1a98 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-936ae9c25b1f15b27994896fd4cb1a98 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-936ae9c25b1f15b27994896fd4cb1a98 av-styling- avia-align-center  avia-builder-el-13  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-4967 avia-img-lazy-loading-not-4967 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner.png\" alt='' title='1702 ProcedureStats_by_DBOwner'  height=\"329\" width=\"860\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner.png 860w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner-600x230.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner-300x115.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner-768x294.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner-705x270.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702-ProcedureStats_by_DBOwner-450x172.png 450w\" sizes=\"(max-width: 860px) 100vw, 860px\" \/><\/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>Interpretation:<\/strong><\/p>\n<ol>\n<li>The obvious: Using a local Windows Account results in a huge performance-penalty for such a simple INSERT-statement<\/li>\n<li>Using a Domain Account I could notice that <strong>every 10 minutes the next execution would be a bit slower<\/strong>.<\/li>\n<\/ol>\n<p><strong>Further analysis<\/strong><\/p>\n<p>When checking the Wait-stats again, I could see that usually the Windows-Domain-Account had the following simple waits:<\/p>\n<p><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-full wp-image-4973\" src=\"http:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount.png\" alt=\"\" width=\"963\" height=\"170\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount.png 963w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount-600x106.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount-300x53.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount-768x136.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount-705x124.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccount-450x79.png 450w\" sizes=\"auto, (max-width: 963px) 100vw, 963px\" \/><\/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>Pretty ok and nothing to worry about. But the first call after 10 minutes would always result in the same wait-types as I observed for the local Windows Account, except that the wait-times are much much lower. (You can compare the below picture with the one from the beginning of the article.)<\/p>\n<p><img loading=\"lazy\" decoding=\"async\" class=\"aligncenter size-full wp-image-4975\" src=\"http:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT.png\" alt=\"\" width=\"1166\" height=\"302\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT.png 1166w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-600x155.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-300x78.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-768x199.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-1030x267.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-705x183.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WaitsDMV_OwnerDomainAccountNewTGT-450x117.png 450w\" sizes=\"auto, (max-width: 1166px) 100vw, 1166px\" \/><\/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>Behind the Scenes: Network Tracing<\/strong><\/p>\n<p>To explain the difference, I ran a <strong>Network Trace using Wireshark <\/strong>And exactly every 10 minutes I saw some additional KERBEROS-traffic going to the Domain Controller. Below you see the opened data frame with the <strong>Request for a Ticket Granting Service Ticket (TGS-REQ).<\/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-6246c63dfa177a5f4d9d39d8aa14e0e5\">\n.avia-image-container.av-av_image-6246c63dfa177a5f4d9d39d8aa14e0e5 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-6246c63dfa177a5f4d9d39d8aa14e0e5 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-6246c63dfa177a5f4d9d39d8aa14e0e5 av-styling- avia-align-center  avia-builder-el-17  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-4983 avia-img-lazy-loading-not-4983 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ.png\" alt='' title='1702_WireShark_TGS-REQ'  height=\"1067\" width=\"1542\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ.png 1542w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-600x415.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-300x208.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-768x531.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-1030x713.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-1500x1038.png 1500w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-705x488.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REQ-450x311.png 450w\" sizes=\"(max-width: 1542px) 100vw, 1542px\" \/><\/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>Background infos:<\/strong><\/p>\n<p>As the User, on whose behalf the service requests the service ticket, is identified using the user name and user realm\/domain (SQL\\SQLDBOwner in my case), the padata type PA-FOR-USER is used, as you can see in the screenshot. You can even see the Checksum added for protection.<\/p>\n<p>The <em>S4U2self<\/em> extension of the PA-DATA structure allows a service to obtain a service ticket to itself on behalf of a user. The user is identified to the KDC using the user&#8217;s name and realm.<\/p>\n<p>Luckily the DC answers right away with a <strong>TGS-REP<\/strong>, containing the PA-DATA-structure with ticket for the service that was named in the TGS-REQ from above:<\/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-ba9414872d22c1b58f5e9e7cec851fc8\">\n.avia-image-container.av-av_image-ba9414872d22c1b58f5e9e7cec851fc8 img.avia_image{\nbox-shadow:none;\n}\n.avia-image-container.av-av_image-ba9414872d22c1b58f5e9e7cec851fc8 .av-image-caption-overlay-center{\ncolor:#ffffff;\n}\n<\/style>\n<div  class='avia-image-container av-av_image-ba9414872d22c1b58f5e9e7cec851fc8 av-styling- avia-align-center  avia-builder-el-19  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-4981 avia-img-lazy-loading-not-4981 avia_image ' src=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP.png\" alt='' title='1702_WireShark_TGS-REP'  height=\"1065\" width=\"1551\"  itemprop=\"thumbnailUrl\" srcset=\"https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP.png 1551w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-600x412.png 600w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-300x206.png 300w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-768x527.png 768w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-1030x707.png 1030w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-1500x1030.png 1500w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-705x484.png 705w, https:\/\/andreas-wolter.com\/wp-content\/uploads\/2017\/12\/1702_WireShark_TGS-REP-450x309.png 450w\" sizes=\"(max-width: 1551px) 100vw, 1551px\" \/><\/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>There is plenty literature available if you want to learn more about the Kerberos Protocol-Elements. Here is a documentation from Microsoft:<\/p>\n<p><a href=\"https:\/\/msdn.microsoft.com\/en-us\/library\/cc246071.aspx\" target=\"_blank\" rel=\"noopener\">Kerberos Protocol Extensions: Service for User and Constrained Delegation Protocol<\/a><\/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 10-minutes puzzle: <\/strong>1) After doing some extensive testing, I conclude that the <strong>10-minute interval<\/strong> after which <strong>a new Ticket Granting Service Ticket-Request is initiated<\/strong> must be a SQL Server specific enhancement for Domain Accounts to avoid making this round trip for every SID-validation. The 10 minutes are consistent and independent from other workload influencers. The cause behind is not documented.<\/p>\n<p>2) The much faster validation for the AD-Account is very fast thanks to some caching in Windows. (Thank you, Jack Richins from formerly SQL Security Team, for reminding me of this)<\/p>\n<p>3) For the local Windows Account, there is no such performance improvement via caching which results in much slower response times.<\/p>\n<p><strong>Final results and learnings:<\/strong><\/p>\n<ol>\n<li>Using local users for SQL Server can create noticeable impact for short transactions. Yet another reason to <strong>stay away from local accounts.<\/strong><\/li>\n<li>For the SQL Account, naturally no Windows calls are necessary at all, but the performance-advantage compared to the AD-Account is marginal, even for high-speed scenarios.<\/li>\n<li><strong>Network latency matters even between SQL Server and DC.<\/strong> Not just for the initial Login-phase but even for ongoing validations from within SQL-statements.<\/li>\n<\/ol>\n<p>I can stick to my recommendation for Database Ownerships (<a href=\"https:\/\/andreas-wolter.com\/en\/sql-server-database-ownership-survey-results-recommendations\/\">SQL Server Database Ownership: survey results &#038; recommendations<\/a>) \ud83d\ude42<\/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>I hope you found this an interesting read.<\/p>\n<p>Andreas<\/p>\n<p><br class=\"\u201cclear\u201c\" \/>PS: for the geeks among you:<\/p>\n<p><strong>The Stack Dump in Text format together with some comments:<\/strong><br \/>\n<br class=\"\u201cclear\u201c\" \/><\/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>Child-SP\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 RetAddr\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 Call Site<\/p>\n<p>000000e9`2f0b79d8 00007ffe`f9e51118 ntdll!<strong>NtWaitForSingleObject<\/strong>+0xa<\/p>\n<p>-> this function is actually <a href=\"https:\/\/msdn.microsoft.com\/en-us\/library\/ms648412(v=vs.85).aspx\" target=\"_blank\" rel=\"noopener\">deprecated<\/a> (Hello, Microsoft?)<\/p>\n<p>000000e9`2f0b79e0 00007ff7`04999fef KERNELBASE!WaitForSingleObjectEx+0x94<\/p>\n<p>000000e9`2f0b7a80 00007ff7`04999d7d sqlservr!CDmpDump::DumpInternal+0x22f<\/p>\n<p>000000e9`2f0b7b20 00007ff7`049a15b8 sqlservr!CDmpDump::DumpFilter+0xcd<\/p>\n<p>000000e9`2f0b7c10 00007ffe`ef0ef2cb sqlservr!memset+0x1819<\/p>\n<p>000000e9`2f0b7c40 00007ffe`fc98398d msvcr120!__C_specific_handler+0x93 [f:\\dd\\vctools\\crt\\crtw32\\misc\\amd64\\chandler.c @ 162]<\/p>\n<p>000000e9`2f0b7cb0 00007ffe`fc9493a7 ntdll!RtlpExecuteHandlerForException+0xd<\/p>\n<p>000000e9`2f0b7ce0 00007ffe`fc948fbd ntdll!RtlDispatchException+0x197<\/p>\n<p>000000e9`2f0b83b0 00007ffe`f9e58b9c ntdll!RtlRaiseException+0x18d<\/p>\n<p>000000e9`2f0b8b70 00007ff7`04999c9c KERNELBASE!RaiseException+0x68<\/p>\n<p>000000e9`2f0b8c50 00007ffe`f05602c6 sqlservr!CDmpDump::Dump+0x4c<\/p>\n<p>000000e9`2f0b8c90 00007ffe`f105c411 sqllang!SQLDumperLibraryInvoke+0x1f6<\/p>\n<p>000000e9`2f0b8cd0 00007ffe`f105ce94 sqllang!SQLLangDumperLibraryInvoke+0x161<\/p>\n<p>000000e9`2f0b8d80 00007ffe`f102cd0b sqllang!CImageHelper::DoMiniDump+0x475<\/p>\n<p>000000e9`2f0b8f90 00007ffe`f072e9c4 sqllang!stackTrace+0x9db<\/p>\n<p>000000e9`2f0ba9b0 00007ffe`f072f6ae sqllang!XeSqlPkg::IsSystem+0x174<\/p>\n<p>000000e9`2f0bab90 00007ffe`ef2e779a sqllang!XeSqlPkg::<strong>CreateDumpSingleThreadActionInvoke<\/strong>+0x1e<\/p>\n<p>-> you can clearly see how this stack dump was created: XEvents<\/p>\n<p>000000e9`2f0babc0 00007ffe`ef2a1b8e sqldk!XeSosPkg::<strong>wait_info_external<\/strong>::Publish+0x1a9<\/p>\n<p>-> Now we will see our wait-type when we ask the DMVs or XEvents<\/p>\n<p>000000e9`2f0bac20 00007ffe`ef2a63a4 sqldk!SOS_Scheduler::<strong>UpdateWaitTimeStats<\/strong>+0x596<\/p>\n<p>000000e9`2f0bb530 00007ffe`f0d94fac sqldk!SOS_Task::PopWait+0xba<\/p>\n<p>000000e9`2f0bb590 00007ffe`f0d9481e sqllang!CWindowsSecurityPrimaryInfo::<strong>GetNtGroupsViaAuthZ<\/strong>+0x75c<\/p>\n<p>-> this will lead to the Preemptive Wait: PREEMPTIVE_OS_AUTHZINITIALIZERESOURCEMANAGER<\/p>\n<p>000000e9`2f0bb890 00007ffe`f0d956ed sqllang!CWindowsSecurityPrimaryInfo::Init+0x2ce<\/p>\n<p>000000e9`2f0bba00 00007ffe`f041a88b sqllang!GetWindowsSecurityPrimaryInfo+0xbe<\/p>\n<p>000000e9`2f0bba60 00007ffe`f041cadb sqllang!CreateLoginToken+0x2d7<\/p>\n<p>000000e9`2f0bbc50 00007ffe`f041dca8 sqllang!CreateLoginTokenForImpersonation+0xcb2<\/p>\n<p>-> an Impersonation is happening (EXECUTE AS)<\/p>\n<p>000000e9`2f0bc400 00007ffe`f0358342 sqllang!CAutoExecuteAsContext::Set+0xe2d<\/p>\n<p>000000e9`2f0bc680 00007ffe`f001245e sqllang!CSECExecAsRuntimeServices::_Set+0x424<\/p>\n<p>000000e9`2f0bc900 00007ffe`f0012041 sqllang!CMsqlExecContext::FExecute+0x336<\/p>\n<p>000000e9`2f0bcc30 00007ffe`f0d1d83d sqllang!CSQLSource::Execute+0x983<\/p>\n<p>000000e9`2f0bcdd0 00007ffe`f0d1d241 sqllang!CStmtExecProc::XretLocalExec+0x26e<\/p>\n<p>000000e9`2f0bce50 00007ffe`f0d19f98 sqllang!CStmtExecProc::XretExecExecute+0x481<\/p>\n<p>000000e9`2f0bd600 00007ffe`f00119ca sqllang!CXStmtExecProc::XretExecute+0x38<\/p>\n<p>000000e9`2f0bd640 00007ffe`f0012933 sqllang!CMsqlExecContext::ExecuteStmts<1,1>+0x40d<\/p>\n<p>000000e9`2f0bd780 00007ffe`f0012041 sqllang!CMsqlExecContext::FExecute+0xa9e<\/p>\n<p>000000e9`2f0bdab0 00007ffe`f0cd3f6d sqllang!CSQLSource::Execute+0x983<\/p>\n<p>000000e9`2f0bdc50 00007ffe`f0ce0e6c sqllang!ExecuteSql+0x93d<\/p>\n<p>000000e9`2f0be7d0 00007ffe`f0ce1549 sqllang!CSpecProc::ExecuteSpecial+0x15c<\/p>\n<p>000000e9`2f0be8d0 00007ffe`f001a82b sqllang!CSpecProc::Execute+0x299<\/p>\n<p>000000e9`2f0bea00 00007ffe`f0021542 sqllang!process_request+0xe61<\/p>\n<p>000000e9`2f0befd0 00007ffe`f00210a3 sqllang!process_commands_internal+0x2df<\/p>\n<p>000000e9`2f0bf050 00007ffe`ef2a5bfd sqllang!process_messages+0x253<\/p>\n<p>000000e9`2f0bf260 00007ffe`ef2a58f5 sqldk!SOS_Task::Param::Execute+0x231<\/p>\n<p>000000e9`2f0bf860 00007ffe`ef2a554d sqldk!SOS_Scheduler::RunTask+0xaa<\/p>\n<p>000000e9`2f0bf8d0 00007ffe`ef2cd7c8 sqldk!SOS_Scheduler::ProcessTasks+0x3cd<\/p>\n<p>000000e9`2f0bf9b0 00007ffe`ef2cdb10 sqldk!SchedulerManager::WorkerEntryPoint+0x2a1<\/p>\n<p>000000e9`2f0bfa80 00007ffe`ef2cdcd7 sqldk!SystemThread::RunWorker+0x8f<\/p>\n<p>000000e9`2f0bfab0 00007ffe`ef2cd9f8 sqldk!SystemThreadDispatcher::ProcessWorker+0x2de<\/p>\n<p>000000e9`2f0bfb60 00007ffe`fc6e13d2 sqldk!SchedulerManager::ThreadEntryPoint+0x1d8<\/p>\n<p>000000e9`2f0bfc10 00007ffe`fc9603c4 kernel32!BaseThreadInitThunk+0x22<\/p>\n<p>000000e9`2f0bfc40 00000000`00000000 ntdll!RtlUserThreadStart+0x34<\/p>\n<p>EOF<\/p>\n<\/div><\/section>\r\n\r\n<div  class='hr av-av_hr-0ff602b3e980a3377077ff3c1c834df6 hr-default  avia-builder-el-24  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-25  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-27  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\/where-is-that-preemptive-wait-coming-from\/&#038;t=Where%20is%20that%20Preemptive%20Wait%20coming%20from%3F\" 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=Where%20is%20that%20Preemptive%20Wait%20coming%20from%3F&#038;url=https:\/\/andreas-wolter.com\/en\/?p=1853\" 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=Where%20is%20that%20Preemptive%20Wait%20coming%20from%3F&#038;url=https:\/\/andreas-wolter.com\/en\/where-is-that-preemptive-wait-coming-from\/\" 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-28  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":"In this article I will bring together several techniques for troubleshooting a performance- and security-related \u201cphenomenon\u201d I recently noticed when doing some tests with Natively Compiled Stored Procedures.","protected":false},"author":4,"featured_media":5002,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[55,46,43,57,45,56],"tags":[],"class_list":["post-1853","post","type-post","status-publish","format-standard","has-post-thumbnail","hentry","category-extended-events-en","category-in-memory-oltpxtp-htap","category-performance","category-security-en","category-sql-server-2016","category-tracing-monitoring-en"],"_links":{"self":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/1853","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=1853"}],"version-history":[{"count":20,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/1853\/revisions"}],"predecessor-version":[{"id":6957,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/posts\/1853\/revisions\/6957"}],"wp:featuredmedia":[{"embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/media\/5002"}],"wp:attachment":[{"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/media?parent=1853"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/categories?post=1853"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/andreas-wolter.com\/en\/wp-json\/wp\/v2\/tags?post=1853"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}