SQL Server 性能:PREEMPTIVE_OS_DELETESECURITYCONTEXT 顯性等待類型
昨天我接到一個客戶的電話,他抱怨他們的 SQL Server 上的 CPU 使用率很高。我們使用的是 SQL Server 2012 64 位 SE。伺服器正在執行 Windows Server 2008 R2 Standard、2.20 GHz Intel Xeon(4 核)、16 GB RAM。
在確定罪魁禍首實際上是 SQL Server 之後,我在此處查看了使用 DMV 查詢的頂部等待實例。前兩個等待是: (1)
PREEMPTIVE_OS_DELETESECURITYCONTEXT
和 (2)SOS_SCHEDULER_YIELD
。編輯:這是“頂級等待查詢”的結果(儘管今天早上有人違背我的意願重新啟動了伺服器):
我們做了很多激烈的計算/轉換,所以我能理解
SOS_SCHEDULER_YIELD
。但是,我很好奇PREEMPTIVE_OS_DELETESECURITYCONTEXT
等待類型以及為什麼它可能是最高的。可以在此處找到關於此等待類型的最佳描述/討論。它提到:
PREEMPTIVE_OS_ 等待類型是離開數據庫引擎的呼叫,通常是 Win32 API,並在 SQL Server 之外執行各種任務的程式碼。在這種情況下,它正在刪除以前用於遠端資源訪問的安全上下文。相關的 API 實際上命名為 DeleteSecurityContext()
據我所知,我們沒有任何外部資源,如鍊接伺服器或文件表。而且我們不會進行任何模擬等操作。備份是否會導致這種情況激增或域控制器出現故障?
到底是什麼導致這成為主要的等待類型?如何進一步跟踪這種等待類型?
**編輯 2:**我檢查了 Windows 安全日誌的內容。我看到一些可能感興趣的條目,但我不確定這些是否正常:
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
編輯 3:@Jon Seigel,根據您的要求,這是您的查詢結果。與保羅略有不同:
**編輯 4:**我承認,我是第一次擴展事件使用者。我將此等待類型添加到 wait_info_external 事件並看到數百個條目。沒有 sql 文本或計劃句柄,只有呼叫堆棧。如何進一步追查源頭?
根據標題,我知道這個問題主要與 PREEMPTIVE_OS_DELETESECURITYCONTEXT 等待類型有關,但我認為這是對真正問題的誤導,即“客戶抱怨其 SQL Server 上 CPU 使用率過高”。
我認為專注於這種特定的等待類型是徒勞的,因為它會隨著每一次建立的連接而上升。我在筆記型電腦上執行以下查詢(這意味著我是唯一的使用者):
SELECT * FROM sys.dm_os_wait_stats WHERE wait_type = N'PREEMPTIVE_OS_DELETESECURITYCONTEXT'
然後我執行以下任何操作並重新執行此查詢:
- 打開一個新的查詢選項卡
- 關閉新的查詢選項卡
- 在 DOS 提示符下執行以下命令:
SQLCMD -E -Q "select 1"
現在,我們知道 CPU 很高,所以我們應該查看正在執行的內容,看看哪些會話的 CPU 很高:
SELECT req.session_id AS [SPID], req.blocking_session_id AS [BlockedBy], req.logical_reads AS [LogReads], DB_NAME(req.database_id) AS [DatabaseName], SUBSTRING(txt.[text], (req.statement_start_offset / 2) + 1, CASE WHEN req.statement_end_offset > 0 THEN (req.statement_end_offset - req.statement_start_offset) / 2 ELSE LEN(txt.[text]) END ) AS [CurrentStatement], txt.[text] AS [CurrentBatch], CONVERT(XML, qplan.query_plan) AS [StatementQueryPlan], OBJECT_NAME(qplan.objectid, qplan.[dbid]) AS [ObjectName], sess.[program_name], sess.[host_name], sess.nt_user_name, sess.total_scheduled_time, sess.memory_usage, req.* FROM sys.dm_exec_requests req INNER JOIN sys.dm_exec_sessions sess ON sess.session_id = req.session_id CROSS APPLY sys.dm_exec_sql_text(req.[sql_handle]) txt OUTER APPLY sys.dm_exec_text_query_plan(req.plan_handle, req.statement_start_offset, req.statement_end_offset) qplan WHERE req.session_id <> @@SPID ORDER BY req.logical_reads DESC, req.cpu_time DESC --ORDER BY req.cpu_time DESC, req.logical_reads DESC
我通常按原樣執行上述查詢,但您也可以切換註釋掉哪個 ORDER BY 子句,看看這是否會產生更有趣/有用的結果。
或者,您可以根據 dm_exec_query_stats 執行以下命令來查找成本最高的查詢。下面的第一個查詢將向您顯示單個查詢(即使它們有多個計劃)並按平均 CPU 時間排序,但您可以輕鬆地將其更改為平均邏輯讀取。一旦你找到一個看起來佔用大量資源的查詢,將“sql_handle”和“statement_start_offset”複製到下面第二個查詢的 WHERE 條件中,以查看各個計劃(可以超過 1 個)。滾動到最右邊,假設有一個 XML 計劃,它將顯示為一個連結(在網格模式下),如果您點擊它,它將帶您進入計劃查看器。
查詢 #1:獲取查詢資訊
;WITH cte AS ( SELECT qstat.[sql_handle], qstat.statement_start_offset, qstat.statement_end_offset, COUNT(*) AS [NumberOfPlans], SUM(qstat.execution_count) AS [TotalExecutions], SUM(qstat.total_worker_time) AS [TotalCPU], (SUM(qstat.total_worker_time * 1.0) / SUM(qstat.execution_count)) AS [AvgCPUtime], MAX(qstat.max_worker_time) AS [MaxCPU], SUM(qstat.total_logical_reads) AS [TotalLogicalReads], (SUM(qstat.total_logical_reads * 1.0) / SUM(qstat.execution_count)) AS [AvgLogicalReads], MAX(qstat.max_logical_reads) AS [MaxLogicalReads], SUM(qstat.total_rows) AS [TotalRows], (SUM(qstat.total_rows * 1.0) / SUM(qstat.execution_count)) AS [AvgRows], MAX(qstat.max_rows) AS [MaxRows] FROM sys.dm_exec_query_stats qstat GROUP BY qstat.[sql_handle], qstat.statement_start_offset, qstat.statement_end_offset ) SELECT cte.*, DB_NAME(txt.[dbid]) AS [DatabaseName], SUBSTRING(txt.[text], (cte.statement_start_offset / 2) + 1, CASE WHEN cte.statement_end_offset > 0 THEN (cte.statement_end_offset - cte.statement_start_offset) / 2 ELSE LEN(txt.[text]) END ) AS [CurrentStatement], txt.[text] AS [CurrentBatch] FROM cte CROSS APPLY sys.dm_exec_sql_text(cte.[sql_handle]) txt ORDER BY cte.AvgCPUtime DESC
查詢 #2:獲取計劃資訊
SELECT *, DB_NAME(qplan.[dbid]) AS [DatabaseName], CONVERT(XML, qplan.query_plan) AS [StatementQueryPlan], SUBSTRING(txt.[text], (qstat.statement_start_offset / 2) + 1, CASE WHEN qstat.statement_end_offset > 0 THEN (qstat.statement_end_offset - qstat.statement_start_offset) / 2 ELSE LEN(txt.[text]) END ) AS [CurrentStatement], txt.[text] AS [CurrentBatch] FROM sys.dm_exec_query_stats qstat CROSS APPLY sys.dm_exec_sql_text(qstat.[sql_handle]) txt OUTER APPLY sys.dm_exec_text_query_plan(qstat.plan_handle, qstat.statement_start_offset, qstat.statement_end_offset) qplan -- paste info from Query #1 below WHERE qstat.[sql_handle] = 0x020000001C70C614D261C85875D4EF3C90BD18D02D62453800.... AND qstat.statement_start_offset = 164 -- paste info from Query #1 above ORDER BY qstat.total_worker_time DESC