I received a call yesterday from a customer who was complaining about high CPU usage on their SQL Server. We're using SQL Server 2012 64 bit SE. Server is running Windows Server 2008 R2 Standard, 2.20 GHz Intel Xeon (4 Cores), 16 GB RAM.
After making sure that the culprit was in fact SQL Server, I took a look at the top waits for the instance using the DMV query here. The top two waits were: (1) PREEMPTIVE_OS_DELETESECURITYCONTEXT
and (2) SOS_SCHEDULER_YIELD
.
EDIT: Here are the result of the "top waits query" (although someone restarted the server this morning against my wishes):
We do a lot of intense calculations/conversion, so I can understand SOS_SCHEDULER_YIELD
. However, I am very curious about the PREEMPTIVE_OS_DELETESECURITYCONTEXT
wait type and why it might be the highest.
The best description/discussion that I can find on this wait type can be found here. It mentions:
The PREEMPTIVE_OS_ wait types are calls that left the database engine, typically to a Win32 API, and are performing code outside of SQL Server for various task. In this case, it is deleting a security context previously used for remote resource access. The related API is actually named DeleteSecurityContext()
To my knowledge, we don't have any external resources like linked servers or filetables. And we don't do any impersonation, etc. Could a backup have caused this to spike or maybe a faulty domain controller?
What the heck could cause this to be the dominant wait type? How can I track this wait type further?
Edit 2: I checked the contents of the Windows Security Log. I see a few entries that may be of interest, but I'm not sure if these are normal:
Special privileges assigned to new logon.
Subject:
Security ID: NT SERVICE\MSSQLServerOLAPService
Account Name: MSSQLServerOLAPService
Account Domain: NT Service
Logon ID: 0x3143c
Privileges: SeImpersonatePrivilege
Special privileges assigned to new logon.
Subject:
Security ID: NT SERVICE\MSSQLSERVER
Account Name: MSSQLSERVER
Account Domain: NT Service
Logon ID: 0x2f872
Privileges: SeAssignPrimaryTokenPrivilege
SeImpersonatePrivilege
Edit 3: @Jon Seigel, as you requested, here are the results of your query. A little different than Paul's:
Edit 4: I admit, I'm a first time Extended Events user. I added this wait type to the wait_info_external event and saw hundreds of entries. There is no sql text or plan handle, only a call stack. How can I further track down the source?
Best Answer
I know this question, based on the Title, is mainly concerned with the PREEMPTIVE_OS_DELETESECURITYCONTEXT wait type, but I believe that is a misdirection of the true issue which is " a customer who was complaining about high CPU usage on their SQL Server ".
The reason I believe that focusing on this specific wait type is a wild goose chase is because it goes up for every connection made. I am running the following query on my laptop (meaning I am the only user):
And then I do any of the following and re-run this query:
SQLCMD -E -Q "select 1"
Now, we know that CPU is high so we should look at what is running to see what sessions have high CPU:
I usually run the above query as it is, but you could also switch which ORDER BY clause is commented out to see if that gives more interesting / helpful results.
Alternatively you can run the following, based on dm_exec_query_stats, to find highest-cost queries. The first query below will show you individual queries (even if they have multiple plans) and is ordered by Average CPU Time, but you can easily change that to be Average Logical Reads. Once you find a query that looks like it is taking a lot of resources, copy the "sql_handle" and "statement_start_offset" into the WHERE condition of the second query below to see the individual plans (can be more than 1). Scroll to the far right and assuming there was an XML Plan, it will display as a link (in Grid Mode) which will take you to the plan viewer if you click on it.
Query #1: Get Query Info
Query #2: Get Plan Info