SQL Server Profiler 的“持续时间”是指什么时间间隔？

Question

我在生产服务器上遇到了奇怪的事情。客户端（都在本地 LAN 上）在查询时出现超时错误，本应完全没有问题。

• 它发生在 CPU 使用率低 (<1%) 的时候
• 以及当硬盘驱动器 I/O 较低 (<1%) 时

我花了一个下午在 SQL Server Profiler 中实时观察跟踪，而毫无意义的绝对缩影是批处理：

SELECT GETDATE() As ServerDate

探查器显示数字的地方：

• 中央处理器： 0
• 阅读次数： 0
• 写入： 0
• 持续时间：17,130毫秒
• 开始时间： 2017-02-28 15:00:20.777
• 结束时间： 2017-02-28 15:00:37.907

在这个数据库引擎中可能会发生什么，完全良性查询需要太长时间？

• 防毒软件？
• 一个不会在 17 秒内调度虚拟机的 VMWare 管理程序？
• 一个内核模型停顿了 17 秒，但没有出现在任务管理器中？

因为即使服务器是忙，一个查询，需要：

• 零CPU
• 零读取
• 零写入
• 并且对内存中的任何页面都没有副作用

不应该需要 17 秒才能完成。

期间

唯一的出路是想办法弄清楚这duration 意味着什么。

持续时间是什么意思？是吗：

• 开始：在数据库引擎接收到整个批次之后
• 结束：查询完成后

或者是：

• 开始：在数据库引擎接收到整个批次之后
• 结束：在最后一个字节被发送到客户端之后

或者是：

• 开始：在数据库引擎接收到整个批次之后
• 结束：在客户端接收到最后一个字节之后

（但是 SQL Server 如何知道客户端“接收”了最后一个字节的时间）。

因为鉴于：

• 服务器上没有任何问题
• 数据库没有问题
• 客户端没有问题

这中间一定有什么问题。所以我需要确切地知道 SQL Server 使用什么概念事件来表示start和end。

锁

• SQL Server 2005 跟踪的持续时间以微秒（百万分之一秒）存储（即当您将跟踪保存到表或文件时）
• Profiler 中的持续时间以毫秒（千分之一秒）显示（即在屏幕上和屏幕截图中）

当然，毫秒与微秒不是我的问题。

鉴于唯一getdate()需要的锁是：

• 获取：D（数据库）上的S（共享）锁
• 释放：S（共享）锁在D（数据库）上

如果问题是由于锁定引起的：

• 谁能建议为什么获取数据库上的共享锁可能需要 17 秒
• 如果是由于获取共享数据库锁的延迟 17 秒
• 为什么其他批次可以继续获取/释放共享数据库锁而不会出现停顿？
• 如果停顿是由于需要 17 秒才能获得锁
• 我该怎么办？

那也不是我的问题。我的问题是同义反复。

同义反复

我写的问题很简单：

持续时间是什么意思？

当然，这很容易回答：

持续时间是EndTime - StartTime。

这意味着我实际上是在问（而不是迂腐）：

• 在查询执行的哪个阶段记录StartTime时间戳？
• 在查询执行的哪个阶段记录EndTime时间戳？

如果我能得到答案，我接下来的问题将是找到介于两者之间的所有事件。

奖金喋喋不休

查看以下期间所有事件的时间表可能会有所帮助select getdate()：

1. 获取共享数据库锁
2. 释放共享数据库锁
3. SP:缓存未命中
4. SQL：批量启动
5. SQL:StmtStarting
6. SQL:StmtCompleted
7. SQL：批量完成

当然，这只是一个不可重复的、随机的、运行时间过长的查询示例。

奖励阅读

• SQL Server 随机插入需要 10+ 秒才能完成？ （被脾气暴躁的人关闭）
• SQL Profiler CPU / 持续时间单位 （17,000 毫秒）
• 使用 SQL Server Profiler 查看和分析跟踪

Answer 1

SQL Server 2005 跟踪的持续时间以微秒（百万分之一秒）为单位存储，而 SQL Server 2000 跟踪的持续时间以毫秒（千分之一秒）为单位存储。CPU 总是以毫秒为单位存储。

长时间没有工作的典型原因是阻塞：其他人锁定了某行。

要了解查询等待的原因，请跳过 Profiler 并前往 Adam Machanic 的 sp_WhoIsActive。它向您显示当前正在运行哪些查询，并且 wait_info 列告诉您它们正在等待什么（以及等待多长时间）。如果你看到 LCK*，那么它就被阻塞了。