Closed florinciubotariu closed 2 years ago
Happened again today. One of our three instances was affected and I had to restart it.
It seems that those weird exceptions started appearing after a CommitFailedException
:
System.Data.Entity.Infrastructure.CommitFailedException: An error was reported while committing a database transaction but it could not be determined whether the transaction succeeded or failed on the database server. See the inner exception and http://go.microsoft.com/fwlink/?LinkId=313468 for more information.
---> System.Data.SqlClient.SqlException (0x80131904): Resource ID : 1. The request limit for the database is 200 and has been reached. See 'http://go.microsoft.com/fwlink/?LinkId=267637' for assistance.
at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action<T> 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.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
at System.Data.SqlClient.SqlInternalTransaction.Commit()
at System.Data.SqlClient.SqlTransaction.Commit()
at System.Data.Entity.Infrastructure.Interception.InternalDispatcher<T>.Dispatch<TTarget,TInterceptionContext>(TTarget target, Action<T1,T2> operation, TInterceptionContext interceptionContext, Action<T1,T2,T3> executing, Action<T1,T2,T3> executed)
ClientConnectionId:x
Error Number:10928,State:1,Class:20
ClientConnectionId before routing:x
Routing Destination:x.tr45.northeurope1-a.worker.database.windows.net,11484
--- End of inner exception stack trace ---
at System.Data.Entity.Infrastructure.Interception.InternalDispatcher<T>.Dispatch<TTarget,TInterceptionContext>(TTarget target, Action<T1,T2> operation, TInterceptionContext interceptionContext, Action<T1,T2,T3> executing, Action<T1,T2,T3> executed)
at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.Commit(DbTransaction transaction, DbInterceptionContext interceptionContext)
at System.Data.Entity.Core.EntityClient.EntityTransaction.Commit()
at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransactionAsync<T>(Func<T> func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess, CancellationToken cancellationToken)
at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesToStoreAsync(SaveOptions options, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, CancellationToken cancellationToken)
at System.Data.Entity.Infrastructure.DbExecutionStrategy.ProtectedExecuteAsync<TResult>(Func<T> operation, CancellationToken cancellationToken)
at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesInternalAsync(SaveOptions options, Boolean executeInExistingTransaction, CancellationToken cancellationToken)
I would like to contribute my experience with what I think is the exact same issue (which I've never found a the root cause or resolved):
I've been seeing these exceptions in our production systems for nearly 3 years. Early on, these exceptions happened frequently in clusters. Sometimes the cluster would last for 5 minutes, sometimes up to 30 minutes. It almost always affects just a single server/instance at a time.
In the past 3 years, the occurrence rate of these exceptions has gone down dramatically. It's just a small "blip" and Users rarely notice since things recover quickly. However just yesterday (August 24 2020) we encountered a cluster of these exceptions affected 1/3 of our production servers over a period of 30-40 minutes. It was bad enough that Users noticed this time - from their perspective the system was down since so many things were crashing.
Usually this problem eventually resolves itself after a few minutes. It's almost as if some/most of the connections in the connection pool are corrupt or in some bad state? And after a while the connection pool clears itself out.
Some notes about application code:
Technical Details
Exceptions/Stack Trace Sample
Below is sample of the types of exceptions we see. We'll often see dozens or hundreds of these exceptions. They all for different queries, different entities. Some async code, some non-async code.
System.InvalidOperationException: The 'x' property on 'y' could not be set to a 'System.Int32' value. You must set this property to a non-null value of type 'System.Guid'.
System.Data.Entity.Core.Common.Internal.Materialization.Shaper+ErrorHandlingValueReader`1.GetValue(DbDataReader reader, Int32 ordinal):104
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Shaper.HandleEntityAppendOnly[TEntity](Func`2 constructEntityDelegate, EntityKey entityKey, EntitySet entitySet):196
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator.MoveNext():39
System.Collections.Generic.List`1..ctor(IEnumerable`1 collection):119
System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source):20
System.InvalidOperationException: The specified cast from a materialized 'System.String' type to the 'System.Guid' type is not valid.
System.Data.Entity.Core.Common.Internal.Materialization.Shaper+ErrorHandlingValueReader`1.GetValue(DbDataReader reader, Int32 ordinal):104
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator.MoveNext():39
System.Linq.Enumerable.FirstOrDefault[TSource](IEnumerable`1 source):48
System.InvalidCastException: Specified cast is not valid.
System.Data.SqlClient.SqlBuffer.get_SqlGuid():22
System.Data.SqlClient.SqlDataReader.GetGuid(Int32 i):9
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator.HasNextElement(Shaper shaper):47
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+RowNestedResultEnumerator.MaterializeRow():52
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+RowNestedResultEnumerator.MoveNext():45
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+ObjectQueryNestedEnumerator.TryReadToNextElement():19
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+ObjectQueryNestedEnumerator.MoveNext():7
System.Collections.Generic.List`1..ctor(IEnumerable`1 collection):119
System.Linq.Enumerable.ToList[TSource](IEnumerable`1 source):20
System.InvalidOperationException: The specified cast from a materialized 'System.Boolean' type to the 'System.Guid' type is not valid.
System.Data.Entity.Core.Common.Internal.Materialization.Shaper+ErrorHandlingValueReader`1.GetValue(DbDataReader reader, Int32 ordinal):104
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator.MoveNext():39
System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source):65
System.Data.Entity.Internal.Linq.InternalSet`1.FindInStore(WrappedEntityKey key, String keyValuesParamName):10
System.Data.Entity.Internal.Linq.InternalSet`1.Find(Object[] keyValues):68
System.IndexOutOfRangeException: Index was outside the bounds of the array.
System.Data.SqlClient.SqlDataReader.CheckHeaderIsReady(Int32 columnIndex, Boolean permitAsync, String methodName)
System.Data.SqlClient.SqlDataReader.IsDBNull(Int32 i):58
System.Data.Entity.Core.Common.Internal.Materialization.Shaper+ErrorHandlingValueReader`1.GetValue(DbDataReader reader, Int32 ordinal)
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Shaper.HandleEntityAppendOnly[TEntity](Func`2 constructEntityDelegate, EntityKey entityKey, EntitySet entitySet):196
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator.MoveNext():39
System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source):65
System.Data.Entity.Internal.Linq.InternalSet`1.FindInStore(WrappedEntityKey key, String keyValuesParamName):10
System.Data.Entity.Internal.Linq.InternalSet`1.Find(Object[] keyValues):68
System.IndexOutOfRangeException: Index was outside the bounds of the array.
System.Data.SqlClient.SqlDataReader.CheckHeaderIsReady(Int32 columnIndex, Boolean permitAsync, String methodName)
System.Data.SqlClient.SqlDataReader.IsDBNull(Int32 i):58
System.Data.Entity.Core.Common.Internal.Materialization.Shaper+ErrorHandlingValueReader`1.GetValue(DbDataReader reader, Int32 ordinal)
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator+<MoveNextAsync>d__4.MoveNext():196
System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw():12
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task):40
System.Data.Entity.Internal.LazyAsyncEnumerator`1+<FirstMoveNextAsync>d__0.MoveNext():311
System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw():12
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task):40
System.Data.Entity.Infrastructure.IDbAsyncEnumerableExtensions+<ForEachAsync>d__5`1.MoveNext():178
System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw():12
System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task):40
System.Runtime.CompilerServices.TaskAwaiter`1.GetResult():11
System.IndexOutOfRangeException: Index was outside the bounds of the array.
System.Data.SqlClient.SqlDataReader.CheckHeaderIsReady(Int32 columnIndex, Boolean permitAsync, String methodName)
System.Data.SqlClient.SqlDataReader.IsDBNull(Int32 i):58
(unknown).lambda_method(Closure , Shaper ):-1
System.Data.Entity.Core.Common.Internal.Materialization.Coordinator`1.ReadNextElement(Shaper shaper):114
System.Data.Entity.Core.Common.Internal.Materialization.Shaper`1+SimpleEnumerator.MoveNext():39
System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source):65
We also have some transaction-related errors in the mix. Some of these exceptions are particularly weird because they're being thrown from queries which aren't being executed in any sort of transaction (no local transaction, no TransactionScope). We do have code that uses local transactions, and we do use TransactionScope in a few specific places.
System.Data.SqlClient.SqlException: New request is not allowed to start because it should come with valid transaction descriptor.
System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction):94
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose):380
System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
System.Data.SqlClient.SqlDataReader.TryConsumeMetaData():64
System.Data.SqlClient.SqlDataReader.get_MetaData():60
System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted):243
System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest):1627
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry):632
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method):25
System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method):103
System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed):241
System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext):114
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):10
System.InvalidOperationException: ExecuteReader requires the command to have a transaction when the connection assigned to the command is in a pending local transaction. The Transaction property of the command has not been initialized.
System.Data.SqlClient.SqlCommand.ValidateCommand(String method, Boolean async):377
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry):51
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method):25
System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method):80
System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed):241
System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext):114
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):10
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):41
System.Data.Entity.Core.Objects.Internal.ObjectQueryExecutionPlan.Execute[TResultType](ObjectContext context, ObjectParameterCollection parameterValues):309
System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess):138
System.Data.Entity.Core.Objects.ObjectQuery`1+<>c__DisplayClass7.<GetResults>b__5():28
System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func`1 operation):54
System.Data.Entity.Core.Objects.ObjectQuery`1.GetResults(Nullable`1 forMergeOption):165
System.Data.Entity.Core.Objects.ObjectQuery`1.<System.Collections.Generic.IEnumerable<T>.GetEnumerator>b__0()
System.Data.Entity.Internal.LazyEnumerator`1.MoveNext():8
System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source):65
System.Data.Entity.Internal.Linq.InternalSet`1.FindInStore(WrappedEntityKey key, String keyValuesParamName):10
System.Data.Entity.Internal.Linq.InternalSet`1.Find(Object[] keyValues):68
System.Data.SqlClient.SqlException: The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION.
System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction):94
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose):380
System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
System.Data.SqlClient.SqlDataReader.TryConsumeMetaData():64
System.Data.SqlClient.SqlDataReader.get_MetaData():60
System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted):243
System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest):1627
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry):632
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method):25
System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method):103
System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed):241
System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext):114
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):10
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):41
System.Data.Entity.Core.Objects.Internal.ObjectQueryExecutionPlan.Execute[TResultType](ObjectContext context, ObjectParameterCollection parameterValues):309
System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransaction[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess):138
System.Data.Entity.Core.Objects.ObjectQuery`1+<>c__DisplayClass7.<GetResults>b__5():28
System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func`1 operation):54
System.Data.Entity.Core.Objects.ObjectQuery`1.GetResults(Nullable`1 forMergeOption):165
System.Data.Entity.Core.Objects.ObjectQuery`1.<System.Collections.Generic.IEnumerable<T>.GetEnumerator>b__0()
System.Data.Entity.Internal.LazyEnumerator`1.MoveNext():8
System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source):65
System.Data.Entity.Internal.Linq.InternalSet`1.FindInStore(WrappedEntityKey key, String keyValuesParamName):10
System.Data.Entity.Internal.Linq.InternalSet`1.Find(Object[] keyValues):68
System.Data.SqlClient.SqlException: New transaction is not allowed because there are other threads running in the session.
System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction):94
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose):380
System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj):32
System.Data.SqlClient.TdsParser.TdsExecuteTransactionManagerRequest(Byte[] buffer, TransactionManagerRequestType request, String transactionName, TransactionManagerIsolationLevel isoLevel, Int32 timeout, SqlInternalTransaction transaction, TdsParserStateObject stateObj, Boolean isDelegateControlRequest):568
System.Data.SqlClient.SqlInternalConnectionTds.ExecuteTransactionYukon(TransactionRequest transactionRequest, String transactionName, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest):384
System.Data.SqlClient.SqlInternalConnection.BeginSqlTransaction(IsolationLevel iso, String transactionName, Boolean shouldReconnect):134
System.Data.SqlClient.SqlConnection.BeginTransaction(IsolationLevel iso, String transactionName)
System.Data.SqlClient.SqlConnection.BeginDbTransaction(IsolationLevel isolationLevel)
System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed):241
System.Data.Entity.Infrastructure.Interception.DbConnectionDispatcher.BeginTransaction(DbConnection connection, BeginTransactionInterceptionContext interceptionContext):114
System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute[TResult](Func`1 operation):54
System.Data.Entity.Core.EntityClient.EntityConnection.BeginDbTransaction(IsolationLevel isolationLevel):163
System.Data.Entity.Core.EntityClient.EntityConnection.BeginDbTransaction(IsolationLevel isolationLevel):194
System.Data.Entity.Core.EntityClient.EntityConnection.BeginTransaction(IsolationLevel isolationLevel)
System.Data.Entity.DbContextTransaction..ctor(EntityConnection connection, IsolationLevel isolationLevel):19
System.Data.Entity.Database.BeginTransaction(IsolationLevel isolationLevel):30
System.Data.SqlClient.SqlException: The server failed to resume the transaction. Desc:13e000000da.
System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection, Action`1 wrapCloseInAction):94
System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj, Boolean callerHasConnectionLock, Boolean asyncClose):380
System.Data.SqlClient.TdsParser.TryRun(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj, Boolean& dataReady)
System.Data.SqlClient.SqlDataReader.TryConsumeMetaData():64
System.Data.SqlClient.SqlDataReader.get_MetaData():60
System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString, Boolean isInternal, Boolean forDescribeParameterEncryption, Boolean shouldCacheForAlwaysEncrypted):243
System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async, Int32 timeout, Task& task, Boolean asyncWrite, Boolean inRetry, SqlDataReader ds, Boolean describeParameterEncryptionRequest):1627
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, TaskCompletionSource`1 completion, Int32 timeout, Task& task, Boolean& usedCache, Boolean asyncWrite, Boolean inRetry):632
System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method):25
System.Data.SqlClient.SqlCommand.ExecuteReader(CommandBehavior behavior, String method):103
System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext,TResult](TTarget target, Func`3 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed):241
System.Data.Entity.Infrastructure.Interception.DbCommandDispatcher.Reader(DbCommand command, DbCommandInterceptionContext interceptionContext):114
System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommands(EntityCommand entityCommand, CommandBehavior behavior):10
@florinciubotariu have you learned anything new? I've been trying to track down the root cause for a long time now.
I have some questions about your issue, trying to compare it to what we're experiencing:
@florinciubotariu have you learned anything new? I've been trying to track down the root cause for a long time now.
I have some questions about your issue, trying to compare it to what we're experiencing:
- Are you doing anything with transactions? Either explicit local transactions with BeginTransaction/Commit, or TransactionScope? We are. I have suspected there is a subtle bug in our application code somewhere in which a connection is incorrectly reused with an active transaction.
- Is all of our data access async? In our case it's a mix, maybe 50/50. We do some work on background threads too, though we're careful to ensure they get their own scoped DbContext. I have suspected there is a subtle bug in our application code where two async threads are somehow sharing the same connection.
@jdaigle Unfortunately not. I've even tried to reproduce the issue by keeping the system under pressure with Apache Benchmark (a lot of parallel and heavy GET requests - keeping the Azure SQL instance at 100% for a long period of time). When I will have enough free time, I will try to simulate a lot of requests which will commit changes to the database.
To answer your questions:
.SaveChanges()
which pushes changes made on the context since the last commit. I'm never instantiating the context - I'm always relaying on the DI framework to do that for me.Personally, I suspect that this bug appears on heavy pressure. I do not know exactly what has to be done to trigger it but since we managed to decrease the number of calls made to our application this issue didn't appear again.
@ajcvickers @roji @bricelam
I know that this might not be an EF6 bug. It might be ADO.NET or something else?
Can you possibly point us to other repositories or resources that might help us track down a root cause, or at least a workaround?
@jdaigle The incident appeared again this morning.
To keep it straight-forward, the client apps made A LOT of requests to our APIs - APIs which are hitting big database tables.
We have 3 pods for our app. Out of a sudden a lot of timeouts started appearing and since the client apps did not block the UI, it didn't stop making requests to our apps and forced us to continue hitting our database. That basically means we got no chance of recovering because the client apps didn't allow us to. When this happens, in order to speed up the recovery, I killed 2/3 pods (in order to create other 2) and the timeouts are starting to disappear (since I get rid of our scheduled DB calls - caused mainly by the triggered API calls)
The weird thing is that the issue we discussed in this thread appeared only on a newly created pod (one of the two):
You can see in the screenshot the lifetime of our pod. When I saw exceptions flooding I immediately logged the stdout to a log file and killed it.
I've ended up scaling the Azure SQL from S3 to S4 and everything is fine now.
I created a timeline showing the Apdex score (all 3 pods combined) during the incident:
In the following 2 screenshots you can see the metrics of the pod which threw mapping exceptions:
What I found out:
System.Data.Entity.Core.EntityCommandExecutionException: An error occurred while executing the command definition. See the inner exception for details.
---> System.Data.SqlClient.SqlException (0x80131904): The ROLLBACK TRANSACTION request has no corresponding BEGIN TRANSACTION.
at System.Data.SqlClient.SqlCommand.<>c.<ExecuteDbDataReaderAsync>b__126_0(Task`1 result)
at System.Threading.Tasks.ContinuationResultTaskFromResultTask`2.InnerInvoke()
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot, Thread threadPoolThread)
--- End of stack trace from previous location where exception was thrown ---
at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommandsAsync(EntityCommand entityCommand, CommandBehavior behavior, CancellationToken cancellationToken)
ClientConnectionId:x
Error Number:3903,State:2,Class:16
ClientConnectionId before routing:x
Routing Destination:x
--- End of inner exception stack trace ---
at System.Data.Entity.Core.EntityClient.Internal.EntityCommandDefinition.ExecuteStoreCommandsAsync(EntityCommand entityCommand, CommandBehavior behavior, CancellationToken cancellationToken)
at System.Data.Entity.Core.Objects.Internal.ObjectQueryExecutionPlan.ExecuteAsync[TResultType](ObjectContext context, ObjectParameterCollection parameterValues, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransactionAsync[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Infrastructure.DbExecutionStrategy.ProtectedExecuteAsync[TResult](Func`1 operation, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Core.Objects.ObjectQuery`1.GetResultsAsync(Nullable`1 forMergeOption, IDbExecutionStrategy executionStrategy, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Internal.LazyAsyncEnumerator`1.FirstMoveNextAsync(CancellationToken cancellationToken)
at System.Data.Entity.Infrastructure.IDbAsyncEnumerableExtensions.FirstOrDefaultAsync[TSource](IDbAsyncEnumerable`1 source, CancellationToken cancellationToken)
System.Data.Entity.Infrastructure.CommitFailedException: An error was reported while committing a database transaction but it could not be determined whether the transaction succeeded or failed on the database server. See the inner exception and http://go.microsoft.com/fwlink/?LinkId=313468 for more information.
---> System.NullReferenceException: Object reference not set to an instance of an object.
at System.Data.SqlClient.SqlInternalTransaction.GetServerTransactionLevel()
at System.Data.SqlClient.SqlInternalTransaction.CheckTransactionLevelAndZombie()
at System.Data.SqlClient.SqlInternalTransaction.Commit()
at System.Data.SqlClient.SqlTransaction.Commit()
at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.<>c.<Commit>b__6_0(DbTransaction t, DbTransactionInterceptionContext c)
at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
--- End of inner exception stack trace ---
at System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch[TTarget,TInterceptionContext](TTarget target, Action`2 operation, TInterceptionContext interceptionContext, Action`3 executing, Action`3 executed)
at System.Data.Entity.Infrastructure.Interception.DbTransactionDispatcher.Commit(DbTransaction transaction, DbInterceptionContext interceptionContext)
at System.Data.Entity.Core.EntityClient.EntityTransaction.Commit()
at System.Data.Entity.Core.Objects.ObjectContext.ExecuteInTransactionAsync[T](Func`1 func, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, Boolean releaseConnectionOnSuccess, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesToStoreAsync(SaveOptions options, IDbExecutionStrategy executionStrategy, Boolean startLocalTransaction, CancellationToken cancellationToken)
at System.Data.Entity.Infrastructure.DbExecutionStrategy.ProtectedExecuteAsync[TResult](Func`1 operation, CancellationToken cancellationToken)
at System.Data.Entity.Utilities.TaskExtensions.CultureAwaiter`1.GetResult()
at System.Data.Entity.Core.Objects.ObjectContext.SaveChangesInternalAsync(SaveOptions options, Boolean executeInExistingTransaction, CancellationToken cancellationToken)
@florinciubotariu I'm cautiously optimistic that we might have resolved our issue. It's only been a few days, but we haven't seen these exceptions since.
We made two changes to our application code which I think helped:
While we were never able to reproduce the problem, even when writing intentionally buggy code, I'm feeling confident that the root cause was some sort of async issue in which two threads were using the same SqlConnection and leaving it in a bad state - perhaps coupled with TransactionScope and it's weirdness preventing it from correctly resetting from the connection pool.
Hopefully this is helpful information. I'll update if we learn that these fixes did not resolve the issue.
Thanks for your reply. I'm sure that we do not use "async over sync" and we are always awaiting our tasks which are using the DbContext (we had some places where we had 2 async calls hitting the same context - we immediately identify those and resolve them).
I hope the fix will work out for you. We will keep our DB at the higher tier now. I hope the issue will not pop out anymore.
Just a general remark to everyone here... I'm not aware of any TransactionScope-specific issues which could cause the above. However, mixing async and sync could definitely be the culprit here. Doing async over sync (and sometimes even just sync) means that a thread pool thread is blocked as the operation is in progress. During application startup, or during a load spike, you can easily exhaust the TP, and that point you're stuck waiting for the TP to allocate new threads, which takes time. This can easily lead to timeouts.
To summarize, it's highly recommended to be async-only, everywhere.
We are facing the same issue now on one of our production environments, out of sudden the exception rate is high and most of the exceptions are originating from Entity Framework, lots of InvalidOperationExceptions as if it is doing lots of wrong mapping and the same concern that it lasts from 30 minutes to 4 hours while trying to recover by many means (recycle, kill process, scale out) but it keeps happening and suddenly everything gets back to normal again.
The exceptions we observe so weird:
The specified cast from a materialized 'System.Guid' type to the 'System.Boolean' type is not valid.
The specified cast from a materialized 'System.Boolean' type to a nullable 'System.Guid' type is not valid.
The 'GradeId' property on 'User' could not be set to a 'System.String' value. You must set this property to a non-null value of type 'System.Int32'.
The 'CreationDate' property on 'UserExternalData' could not be set to a 'System.Int32' value. You must set this property to a non-null value of type 'System.DateTime'.
It is as if EF is generating wrong queries and not being able to map the data.
We are using .NET 5 + EF 6.4
@roji any explanation about why this happens and how to overcome this issue?
This issue has been closed because EF6 is no longer being actively developed. We are instead focusing on stability of the codebase, which means we will only make changes to address security issues. See the repo README for more information.
Hello @florinciubotariu Thanks for pointing out "CommitFailedException".
We got this problem when using SignalR longpolling, we don't have this problem with SignalR websockets.
@ajcvickers Could you please reopen? This sounds like a security issue, somehow you can break EF mapping and that could corrupt/break/DOS your application? Could be multiple connections at once.
This is happening to us as well. Either it gets sorted out by itself or we have to manually restart the web App hosted in Azure.
This is happening to us as well. Either it gets sorted out by itself or we have to manually restart the web App hosted in Azure.
Interesting! What EF version and .NET version are you using? Do you use SignalR (longpolling) by chance? The problem could be because of a lot of requests.
We use .NET 4.8 and EF 6.4.
Describe what is not working as expected.
There was an incident on our production environment. We have two instances of the same application (backend). A client made around 2.5k requests at the same time (1.25k / app).
The first issue which appeared is the following exception:
that is expected taking into consideration the number of concurrent HTTP requests. After that our both applications started throwing a lot of random exceptions as you can see in the following picture:
Those exceptions do not make any sense. I even saw two exceptions for the same property: once trying to map it into a boolean, and second time trying to map it into a decimal (instead of string). It feels like Entity Framework cannot map the retrieved data into correct data types. Seems like everything is scrambled. The major problem is that it does not recover. The incident lasted around 30-40 minutes and a simple recreation of the pod fixed it.
I will paste some stacktraces below:
Useful information
Our context:
DatabaseFactory:
Unfortunately, we use another layer above EF: Generic Repository & UoW Patterns where we inject into constructor the
IDatabaseFactory
. We useMicrosoft.Extensions.DependencyInjection.Abstractions 3.1.2
for DI. The registrations areScoped
. We useasync all the way down
.People with same problem:
https://stackoverflow.com/questions/50560257/entity-framework-throws-unexpected-exceptions-with-a-heavy-workload https://stackoverflow.com/questions/35896100/strange-error-in-sql-server-from-asp-net-app https://stackoverflow.com/questions/47076273/getting-exception-suddenly-from-entityframework https://stackoverflow.com/questions/41839754/entity-framework-6-1-3-invalidoperationexception-after-a-few-days-of-running https://stackoverflow.com/questions/35011086/ef-randomly-sees-wrong-property-type
Further technical details
I have a .NET Framework project with the EDMX. After I generate the entities, I run a powershell script to move them to the .NET Standard 2.1 project.