Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AssertMemberExposure causing flaky test failures #52368

Closed
tmat opened this issue Apr 2, 2021 · 17 comments · Fixed by #53044
Closed

AssertMemberExposure causing flaky test failures #52368

tmat opened this issue Apr 2, 2021 · 17 comments · Fixed by #53044
Assignees
Milestone

Comments

@tmat
Copy link
Member

tmat commented Apr 2, 2021

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

System.AggregateException : One or more errors occurred. (Assertion failed)
---- System.InvalidOperationException : Assertion failed


Stack trace
   at System.Threading.Tasks.TaskReplicator.Run[TState](ReplicatableUserAction`1 action, ParallelOptions options, Boolean stopOnFirstFailure)
   at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Parallel.ThrowSingleCancellationExceptionOrOtherException(ICollection exceptions, CancellationToken cancelToken, Exception otherException)
   at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)
   at System.Threading.Tasks.Parallel.For(Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body)
   at Roslyn.Utilities.RoslynParallel.For(Int32 fromInclusive, Int32 toExclusive, Action`1 body, CancellationToken cancellationToken) in /_/src/Compilers/Core/Portable/InternalUtilities/RoslynParallel.cs:line 23
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceNamespaceSymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceNamespaceSymbol_Completion.cs:line 48
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceModuleSymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceModuleSymbol.cs:line 263
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceAssemblySymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceAssemblySymbol.cs:line 913
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetSourceDeclarationDiagnostics(SyntaxTree syntaxTree, Nullable`1 filterSpanWithinTree, Func`4 locationFilterOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2801
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnosticsWithoutFiltering(CompilationStage stage, Boolean includeEarlierStages, BindingDiagnosticBag builder, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2676
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CompilationStage stage, Boolean includeEarlierStages, DiagnosticBag diagnostics, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2602
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CompilationStage stage, Boolean includeEarlierStages, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2594
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2588
   at Microsoft.CodeAnalysis.DiagnosticExtensions.VerifyDiagnostics[TCompilation](TCompilation c, DiagnosticDescription[] expected) in /_/src/Compilers/Test/Core/Diagnostics/DiagnosticExtensions.cs:line 103
   at Microsoft.CodeAnalysis.CSharp.UnitTests.TopLevelStatementsTests.LocalFunctionStatement_04() in /_/src/Compilers/CSharp/Test/Semantic/Semantics/TopLevelStatementsTests.cs:line 4338
----- Inner Stack Trace -----
   at Microsoft.CodeAnalysis.ThrowingTraceListener.Fail(String message, String detailMessage) in /_/src/Compilers/Test/Core/ThrowingTraceListener.cs:line 26
   at System.Diagnostics.TraceInternal.Fail(String message, String detailMessage)
   at System.Diagnostics.TraceInternal.TraceProvider.Fail(String message, String detailMessage)
   at System.Diagnostics.Debug.Fail(String message, String detailMessage)
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMem
@dotnet-issue-labeler dotnet-issue-labeler bot added Area-Compilers untriaged Issues and PRs which have not yet been triaged by a lead labels Apr 2, 2021
@RikkiGibson
Copy link
Contributor

It looks like the stack trace is incomplete, but I'm not able to find a complete stack trace in the build logs or artifacts.

@jaredpar
Copy link
Member

jaredpar commented Apr 6, 2021

System.InvalidOperationException : Assertion failed

Note that this means we're seeing a Debug.Assert failure vs. an xUnit Assert failure. That is coming from the ThrowingTraceListener class. There are no Debug.Assert calls here though, it's getting pushed up from another source in the Parallel.For call.

Can we disable this test for now and try running it locally to see if we can get a repro?

@jaredpar jaredpar added Bug and removed untriaged Issues and PRs which have not yet been triaged by a lead labels Apr 6, 2021
@jaredpar jaredpar added this to the 16.10 milestone Apr 6, 2021
@Youssef1313
Copy link
Member

Can we disable this test for now and try running it locally to see if we can get a repro?

I think this won't help much. It's not the only test failing with this exception & stacktrace. See #52372

@AlekseyTs
Copy link
Contributor

@Youssef1313

I think this won't help much. It's not the only test failing with this exception & stacktrace. See #52372

As Jared mentioned, the stack here is incomplete. Everything goes through ForceComplete and the assert is failing in code executed by Parallel.For. It looks like the "----- Inner Stack Trace -----" doesn't match, even though it is truncated.

@jaredpar
Copy link
Member

jaredpar commented Apr 8, 2021

The other failure is at least giving us a clue where the problem is

   at Microsoft.CodeAnalysis.ThrowingTraceListener.Fail(String message, String detailMessage) in /_/src/Compilers/Test/Core/ThrowingTraceListener.cs:line 26
   at System.Diagnostics.TraceListener.Fail(String message)
   at System.Diagnostics.TraceInternal.Fail(String message)
   at System.Diagnostics.Debug.Assert(Boolean condition)
   at Microsoft.CodeAnalysis.CustomAttributesBag`1.get_IsEarlyDecodedWellKnownAttributeDataComputed() in /_/src/Compilers/Core/Portable/Symbols/Attributes/CustomAttributesBag.cs:line 179
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceNamedTypeSymbol.GetEarlyDecodedWellKnownAttributeData() in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceNamedTypeSymbol.cs:line 855
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceNamedTypeSymbol.GetAppliedCon```  

That failure happened on Windows .NET Framework where as this bug happened on Linux .NET Core. The reporting diagnostics are just capturing more data in the .NET Framework case.

Looks like we need to dig into the IsEarlyDecodedWellKnownAttributeDataComputed function.

@AlekseyTs
Copy link
Contributor

@jaredpar I think this assert is different. There is enough "----- Inner Stack Trace -----" to see that they are different.

@jaredpar
Copy link
Member

jaredpar commented Apr 8, 2021

@AlekseyTs my suspicion is that the difference in stack traces is due to the difference in how .NET Framework and .NET core handle trace listeners, particularly on Linux. I've seen similar stack differences before when debugging the same failure across the runtimes.

I'm not 100% sure this is the case though. It's just suspicion at this point.

In either case though, the stack from #52372 is actionable. Hence going to dig into that for a bit and see if I can get a bug fix out. If this failure stops reproing after that fix is in then I'll feel more confident in my suspicion here.

@AlekseyTs
Copy link
Contributor

Hence going to dig into that for a bit and see if I can get a bug fix out. If this failure stops reproing after that fix is in then I'll feel more confident in my suspicion here.

Makes sense.

@jaredpar
Copy link
Member

jaredpar commented Apr 8, 2021

Should have a PR out for #52372 shortly.

@jaredpar jaredpar self-assigned this Apr 8, 2021
jaredpar added a commit that referenced this issue Apr 8, 2021
* Fix race conditions in attribute asserts

There are asserts in our `CustomAttributeBag` to verify we maintain the
invariant that early decoding occurs before the full decoding. The
asserts though done in the getters and take the following form:

```cs
bool earlyComplete = IsPartComplete(CustomAttributeBagCompletionPart.EarlyDecodedWellKnownAttributeData);
// If late attributes are complete, early attributes must also be complete
Debug.Assert(!IsPartComplete(CustomAttributeBagCompletionPart.DecodedWellKnownAttributeData) || earlyComplete);
return earlyComplete;
```

This pattern is subject to race conditions. Consider the case where the
`bool earlyComplete` statement runs to completion and returns `false`. Then
another thread swaps in and completes both early and full decoding. At
that point the original thread resumes and the `Debug.Assert` will fail
yet no invariant has been violated.

Moved the `Debug.Assert` into the setters where we can reliably test the
state invariants.

closes #52372
related to #52368

* Fix

* Add back an assert
@Youssef1313
Copy link
Member

@jaredpar Looks like it's not fixed 😕

Another test failed with a similar exception today in #50608.

[xUnit.net 00:00:14.77]     Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS0116ERR_NamespaceUnexpected_4 [FAIL]
  Failed Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS0116ERR_NamespaceUnexpected_4 [40 ms]
  Error Message:
   System.AggregateException : One or more errors occurred. (Assertion failed)
---- System.InvalidOperationException : Assertion failed
  Stack Trace:
     at System.Threading.Tasks.TaskReplicator.Run[TState](ReplicatableUserAction`1 action, ParallelOptions options, Boolean stopOnFirstFailure)
   at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Parallel.ThrowSingleCancellationExceptionOrOtherException(ICollection exceptions, CancellationToken cancelToken, Exception otherException)
   at System.Threading.Tasks.Parallel.ForWorker[TLocal](Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body, Action`2 bodyWithState, Func`4 bodyWithLocal, Func`1 localInit, Action`1 localFinally)
   at System.Threading.Tasks.Parallel.For(Int32 fromInclusive, Int32 toExclusive, ParallelOptions parallelOptions, Action`1 body)
   at Roslyn.Utilities.RoslynParallel.For(Int32 fromInclusive, Int32 toExclusive, Action`1 body, CancellationToken cancellationToken) in /_/src/Compilers/Core/Portable/InternalUtilities/RoslynParallel.cs:line 23
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceNamespaceSymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceNamespaceSymbol_Completion.cs:line 48
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceModuleSymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceModuleSymbol.cs:line 263
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceAssemblySymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceAssemblySymbol.cs:line 913
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetSourceDeclarationDiagnostics(SyntaxTree syntaxTree, Nullable`1 filterSpanWithinTree, Func`4 locationFilterOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2801
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnosticsWithoutFiltering(CompilationStage stage, Boolean includeEarlierStages, BindingDiagnosticBag builder, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2676
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CompilationStage stage, Boolean includeEarlierStages, DiagnosticBag diagnostics, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2602
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CompilationStage stage, Boolean includeEarlierStages, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2594
   at Microsoft.CodeAnalysis.CSharp.CSharpCompilation.GetDiagnostics(CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Compilation/CSharpCompilation.cs:line 2588
   at Microsoft.CodeAnalysis.DiagnosticExtensions.VerifyDiagnostics[TCompilation](TCompilation c, DiagnosticDescription[] expected) in /_/src/Compilers/Test/Core/Diagnostics/DiagnosticExtensions.cs:line 103
   at Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS0116ERR_NamespaceUnexpected_4() in /_/src/Compilers/CSharp/Test/Semantic/Semantics/SemanticErrorTests.cs:line 2796
----- Inner Stack Trace -----
   at Microsoft.CodeAnalysis.ThrowingTraceListener.Fail(String message, String detailMessage) in /_/src/Compilers/Test/Core/ThrowingTraceListener.cs:line 26
   at System.Diagnostics.TraceInternal.Fail(String message, String detailMessage)
   at System.Diagnostics.TraceInternal.TraceProvider.Fail(String message, String detailMessage)
   at System.Diagnostics.Debug.Fail(String message, String detailMessage)
   at System.Diagnostics.Debug.Assert(Boolean condition)
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberContainerTypeSymbol.AssertMemberExposure(Symbol member, Boolean forDiagnostics) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberContainerSymbol.cs:line 1498
   at Microsoft.CodeAnalysis.CSharp.Symbol.AddDeclarationDiagnostics(BindingDiagnosticBag diagnostics) in /_/src/Compilers/CSharp/Portable/Symbols/Symbol.cs:line 860
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberMethodSymbol.LazyMethodChecks() in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberMethodSymbol.cs:line 334
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberMethodSymbol.get_OverriddenOrHiddenMembers() in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberMethodSymbol.cs:line 729
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberContainerTypeSymbol.CheckMembersAgainstBaseType(BindingDiagnosticBag diagnostics, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberContainerSymbol_ImplementationChecks.cs:line 520
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberContainerTypeSymbol.GetSynthesizedExplicitImplementations(CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberContainerSymbol_ImplementationChecks.cs:line 38
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceMemberContainerTypeSymbol.ForceComplete(SourceLocation locationOpt, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceMemberContainerSymbol.cs:line 533
   at Microsoft.CodeAnalysis.CSharp.Symbol.ForceCompleteMemberByLocation(SourceLocation locationOpt, Symbol member, CancellationToken cancellationToken) in /_/src/Compilers/CSharp/Portable/Symbols/Symbol.cs:line 802
   at Microsoft.CodeAnalysis.CSharp.Symbols.SourceNamespaceSymbol.<>c__DisplayClass49_1.<ForceComplete>b__0(Int32 i) in /_/src/Compilers/CSharp/Portable/Symbols/Source/SourceNamespaceSymbol_Completion.cs:line 51
   at Roslyn.Utilities.UICultureUtilities.<>c__DisplayClass6_0`1.<WithCurrentUICulture>b__0(T param) in /_/src/Compilers/Core/Portable/InternalUtilities/UICultureUtilities.cs:line 169
   at Roslyn.Utilities.RoslynParallel.<>c__DisplayClass1_0.<For>g__errorHandlingBody|0(Int32 i) in /_/src/Compilers/Core/Portable/InternalUtilities/RoslynParallel.cs:line 30
   at System.Threading.Tasks.Parallel.<>c__DisplayClass19_0`1.<ForWorker>b__1(RangeWorker& currentWorker, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)
--- End of stack trace from previous location ---
   at System.Threading.Tasks.Parallel.<>c__DisplayClass19_0`1.<ForWorker>b__1(RangeWorker& currentWorker, Int32 timeout, Boolean& replicationDelegateYieldedBeforeCompletion)
   at System.Threading.Tasks.TaskReplicator.Replica`1.ExecuteAction(Boolean& yieldedBeforeCompletion)
   at System.Threading.Tasks.TaskReplicator.Replica.Execute()
[xUnit.net 00:00:14.84]     Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS1592WRN_XMLParseIncludeError [SKIP]
  Skipped Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS1592WRN_XMLParseIncludeError [1 ms]
[xUnit.net 00:00:15.05]     Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS0122ERR_InaccessibleGenericType [SKIP]
  Skipped Microsoft.CodeAnalysis.CSharp.UnitTests.SemanticErrorTests.CS0122ERR_InaccessibleGenericType [1 ms]
Results File: /datadisks/disk1/work/A9F209AF/w/AA2C097C/e/Microsoft.CodeAnalysis.CSharp.Semantic.UnitTests.dll.7_net5.0_x64_test_results.xml

Failed!  - Failed:     1, Passed:   826, Skipped:    14, Total:   841, Duration: 11 s - /datadisks/disk1/work/A9F209AF/w/AA2C097C/e/Microsoft.CodeAnalysis.CSharp.Semantic.UnitTests.dll (net5.0)

https://dev.azure.com/dnceng/public/_build/results?buildId=1085303&view=logs&jobId=8225d539-f709-56d9-e8fb-4b6141b087c9&j=8225d539-f709-56d9-e8fb-4b6141b087c9&t=60710b2d-694c-5f9a-9f24-31a79ea198f9

@jaredpar
Copy link
Member

I agree it's still happening. Unfortunately all the failures have the same lack of info here that makes it hard to debug this. Think we may need to run this in a loop locally to see where it's failing.

@jaredpar
Copy link
Member

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

This hit the failure today on Windows Desktop. The stack trace was a bit better this time. Pretty clear this is the assert in AssertMemberExposure that is getting tripped

var declared = Volatile.Read(ref _lazyDeclaredMembersAndInitializers);
Debug.Assert(declared != DeclaredMembersAndInitializers.UninitializedSentinel);

The test failing here is CS0267ERR_PartialMisplaced_Delegate1. The test is pretty straight forward. It's just asserting diagnostics on the following declaration:

partial delegate E { }

The original bug report occurred against LocalFunctionStatement_04 which also has a top level partial. Not sure if that is just a coincidence but is interesting to note.

@AlekseyTs does this ring any bells? The AssertMemberExposure check is tripping here pretty regularly now. For the delegate case thought possibly it was the synthesized members that are getting exposed in the partial check.

@AlekseyTs
Copy link
Contributor

@jaredpar Can we "instrument" the AssertMemberExposure to get a dump next time it fails?

@jaredpar
Copy link
Member

PR #52849 added AssertOrFailFast to the AssertMemberExposure here which should produce a heap dump next time it is hit.

@jaredpar jaredpar changed the title Microsoft.CodeAnalysis.CSharp.UnitTests.TopLevelStatementsTests.LocalFunctionStatement_04 failed in CI on Linux AssertMemberExposure causing flaky test failures Apr 26, 2021
@sharwell
Copy link
Member

Duplicate of #51195

@sharwell sharwell marked this as a duplicate of #51195 Apr 26, 2021
@sharwell
Copy link
Member

I marked this one as a duplicate of #51195 since that issue is the one tracked in runfo

@jaredpar jaredpar reopened this Apr 26, 2021
@jaredpar
Copy link
Member

@AlekseyTs have a heap dump of this failure now.

Direct link to the heap dump: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-roslyn-refs-heads-main-a3902d9630b048b28f/Microsoft.CodeAnalysis.CSharp.Semantic.UnitTests.dll.13/core.1000.16548?%3F%253Fsv%253D2019-07-07%2526se%253D2021-05-19T05%25253A05%25253A14Z%2526sr%253Dc%2526sp%253Drl%2526sig%253DzVGPEbRhrT50qsHBAWwLk21q05bvR%25252FLC805kDLcKvEo%25253D

When you click on that link it will download a file with a number extension. You need to rename it to have a .dmp extension before VS will open it as a dump

Containing build: https://dev.azure.com/dnceng/public/_build/results?buildId=1113392

Note: this is a core dump from Linux but that shouldn't impact the VS experience (tested locally)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants