GC.API.NoGCRegion.NoGC.NoGC failing on Ubuntu x64 in CI

[jkotas]

19:25:41                BEGIN EXECUTION
19:25:41                /mnt/j/workspace/dotnet_coreclr/master/checked_ubuntu_tst_prtest/bin/tests/Windows_NT.x64.Checked/Tests/coreoverlay/corerun NoGC.exe
19:25:41                Server on 64-bit with 4 procs
19:25:41                =====allocating 200mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 200 MB
19:25:41                200 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 6, after GC: 6
19:25:41                ended no gc region
19:25:41                current GC count: 13
19:25:41                
19:25:41                =====allocating 200mb allowing full blocking GC first Succeeded=====
19:25:41                =====allocating 400mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 400 MB
19:25:41                400 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 21, after GC: 21
19:25:41                ended no gc region
19:25:41                current GC count: 28
19:25:41                
19:25:41                =====allocating 400mb allowing full blocking GC first Succeeded=====
19:25:41                =====allocating 400mb disallowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 400 MB
19:25:41                400 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 36, after GC: 36
19:25:41                ended no gc region
19:25:41                current GC count: 42
19:25:41                
19:25:41                =====allocating 400mb disallowing full blocking GC first Succeeded=====
19:25:41                =====allocating 4096mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 0 MB
19:25:41                4,096 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 51, after GC: 51
19:25:41                ended no gc region
19:25:41                current GC count: 57
19:25:41                
19:25:41                =====allocating 4096mb allowing full blocking GC first Succeeded=====
19:25:41                =====allocating 4096mb disallowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 0 MB
19:25:41                4,096 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 65, after GC: 65
19:25:41                ended no gc region
19:25:41                current GC count: 71
19:25:41                
19:25:41                =====allocating 4096mb disallowing full blocking GC first Succeeded=====
19:25:41                =====allocating 200mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 200 MB
19:25:41                200 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 79, after GC: 79
19:25:41                ended no gc region
19:25:41                current GC count: 87
19:25:41                
19:25:41                =====allocating 200mb allowing full blocking GC first Succeeded=====
19:25:41                =====allocating 400mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 400 MB
19:25:41                400 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 95, after GC: 95
19:25:41                ended no gc region
19:25:41                current GC count: 103
19:25:41                
19:25:41                =====allocating 400mb allowing full blocking GC first Succeeded=====
19:25:41                =====allocating 400mb disallowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 400 MB
19:25:41                400 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 111, after GC: 111
19:25:41                ended no gc region
19:25:41                current GC count: 119
19:25:41                
19:25:41                =====allocating 400mb disallowing full blocking GC first Succeeded=====
19:25:41                =====allocating 4096mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 0 MB
19:25:41                4,096 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 126, after GC: 140
19:25:41                We did GCs in no gc mode!!!
19:25:41                ended no gc region
19:25:41                End NoGC region: 4,096 MB InvalidOperationException Allocated memory exceeds specified memory for NoGCRegion mode
19:25:41                current GC count: 147
19:25:41                
19:25:41                =====allocating 4096mb allowing full blocking GC first Failed=====
19:25:41                =====allocating 4096mb disallowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 0 MB
19:25:41                4,096 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 156, after GC: 169
19:25:41                We did GCs in no gc mode!!!
19:25:41                ended no gc region
19:25:41                End NoGC region: 4,096 MB InvalidOperationException Allocated memory exceeds specified memory for NoGCRegion mode
19:25:41                current GC count: 176
19:25:41                
19:25:41                =====allocating 4096mb disallowing full blocking GC first Failed=====
19:25:41                =====allocating 4096mb allowing full blocking GC first=====
19:25:41                
19:25:41                Calling TryStartNoGCRegion(..) with totalSize = 0 MB
19:25:41                4,096 MB SUCCEEDED, did 1 gen2 GCs
19:25:41                before GC: 184, after GC: 184
19:25:41                ended no gc region
19:25:41                current GC count: 190
19:25:41                
19:25:41                =====allocating 4096mb allowing full blocking GC first Succeeded=====
19:25:41                Expected: 100
19:25:41                Actual: 1
19:25:41                END EXECUTION - FAILED

[jkotas]

Failed in dotnet/coreclr#13728, dotnet/coreclr#13576, dotnet/coreclr#13668

[swgillespie]

I suspect there is a test issue here: https://github.com/dotnet/coreclr/blob/master/tests/src/GC/API/NoGCRegion/NoGC.cs#L60. 4096 * 1024 * 1024 is large enough to overflow a 32-bit integer, and the overflow occurs before the type promotion to long (by the assignment). The documentation is unclear about what TryStartNoGCRegion is supposed do when given 0 as an alloc budget. On Windows, we throw an ArgumentOutOfRangeException indicating that the budget is too large (which is certainly an incorrect message), and as the test failure indicates Ubuntu will continue with a budget of 0 and immediately boot the user out of the No GC region on first alloc, which fails the test.

I will take a look in more detail today what is supposed to occur when the budget is 0 and why there are platform differences here.

[swgillespie]

cc @Maoni0 @shimingsg , who may be interested

[danmoseley]

twice for me
https://ci.dot.net/job/dotnet_coreclr/job/master/job/checked_ubuntu_tst_prtest/9046/consoleFull#2096352037c7af6a29-b465-404a-b249-90a3911e4354

[swgillespie]

Okay, so this code in gc.cpp is potentially a problem:

    total_size = (size_t)((float)total_size * 1.05);
    if (loh_size_known)
    {
        loh_size = (size_t)((float)loh_size * 1.05);
        allocation_no_gc_loh = (size_t)loh_size;
        allocation_no_gc_soh = (size_t)(total_size - loh_size);
    }
    else
    {
        allocation_no_gc_soh = (size_t)total_size;
        allocation_no_gc_loh = (size_t)total_size;
    }

If total_size > loh_size (which it is in the case of the test failure - total_size (the SOH allocation budget) is 0 and loh_size (the LOH allocation budget) is extremely large (due to passing a large negative value to GC.TryStartNoGCRegion , again due to overflow), we'll underflow and allocation_no_gc_soh will be extremely large, which triggers the weird "too large" failure on Windows.

There's definitely at least one argument validation bug in here somewhere, but I'm going to have to take some time to sort out exactly what is going on (especially with the overflows in the C# test code). I'll try and get either a PR disabling this test (if I can't figure it out fast enough) or a fix in place early this afternoon.

[swgillespie]

cc @sergiy-k

[Maoni0]

total_size should never be 0 when it gets to GC so we should have failed before that.

for the time being, if you change this line in test from

long size = sizeMB * 1024 * 1024;

to

long size = (long)sizeMB * (long)1024 * (long)1024;

would that fix the issue? (you probably don't need the (long) cast on the last 2 but no harm in putting it there.

[swgillespie]

@Maoni0 Yep, it would, we'd avoid the overflow that's putting us on to this codepath. We should probably extend this test to (deliberately) include the paths we are hitting now too, though.

[Maoni0]

for sure. for now let's unblock the CI first. I've submitted a PR.

[swgillespie]

This has been fixed.