BUG: TransactionStatePSPEOperation throws exception in valid enviroment

[ionmincu]

Description

Sometimes on our servers we see the following exception

The operation is not valid for the state of the transaction.

Stacktrace:

Linux x64

0 { "method":"System.Transactions.TransactionStatePSPEOperation.get_Status",     "level":0, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }
1 { "method":"System.Transactions.TransactionInformation.get_Status",            "level":1, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }
2 { "method":"System.Data.SqlClient.SqlDelegatedTransaction.Promote",            "level":2, "line":0, "assembly":"System.Data.SqlClient,     Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a" }
3 { "method":"System.Transactions.TransactionStatePSPEOperation.PSPEPromote",    "level":3, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }
4 { "method":"System.Transactions.TransactionStateDelegatedNonMSDTC.EnterState", "level":4, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }
5 { "method":"System.Transactions.EnlistableStates.PromotedToken",               "level":5, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }
6 { "method":"System.Transactions.Transaction.GetPromotedToken",                 "level":6, "line":0, "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51" }


0  { "method":"System.RuntimeMethodHandle.InvokeMethod",                                                     "assembly":"System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e",    "level":0,"line":0}
1  { "method":"System.Data.SqlClient.SqlInternalConnection.EnlistNonNull",                                   "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":1,"line":0}
2  { "method":"System.Data.ProviderBase.DbConnectionPool.PrepareConnection",                                 "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":2,"line":0}
3  { "method":"System.Data.ProviderBase.DbConnectionPool.TryGetConnection",                                  "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":3,"line":0}
4  { "method":"System.Data.ProviderBase.DbConnectionPool.TryGetConnection",                                  "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":4,"line":0}
5  { "method":"System.Data.ProviderBase.DbConnectionFactory.TryGetConnection",                               "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":5,"line":0}
6  { "method":"System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal",                     "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":6,"line":0}
7  { "method":"System.Data.SqlClient.SqlConnection.TryOpen",                                                 "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":7,"line":0}
8  { "method":"System.Data.SqlClient.SqlConnection.Open",                                                    "assembly":"System.Data.SqlClient, Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a",     "level":8,"line":0}
9  { "method":"System.Data.Entity.Infrastructure.Interception.InternalDispatcher`1.Dispatch",                "assembly":"EntityFramework, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089",           "level":9,"line":0}
10 { "method":"System.Data.Entity.Infrastructure.Interception.DbConnectionDispatcher.Open",                  "assembly":"EntityFramework, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089",           "level":10,"line":0}
11 { "method":"System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy+<>c__DisplayClass2_0.<Execute>b__0", "assembly":"EntityFramework.SqlServer, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "level":11,"line":0}
12 { "method":"System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute",                            "assembly":"EntityFramework.SqlServer, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "level":12,"line":0}
13 { "method":"System.Data.Entity.SqlServer.DefaultSqlExecutionStrategy.Execute",                            "assembly":"EntityFramework.SqlServer, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089", "level":13,"line":0}
14 { "method":"System.Data.Entity.Core.EntityClient.EntityConnection.Open",                                  "assembly":"EntityFramework, Version=6.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089",           "level":14,"line":0}

EDIT:
We found the same stack trace under a Windows environment as well

Windows x64

0 { "method":"System.Transactions.TransactionStatePSPEOperation.get_Status",     "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":0,"line":0 }
1 { "method":"System.Transactions.TransactionInformation.get_Status",            "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":1,"line":0 }
2 { "method":"System.Data.SqlClient.SqlDelegatedTransaction.Promote",            "assembly":"System.Data.SqlClient,     Version=4.6.1.2, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a", "level":2,"line":0 }
3 { "method":"System.Transactions.TransactionStatePSPEOperation.PSPEPromote",    "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":3,"line":0 }
4 { "method":"System.Transactions.TransactionStateDelegatedNonMSDTC.EnterState", "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":4,"line":0 }
5 { "method":"System.Transactions.EnlistableStates.PromotedToken",               "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":5,"line":0 }
6 { "method":"System.Transactions.Transaction.GetPromotedToken",                 "assembly":"System.Transactions.Local, Version=5.0.0.0, Culture=neutral, PublicKeyToken=cc7b13ffcd2ddd51", "level":6,"line":0 }

Configuration

• Runtime Linux x64 (first stack trace), Windows x64 (after edit)
• dotnet 5.0.203

Regression?

• Not sure if this is a regression

Other information

Based on the documentation page of Promotable Single Phase Enlistment

the Promotable Single Phase Enlistment (PSPE) that allows a single remote durable resource, located in a different application domain, process or machine, to participate in a System.Transactions transaction without causing it to be escalated to an MSDTC transaction.

...TransactionStatePSPEOperation should not throw an exception under a Linux environment where we don't have MSDTC.

Related

Issue dotnet/SqlClient#784 seems to present the same stacktrace (second one) .

This mentions dotnet/SqlClient#543 which seems to be the culprid because they introduced a new if statement and checks the status here

                //Throw exception only if Transaction is still active and not yet aborted.
                if (promoteException != null && Transaction.TransactionInformation.Status != TransactionStatus.Aborted)
                {
                    throw SQL.PromotionFailed(promoteException);
                }

Source: https://github.com/dotnet/SqlClient/pull/543/files#diff-318a0b3769dd34240f6758ac2efc7fc599875e28230753d10d438f6a1c797fbfR211

Also opened an issue here: dotnet/SqlClient#1163

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[sergey-netdev]

I have a similar issue on Windows in a .NET 4.8 application using EF Core 3.1
Microsoft.Data.SqlClient 1.13.20136.2
Microsoft SQL Server 2019 (RTM-GDR) (KB5014356) - 15.0.2095.3 (X64) Apr 29 2022 18:00:13 Copyright (C) 2019 Microsoft Corporation Developer Edition (64-bit) on Windows 10 Pro 10.0 (Build 19044: ) (Hypervisor)

I have no distributed transactions (unless some library code does something funny) so use of MSDTC is not expected. The issue manifests itself under high load when there are a lot of write-heavy transactions.

System.Transactions.TransactionException: The operation is not valid for the state of the transaction.
   at System.Transactions.TransactionStatePSPEOperation.get_Status(InternalTransaction tx)
   at System.Transactions.TransactionInformation.get_Status()
   at Microsoft.Data.SqlClient.SqlDelegatedTransaction.Promote()
   at System.Transactions.TransactionStatePSPEOperation.PSPEPromote(InternalTransaction tx)
   at System.Transactions.TransactionStateDelegatedBase.EnterState(InternalTransaction tx)
   at System.Transactions.EnlistableStates.Promote(InternalTransaction tx)
   at System.Transactions.Transaction.Promote()
   at System.Transactions.TransactionInterop.ConvertToOletxTransaction(Transaction transaction)
   at System.Transactions.TransactionInterop.GetExportCookie(Transaction transaction, Byte[] whereabouts)
   at Microsoft.Data.SqlClient.SqlInternalConnection.GetTransactionCookie(Transaction transaction, Byte[] whereAbouts)
   at Microsoft.Data.SqlClient.SqlInternalConnection.EnlistNonNull(Transaction tx)
   at Microsoft.Data.SqlClient.SqlInternalConnection.Enlist(Transaction tx)
   at Microsoft.Data.ProviderBase.DbConnectionInternal.ActivateConnection(Transaction transaction)
   at Microsoft.Data.ProviderBase.DbConnectionPool.PrepareConnection(DbConnection owningObject, DbConnectionInternal obj, Transaction transaction)
   at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, UInt32 waitForMultipleObjectsTimeout, Boolean allowCreate, Boolean onlyOneCheckConnection, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionPool.TryGetConnection(DbConnection owningObject, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
   at Microsoft.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
   at Microsoft.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
   at Microsoft.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
   at Microsoft.Data.SqlClient.SqlConnection.Open()
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.OpenDbConnection(Boolean errorsExpected)
   at Microsoft.EntityFrameworkCore.Storage.RelationalConnection.Open(Boolean errorsExpected)
   at Microsoft.EntityFrameworkCore.SqlServer.Storage.Internal.SqlServerExecutionStrategy.Execute[TState,TResult](TState state, Func`3 operation, Func`3 verifySucceeded)
   at Microsoft.EntityFrameworkCore.RelationalDatabaseFacadeExtensions.OpenConnection(DatabaseFacade databaseFacade)