Entity Framework 4 Stored Procedure Call Timing Out

.net, entity-framework, sql-server-2008-r2

Solution

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.

Problem

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(Nullable`1 positionDT, Nullable`1 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

Original source