Server性能: PREEMPTIVE_OS_DELETESECURITYCONTEXT主导等待类型

Question

昨天我接到一个客户的电话，他抱怨他们的Server上CPU使用率很高。我们使用的是Server 2012 64位SE。服务器正在运行Windows 2008 R2标准，2.20 GHz英特尔Xeon (4核)，16 GB内存。

在确定罪魁祸首实际上是Server之后，我查看了使用DMV查询这里对实例的顶部等待。排在前两位的是：(1) PREEMPTIVE_OS_DELETESECURITYCONTEXT和(2) SOS_SCHEDULER_YIELD。

编辑:下面是"top waits query“的结果(尽管今天早上有人违背我的意愿重新启动了服务器)：

我们做了大量的计算/转换，所以我可以理解SOS_SCHEDULER_YIELD。然而，我非常好奇PREEMPTIVE_OS_DELETESECURITYCONTEXT等待类型，以及为什么它可能是最高的。

我能找到的关于这个等待类型的最好的描述/讨论可以找到这里。它提到：

Server等待类型是将数据库引擎(通常为Server)留给Win32的调用，并在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，如您所要求，这是您的查询结果。和保罗的有一点不同：

编辑4:我承认，我是第一次扩展事件用户。我将这个等待类型添加到wait_info_external事件中，并看到了数百个条目。没有sql文本或计划句柄，只有调用堆栈。我怎样才能进一步追踪源头？

Answer 1

我知道基于标题的这个问题主要与PREEMPTIVE_OS_DELETESECURITYCONTEXT等待类型有关，但我认为这是对真正问题的误导，即“客户抱怨他们的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子句被注释掉，以查看这是否提供了更有趣/有用的结果。

或者，您可以基于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

Answer 2

server在几个地方使用SecurityContext。您已经命名的一个示例是链接服务器和文件。也许你在用cmdexec？具有代理帐户的Server代理作业？打电话给网络服务？远程资源可能是很多有趣的东西。

可以在windows安全事件中记录模拟事件。可能你在那里找到了线索。此外，您可能需要检查黑匣子记录器，也就是扩展事件。

您是否检查过这些等待类型是新的(以及与高cpu的连接)，还是只是服务器的正常类型？