Test failure: System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get

v-wenyuxu commented 1 month ago

Failed in: runtime-coreclr crossgen2 20240717.1

Failed tests:

net9.0-windows-Release-x64-TestReadyToRun_Release-(Windows.Nano.1809.Amd64.Open)windows.10.amd64.serverrs5.open@mcr.microsoft.com/dotnet-buildtools/prereqs:nanoserver-1809-helix-amd64
    - System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get

Error message:

 Assert.Equal() Failure: Values differ
Expected: 00:02:00
Actual:   00:01:00

Stack trace:

   at System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get() in /_/src/libraries/System.Transactions.Local/tests/TransactionManagerTest.cs:line 15
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)

Known Issue Error Message

Fill the error message using step by step known issues guidance.

{
  "ErrorMessage": "at System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get",
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: :mag_right: https://dev.azure.com/dnceng-public/public/_build/results?buildId=745900 Error message validated: [at System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get] Result validation: :white_check_mark: Known issue matched with the provided build. Validation performed at: 7/24/2024 6:15:28 PM UTC

Report

Summary

24-Hour Hit Count	7-Day Hit Count	1-Month Count
0	0	0

dotnet-policy-service[bot] commented 1 month ago

Tagging subscribers to this area: @roji, @ajcvickers See info in area-owners.md if you want to be subscribed.

steveisok commented 1 month ago

@jkotas I'm perplexed at how this can happen. Any insight?

steveisok commented 1 month ago

Since this isn't happening in any current runs, I'm going to close.

jkotas commented 1 month ago

I'm perplexed at how this can happen. Any insight?

This is a bug in TransationManager.

TransationManager.DefaultTimeOut is a global static. What can happen is:

One thread is running this test that is setting the global static to a non-default value using Interlocked.Exchange: https://github.com/dotnet/runtime/blob/dff1d8467845fd93c517f89dc81598e5fd17c270/src/libraries/System.Transactions.Local/src/System/Transactions/TransactionManager.cs#L328
Some other thread is running a test that tries to read the timeout. The act of reading the timeout initializes the global static using LazyInitializer.EnsureInitialized: https://github.com/dotnet/runtime/blob/dff1d8467845fd93c517f89dc81598e5fd17c270/src/libraries/System.Transactions.Local/src/System/Transactions/TransactionManager.cs#L304

This is a product bug. Reading the default timeout value on one thread should not lead to default value set on the on a different thread to be lost.

The bug is caused by mixing of lock used by LazyInitializer.EnsureInitialized and Interlocked operations that does not provide the thread safety desired here. Either both places should use lock or both places should use Interlocked operations.

This does not always repro, but it reproes often enough that we have seen the same issue filled in the past (e.g. https://github.com/dotnet/runtime/issues/90085).

jkotas commented 1 month ago

This bug was introduced in #71703. cc @imcarolwang @HongGit

dotnet / runtime