Sql-Server

SQL Server 性能:PREEMPTIVE_OS_DELETESECURITYCONTEXT 顯性等待類型

  • March 18, 2014

昨天我接到一個客戶的電話,他抱怨他們的 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

引用自:https://dba.stackexchange.com/questions/60830