Runtime: PayloadGroup0 is timing out

Created on 23 Jun 2020 · 17Comments · Source: dotnet/runtime

This test group is failing in a lot of different runs right now, most commonly it is timing out.

Console Log Summary

Builds

|Build|Pull Request | Test Failure Count|
| --- | --- | --- |
|#696661|#37882|2|
|#697941|#36847|2|
|#697959|#38204|2|
|#698572|#38212|1|
|#698693|Rolling|1|
|#698810|#38127|1|
|#698956|#38163|1|
|#699019|#38227|1|
|#699127|#38235|1|
|#699175|#38236|9|
|#699269|#38128|1|
|#699449|#38241|1|
|#699474|#38247|1|
|#699481|#38179|4|
|#699482|Rolling|4|
|#699510|#38251|2|
|#699528|#38236|8|
|#699618|#38255|1|
|#699696|#36847|1|
|#699893|#36847|2|
|#699910|Rolling|1|
|#699918|#38229|12|
|#700015|#38265|1|
|#700129|#37745|6|
|#700222|#38129|1|
|#700279|#38273|1|

Configurations

CoreCLR Linux arm64 Checked @ (Ubuntu.1804.Arm64.Open)Ubuntu.1804.Armarch.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm64v8-a45aeeb-20190620155855
CoreCLR Linux arm64 Checked no_tiered_compilation @ (Ubuntu.1804.Arm64.Open)Ubuntu.1804.Armarch.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:ubuntu-18.04-helix-arm64v8-a45aeeb-20190620155855
CoreCLR Linux x64 Checked @ Ubuntu.1804.Amd64.Open
CoreCLR Linux x64 Checked no_tiered_compilation @ Ubuntu.1804.Amd64.Open
CoreCLR OSX x64 Checked @ OSX.1013.Amd64.Open
CoreCLR OSX x64 Checked no_tiered_compilation @ OSX.1013.Amd64.Open
CoreCLR Windows_NT arm Checked @ Windows.10.Arm64v8.Open
CoreCLR Windows_NT arm Checked no_tiered_compilation @ Windows.10.Arm64v8.Open
CoreCLR Windows_NT arm64 Checked @ Windows.10.Arm64.Open
CoreCLR Windows_NT arm64 Checked no_tiered_compilation @ Windows.10.Arm64.Open
CoreCLR Windows_NT x64 Checked @ Windows.10.Amd64.Open
CoreCLR Windows_NT x64 Checked no_tiered_compilation @ Windows.10.Amd64.Open
CoreCLR Windows_NT x86 Checked @ Windows.10.Amd64.Open
CoreCLR Windows_NT x86 Checked no_tiered_compilation @ Windows.10.Amd64.Open
Mono OSX x64 Release @ OSX.1013.Amd64.Open
Mono OSX x64 Release interpreter @ OSX.1013.Amd64.Open

Helix Logs

area-Infrastructure-coreclr blocking-clean-ci

Source

jaredpar

Most helpful comment

@josalem

If need be, we can temporarily disable this test, but I think it might an actual regression and not just flakiness

Given the hit count right now we should be disabling unless a fix is eminent. Even if this is a regression we should still be disabling the test. In the current state it's just serving to mask other failures in the system.

jaredpar on 23 Jun 2020

👍2

All 17 comments

I couldn't figure out the best area label to add to this issue. Please help me learn by adding exactly one area label.

Dotnet-GitSync-Bot on 23 Jun 2020

safern on 23 Jun 2020

Spot checked those logs.

Looks like a few of these are #38156. I'm currently investigating that failure. However, it seems the frequency of hitting it has increased recently. If need be, we can temporarily disable this test, but I think it might an actual regression and not just flakiness.

