Tests failed on WASM with NRE in CustomAttributeTypedArgument.CanonicalizeValue

[danmoseley]

net5.0-Browser-Release-wasm-Mono_Release-Ubuntu.1804.Amd64.Open

https://dev.azure.com/dnceng/public/_build/results?buildId=733324&view=ms.vss-test-web.build-test-results-tab&runId=22691562&resultId=139620&paneView=debug

#39420

System.SpanTests.ReadOnlySpanTests.Overlap

System.NullReferenceException : Object reference not set to an instance of an object.


Stack trace
   at System.Reflection.CustomAttributeTypedArgument.CanonicalizeValue(Object value)
   at System.Reflection.CustomAttributeTypedArgument..ctor(Type argumentType, Object value)
   at System.Reflection.CustomAttributeData.ResolveArguments()
   at System.Reflection.CustomAttributeData.get_ConstructorArguments()
   at ReflectionAbstractionExtensions.GetCustomAttributes(IMethodInfo methodInfo, Type attributeType)

[danmoseley]

Same for unrelated Asn1 test:

System.NullReferenceException : Object reference not set to an instance of an object.


Stack trace
   at System.Reflection.CustomAttributeTypedArgument.CanonicalizeValue(Object value)
   at System.Reflection.CustomAttributeTypedArgument..ctor(Type argumentType, Object value)
   at System.Reflection.CustomAttributeData.ResolveArguments()
   at System.Reflection.CustomAttributeData.get_ConstructorArguments()
   at ReflectionAbstractionExtensions.GetCustomAttributes(IMethodInfo methodInfo, Type attributeType)

[safern]

@akoeplinger and I were looking at this. This is a flaky issue that started happening yesterday morning. @akoeplinger is suspecting of: ef2ecfd#diff-a70a13cf973dcdf79e3a506980ae1a2d

I looked at the first build that hit this which ran against the following commits:
HEAD is now at 23d574901 Merge 5e493d6 into 37cf387

The commit in question above is not in that tree, however there is: c80cc2a#diff-a70a13cf973dcdf79e3a506980ae1a2d

But I don't have enough expertise to know that? Maybe the runtime is returning null when doing GetType().

This is flaky enough that I was not able to get a repro, but since this is hit when Xunit tries to get attributes for the test to execute, it could hit any test case.

cc: @marek-safar @vargaz @BrzVlad @steveisok

[safern]

@vargaz I sent a private job that ran System.Memory.Tests 30 times and added:

g_warning ("NULL interp_runtime_invoke");

To this if block:

runtime/src/mono/mono/mini/interp/interp.c

Lines 1915 to 1921 in c80cc2a

	if (context->has_resume_state) {
	/*
	* This can happen on wasm where native frames cannot be skipped during EH.
	* EH processing will continue when control returns to the interpreter.
	*/
	return NULL;
	}

And it did print the warning when failed:

L: NULL interp_runtime_invoke
[FAIL] System.Memory.Tests.ReadOnlySequenceTestsByte+SegmentPerByte.PositionOf_ReturnsPosition
System.NullReferenceException : Object reference not set to an instance of an object.
   at System.Reflection.CustomAttributeTypedArgument.CanonicalizeValue(Object value)
   at System.Reflection.CustomAttributeTypedArgument..ctor(Type argumentType, Object value)
   at System.Reflection.CustomAttributeData.ResolveArguments()
   at System.Reflection.CustomAttributeData.get_ConstructorArguments()
   at ReflectionAbstractionExtensions.GetCustomAttributes(IMethodInfo methodInfo, Type attributeType)

So it seems like: c80cc2a is what introduced this regression, right?

[vargaz]

I can't reproduce the failures locally, but it does look like this is the cause, we should revert.

[safern]

It reproed 2 times out of 30 runs for System.Memory.Tests and that took like 3 hours to run 😫

[akoeplinger]

I also tried the same with a bit more logging to print out the exception stacktrace and it is indeed the NullReferenceException:

L: NULL interp_runtime_invoke
L: backtrace:
System.NullReferenceException : Object reference not set to an instance of an object.
at System.Reflection.CustomAttributeTypedArgument.CanonicalizeValue (object) <0x0000a>
at System.Reflection.CustomAttributeTypedArgument..ctor (System.Type,object) <0x00030>
at (wrapper managed-to-native) System.Reflection.CustomAttributeData.ResolveArgumentsInternal (System.Reflection.ConstructorInfo,System.Reflection.Assembly,intptr,uint,object[]&,object[]&) <0x00038>
at System.Reflection.CustomAttributeData.ResolveArguments () <0x00044>
at System.Reflection.CustomAttributeData.get_ConstructorArguments () <0x0000a>
at Xunit.Sdk.ReflectionAttributeInfo.GetConstructorArguments () <0x00010>
at Xunit.Sdk.ReflectionAttributeInfo.Instantiate (System.Reflection.CustomAttributeData) <0x00010>
at Xunit.Sdk.ReflectionAttributeInfo..ctor (System.Reflection.CustomAttributeData) <0x0001a>
at Xunit.Sdk.ReflectionMethodInfo.GetCustomAttributes (System.Reflection.MethodInfo,System.Type,System.AttributeUsageAttribute) <0x0009a>
at Xunit.Sdk.ReflectionMethodInfo.GetCustomAttributes (System.Reflection.MethodInfo,string) <0x00030>
at Xunit.Sdk.ReflectionMethodInfo.GetCustomAttributes (string) <0x00010>
at ReflectionAbstractionExtensions.GetCustomAttributes (Xunit.Abstractions.IMethodInfo,System.Type) <0x0001e>
at Xunit.Sdk.XunitTheoryTestCaseRunner/<AfterTestCaseStartingAsync>d__9.MoveNext () <0x0010a>

We currently think that this might have been there all the time, it's just that c80cc2a now properly propagates the exception instead of hiding it.

Since there shouldn't be a way to hit a NullRef in that method we currently think we're hitting some sort of GC bug.

[ViktorHofer]

Happened here again: https://helix.dot.net/api/2019-06-17/jobs/9b6ba048-2f3a-47aa-9f8d-67a294408c7b/workitems/System.Runtime.Extensions.Tests/files/console.6dbef032.log

[safern]

Another hit in: #39854

[akoeplinger]

We think this is fixed with #39856 which is merged now (I ran four helix jobs with a loop of System.Memory.Tests for three hours with no crashes).

I'll keep a close eye on the CI results over the next few days.

[safern]

Let's keen an eye and look at the data tomorrow or Monday that will give us an idea as there can be many runs today that checked out sources without this change.

[akoeplinger]

I checked the data and couldn't find any run that hit this after the fix was merged :)

[steveisok]

Nice job everybody! That was a tough one.

[safern]

This looks like a different stack trace. Maybe another bug. @v-haren would you mind opening a new issue?

[safern]

Actually that is: #40307