More logical reads when query called from code than from SSMS

Posts   
 
    
PatrickD
User
Posts: 65
Joined: 05-Sep-2006
# Posted on: 28-Mar-2013 10:52:08   

Hi,

When I analyzed a bad performing query I came to the conclusion that the query when called from .Net causes much more logical reads than the same query called from Management Studio. I copied the bad performing query from Profiler into SSMS. The query is a dynamic SQL statement generated by LLBLGen. Queries are called against the same instance from the same computer and under the same account.

Number of logical reads when called from code: 2.967.173 Number of logical reads when called from SSMS: 4.655

How can this difference be explained and is there a solution by configuring LLBLGen in some way?

My setup: - LLBLGEN Pro Version 3.5 Build November 6th 2012 - Selfservicing for .Net 4.0 - SQL Server 2008 R2 Express Edition With Advanced Services SP2

(Please ignore the setup from my profile, I get an error when trying to update my profile)

Kind regards, Patrick

Otis avatar
Otis
LLBLGen Pro Team
Posts: 39614
Joined: 17-Aug-2003
# Posted on: 28-Mar-2013 11:14:55   

PatrickD wrote:

Hi,

When I analyzed a bad performing query I came to the conclusion that the query when called from .Net causes much more logical reads than the same query called from Management Studio. I copied the bad performing query from Profiler into SSMS. The query is a dynamic SQL statement generated by LLBLGen. Queries are called against the same instance from the same computer and under the same account.

Number of logical reads when called from code: 2.967.173 Number of logical reads when called from SSMS: 4.655

How can this difference be explained and is there a solution by configuring LLBLGen in some way?

One difference you have to take into account is that all ADO.NET commands executed on SqlClient will be wrapped with exec sp_executesql(), to cache the plans. We can't work around this, SqlClient's SqlCommand does this internally, and it's unavoidable.

This might be the problem, and you might run into the problem which is related to something called 'parameter sniffing'. Please search on 'parameter sniffing' on this forum to get more info about this. You have to check the execution plan executed using EXEC sp_executesql (so copy the FULL query from sql profiler), to see whether it misses indexes and causes table scans instead.

My setup: - LLBLGEN Pro Version 3.5 Build November 6th 2012 - Selfservicing for .Net 4.0 - SQL Server 2008 R2 Express Edition With Advanced Services SP2

(Please ignore the setup from my profile, I get an error when trying to update my profile)

'an error' isn't very clear, Patrick wink We can't fix things if we don't know what's wrong. simple_smile

Frans Bouma | Lead developer LLBLGen Pro
PatrickD
User
Posts: 65
Joined: 05-Sep-2006
# Posted on: 28-Mar-2013 11:20:30   

Hi Frans,

I copied the complete statement including the exec sp_executesql and the parameters, so there is no difference. So I suppose parameter sniffing won't be the issue.

Off-topic: The error when updating my profile: An error occured. Please try again. If you're using IE6, this might be the reason. In that case, update your browser (e.g. download Firefox). Not a very informational error message itself, so what can I add to this? wink BTW, tried on IE and Chrome and same result.

Otis avatar
Otis
LLBLGen Pro Team
Posts: 39614
Joined: 17-Aug-2003
# Posted on: 28-Mar-2013 13:02:23   

PatrickD wrote:

Hi Frans,

I copied the complete statement including the exec sp_executesql and the parameters, so there is no difference. So I suppose parameter sniffing won't be the issue.

Hmmm. Then I don't know what caused the difference in reads, other than in SSMS it might be it re-used a cached plan or cached sets which had already been evaluated when the ado.net call was executed. One thing which might be causing the difference is that the profiler's data is actually from the server, the SSMS read statistics might be client-side statistics, or did you run it also through profiler?

The thing is, what happens after SqlCommand.Execute...() is called is not up to what we do. We open a connection, call the execute method and that's it. it might be that with the reader, more data is read than when SSMS is returning the complete resultset at once, but I'm not sure what profiling you're looking at: the data read by the profiler from disk or also sent to the client.

Either way, look at the actual execution plan (not the estimated) and see whether indexes were missed or not. The big difference suggests it did a table scan. We can't do much about this as all we do is formulate the query, add the parameters and call execute. What the DB does with it is out of our hands.

Btw, did you have a transaction open when you called the query?

Off-topic: The error when updating my profile: An error occured. Please try again. If you're using IE6, this might be the reason. In that case, update your browser (e.g. download Firefox). Not a very informational error message itself, so what can I add to this? wink BTW, tried on IE and Chrome and same result.

Ah, the default error page. sunglasses Likely your signature was too long.

Frans Bouma | Lead developer LLBLGen Pro
PatrickD
User
Posts: 65
Joined: 05-Sep-2006
# Posted on: 28-Mar-2013 13:24:11   

It's all very confusing. Although the queries are the same, sys.dm_exec_query_stats shows two plans. This is of course because the connection strings differ between the application and SSMS. After I do a DBCC DROPCLEANBUFFERS and FREEPROCCACHE, the query from LLBLGen is almost as fast as from SSMS, so it seems there was something corrupt in the execution plan. Alas, this does not solve the issue, because for some reason after some time the query gets slower again. When looking at both plans in sys.dm_exec_query_plan there is no difference.

I understand the problem does not ring a bell for you, so probably I have to investigate in another direction. However thanks, and if you or some reader comes up with an idea I will be very happy.

Otis avatar
Otis
LLBLGen Pro Team
Posts: 39614
Joined: 17-Aug-2003
# Posted on: 28-Mar-2013 13:52:20   

Query plans are constructed on statistics. It might be the statistics collected along the way for the data involved is not done properly. I lack the knowledge to point you to a resource where you can get more info about this, sorry, but it might be a thing to look into...

(as in: the plan needs re-compilation so a more efficient plan is constructed, but that's not done as the db thinks the old plan is still sufficient enough). I don't know whether recompilation based on new statistics is postponed due to some setting/issue in the DB, but it might be recompilation might be not considered because the DB thinks it will take too long or won't give proper results.

Frans Bouma | Lead developer LLBLGen Pro
DvK
User
Posts: 318
Joined: 22-Mar-2006
PatrickD
User
Posts: 65
Joined: 05-Sep-2006
# Posted on: 29-Mar-2013 10:21:14   

I found the cause of the problem and will try to explain it disappointed

The query in question returned a number of user actions within a time period (with as parameters a start and end datetime).

Our application by default shows only the user actions of the last day. When I then asked the application for the user actions of the last year, the query lasted long.

But when copying the query that returns the actions of one year into SSMS, it performed much faster.

But what happened? - The first query ran by the application (returning only actions of one day) was compiled by SQL Server into an execution plan. This plan was optimized for a small amount of data (one day). So querying for the whole year lasted long, as the compiled query plan that was reused was not optimized for a large set of data. - The query that I ran in SSMS was compiled into a new execution plan because I used another connection string. This generated another execution plan that was optimized for a large set of data (a whole year). And thus ran fast.

When I did DBCC FREEPROCCACHE and ran the query in SSMS first for only one day, SQL Server compiled the query into the same execution plan as for the application. When then called for a year it also ran slow in SSMS.

So now my problem is not solved because somehow I have to convince SQL Server to recompile when using large sets of data. But I now understand the cause, which has to do with SQL Server. I want to emphasize that the problem is not caused by LLBLGen.

@Frans: you already pointed me to this with your remark regarding 'Parameter sniffing' but I didn't get that flushed