May 19, 2017 at 12:21 pm
When running query from .net code, sometimes we got below message, it is not happened all the time, but occasionally.
I cannot find any significant spikes in our monitoring tool during the time it may happen.
How can we trouble shoot this?
It is a web server that connects a SQL 2014 database server.
System.Data.Entity.Core.EntityCommandExecutionException: An error occurred while executing the command definition. See the inner exception for details. ---> System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding. ---> System.ComponentModel.Win32Exception: The wait operation timed out --- End of inner exception stack trace --- at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) at System.Data.SqlClient.SqlInternalConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose) at System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady) at System.Data.SqlClient.SqlDataReader.TryConsumeMetaData() at System.Data.SqlClient.SqlDataReader.get_MetaData() at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, SqlDataReader ds) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean asyncWrite) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method) at System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method) at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader(CommandBehavior behavior) at System.Data.Common.DbCommand.ExecuteReader(CommandBehavior behavior) at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.<Reader>b__c(DbCommand t, DbCommandInterceptionContext`1 c) at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed) at System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext) at System.Data.Entity.Internal.InterceptableDbCommand.ExecuteDbDataReader(CommandBehavior behavior) at System.Data.Common.DbCommand.ExecuteReader(CommandBehavior behavior) at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior) --- End of inner exception stack trace --- at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior) at System.Data.Entity.Core.Objects.Internal.ObjectQueryExecutionPlan.Execute[TResultType](ObjectContext context, ObjectParameterCollection parameterValues) at System.Data.Entity.Core.Objects.ObjectQuery`1.<>c__DisplayClass7.<GetResults>b__6() at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess) at System.Data.Entity.Core.Objects.ObjectQuery`1.<>c__DisplayClass7.<GetResults>b__5() at System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func`1 operation) at System.Data.Entity.Core.Objects.ObjectQuery`1.GetResults(Nullable`1 forMergeOption) at System.Data.Entity.Core.Objects.ObjectQuery`1.<System.Collections.Generic.IEnumerable<T>.GetEnumerator>b__0() at System.Data.Entity.Internal.LazyEnumerator`1.MoveNext() at System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source) at System.Data.Entity.Core.Objects.ELinq.ObjectQueryProvider.<GetElementFunction>b__1[TResult](IEnumerable`1 sequence) at System.Data.Entity.Core.Objects.ELinq.ObjectQueryProvider.ExecuteSingle[TResult](IEnumerable`1 query, Expression queryRoot) at System.Data.Entity.Core.Objects.ELinq.ObjectQueryProvider.System.Linq.IQueryProvider.Execute[TResult](Expression expression) at System.Data.Entity.Internal.Linq.DbQueryProvider.Execute[TResult](Expression expression) at System.Linq.Queryable.FirstOrDefault[TSource](IQueryable`1 source) at MYDB.Parent.Models.Adw.GetStasScore(IQueryable`1 studentStasScores, String adminCode, String subjectArea) at MYDB.Parent.Models.Adw.GetSpringStasScores(Int32 studentNumber, Int32 schoolYear) at MyDB.Parent.Models.ParentReferral.AddAssessmentsData() at Mydb.Parent.Models.ParentReferral..ctor(ParentReferralSubmission submission) at Mydb.Parent.Controllers.ReferralController.Submit(ParentReferralSubmission submission)
May 19, 2017 at 12:53 pm
Your query is taking longer than 30 seconds to run, so the .net app cancels it (that's what a timeout is). Identify the query, see if you can tune it to run faster.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
May 19, 2017 at 12:54 pm
Option 1: Tune the query (recommended). This is done on SQL Server code.
Option 2: Increase the time before the connection times out. This is done in .NET code.
May 19, 2017 at 1:09 pm
Thanks all.
But the problem is we don't know what query that caused this problem. could you know from the error message?
May 19, 2017 at 1:45 pm
the last lines of the error message tells you where in the code it failed, right?
I'd guess that EF/Linq is adding a bunch of tables to your context that are not needed, which end up building a punishingly slow query.
in those situations, i'd have the developers switch to using a new stored procedure for that call instead of letting EF build a whopper query.
at SPS.AdvancedLearning.Parent.Models.Adw.GetSpringStasScores(Int32 studentNumber, Int32 schoolYear)
at SPS.AdvancedLearning.Parent.Models.ParentReferral.AddAssessmentsData()
at SPS.AdvancedLearning.Parent.Models.ParentReferral..ctor(ParentReferralSubmission submission)
at SPS.AdvancedLearning.Parent.Controllers.ReferralController.Submit(ParentReferralSubmission submission)
Lowell
May 19, 2017 at 2:03 pm
sqlfriends - Friday, May 19, 2017 1:09 PMThanks all.But the problem is we don't know what query that caused this problem. could you know from the error message?
As Lowell pointed out, the location that the error was thrown from is in the error message. Investigate what that method does, what query it generates.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
May 19, 2017 at 2:26 pm
I checked with the .net developer what code behind when running those pages,
He says:
It’s a series of entity framework queries, an update and some inserts. The update and the inserts are under a transaction using the Entity Framework.
1. Get any existing teacher recommendation from the TeacherRecomendation table. table only has 41 rows
2. Get a test from the ScheduledTest table
The following are in a transaction:
3. Insert into the StudentScheduledTests table : currently there are only 180 rows
4. Update the ScheduledTests table : currently only 151 rows
5. Insert into the ParentReferral table : total 184 rows
6. Insert into the ParentRatings table : 47 rows
These tables only have Primary keys.
I am not seeing any significant problem with this, what else can I do the troubleshooting?
thanks
May 19, 2017 at 2:40 pm
sqlfriends - Friday, May 19, 2017 2:26 PMwhat else can I do the troubleshooting?
Identify the query, see if you can tune it to run faster.
A .net timeout happens when a database call takes longer than 30 seconds, so you need to identify which of those can run longer than 30 seconds, confirm that the query run is what the developer thinks it is, and once you've identified the problem, take necessary steps to fix it.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
May 19, 2017 at 2:41 pm
you missed the point about entity framework.
the EF DBContext probably has fifty tables or more inside.
It's absolutely possible/probable, that because the context is using a big transaction update lots of stuff, even though your core table has 128 rows, it is joined to the other fifty tables, even though they are not needed for the query. you have to run a profile or extended event to capture the actual query generated, and not the visual one you can do by looking at the tables that are only in that procedure..
that is where you will see the other fifty tables appended to what should be a simple query
the typical fix is to take that query away from entity framework and put it in a procedure,a nd have the framework call a procedure instead, or create a smaller, lighter context that has fewer tables for that portion of the code.
I've seen this plenty of times, EF is Ok for 90% of the code, but 10% needs a DBA to fix a few outliers like this.
Lowell
May 19, 2017 at 3:11 pm
Thank you, we will see if we can make it to a stored procedure and also run profiler to see what sqls are running when this happened.
It is difficult to catch, because it does not happen all the time.
Thanks
May 20, 2017 at 11:42 am
A stored procedure would go a long way toward solving the problem. One benefit is that you'll know the parameters will be received with the proper data types and you'll be able to identify the implicit casts and fix them.
Viewing 11 posts - 1 through 10 (of 10 total)
You must be logged in to reply to this topic. Login to reply