I'm having strange timeout errors on a server for trivial queries (that take too long even when no other server load is going on).
Using Extended Events or SQL Profiler, I monitored a query:
- Timestamp: 12/7/2017 12:14:36 PM
- Name: sql_batch_completed
- Batch Text:
SELECT 'Testing Connection...'
- Result: OK
- Row Count: 1
- Logical Reads: 0
- CPU Time: 78,000 us (78 ms)
- Duration: 15,796,907 us (15,797 ms)
For some reason the query:
SELECT 'Testing Connection...'
took 15 seconds to complete.
But what took 15 seconds to complete? It only took 78ms of CPU time. What was in the other 14.2 seconds?
What is the duration that SQL Profiler (and Extended Events) are measuring?
Is it Time-To-Last-Byte delivered to the client? If so, how does it know when the last byte was delivered to the client?
If it does include network time, then this is a fairly slow LAN sometimes.
Books Online
From the SQL Server 2000 Books Online (the last time Profiler was documented):
SQL Profiler Data Columns
SQL Profiler allows you to select data columns when you create a template. These data columns represent the information you would like returned when a trace is running. The data displayed in SQL Profiler can be displayed either in the order the events occur or in a group based on one or a combination of data columns.
The following table describes the SQL Profiler data columns, and which are selected by default.
| Data Column | Column Number | Description | |-------------|---------------|-------------------------------------------------------| | Duration | 13 | Amount of time (in milliseconds) taken by the event. |