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

[v-wenyuxu]

Failed in: runtime-coreclr crossgen2 20240717.1

Failed tests:

net9.0-windows-Release-x64-TestReadyToRun_Release-(Windows.Nano.1809.Amd64.Open)[email protected]/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: 🔎 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: ✅ Known issue matched with the provided build.
Validation performed at: 7/24/2024 6:15:28 PM UTC

Report

Build	Definition	Test	Pull Request
937032	dotnet/runtime	System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get	#112060
929200	dotnet/runtime	System.Transactions.Tests.TransactionManagerTest.DefaultTimeout_MaxTimeout_Set_Get	#111691

Summary

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

[dotnet-policy-service]

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

[steveisok]

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

[steveisok]

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

[jkotas]

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:

  runtime/src/libraries/System.Transactions.Local/src/System/Transactions/TransactionManager.cs

  Line 328 in dff1d84

  Interlocked.Exchange(ref s_defaultTimeoutTicks, ValidateTimeout(value).Ticks);

• 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:

  runtime/src/libraries/System.Transactions.Local/src/System/Transactions/TransactionManager.cs

  Line 304 in dff1d84

  LazyInitializer.EnsureInitialized(ref s_defaultTimeoutTicks, ref s_defaultTimeoutValidated, ref s_classSyncObject, () => ValidateTimeout(DefaultSettingsSection.Timeout).Ticks);

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. #90085).

[jkotas]

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

[SamMonoRT]

@HongGit - assigning to you for tracking. Please adjust milestone based on your investigation and estimated timeline for the fix.