Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Making sense of the number of reads/writes in SQL Profiler

Tags:

sql-server

alt text

See the SQL Statements indicated in this SQL Profiler view. All these events are coming from one Client machine that is busy with a long-running process, working through a couple thousand rows. Each processing of a row takes about 6.5 seconds, which is what the SQL Profiler is showing as the time between logouts, even though the actual update statement takes only 1ms. Each login/logout uses the same SPID. See that between any given Login and Logout event, the SQL Statements indicate a Reads count of 17 and a Writes count of 0. Yet, the Logout event indicates a total Reads count in excess of 2million and a writes count in excess of 10k. What events do I need to be profiling to try to figure out what statement is causing those reads/writes, because I suspect that those are the ones causing the 6.5 second delay, yet I can't see them happening?

like image 429
Shawn de Wet Avatar asked Dec 01 '10 10:12

Shawn de Wet


1 Answers

The Reads/Writes figures given for the Audit:Logout event are the cumulative totals for the duration of that connection. In itself, the values don't tell you any detail - if you run 10 commands within the lifetime of a connection, you'll be seeing the total figures for all 10 commands within that session.

To know what the breakdown was by statement, you need to look at the SQL:BatchCompleted (or SQL:StmtCompleted) events that are recorded for that same SPID between the starting Audit:Login event, and the ending Audit:Logout event.

Update: Looking at the image, the thing that looks a bit odd (to me at least), is that after each Audit:Logout, the Reads value is not reset, and so each time it is being incremented by the number of reads for the statement being executed (17). I'm not sure 100% therefore at what point that figure will be reset - but the basic point is that the figure is cumulative and could have been built up over time/a number of statements so doesn't necessarily mean you have a heavy query hitting the server!

I suspect that Reads/Writes figures for Audit:Logout are behaving cumulatively as above. But the Duration bucks that trend. It looks like Duration is not cumulative. Some descriptions from MSDN:

Duration : Amount of time since the user logged in (approximately).
Reads: Number of logical read I/Os issued by the user during the connection.
Writes: Number of logical write I/Os issued by the user during the connection.

like image 190
AdaTheDev Avatar answered Oct 04 '22 12:10

AdaTheDev