Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 


 
     
Recent Posts
   
Popular Topics
Home   
Search
    Members    Calendar    Who's On

Home » SQL Server 2008 » SQL Server 2008 - General » Double counting reads in profiler
Add to briefcase

Double counting reads in profiler Expand / Collapse
Rate Topic
Display Mode
Topic Options
Author
Message
SwedishOrr
Posted Wednesday, May 05, 2010 4:36 PM


SSC Veteran

SSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC Veteran

Group: General Forum Members
Last Login: Thursday, September 13, 2012 3:25 PM
Points: 205, Visits: 640
This is a strange one. I'm tracing a proc in profiler and it seems that it's double counting reads for a specific set of statements.

In my proc, I have the following two lines:

select @sql = 'insert into lookups (fieldname) select distinct '+QUOTENAME(@fieldname)+' from '+QUOTENAME(@tablename)+' where '+QUOTENAME(@fieldname)+' IS NOT NULL and ltrim(rtrim(convert(nvarchar(max),'+QUOTENAME(@fieldname)+'))) <> ''\'''
exec /*test*/ sp_executesql @sql

Now, in profiler I see the following two lines:

TextData
insert into lookups (fieldname) select distinct [languages] from [table] where [languages] IS NOT NULL and ltrim(rtrim(convert(nvarchar(max),[languages]))) <> '\'
exec /*test*/ sp_executesql @sql

Reads
58161
58161


I used /*test*/ in my exec line to be sure I was seeing the correct sp_executesql call. I'm not sure where to look for answers to this, or even how I would google this... So I turn to you folks.

Any help is hugely appreciated!
Post #916562
Grant Fritchey
Posted Wednesday, May 05, 2010 8:16 PM


SSChampion

SSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampion

Group: General Forum Members
Last Login: Today @ 6:59 AM
Points: 13,378, Visits: 25,163
what events are you tracing? You could see this if you were tracing statement and rpc complete, for example.

----------------------------------------------------
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood..." Theodore Roosevelt
The Scary DBA
Author of: SQL Server 2012 Query Performance Tuning
SQL Server 2008 Query Performance Tuning Distilled
and
SQL Server Execution Plans

Product Evangelist for Red Gate Software
Post #916622
Jeff Moden
Posted Wednesday, May 05, 2010 11:30 PM


SSC-Dedicated

SSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-DedicatedSSC-Dedicated

Group: General Forum Members
Last Login: Yesterday @ 9:57 PM
Points: 32,906, Visits: 26,790
Contrary to popular belief, the reads are usually the result of an index or two on the table you're inserting into. There could also be a trigger on the table.

--Jeff Moden
"RBAR is pronounced "ree-bar" and is a "Modenism" for "Row-By-Agonizing-Row".

First step towards the paradigm shift of writing Set Based code:
Stop thinking about what you want to do to a row... think, instead, of what you want to do to a column."

For better, quicker answers on T-SQL questions, click on the following...
http://www.sqlservercentral.com/articles/Best+Practices/61537/

For better answers on performance questions, click on the following...
http://www.sqlservercentral.com/articles/SQLServerCentral/66909/
Post #916665
Grant Fritchey
Posted Thursday, May 06, 2010 5:20 AM


SSChampion

SSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampion

Group: General Forum Members
Last Login: Today @ 6:59 AM
Points: 13,378, Visits: 25,163
Jeff Moden (5/5/2010)
Contrary to popular belief, the reads are usually the result of an index or two on the table you're inserting into. There could also be a trigger on the table.


Not to mention any referential integrity checks that could go against other tables.

But based on what they said, and the way it was said, it almost sounded like they were seeing two rows worth of information in the trace output. That sounds like multiple events to me.

----------------------------------------------------
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood..." Theodore Roosevelt
The Scary DBA
Author of: SQL Server 2012 Query Performance Tuning
SQL Server 2008 Query Performance Tuning Distilled
and
SQL Server Execution Plans

Product Evangelist for Red Gate Software
Post #916814
SwedishOrr
Posted Thursday, May 06, 2010 8:04 AM


SSC Veteran

SSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC Veteran

Group: General Forum Members
Last Login: Thursday, September 13, 2012 3:25 PM
Points: 205, Visits: 640
I double checked to make sure I wasn't looking at two different event classes, and both are SP:StmtCompleted.

HTH
Post #916988
Grant Fritchey
Posted Thursday, May 06, 2010 8:09 AM


SSChampion

SSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampionSSChampion

Group: General Forum Members
Last Login: Today @ 6:59 AM
Points: 13,378, Visits: 25,163
SwedishOrr (5/6/2010)
I double checked to make sure I wasn't looking at two different event classes, and both are SP:StmtCompleted.

HTH


If you're seeing two SP:StmtCompleted entries, then you've got two statements that are completing. Double-check the code.

----------------------------------------------------
"The credit belongs to the man who is actually in the arena, whose face is marred by dust and sweat and blood..." Theodore Roosevelt
The Scary DBA
Author of: SQL Server 2012 Query Performance Tuning
SQL Server 2008 Query Performance Tuning Distilled
and
SQL Server Execution Plans

Product Evangelist for Red Gate Software
Post #916992
Dave Ballantyne
Posted Thursday, May 06, 2010 8:18 AM


SSCommitted

SSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommitted

Group: General Forum Members
Last Login: Friday, May 10, 2013 4:07 PM
Points: 1,943, Visits: 8,227
Its not double counting...

Its telling you that to do the insert command it has done 58k reads.

Also it is telling you that the total amount of reads for the "exec sp_executesql" statement is 58k.

The "parent" statements are always the sum of the child statements.


Clear Sky SQL
My Blog
Kent user group
Post #917005
Eric M Russell
Posted Thursday, May 06, 2010 8:24 AM
Ten Centuries

Ten CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen CenturiesTen Centuries

Group: General Forum Members
Last Login: Today @ 7:23 AM
Points: 1,162, Visits: 3,334

In my proc, I have the following two lines:
select @sql = 'insert into lookups (fieldname) select distinct '+QUOTENAME(@fieldname)+' from '+QUOTENAME(@tablename)+' where '+QUOTENAME(@fieldname)+' IS NOT NULL and ltrim(rtrim(convert(nvarchar(max),'+QUOTENAME(@fieldname)+'))) <> ''\'''
exec /*test*/ sp_executesql @sql


How many StmtCompleted events are logged if you remove the "insert into lookups (fieldname)" portion of the statement and just execute the "select distinct ..." ?

"Wise people understand the 10,000 things without going to each one.
They know them without having to look at each one,
and they transform all without acting on each one." - The Tao Te Ching: Verse 47
Post #917012
SwedishOrr
Posted Friday, May 14, 2010 10:04 AM


SSC Veteran

SSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC Veteran

Group: General Forum Members
Last Login: Thursday, September 13, 2012 3:25 PM
Points: 205, Visits: 640
Sorry for the delay in reply. It looks like Dave is correct for my situation. Adding up each line and comparing to the total shows that Profiler is not double counting the reads.

Thanks all!
Post #922168
« Prev Topic | Next Topic »

Add to briefcase

Permissions Expand / Collapse

 
 
Copyright © 2002-2013 Simple Talk Publishing. All Rights Reserved. Privacy Policy. Terms of Use. Report Abuse.