patternsqlMinor
What interval does SQL Server Profiler's "duration" refer to?
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.
I spent an afternoon watching traces live in SQL Server Profiler, and the absolute epitome of the non-sense was the batch:
Where profiler shows the numbers:
What can possibly be going on in this database engine that perfectly benign queries take too long?
Because even if the server were busy, a query that takes:
should not take 17 seconds to complete.
Duration
The only way forward is to try to figure out what
What does duration mean? Is it:
or is it:
or is it:
(but then how does SQL Server know when the last byte has been "received" by the client).
Because given that:
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
- 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 ServerDateWhere 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.
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.