Low Statistics Logical Reads and High Profiler Reads

Question

I had executed the following procedure in SSMS:

CREATE Procedure [dbo].[MyTableLoadByPK]  
(  
    @MyTableID int  
)  
AS  
BEGIN  
    SET NOCOUNT ON  
    SELECT  
    *  
    FROM [MyTable]  
    WHERE  
    del = 0 AND MyTableID = @MyTableID 
END  

exec MyTableLoadByPK @MyTableID=1001

MyTable is having 40000 records and there is a clustered index on MyTableID.

The STATISTICS IO were same every time I called the above procedure logical reads 2, physical reads 2:

Table 'MyTable'. Scan count 0, logical reads 2, physical reads 2, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

But when I checked the trace in Profiler for the same procedure, I found a huge difference in reads and even difference in difference. One time 248 and three times 228.

Following are reads from the trace:

TextData                                    CPU  Reads   Writes    Duration

exec MyTableLoadByPK @MyTableID=1001        0    228     0         223
exec MyTableLoadByPK @MyTableID=1001        0    228     0         230
exec MyTableLoadByPK @MyTableID=1001        0    248     0         751
exec MyTableLoadByPK @MyTableID=1001        0    228     0         360

Note: I had executed DBCC DROPCLEANBUFFERS; DBCC FREEPROCCACHE; before each four executions.

The execution plan is same in both SSMS and Profiler. There is only one Clustered Index Seek. Cost, rows, executions, size everything is same in both, then why there is so much difference in reads.

Edit:

MyTable create statement is as following:

CREATE TABLE [dbo].[MyTable](
    [MyTableID] [int] IDENTITY(1,1) NOT NULL,
    [na] [nvarchar](255) NOT NULL,
    [conID] [int] NOT NULL,
    [coID] [int] NOT NULL,
    [sID] [int] NOT NULL,
    [coID_O] [int] NOT NULL,
    [sID_O] [int] NOT NULL,
    [ufmts] [bit] NOT NULL,
    [Lte] [float] NOT NULL,
    [Late] [float] NOT NULL,
    [tz] [nvarchar](20) NOT NULL,
    [dm] [int] NOT NULL,
    [ca] [nvarchar](20) NOT NULL,
    [Tt] [nvarchar](50) NOT NULL,
    [Ct] [nvarchar](2048) NOT NULL,
    [pub] [bit] NOT NULL,
    [do] [int] NOT NULL,
    [cuID] [int] NOT NULL,
    [ia] [nvarchar](50) NOT NULL,
    [con] [datetime] NOT NULL,
    [uon] [datetime] NOT NULL,
    [upc] [int] NOT NULL,
    [del] [bit] NOT NULL,
 CONSTRAINT [PK_MyTable] PRIMARY KEY CLUSTERED 
(
    [MyTableID] ASC
)WITH (PAD_INDEX  = OFF, STATISTICS_NORECOMPUTE  = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS  = ON, ALLOW_PAGE_LOCKS  = ON, FILLFACTOR = 80) ON [PRIMARY]
) ON [PRIMARY]

GO

ALTER TABLE [dbo].[MyTable]  WITH CHECK ADD  CONSTRAINT [FK_MyTable_con] FOREIGN KEY([conID])
REFERENCES [dbo].[MYcon] ([conID])
GO

ALTER TABLE [dbo].[MyTable] CHECK CONSTRAINT [FK_MyTable_Mycon]
GO

ALTER TABLE [dbo].[MyTable]  WITH CHECK ADD  CONSTRAINT [FK_MyTable_Myco] FOREIGN KEY([coID])
REFERENCES [dbo].[Myco] ([coID])
GO

ALTER TABLE [dbo].[MyTable] CHECK CONSTRAINT [FK_MyTable_Myco]
GO

ALTER TABLE [dbo].[MyTable]  WITH CHECK ADD  CONSTRAINT [FK_MyTable_Mys] FOREIGN KEY([sID])
REFERENCES [dbo].[Mys] ([sID])
GO

ALTER TABLE [dbo].[MyTable] CHECK CONSTRAINT [FK_MyTable_Mys]
GO

ALTER TABLE [dbo].[MyTable] ADD  CONSTRAINT [DF_MyTable_upc]  DEFAULT ((0)) FOR [upc]
GO

Answer 1

You should not expect to see the same values for logical reads in these two cases (SET STATISTICS IO ON and SQL Profiler:Batch Completed) because they have measure different things:

• SET STATISTICS IO ON will return logical reads for statement[s] only,
• SQL Profiler:Batch Completed column Reads will return logical reads for entire batch including here logical reads generated by compilation (your batch has a DBCC FREEPROCCACHE statement which force a compilation and this means logical reads because SQL Server have to read metadata information). Also, if you activate Query > Actual execution plan in SQL Server Management Studio you will see an increase in Reads column).

For example, when I run these the two batches in SSMS

-- Without Query > Actual Execution Plan
DBCC DROPCLEANBUFFERS; 
DBCC FREEPROCCACHE;
exec MyTableLoadByPK @MyTableID=1001
GO
-- With Query > Actual Execution Plan
DBCC DROPCLEANBUFFERS; 
DBCC FREEPROCCACHE;
exec MyTableLoadByPK @MyTableID=1001
GO

the output from SET STATISTICS IO ON is 0 logical reads

DBCC execution completed. If DBCC printed error messages, contact your system administrator.
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
Table 'MyTable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
DBCC execution completed. If DBCC printed error messages, contact your system administrator.
Table 'MyTable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

but SQL Profiler shows for Batch completed event another results in Reads column:

TLDR: Simple explanation is that you're trying to compare different things.