17
votes

I have a stored procedure imported into EF4, and when I call it with certain parameters after 30 seconds it throws a time out error. In SQL Server profiler I can see the stored procedure call with the proper parameters taking just over 30 seconds, which is the timeout on my application.

HOWEVER when I execute the same SQL sent to the profiler in Query Analyzer it executes sub-second. What could cause this discrepancy between being called from EF and being called from SQL Server Management Studio?

Full stack trace of .NET error bellow.

[SqlException (0x80131904): Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.]
System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) +2073486
System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection) +5064444
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning() +234
System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) +2275
System.Data.SqlClient.SqlDataReader.ConsumeMetaData() +33
System.Data.SqlClient.SqlDataReader.get_MetaData() +86
System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) +311
System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) +987
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) +162
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) +32
System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) +141
System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) +12
System.Data.Common.DbCommand.ExecuteReader(CommandBehavior behavior) +10 System.Data.EntityClient.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior) +443

[EntityCommandExecutionException: An error occurred while executing the command definition. See the inner exception for details.]
System.Data.EntityClient.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior) +479
System.Data.Objects.ObjectContext.CreateFunctionObjectResult(EntityCommand entityCommand, EntitySet entitySet, EdmType edmType, MergeOption mergeOption) +182
System.Data.Objects.ObjectContext.ExecuteFunction(String functionName, MergeOption mergeOption, ObjectParameter[] parameters) +218
System.Data.Objects.ObjectContext.ExecuteFunction(String functionName, ObjectParameter[] parameters) +53
MetaView.DAL.MFCMData.MFCMDATAEntities.GetTradingOpenPositionCounterParty(Nullable1 positionDT, Nullable1 tradingAccountID) in C:\Projects\CASH\web\MetaView\MetaView.DAL.MFCMData\MFCMData.Designer.cs:7064 MetaView.BusinessLayer.Shared.Accounts.CounterParties.GetCounterParties(Int32 tradingAccountID) in C:\Projects\CASH\web\MetaView\MetaView.BusinessLayer\Shared\Accounts\CounterParties.cs:161

1
Please post the query and both execution plans.usr

1 Answers

24
votes

So I had a similar issue a couple of weeks ago, which was explained to me by one of our DBAs thusly (paraphrased and dumbed down to my level of course):

When a SQL Server stored procedure is called, the server creates and caches an execution plan per stored procedure per object_id. Sometimes a bad execution plan can be created by SQL Server depending on the parameter value that is passed in (in our case it was null for a nullable parameter). When this happens, the quick fix is to run sp_recompile 'Schema.Procedure' in SQL Server Management Studio (or whatever DB management tool you might be using). All this does is clear the plan cache for that stored procedure. If the next callee of the proc passes in the "bad" parameter value again you'll be stuck in the same situation so the real fix is to give the query a hint using the OPTIMIZE FOR syntax (see http://msdn.microsoft.com/en-gb/library/ms181714.aspx).

In short if you add OPTION (OPTIMIZE FOR (@myParameter = 'Some value that gives you a GOOD execution plan')) after your WHERE and/or ORDER BY clauses it should fix the issue.

Also, if you're wondering why when executing the same SQL in SSMS you always get fast results it's because SSMS has a default setting of ON for an option called ARITHABORT (SET ARITHABORT ON) which all other apps have set to OFF by default, but how it works and its implications are beyond my experience and I haven't bothered to read up on it. I have been told that I shouldn't use it though. I'm sure a real DBA can do a better job of explaining why.