the reads of SQL profiler is the number of SQL Server logical read?

  • I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

     

    Attachments:
    You must be logged in to view attached files.
  • Thanks for posting your issue and hopefully someone will answer soon.

    This is an automated bump to increase visibility of your question.

  • One possible explanation, assuming identical parameter values, is that a plan recompile occurred. The execution from Profiler was in one plan and the execution from SSMS was in a different plan. However, statistics io measures just the behavior of the query itself. It doesn't measure additional behaviors like reads to system tables to look up statistics, find a query plan, stuff like that. So generally, you'll find that Profiler is equal to, or greater than, statistics io. If it's less than statistics io, something weird is going on, call support.

    "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

  • 892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    --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 wrote:

    One possible explanation, assuming identical parameter values, is that a plan recompile occurred. The execution from Profiler was in one plan and the execution from SSMS was in a different plan. However, statistics io measures just the behavior of the query itself. It doesn't measure additional behaviors like reads to system tables to look up statistics, find a query plan, stuff like that. So generally, you'll find that Profiler is equal to, or greater than, statistics io. If it's less than statistics io, something weird is going on, call support.

    I think maybe it was caused by using different execution plan, but I can't make sure it. so  I'm confused by this case, thanks!

     

  • Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    I don't good idea to explain this problem aside from explanation brought up by Grant Fritchey, thank you!

    if this case often ocurrs  for SQL profiler, it will give  wrong inforamtion for DBA

  • Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    Could this be an issue of what is being captured by profiler?  If you are capturing the values at RPC:Completed or Batch:Completed - then profiler is grouping all statements into that value, where SET STATISTICS IO would be showing each statement individually.

    Jeffrey Williams
    “We are all faced with a series of great opportunities brilliantly disguised as impossible situations.”

    ― Charles R. Swindoll

    How to post questions to get better answers faster
    Managing Transaction Logs

  • the “Reads” of SQL Server profiler is the times of the logical read?

    • This reply was modified 2 years, 9 months ago by  892717952. Reason: mistyping
  • Jeffrey Williams wrote:

    Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    Could this be an issue of what is being captured by profiler?  If you are capturing the values at RPC:Completed or Batch:Completed - then profiler is grouping all statements into that value, where SET STATISTICS IO would be showing each statement individually.

    Do you mean the value of reads is an accumulative value?

  • What event are you capturing in your profiler trace?

    Jeffrey Williams
    “We are all faced with a series of great opportunities brilliantly disguised as impossible situations.”

    ― Charles R. Swindoll

    How to post questions to get better answers faster
    Managing Transaction Logs

  • 892717952 wrote:

    Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    I don't good idea to explain this problem aside from explanation brought up by Grant Fritchey, thank you!

    if this case often ocurrs  for SQL profiler, it will give  wrong inforamtion for DBA

    No, Profiler is accurate. It's not giving you bad information. It's giving you different information.

    "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

  • Jeffrey Williams wrote:

    Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    Could this be an issue of what is being captured by profiler?  If you are capturing the values at RPC:Completed or Batch:Completed - then profiler is grouping all statements into that value, where SET STATISTICS IO would be showing each statement individually.

    Oh, yeah, Great point.

    "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

  • Jeffrey Williams wrote:

    What event are you capturing in your profiler trace?

    the events I captured as below

    Stored Procedures

    RPC:Completed

    SP:StmtCompleted

    TSQL

    SQL:BatchCompleted

  • 892717952 wrote:

    Jeffrey Williams wrote:

    What event are you capturing in your profiler trace?

    the events I captured as below

    Stored Procedures RPC:Completed SP:StmtCompleted TSQL SQL:BatchCompleted

    So which row in the trace are you looking at for the read values?  The RPC:Completed event captures everything that happens in the stored procedure.  SP:StmtCompleted captures each statement within the stored procedure - and SQL:BatchCompleted is everything that happens within the batch.

    Jeffrey Williams
    “We are all faced with a series of great opportunities brilliantly disguised as impossible situations.”

    ― Charles R. Swindoll

    How to post questions to get better answers faster
    Managing Transaction Logs

  • Grant Fritchey wrote:

    892717952 wrote:

    Jeff Moden wrote:

    892717952 wrote:

    I used SQL Profiler to trace SQL scripts and got one sql statement with 53142 reads (as picture), but I executed that sql statement but found its logical reads is 8,  the value of  reads column of SQL profiler  is the number of SQL Server logical read?  if yes, why there is so big difference for them?  I found many sql statement like this big difference.  thanks!

    Funny that you brought that up.  I'm having a similar issue with a bit of code that I'm looking at now and again.  I haven't decided if it's the fault of the two different tools (SQL Profiler v.s. SET STATISTICS IO ON) or if there's some changing conditions in the data behind the scenes between the time SQL Profiler picks up on the high number of reads and when I run the code that SQL Profiler captured.

    I don't good idea to explain this problem aside from explanation brought up by Grant Fritchey, thank you!

    if this case often ocurrs  for SQL profiler, it will give  wrong inforamtion for DBA

    No, Profiler is accurate. It's not giving you bad information. It's giving you different information.

    I'm in the process of a proof but I'm thinking that it's an old problem that I ran into a long time ago with another query... compile/recompile time.  The code that I'm having the problem with is an EXEC with changing literals being passed as a part of the code being executed.  I'm thinking that if it were an sp_ExecuteSQL call with parameters, the number of reads I'm seeing in SET STATISTICS results (< 100) would be showing up in Profiler instead of the almost 900 THOUSAND reads that are showing up now.  Manually running the code captured by the profiler also comes in at <100 reads even though profiler said it took almost 900K.

    I've got code to find the recompiles.  I'll try to find time to play with it tonight.

    And, yes... I'm using RPC Complete in Profiler.

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

Viewing 15 posts - 1 through 15 (of 21 total)

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