Test failure System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector #66571

VincentBu · 2022-03-14T02:08:50Z

Run: runtime-coreclr libraries-jitstressregs 20220313.1

Failed test:

net7.0-windows-Release-arm64-CoreCLR_checked-jitstressregs1-Windows.10.Arm64v8.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

net7.0-windows-Release-x64-CoreCLR_checked-jitstressregs0x10-Windows.10.Amd64.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

net7.0-windows-Release-x64-CoreCLR_checked-jitstressregs0x1000-Windows.10.Amd64.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC
Expected: True
Actual:   False


Stack trace

Runfo Tracking Issue: system.runtime.interopservices.handlecollectortests.testhandlecollector

Build	Definition	Kind	Run Name	Console	Run Client
1728243	runtime	PR 68251	net7.0-windows-Debug-x64-CoreCLR_release-Windows.10.Amd64.Server2022.ES.Open	console.log	runclient.py
1727199	runtime	PR 68236	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1726405	runtime	PR 68219	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1726335	runtime	PR 68221	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1724082	runtime	PR 68077	net7.0-windows-Debug-x64-CoreCLR_release-Windows.81.Amd64.Open	console.log	runclient.py
1723556	runtime	PR 67903	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1723058	runtime	PR 68141	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1722815	runtime	PR 68130	net7.0-windows-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py
1722478	runtime	Rolling	net7.0-windows-Release-x64-CoreCLR_checked-Windows.10.Amd64.Open	console.log	runclient.py

Build Result Summary

Day Hit Count	Week Hit Count	Month Hit Count
2	9	9

The text was updated successfully, but these errors were encountered:

ghost · 2022-03-14T02:08:53Z

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

Issue Details

Run: runtime-coreclr libraries-jitstressregs 20220313.1

Failed test:

net7.0-windows-Release-arm64-CoreCLR_checked-jitstressregs1-Windows.10.Arm64v8.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

net7.0-windows-Release-x64-CoreCLR_checked-jitstressregs0x10-Windows.10.Amd64.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

net7.0-windows-Release-x64-CoreCLR_checked-jitstressregs0x1000-Windows.10.Amd64.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC
Expected: True
Actual:   False


Stack trace

Author:	VincentBu
Assignees:	-
Labels:	`arch-arm64`, `area-System.Runtime.InteropServices`, `os-windows`, `arch-x64`
Milestone:	-

jkoritzinsky · 2022-03-15T17:54:12Z