I am also noticing several that are varying failures of Crossgen2 Determinism test failures. Some of these are AVs in managed code like the Socket failures I mention below:

Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
         at Internal.TypeSystem.TypeSystemContext+InstantiatedTypeKey..ctor(Internal.TypeSystem.TypeDesc, Internal.TypeSystem.Instantiation)
         at Internal.TypeSystem.TypeSystemContext.GetInstantiatedType(Internal.TypeSystem.MetadataType, Internal.TypeSystem.Instantiation)
         at Internal.TypeSystem.Ecma.EcmaSignatureParser.ParseTypeImpl(System.Reflection.Metadata.SignatureTypeCode)
         at Internal.TypeSystem.Ecma.EcmaSignatureParser.ParseType(System.Reflection.Metadata.SignatureTypeCode)
         at Internal.TypeSystem.Ecma.EcmaSignatureParser.ParseTypeImpl()
         at Internal.TypeSystem.Ecma.EcmaSignatureParser.ParseType()
         at Internal.TypeSystem.Ecma.EcmaSignatureParser.ParseFieldSignature()
         at Internal.TypeSystem.Ecma.EcmaField.InitializeFieldType()
         at Internal.TypeSystem.Ecma.EcmaField.get_FieldType()
         at ILCompiler.ReadyToRunMetadataFieldLayoutAlgorithm+ModuleFieldLayoutMap.GetElementTypeInfo(Internal.TypeSystem.Ecma.EcmaModule, Internal.TypeSystem.FieldDesc, System.Reflection.Metadata.EntityHandle, Internal.CorConstants.CorElementType, Int32, Boolean, Int32 ByRef, Int32 ByRef, Boolean ByRef, Boolean ByRef)
         at ILCompiler.ReadyToRunMetadataFieldLayoutAlgorithm+ModuleFieldLayoutMap.CreateValueFromKey(Internal.TypeSystem.Ecma.EcmaModule)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].CreateValueAndEnsureValueIsInTable(System.__Canon)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].GetOrCreateValue(System.__Canon)
         at ILCompiler.ReadyToRunMetadataFieldLayoutAlgorithm.ComputeStaticFieldLayout(Internal.TypeSystem.DefType, Internal.TypeSystem.StaticLayoutKind)
         at ILCompiler.SystemObjectFieldLayoutAlgorithm.ComputeStaticFieldLayout(Internal.TypeSystem.DefType, Internal.TypeSystem.StaticLayoutKind)
         at Internal.TypeSystem.DefType.ComputeStaticFieldLayout(Internal.TypeSystem.StaticLayoutKind)
         at ILCompiler.CompilerTypeSystemContext.EnsureLoadableTypeUncached(Internal.TypeSystem.TypeDesc)
         at ILCompiler.CompilerTypeSystemContext+ValidTypeHashTable.CreateValueFromKey(Internal.TypeSystem.TypeDesc)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].CreateValueAndEnsureValueIsInTable(System.__Canon)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].GetOrCreateValue(System.__Canon)
         at ILCompiler.CompilerTypeSystemContext.EnsureLoadableType(Internal.TypeSystem.TypeDesc)
         at ILCompiler.CompilerTypeSystemContext.EnsureLoadableTypeUncached(Internal.TypeSystem.TypeDesc)
         at ILCompiler.CompilerTypeSystemContext+ValidTypeHashTable.CreateValueFromKey(Internal.TypeSystem.TypeDesc)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].CreateValueAndEnsureValueIsInTable(System.__Canon)
         at Internal.TypeSystem.LockFreeReaderHashtable`2[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].GetOrCreateValue(System.__Canon)
         at ILCompiler.CompilerTypeSystemContext.EnsureLoadableType(Internal.TypeSystem.TypeDesc)
         at ILCompiler.CompilerTypeSystemContext.EnsureLoadableMethod(Internal.TypeSystem.MethodDesc)
         at ILCompiler.ReadyToRunRootProvider.CheckCanGenerateMethod(Internal.TypeSystem.MethodDesc)
         at ILCompiler.ReadyToRunRootProvider.RootMethods(Internal.TypeSystem.TypeDesc, System.String, ILCompiler.IRootingServiceProvider)
         at ILCompiler.ReadyToRunRootProvider.AddCompilationRoots(ILCompiler.IRootingServiceProvider)
         at ILCompiler.Compilation..ctor(ILCompiler.DependencyAnalysisFramework.DependencyAnalyzerBase`1<ILCompiler.DependencyAnalysis.NodeFactory>, ILCompiler.DependencyAnalysis.NodeFactory, System.Collections.Generic.IEnumerable`1<ILCompiler.ICompilationRootProvider>, Internal.IL.ILProvider, ILCompiler.DevirtualizationManager, System.Collections.Generic.IEnumerable`1<Internal.TypeSystem.ModuleDesc>, ILCompiler.Logger, ILCompiler.InstructionSetSupport)
         at ILCompiler.ReadyToRunCodegenCompilation..ctor(ILCompiler.DependencyAnalysisFramework.DependencyAnalyzerBase`1<ILCompiler.DependencyAnalysis.NodeFactory>, ILCompiler.DependencyAnalysis.NodeFactory, System.Collections.Generic.IEnumerable`1<ILCompiler.ICompilationRootProvider>, Internal.IL.ILProvider, ILCompiler.Logger, ILCompiler.DevirtualizationManager, System.Collections.Generic.IEnumerable`1<System.String>, System.String, ILCompiler.InstructionSetSupport, Boolean, Boolean, Int32, ILCompiler.ProfileDataManager, ILCompiler.ReadyToRunMethodLayoutAlgorithm, ILCompiler.ReadyToRunFileLayoutAlgorithm, System.Nullable`1<Int32>)
         at ILCompiler.ReadyToRunCodegenCompilationBuilder.ToCompilation()
         at ILCompiler.Program.Run()
         at ILCompiler.Program.InnerMain(ILCompiler.CommandLineOptions)
         at ILCompiler.Program+<>c.<Main>b__20_0(ILCompiler.CommandLineOptions)
         at System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean, Boolean)
         at System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
         at System.Delegate.DynamicInvokeImpl(System.Object[])
         at System.CommandLine.Invocation.ModelBindingCommandHandler+<InvokeAsync>d__8.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Invocation.ModelBindingCommandHandler+<InvokeAsync>d__8, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<InvokeAsync>d__8 ByRef)
         at System.CommandLine.Invocation.ModelBindingCommandHandler.InvokeAsync(System.CommandLine.Invocation.InvocationContext)
         at System.CommandLine.Invocation.InvocationPipeline+<>c__DisplayClass4_0+<<BuildInvocationChain>b__0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Invocation.InvocationPipeline+<>c__DisplayClass4_0+<<BuildInvocationChain>b__0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<BuildInvocationChain>b__0>d ByRef)
         at System.CommandLine.Invocation.InvocationPipeline+<>c__DisplayClass4_0.<BuildInvocationChain>b__0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseParseErrorReporting>b__20_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseParseErrorReporting>b__20_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseParseErrorReporting>b__20_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<UseParseErrorReporting>b__20_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass15_0+<<UseHelp>b__0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass15_0+<<UseHelp>b__0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseHelp>b__0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass15_0.<UseHelp>b__0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass24_0+<<UseVersionOption>b__0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass24_0+<<UseVersionOption>b__0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseVersionOption>b__0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass24_0.<UseVersionOption>b__0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass22_0+<<UseTypoCorrections>b__0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass22_0+<<UseTypoCorrections>b__0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseTypoCorrections>b__0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass22_0.<UseTypoCorrections>b__0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseSuggestDirective>b__21_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseSuggestDirective>b__21_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseSuggestDirective>b__21_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<UseSuggestDirective>b__21_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseParseDirective>b__19_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseParseDirective>b__19_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseParseDirective>b__19_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<UseParseDirective>b__19_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseDebugDirective>b__11_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<UseDebugDirective>b__11_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseDebugDirective>b__11_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<UseDebugDirective>b__11_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<RegisterWithDotnetSuggest>b__10_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<RegisterWithDotnetSuggest>b__10_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<RegisterWithDotnetSuggest>b__10_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<RegisterWithDotnetSuggest>b__10_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass13_0+<<UseExceptionHandler>b__0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass13_0+<<UseExceptionHandler>b__0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<UseExceptionHandler>b__0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c__DisplayClass13_0.<UseExceptionHandler>b__0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<CancelOnProcessTermination>b__5_0>d.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Builder.CommandLineBuilderExtensions+<>c+<<CancelOnProcessTermination>b__5_0>d, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<<CancelOnProcessTermination>b__5_0>d ByRef)
         at System.CommandLine.Builder.CommandLineBuilderExtensions+<>c.<CancelOnProcessTermination>b__5_0(System.CommandLine.Invocation.InvocationContext, System.Func`2<System.CommandLine.Invocation.InvocationContext,System.Threading.Tasks.Task>)
         at System.CommandLine.Invocation.InvocationPipeline+<InvokeAsync>d__2.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.Invocation.InvocationPipeline+<InvokeAsync>d__2, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<InvokeAsync>d__2 ByRef)
         at System.CommandLine.Invocation.InvocationPipeline.InvokeAsync(System.CommandLine.IConsole)
         at System.CommandLine.CommandExtensions+<InvokeAsync>d__2.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.CommandLine.CommandExtensions+<InvokeAsync>d__2, System.CommandLine, Version=2.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]](<InvokeAsync>d__2 ByRef)
         at System.CommandLine.CommandExtensions.InvokeAsync(System.CommandLine.Command, System.String[], System.CommandLine.IConsole)
         at ILCompiler.Program+<Main>d__20.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]](System.__Canon ByRef)
         at ILCompiler.Program.Main(System.String[])
         at ILCompiler.Program.<Main>(System.String[])
      Unhandled exception. System.IO.FileNotFoundException: Could not load file or assembly 'C:\h\w\BA3C09D7\w\B0E709A0\e\readytorun\crossgen2\crossgen2smoke\crossgen2smoke.dll'. The system cannot find the file specified.
      File name: 'C:\h\w\BA3C09D7\w\B0E709A0\e\readytorun\crossgen2\crossgen2smoke\crossgen2smoke.dll'

I also saw the binder event test timeouts that @safern linked.

There also appears to be some AVs coming out of the Socket APIs in the libraries:

Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
      Fatal error. System.AccessViolationException: Attempted to read or write protected memory. This is often an indication that other memory is corrupt.
         at System.Collections.Concurrent.ConcurrentDictionary`2[[System.IntPtr, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Sockets.SocketAsyncEngine+SocketAsyncContextWrapper, System.Net.Sockets, Version=5.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].TryAddInternal(IntPtr, System.Nullable`1<Int32>, SocketAsyncContextWrapper, Boolean, Boolean, SocketAsyncContextWrapper ByRef)
         at System.Collections.Concurrent.ConcurrentDictionary`2[[System.IntPtr, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Sockets.SocketAsyncEngine+SocketAsyncContextWrapper, System.Net.Sockets, Version=5.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].TryAddInternal(IntPtr, System.Nullable`1<Int32>, SocketAsyncContextWrapper, Boolean, Boolean, SocketAsyncContextWrapper ByRef)
         at System.Collections.Concurrent.ConcurrentDictionary`2[[System.IntPtr, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Sockets.SocketAsyncEngine+SocketAsyncContextWrapper, System.Net.Sockets, Version=5.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].TryAdd(IntPtr, SocketAsyncContextWrapper)
         at System.Net.Sockets.SocketAsyncEngine.RegisterCore(IntPtr, System.Net.Sockets.SocketAsyncContext)
         at System.Net.Sockets.SocketAsyncEngine.RegisterSocket(IntPtr, System.Net.Sockets.SocketAsyncContext)
         at System.Net.Sockets.SocketAsyncContext.Register()
         at System.Net.Sockets.SocketAsyncContext+OperationQueue`1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].StartAsyncOperation(System.Net.Sockets.SocketAsyncContext, System.__Canon, Int32, System.Threading.CancellationToken)
         at System.Net.Sockets.SocketAsyncContext.ReceiveFromAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Byte[], Int32 ByRef, Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, System.Action`5<Int32,Byte[],Int32,System.Net.Sockets.SocketFlags,System.Net.Sockets.SocketError>, System.Threading.CancellationToken)
         at System.Net.Sockets.SocketAsyncContext.ReceiveAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, System.Action`5<Int32,Byte[],Int32,System.Net.Sockets.SocketFlags,System.Net.Sockets.SocketError>, System.Threading.CancellationToken)
         at System.Net.Sockets.SocketAsyncEventArgs.DoOperationReceive(System.Net.Sockets.SafeSocketHandle, System.Threading.CancellationToken)
         at System.Net.Sockets.Socket.ReceiveAsync(System.Net.Sockets.SocketAsyncEventArgs, System.Threading.CancellationToken)
         at System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.ReceiveAsync(System.Net.Sockets.Socket, System.Threading.CancellationToken)
         at System.Collections.Concurrent.ConcurrentDictionary`2[[System.IntPtr, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e],[System.Net.Sockets.SocketAsyncEngine+SocketAsyncContextWrapper, System.Net.Sockets, Version=5.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a]].TryAdd(IntPtr, SocketAsyncContextWrapper)   at System.Net.Sockets.Socket.ReceiveAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Boolean, System.Threading.CancellationToken)

         at System.Net.Sockets.SocketAsyncEngine.RegisterCore(IntPtr, System.Net.Sockets.SocketAsyncContext)
         at System.Net.Sockets.NetworkStream.ReadAsync(System.Memory`1<Byte>, System.Threading.CancellationToken)
         at System.Net.Sockets.SocketAsyncEngine.RegisterSocket(IntPtr, System.Net.Sockets.SocketAsyncContext)
         at System.Diagnostics.AsyncStreamReader+<ReadBufferAsync>d__16.MoveNext()   at System.Net.Sockets.SocketAsyncContext.Register()

         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]](System.__Canon ByRef)
         at System.Net.Sockets.SocketAsyncContext+OperationQueue`1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].StartAsyncOperation(System.Net.Sockets.SocketAsyncContext, System.__Canon, Int32, System.Threading.CancellationToken)
         at System.Net.Sockets.SocketAsyncContext.ReceiveFromAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Byte[], Int32 ByRef, Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, System.Action`5<Int32,Byte[],Int32,System.Net.Sockets.SocketFlags,System.Net.Sockets.SocketError>, System.Threading.CancellationToken)   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]](System.__Canon ByRef)

         at System.Diagnostics.AsyncStreamReader.ReadBufferAsync()
         at System.Net.Sockets.SocketAsyncContext.ReceiveAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Int32 ByRef, System.Net.Sockets.SocketFlags ByRef, System.Action`5<Int32,Byte[],Int32,System.Net.Sockets.SocketFlags,System.Net.Sockets.SocketError>, System.Threading.CancellationToken)   at System.Threading.Tasks.Task`1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].InnerInvoke()

         at System.Threading.Tasks.Task+<>c.<.cctor>b__277_0(System.Object)
         at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
         at System.Net.Sockets.SocketAsyncEventArgs.DoOperationReceive(System.Net.Sockets.SafeSocketHandle, System.Threading.CancellationToken)   at System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread)

         at System.Threading.Tasks.Task.ExecuteEntryUnsafe(System.Threading.Thread)
         at System.Threading.Tasks.Task.ExecuteFromThreadPool(System.Threading.Thread)
         at System.Threading.ThreadPoolWorkQueue.Dispatch()
         at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()   at System.Net.Sockets.Socket.ReceiveAsync(System.Net.Sockets.SocketAsyncEventArgs, System.Threading.CancellationToken)

         at System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.ReceiveAsync(System.Net.Sockets.Socket, System.Threading.CancellationToken)
         at System.Net.Sockets.Socket.ReceiveAsync(System.Memory`1<Byte>, System.Net.Sockets.SocketFlags, Boolean, System.Threading.CancellationToken)
         at System.Net.Sockets.NetworkStream.ReadAsync(System.Memory`1<Byte>, System.Threading.CancellationToken)
         at System.Diagnostics.AsyncStreamReader+<ReadBufferAsync>d__16.MoveNext()
         at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]](System.__Canon ByRef)
         at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]](System.__Canon ByRef)
         at System.Diagnostics.AsyncStreamReader.ReadBufferAsync()
         at System.Threading.Tasks.Task`1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].InnerInvoke()
         at System.Threading.Tasks.Task+<>c.<.cctor>b__277_0(System.Object)
         at System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
         at System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread)
         at System.Threading.Tasks.Task.ExecuteEntryUnsafe(System.Threading.Thread)
         at System.Threading.Tasks.Task.ExecuteFromThreadPool(System.Threading.Thread)
         at System.Threading.ThreadPoolWorkQueue.Dispatch()
         at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

This is affecting tests that use sockets like the Binder event tests and the eventpipe tests.

josalem on 23 Jun 2020

CC @mangod9 for R2R test failures.

josalem on 23 Jun 2020

@trylek have you noticed any AVs within your recent cg2 CI runs like the one noted above? It appears its probably unrelated to cg2, but some corruption similar to the socket AV.

mangod9 on 23 Jun 2020

@josalem

If need be, we can temporarily disable this test, but I think it might an actual regression and not just flakiness

jaredpar on 23 Jun 2020

👍2

Sounds good; PR incoming.

josalem on 23 Jun 2020

@mangod9 - I didn't hit it in the Crossgen2 runs but I have seen the PayloadGroup0 timeouts pretty regularly in my recent PR runs.

trylek on 23 Jun 2020

Tagging subscribers to this area: @ViktorHofer
Notify danmosemsft if you want to be subscribed.

msftbot[bot] on 24 Jun 2020

Just hit this, it seems by the logs that it hung:

https://helix.dot.net/api/2019-06-17/jobs/e2e281bd-94b4-4901-9707-a635ef046d10/workitems/PayloadGroup0/console

safern on 3 Jul 2020

@safern, can you link to the AzDO run that created that console log? That looks new/different considering it is on Windows.

josalem on 6 Jul 2020

Sure, this is the one:

https://dev.azure.com/dnceng/public/_build/results?buildId=715290&view=results

Note, this happened on the second attempt.

safern on 6 Jul 2020

Unfortunately, it looks like there aren't logs from the tests themselves so I can't triage it without more info. It looks like there are a couple of the Binder tests in there that display similar symptoms, i.e., console output prematurely ending after starting the test wrapper (CC @jashook).

Also, @jaredpar, I'm curious: not all of the console.logs in the original comment seem to be timeouts. Is there a specific test failure or symptom this issue is tracking? I spot checked the linked failures again, and several of them still appear to be AVs in managed code or failures in the a variety of tests (I saw binding, baseservices, gc, etc.). Should we split this out into issues that track specific tests so we aren't lumping everything into a PayloadGroup0 or general "timeout" bucket? I'm worried we'll end up sweeping other test failures into this issue and merging changes that caused _new_ failures.

josalem on 7 Jul 2020

@josalem

Yes we should have issues tracking the different failures here. The reason for creating this uber issue initially is because they were all bucketing into it and there was no discernable smaller failures. If the followup investigation finds them we should be filing bugs to track them.

jaredpar on 7 Jul 2020

👍1

Curious, did we already file follow-up issues?

ViktorHofer on 15 Jul 2020

I haven't checked up on the status of the non timeout tests in the list, e.g., Binder, base services, the BCL AVs, etc. I've been investigating the workitem timeout as time permits, but haven't discovered anything.

38167 seems to show the same behavior. I'm not sure what is going on yet, but I'm not 100% convinced that this is a test failure. A test timeout in this payload _should_ cause the test wrapper to fail the test and print errors immediately to the log via the xunit runner as they timeout. The per test timeout inside the test wrapper is 10 minutes on a regular run. Without any additional information this log seems to show that the Helix workitem _itself_ timed out while running tests and it isn't necessarily the underlying test timing out.

It's possible that there is an underlying test timeout that is happening when the workitem times out, e.g., if the workitem timeout is 30 minutes and tests 1-50 took 25 minutes collectively, then if test 51 is _going_ to timeout and is hung for >5 minutes, the workitem would timeout _before_ the test. I tried the other day to query the Helix data to get some insight for this specific payload and I wasn't able to get anything meaningful. I'll see about querying some more after the p8 snap. One thing that might help with this and any future time related issues is to always have a timestamp logged in the output for everything including the xunit runner.

I'm approaching this from the perspective that a test _is_ timing out since that would be easier to diagnose, but it can be hard to prove that when trying to repro locally due to resource differences with CI and a lack of evidence that the test is _actually_ timing out.

josalem on 15 Jul 2020

Closing as there are no recent occurrences of this timing out. There are recent occurrences of it failing but it is normal failures, not timeouts.

https://runfo.azurewebsites.net/search/tests/?bq=definition%3Aruntime+started%3A%7E7+kind%3A%21pr&tq=PayloadGroup0+

jaredpar on 30 Sep 2020

Was this page helpful?

0 / 5 - 0 ratings