HiveBrain v1.2.0
Get Started
← Back to all entries
patternsqlMinor

What interval does SQL Server Profiler's "duration" refer to?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
referwhatsqlintervaldoesprofilerserverduration

Problem

I've been having strange things on a production server. Clients (all on the local LAN) are getting timeout errors on queries that should have no problem at all.

  • it happens during times of low CPU usage (



  • and when there is low hard drive I/O (



I spent an afternoon watching traces live in SQL Server Profiler, and the absolute epitome of the non-sense was the batch:

SELECT GETDATE() As ServerDate


Where profiler shows the numbers:

  • CPU: 0



  • Reads: 0



  • Writes: 0



  • Duration: 17,130 ms



  • StartTime: 2017-02-28 15:00:20.777



  • EndTime: 2017-02-28 15:00:37.907



What can possibly be going on in this database engine that perfectly benign queries take too long?

  • anti-virus software?



  • a VMWare hypervisor that doesn't schedule the virtual machine for 17 seconds?



  • a kernel model stall for 17 seconds that doesn't show up in Task Manager?



Because even if the server were busy, a query that takes:

  • zero cpu



  • zero reads



  • zero writes



  • and has no side effect on any pages in memory



should not take 17 seconds to complete.

Duration

The only way forward is to try to figure out what duration means.

What does duration mean? Is it:

  • Start: after entire batch has been received by the database engine



  • End: after the query is complete



or is it:

  • Start: after entire batch has been received by the database engine



  • End: after the last byte has been sent to the client



or is it:

  • Start: after entire batch has been received by the database engine



  • End: after the last byte has been received by the client



(but then how does SQL Server know when the last byte has been "received" by the client).

Because given that:

  • there's nothing wrong on the server



  • there's nothing wrong on the database



  • there's nothing wrong on the client



there must be something wrong in between. So I need to know exactly what conceptual events SQL Server uses to denote the start and end.

Locks

  • Duration from SQL Server 2005 traces is stored (i.e. when you save the tra

Solution

Duration from SQL Server 2005 traces is stored in microseconds (one-millionth of a second) while Duration from SQL Server 2000 is stored in milliseconds (one-thousandth of a second). CPU is always stored in milliseconds.

The typical cause for long durations with no work is blocking: someone else has a lock on a row.

To find out why queries are waiting, skip Profiler and head to Adam Machanic's sp_WhoIsActive. It shows you what queries are running right now, and the wait_info column tells you what they're waiting on (and for how long). If you see LCK*, then it's blocking.

Context

StackExchange Database Administrators Q#165848, answer score: 5

Revisions (0)

No revisions yet.