Double counting reads in profiler

Question

Double counting reads in profiler

SwedishOrr

SSCrazy

Points: 2955
More actions
May 5, 2010 at 4:36 pm

#232375

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
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!

Viewing 9 posts - 1 through 8 (of 8 total)

You must be logged in to reply to this topic. Login to reply

Grant Fritchey SSC Guru Points: 398882 More actions · Answer 1

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

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Jeff Moden SSC Guru Points: 1004341 More actions · Answer 2

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.

Change is inevitable... Change for the better is not.

Helpful Links:
How to post code problems
How to Post Performance Problems
Create a Tally Function (fnTally)

Grant Fritchey SSC Guru Points: 398882 More actions · Answer 3

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

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

SwedishOrr SSCrazy Points: 2955 More actions · Answer 4

I double checked to make sure I wasn't looking at two different event classes, and both are SP:StmtCompleted.

HTH

Grant Fritchey SSC Guru Points: 398882 More actions · Answer 5

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

Author of:
SQL Server Execution Plans
SQL Server Query Performance Tuning

Dave Ballantyne SSC-Dedicated Points: 33667 More actions · Answer 6

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[/url]

Eric M Russell SSC Guru Points: 125561 More actions · Answer 7

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 ..." ?

"Do not seek to follow in the footsteps of the wise. Instead, seek what they sought." - Matsuo Basho

SwedishOrr SSCrazy Points: 2955 More actions · Answer 8

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!