dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
14.95k stars 4.65k forks source link

System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch failure #104905

Closed elinor-fung closed 2 weeks ago

elinor-fung commented 2 months ago
System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(value: WeakReference { IsAlive = True, Target = https://dot.net/, TrackResurrection = True }, _: [BinaryFormatTests.TypeSerializableValue, BinaryFormatTests.TypeSerializableValue]) [FAIL]
  Assert.Equal() Failure: Values differ
  Expected: 242
  Actual:   85
  Stack Trace:
    /_/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/FormattedObject/BasicObjectTests.cs(40,0): at System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(Object value, TypeSerializableValue[] _)
        at System.Object.InvokeStub_BasicObjectTests.BasicObjectsRoundTripAndMatch(Object , Span`1 )
    /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs(136,0): at System.Reflection.MethodBaseInvoker.InvokeWithFewArgs(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)

Build Information

Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=739427 Build error leg or test failing: System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch Pull request: https://github.com/dotnet/runtime/pull/104749

Error Message

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

{
  "ErrorMessage": ["BasicObjectsRoundTripAndMatch", "Expected:"],
  "ErrorPattern": "",
  "BuildRetry": false,
  "ExcludeConsoleLog": false
}

Known issue validation

Build: :mag_right: Result validation: :warning: Provided build not found. Provide a valid build in the "Build: :mag_right:" line. Validation performed at: 8/14/2024 10:23:52 PM UTC

Report

Build Definition Test Pull Request
791827 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#107117
790572 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106965
790309 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#107050
784110 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106409
779942 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106613
779313 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106578
777681 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch
777119 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106474
776563 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106437
776146 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106416
775754 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106398
775106 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106218
769299 dotnet/runtime System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch dotnet/runtime#106108

Summary

24-Hour Hit Count 7-Day Hit Count 1-Month Count
1 3 13
dotnet-policy-service[bot] commented 2 months ago

Tagging subscribers to this area: @dotnet/area-system-resources See info in area-owners.md if you want to be subscribed.

elinor-fung commented 2 months ago

cc @adamsitnik - test was added in https://github.com/dotnet/runtime/pull/102379

ericstj commented 1 month ago

Adding some detail about the failure. Seems this was deserializing a WeakReference object:

System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(value: WeakReference { IsAlive = True, Target = https://dot.net/, TrackResurrection = True }, _: [BinaryFormatTests.TypeSerializableValue, BinaryFormatTests.TypeSerializableValue]) [FAIL]
      Assert.Equal() Failure: Values differ
      Expected: 242
      Actual:   85
      Stack Trace:
        /_/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/FormattedObject/BasicObjectTests.cs(40,0): at System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(Object value, TypeSerializableValue[] _)
           at System.Object.InvokeStub_BasicObjectTests.BasicObjectsRoundTripAndMatch(Object , Span`1 )
        /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs(136,0): at System.Reflection.MethodBaseInvoker.InvokeWithFewArgs(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)

https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-pull-104749-merge-d99a4fd2282b40b389/System.Resources.Extensions.BinaryFormat.Tests/1/console.d365210d.log?helixlogtype=result

Here's the corresponding test data: https://github.com/dotnet/runtime/blob/66ae90f3b7ec4f13fffcd71913eca0b45777e58c/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/Legacy/BinaryFormatterTestData.cs#L717-L720

Seems pretty odd to me that this would be flaky. Any theories, @adamsitnik?

adamsitnik commented 1 month ago

Any theories, @adamsitnik?

The test failed when comparing the lengths of a streams that contained:

https://github.com/dotnet/runtime/blob/bec59708182682410afb4014a729149c1cf3439f/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/FormattedObject/BasicObjectTests.cs#L39-L40

My theory: WeakReference was no longer pointing to an alive object when the value was serialized to another stream, so the content was different and hence the stream length difference.

Repro:

using System.Runtime.Serialization.Formatters.Binary;

Uri? dotnetUri = new("https://dot.net");
WeakReference weakReference = new(dotnetUri, true);

BinaryFormatter binaryFormatter = new();
MemoryStream memoryStream = new();

binaryFormatter.Serialize(memoryStream, weakReference);
Console.WriteLine($"IsAlive: {weakReference.IsAlive}, Length: {memoryStream.Length}");

memoryStream.Position = 0;
memoryStream.SetLength(0);

dotnetUri = null;

do
{
    GC.Collect();
    GC.WaitForPendingFinalizers();
    GC.Collect();
} while (weakReference.IsAlive);

binaryFormatter.Serialize(memoryStream, weakReference);
Console.WriteLine($"IsAlive: {weakReference.IsAlive}, Length: {memoryStream.Length}");
IsAlive: True, Length: 242
IsAlive: False, Length: 85
stephentoub commented 1 month ago

I just hit this in https://github.com/dotnet/runtime/pull/105339, which was opened after and which includes the fix for this issue...

Data Driven SubResults
❌ System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(value: WeakReference { IsAlive = True, Target = https://dot.net/, TrackResurrection = True }, _: [BinaryFormatTests.TypeSerializableValue, BinaryFormatTests.TypeSerializableValue])
Exception Message
Assert.Equal() Failure: Values differ
Expected: 242
Actual:   85
Stack Trace
   at System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(Object value, TypeSerializableValue[] _) in /_/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/FormattedObject/BasicObjectTests.cs:line 40
   at System.Object.InvokeStub_BasicObjectTests.BasicObjectsRoundTripAndMatch(Object , Span`1 )
   at System.Reflection.MethodBaseInvoker.InvokeWithFewArgs(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs:line 136
adamsitnik commented 1 month ago

In #105072 I've rooted the target of WeakReference by storing it in a static field:

https://github.com/dotnet/runtime/blob/a47eeecf12361751b494e83fd49adc9a28969687/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/Legacy/BinaryFormatterTestData.cs#L55-L58

https://github.com/dotnet/runtime/blob/a47eeecf12361751b494e83fd49adc9a28969687/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/Legacy/BinaryFormatterTestData.cs#L723

I was expecting that this is going to prevent the GC from feeing it.

@stephentoub do you have any idea what I am missing here? (I've simply run out of ideas for now)

stephentoub commented 1 month ago

Thanks. Let's close this again and see if any further occurrences are reported separately. It's possible there was some kind of staleness happening.

mdh1418 commented 1 month ago

I hit this in #106040

Data Driven SubResults
❌ System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(value: WeakReference`1 { }, _: [BinaryFormatTests.TypeSerializableValue, BinaryFormatTests.TypeSerializableValue])
Exception Message
Assert.Equal() Failure: Values differ
Expected: 479
Actual:   407
Stack Trace
   at System.Resources.Extensions.Tests.FormattedObject.BasicObjectTests.BasicObjectsRoundTripAndMatch(Object value, TypeSerializableValue[] _) in /_/src/libraries/System.Resources.Extensions/tests/BinaryFormatTests/FormattedObject/BasicObjectTests.cs:line 40
   at InvokeStub_BasicObjectTests.BasicObjectsRoundTripAndMatch(Object, Span`1)
   at System.Reflection.MethodBaseInvoker.InvokeWithFewArgs(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs:line 136

Config: net9.0-windows-Release-x64-coreclr_checked-Windows.10.Amd64.Open

adamsitnik commented 3 weeks ago

I am moving it to 10 as it's not a product issue, but a flaky test.