Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 
        
Home       Members    Calendar    Who's On


Add to briefcase

Double counting reads in profiler Expand / Collapse
Author
Message
Posted Wednesday, May 5, 2010 4:36 PM


SSC Veteran

SSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC Veteran

Group: General Forum Members
Last Login: Friday, September 12, 2014 10:47 AM
Points: 205, Visits: 643
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
Posted Wednesday, May 5, 2010 8:16 PM


SSCoach

SSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoach

Group: General Forum Members
Last Login: Today @ 4:14 PM
Points: 15,725, Visits: 28,130
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
Posted Wednesday, May 5, 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: Today @ 11:43 PM
Points: 37,064, Visits: 31,627
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."

(play on words) "Just because you CAN do something in T-SQL, doesn't mean you SHOULDN'T." --22 Aug 2013

Helpful Links:
How to post code problems
How to post performance problems
Post #916665
Posted Thursday, May 6, 2010 5:20 AM


SSCoach

SSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoach

Group: General Forum Members
Last Login: Today @ 4:14 PM
Points: 15,725, Visits: 28,130
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
Posted Thursday, May 6, 2010 8:04 AM


SSC Veteran

SSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC VeteranSSC Veteran

Group: General Forum Members
Last Login: Friday, September 12, 2014 10:47 AM
Points: 205, Visits: 643
I double checked to make sure I wasn't looking at two different event classes, and both are SP:StmtCompleted.

HTH
Post #916988
Posted Thursday, May 6, 2010 8:09 AM


SSCoach

SSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoachSSCoach

Group: General Forum Members
Last Login: Today @ 4:14 PM
Points: 15,725, Visits: 28,130
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
Posted Thursday, May 6, 2010 8:18 AM


SSCommitted

SSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommitted

Group: General Forum Members
Last Login: Tuesday, September 9, 2014 2:06 AM
Points: 1,949, Visits: 8,318
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
Posted Thursday, May 6, 2010 8:24 AM


SSCommitted

SSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommittedSSCommitted

Group: General Forum Members
Last Login: Today @ 6:39 PM
Points: 1,657, Visits: 4,740

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 ..." ?
Post #917012
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: Friday, September 12, 2014 10:47 AM
Points: 205, Visits: 643
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