rebus-org / Rebus.SqlServer

:bus: Microsoft SQL Server transport and persistence for Rebus
https://mookid.dk/category/rebus
Other
43 stars 42 forks source link

The transaction operation cannot be performed because there are pending requests working on this transaction #7

Closed JornWildt closed 7 years ago

JornWildt commented 7 years ago

In a scenario where a service has been shutdown for a while, we get the following error when it starts going through the ton of messages that are waiting for it on start-up:

WARN  2017-03-31 11:03:43,604 334386ms  [15] RebusLogger            Warn               - Unhandled exception 1 while handling message with ID 9fff59ae-b132-479a-9813-da386d35b68f: System.Data.SqlClient.SqlException (0x80131904): The transaction operation cannot be performed because there are pending requests working on this transaction.
   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.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.SqlInternalConnectionTds.ExecuteTransaction(TransactionRequest transactionRequest, String name, IsolationLevel iso, SqlInternalTransaction internalTransaction, Boolean isDelegateControlRequest)
   at System.Data.SqlClient.SqlInternalTransaction.Commit()
   at System.Data.SqlClient.SqlTransaction.Commit()
   at Rebus.SqlServer.DbConnectionWrapper.<Complete>d__8.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Rebus.SqlServer.Transport.SqlServerTransport.<>c__DisplayClass32_1.<<GetConnection>b__1>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Rebus.Transport.TransactionContext.<Invoke>d__24.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Rebus.Transport.TransactionContext.<Commit>d__17.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Rebus.Retry.Simple.SimpleRetryStrategyStep.<DispatchWithTrackerIdentifier>d__7.MoveNext()

It does not happen for all of the messages - only very few.

A quick search for "The transaction operation cannot be performed because there are pending requests working on this transaction" reveals that it could be a "reader" somewhere that has not been closed (se for instance http://stackoverflow.com/questions/36552285/the-transaction-operation-cannot-be-performed-because-there-are-pending-requests).

JornWildt commented 7 years ago

It turns out that it happens as a result of a call to Bus.Defer(...) without await in front of it. We are now going through the code to add all the missing await keywords and then see if that fixes the problem.

mookid8000 commented 7 years ago

Thanks for getting back to this one – I had completely forgotten about it 😨

JornWildt commented 7 years ago

Tests so far shows that the missing "defer" was indeed the problem. It makes sense too - if the caller of Defer() does not wait for it to complete and commits the transaction as soon as possible then that may happen before what ever SQL-interaction in Defer() is finished and thus give the above mentioned error.

JornWildt commented 7 years ago

Testing shows the issue is fixed.

mookid8000 commented 7 years ago

Good news 👍