search

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

Long running test: SynchronizationContextCurrent_NotUsedForAsyncOperations #53987

Open ViktorHofer opened 3 years ago

ViktorHofer commented 3 years ago 
  Discovering: System.Xml.RW.XmlReader.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Xml.RW.XmlReader.Tests (found 21 test cases)
  Starting:    System.Xml.RW.XmlReader.Tests (parallel test collections = on, max threads = 2)
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:02:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:04:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:06:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:08:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:10:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:12:11
   System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:14:11

Log: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-53023-merge-09de05e127d14c2590/System.Xml.RW.XmlReader.Tests/console.8899153b.log?sv=2019-07-07&se=2021-06-30T07%3A54%3A32Z&sr=c&sp=rl&sig=4sF7Do1BpO1vQhTHcfHI7xG2DgPyABmjKhe4jrUrXrg%3D

Configuration: net6.0-Linux-Debug-x64-Mono_release-(Centos.8.Amd64.Open)Ubuntu.1604.Amd64.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:centos-8-helix-20201229003624-c1bf759

ghost commented 3 years ago

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

Issue Details
``` Discovering: System.Xml.RW.XmlReader.Tests (method display = ClassAndMethod, method display options = None) Discovered: System.Xml.RW.XmlReader.Tests (found 21 test cases) Starting: System.Xml.RW.XmlReader.Tests (parallel test collections = on, max threads = 2) System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:02:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:04:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:06:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:08:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:10:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:12:11 System.Xml.RW.XmlReader.Tests: [Long Running Test] 'System.Xml.Tests.AsyncReaderLateInitTests.SynchronizationContextCurrent_NotUsedForAsyncOperations', Elapsed: 00:14:11 ``` Log: https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-53023-merge-09de05e127d14c2590/System.Xml.RW.XmlReader.Tests/console.8899153b.log?sv=2019-07-07&se=2021-06-30T07%3A54%3A32Z&sr=c&sp=rl&sig=4sF7Do1BpO1vQhTHcfHI7xG2DgPyABmjKhe4jrUrXrg%3D Configuration: net6.0-Linux-Debug-x64-Mono_release-(Centos.8.Amd64.Open)Ubuntu.1604.Amd64.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:centos-8-helix-20201229003624-c1bf759
Author: ViktorHofer
Assignees: -
Labels: `area-System.Xml`
Milestone: -
akoeplinger commented 3 years ago

First failure according to AzDO is 197cfb6 and last successful one 27baae9, so something in this range: https://github.com/dotnet/runtime/compare/27baae9...197cfb6.

akoeplinger commented 3 years ago

Seems to be specific to mono, will disable the test for now.

akoeplinger commented 3 years ago

The only commit that looks related is https://github.com/dotnet/runtime/commit/a7a2fd6543ff71cecbbfe901b81ee27a6cf428c0 by @kouvel.

/cc @lambdageek

ViktorHofer commented 3 years ago

Adding the disabled-test label.

lambdageek commented 3 years ago

Hmm. The code to perform the adjustment depends on GCMemoryInfo

https://github.com/dotnet/runtime/blob/a7a2fd6543ff71cecbbfe901b81ee27a6cf428c0/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.cs#L376-L385

and it's used here:

https://github.com/dotnet/runtime/blob/a7a2fd6543ff71cecbbfe901b81ee27a6cf428c0/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.Blocking.cs#L191-L213

@kouvel how would this behave if the GCMemoryInfo data wasn't right? @naricc did we implement all of these GCMemoryInfo properties?

lambdageek commented 3 years ago

@radekdoulik I don't understand what's going on withGCMemoryInfo.MemoryLoadBytes here

https://github.com/dotnet/runtime/blob/93cf5df65fc13bfbc29256acc8c9c0e102a1170b/src/mono/mono/sgen/sgen-memory-governor.c#L148

https://github.com/dotnet/runtime/commit/93cf5df65fc13bfbc29256acc8c9c0e102a1170b

radekdoulik commented 3 years ago

@radekdoulik I don't understand what's going on withGCMemoryInfo.MemoryLoadBytes here

https://github.com/dotnet/runtime/blob/93cf5df65fc13bfbc29256acc8c9c0e102a1170b/src/mono/mono/sgen/sgen-memory-governor.c#L148

93cf5df

It calculates the load bytes as total - available size and scales it by max_heap/physical_ram_size ratio if max_heap is used.

naricc commented 3 years ago

@lambdageek Yes, we did implement all the GCMemoryInfo properties. Although there is no way to garauntee they behave 100 % the same as in CoreGC, given the different garbage collectors.

kouvel commented 3 years ago

The GC memory info is only used as a heuristic in https://github.com/dotnet/runtime/commit/a7a2fd6543ff71cecbbfe901b81ee27a6cf428c0, when low memory is detected it would fall back to the same behavior as before the change