This might not be only JitStress (I'm seeing intermittent repros in some PR failures in the runtime pipeline), but JitStress might be the best way to repro it

VincentBu · 2022-03-23T01:18:58Z

Failed again in: runtime-coreclr libraries-jitstress 20220322.1

Failed test:

net7.0-windows-Release-x64-CoreCLR_checked-jitstress1_tiered-Windows.10.Amd64.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC
Expected: True
Actual:   False


Stack trace
   at System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector() in /_/src/libraries/System.Runtime.InteropServices/tests/System.Runtime.InteropServices.UnitTests/System/Runtime/InteropServices/HandleCollectorTests.cs:line 144

adamsitnik · 2022-03-28T09:07:18Z

Hit again in https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-heads-main-d38cf73ba255498fa4/System.Runtime.InteropServices.Tests/1/console.1e36f4c8.log?sv=2019-07-07&se=2022-04-14T09%3A06%3A23Z&sr=c&sp=rl&sig=uDZFbVyRZK5cDOI9bm1CaZmEqIOWIiXmDLL1ex3Ac9M%3D

lewing · 2022-03-29T17:30:07Z

hit again in #67289 https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-67289-merge-a849d3ef657e41ec85/System.Runtime.InteropServices.Tests/1/console.ca03e5cf.log?sv=2019-07-07&se=2022-04-18T13%3A35%3A45Z&sr=c&sp=rl&sig=YwnVzH2lC%2Bc4k6tulsxVOwo8M%2FewKh53GBQgbOvLWfc%3D

VincentBu · 2022-04-06T01:55:53Z

Failed again in: runtime-coreclr libraries-jitstress 20220405.1

Failed test:

net7.0-windows-Release-arm64-CoreCLR_checked-jitstress2-Windows.10.Arm64v8.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC
Expected: True
Actual:   False


Stack trace

kouvel · 2022-04-07T03:44:18Z

Hit again in https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-67160-merge-fce57385286b4acdbd/System.Runtime.InteropServices.Tests/1/console.51df3830.log?sv=2019-07-07&se=2022-04-27T01%3A23%3A31Z&sr=c&sp=rl&sig=HGoNjqy5wdwOJiN%2B4k9dooAvVHHVn7myC2nYC5cshT4%3D

VincentBu · 2022-04-14T03:17:07Z

Failed again in: runtime-coreclr libraries-jitstress 20220413.1

Failed test:

net7.0-windows-Release-arm64-CoreCLR_checked-zapdisable-Windows.10.Arm64v8.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC
Expected: True
Actual:   False


Stack trace
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.RuntimeMethodInfo.InvokeNonEmitUnsafe(Object obj, IntPtr* arguments, Span`1 argsForTemporaryMonoSupport, BindingFlags invokeAttr)

ViktorHofer · 2022-04-20T06:36:36Z

Happened again in https://dev.azure.com/dnceng/public/_build/results?buildId=1726335&view=ms.vss-test-web.build-test-results-tab&runId=46812918&resultId=146155&paneView=debug. I converted this issue to a live tracking one.

@AaronRobinsonMSFT @jkoritzinsky @jeffschwMSFT can you please take a look and disable the test if necessary? It hits 3 times per day...

AaronRobinsonMSFT · 2022-04-20T15:26:00Z

@ViktorHofer Someone will look into this today.

elinor-fung · 2022-04-26T04:58:30Z

@AaronRobinsonMSFT it looks like this is still happening

System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector [FAIL]
      High limit handle did not trigger a GC: 21 < 21
      Expected: True
      Actual:   False
      Stack Trace:

Console log

13 hits in the past five days after #68285 went in: https://runfo.azurewebsites.net/search/tests/?q=started%3A%7E5+definition%3Aruntime+name%3ATestHandleCollector

AaronRobinsonMSFT · 2022-04-26T15:25:09Z

@elinor-fung Thanks for keeping an eye on this. The new logging is very interesting. Based on the above log output there is something odd going on here. The HighLimitSize is hardcoded to 100000 so I would expect there to always be at least 1 additional collected object, but clearly that is not occurring under some scenario. I can think of three possible scenarios, others are welcome.

The "High limit" loop wasn't run. The JIT elided it entirely or some other optimization caused it to not execute any iterations.

runtime/src/libraries/System.Runtime.InteropServices/tests/System.Runtime.InteropServices.UnitTests/System/Runtime/InteropServices/HandleCollectorTests.cs

Lines 141 to 145 in 2ea67f1

    
           HandleCollector highLimitCollector = new HandleCollector("HighLimit.Collector", HighLimitSize); 
        
           for (int i = 0; i < HighLimitSize + 10; ++i) 
        
           { 
        
               HandleLimitTester hlt = new HandleLimitTester(highLimitCollector); 
        
           }

The GC didn't allocate new memory for each iteration for some reason and reused existing object instances. This could mean the "collected" count didn't change - I don't know if that is possible.
Some combination of (1) and (2) around a JIT optimization and the GC doing what it is told that changes how this is expected to run.

The ctor for HandleLimitTester is doing all the right things in my mind:

runtime/src/libraries/System.Runtime.InteropServices/tests/System.Runtime.InteropServices.UnitTests/System/Runtime/InteropServices/HandleCollectorTests.cs

Lines 160 to 165 in 2ea67f1

    
           internal HandleLimitTester(HandleCollector collector) 
        
           { 
        
               _collector = collector; 
        
               _collector.Add(); 
        
               GC.KeepAlive(this); 
        
           }

I'm not really sure what is occurring, and I've been unable to reproduce this locally under any DOTNET_ variable combination. Perhaps @jkotas or @Maoni0 could help educate me on what could be happening here.

jkotas · 2022-04-26T17:44:06Z

This test can be running together with all other System.Runtime.InteropServices tests. Those other tests can be allocating and triggering GCs (ie altering the global state that this test asserts are based on). Is the logic of the test robust against that?

AaronRobinsonMSFT · 2022-04-26T18:11:24Z

Yes, I believe so. All we are attempting to validate is that the sum of GC.CollectionCount(0) + GC.CollectionCount(1) + GC.CollectionCount(2) after the above loop is greater than the same computed sum before the loop. The test is arguably not that useful in a situation where multiple tests are running so it is odd that it fails at all since we simply need 1 additional object to be collected for the test to pass.

Let me confirm again the logic in HandleCollector.Add() and confirm that GC.Collect() will be called more than once.

VincentBu · 2022-04-28T01:15:34Z

Failed again in: runtime-coreclr libraries-jitstress 20220427.1

Failed test:

net7.0-windows-Release-arm64-CoreCLR_checked-jitminopts-Windows.10.Arm64v8.Open

- System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector

Error message:

High limit handle did not trigger a GC: 41 < 41
Expected: True
Actual:   False


Stack trace
   at System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector() in /_/src/libraries/System.Runtime.InteropServices/tests/System.Runtime.InteropServices.UnitTests/System/Runtime/InteropServices/HandleCollectorTests.cs:line 153
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.RuntimeMethodInfo.InvokeNonEmitUnsafe(Object obj, IntPtr* arguments, Span`1 argsForTemporaryMonoSupport, BindingFlags invokeAttr) in /_/src/coreclr/System.Private.CoreLib/src/System/Reflection/RuntimeMethodInfo.CoreCLR.cs:line 383

AaronRobinsonMSFT · 2022-04-28T11:40:59Z

I finally see what is going on here. This is a classic lack of memory pressure and the GC is making the right call and saying: "leave me alone". I am working on a fix to provide the needed pressure.

VincentBu added arch-arm64 area-System.Runtime.InteropServices os-windows arch-x64 labels Mar 14, 2022

dotnet-issue-labeler bot added the untriaged New issue has not been triaged by the area owner label Mar 14, 2022

jkoritzinsky added the JitStress CLR JIT issues involving JIT internal stress modes label Mar 14, 2022

kunalspathak mentioned this issue Mar 14, 2022

Structs: Do not mark "Hidden buffer pointer" as address-exposed #64130

Merged

jkoritzinsky mentioned this issue Mar 15, 2022

Add the CustomTypeMarshallerAttribute type to make it easier to identify marshaller types #65591

Merged

AaronRobinsonMSFT mentioned this issue Mar 17, 2022

Reenable CA 4701 #66676

Merged

jakobbotsch mentioned this issue Mar 20, 2022

Add flags checks to BMI1 intrinsic lowering #66736

Merged

jkotas mentioned this issue Mar 22, 2022

Include method instantiation MethodTables in compilation #66984

Merged

AndyAyersMS mentioned this issue Mar 25, 2022

JIT: block some struct promotion for OSR #67131

Merged

jkotas mentioned this issue Mar 25, 2022

Delete unused native code in src/native #67087

Merged

adamsitnik added the blocking-clean-ci Blocking PR or rolling runs of 'runtime' or 'runtime-extra-platforms' label Mar 28, 2022

runfoapp bot mentioned this issue Mar 28, 2022

Infrastructure - Status/Health #702

Closed

lewing mentioned this issue Mar 29, 2022

[main] Update dependencies from dotnet/xharness dotnet/runtime-assets dotnet/hotreload-utils dotnet/llvm-project #67289

Merged

kouvel mentioned this issue Apr 7, 2022

Change CrossLoaderAllocatorHash to not use the GC #67160

Merged

elinor-fung mentioned this issue Apr 12, 2022

[LibraryImportGenerator] Add/use CustomTypeMarshaller implementations for string marshalling #67635

Merged

lewing mentioned this issue Apr 16, 2022

[main] Update dependencies from dotnet/emsdk #68090

Merged

This was referenced Apr 20, 2022

Exclude all markdown files from triggering CI #68221

Merged

Update 'main' branding to release/7.0-preview5 #68236

Merged

jakobbotsch mentioned this issue Apr 20, 2022

Make BSWAP16 nodes normalize upper 16 bits #67903

Merged

AaronRobinsonMSFT mentioned this issue Apr 20, 2022

Update TestHandleCollector() test #68285

Merged

ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 20, 2022

AaronRobinsonMSFT closed this as completed in #68285 Apr 20, 2022

ghost removed the in-pr There is an active PR which will close this issue when it is merged label Apr 20, 2022

AaronRobinsonMSFT reopened this Apr 26, 2022

elinor-fung mentioned this issue Apr 26, 2022

[LibraryImportGenerator] Update diagnostic titles to use localized strings #68533

Merged

AaronRobinsonMSFT mentioned this issue Apr 28, 2022

Ensure TestHandleCollector has enough memory pressure to trigger #68652

Merged

ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 28, 2022

SingleAccretion mentioned this issue Apr 28, 2022

Handle mis-sized structs in XARCH PUTARG_STK codegen #68611

Merged

AaronRobinsonMSFT closed this as completed in #68652 Apr 29, 2022

ghost removed the in-pr There is an active PR which will close this issue when it is merged label Apr 29, 2022

jeffhandley removed the untriaged New issue has not been triaged by the area owner label May 6, 2022

ghost locked as resolved and limited conversation to collaborators Jun 5, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Test failure System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector #66571

Test failure System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector #66571

VincentBu commented Mar 14, 2022 •

edited by runfoapp bot

Loading

ghost commented Mar 14, 2022

jkoritzinsky commented Mar 15, 2022

VincentBu commented Mar 23, 2022

adamsitnik commented Mar 28, 2022

lewing commented Mar 29, 2022 •

edited

Loading

VincentBu commented Apr 6, 2022

kouvel commented Apr 7, 2022

VincentBu commented Apr 14, 2022

ViktorHofer commented Apr 20, 2022 •

edited

Loading

AaronRobinsonMSFT commented Apr 20, 2022

elinor-fung commented Apr 26, 2022

AaronRobinsonMSFT commented Apr 26, 2022

jkotas commented Apr 26, 2022

AaronRobinsonMSFT commented Apr 26, 2022

VincentBu commented Apr 28, 2022

AaronRobinsonMSFT commented Apr 28, 2022

Test failure System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector #66571

Test failure System.Runtime.InteropServices.HandleCollectorTests.TestHandleCollector #66571

Comments

VincentBu commented Mar 14, 2022 • edited by runfoapp bot Loading

ghost commented Mar 14, 2022

jkoritzinsky commented Mar 15, 2022

VincentBu commented Mar 23, 2022

adamsitnik commented Mar 28, 2022

lewing commented Mar 29, 2022 • edited Loading

VincentBu commented Apr 6, 2022

kouvel commented Apr 7, 2022

VincentBu commented Apr 14, 2022

ViktorHofer commented Apr 20, 2022 • edited Loading

AaronRobinsonMSFT commented Apr 20, 2022

elinor-fung commented Apr 26, 2022

AaronRobinsonMSFT commented Apr 26, 2022

jkotas commented Apr 26, 2022

AaronRobinsonMSFT commented Apr 26, 2022

VincentBu commented Apr 28, 2022

AaronRobinsonMSFT commented Apr 28, 2022

VincentBu commented Mar 14, 2022 •

edited by runfoapp bot

Loading

lewing commented Mar 29, 2022 •

edited

Loading

ViktorHofer commented Apr 20, 2022 •

edited

Loading