Memory usage regression

[sebastienros]

I am noticing an important regression in GC heap sizes and working set measurement on ASP.NET benchmarks (most of them).

These are the charts for Json MVC.

An early range of changes points to these commits: cfe26ec...68bd58e
Smallest set of changes reproducing the regression: cfe26ec...e415018

One of these changes impacted some GC work: #72923

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[ghost]

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

Issue Details

---

I am noticing an important regression in GC heap sizes and working set measurement on ASP.NET benchmarks (most of them).

These are the charts for Json MVC.

An early range of changes points to these commits: cfe26ec...68bd58e
Smallest set of changes reproducing the regression: cfe26ec...e415018

One of these changes impacted some GC work: #72923

Author:	sebastienros
Assignees:	-
Labels:	tenet-performance, area-GC-coreclr, untriaged
Milestone:	7.0.0

[Maoni0]

does this use Server GC? If so it's not affected by #72923.

[sebastienros]

The benchmarks use Server GC. Is there a slight chance that it's still affecting it, because I can repro consistently with just this changeset, and all the other commits have nothing to do with the GC. Is there a trace I can provide that would confirm it?

[mrsharm]

Could you provide instructions on how to repro? I can try to see if I see the same error locally with and without the change.

[EgorBo]

Can confirm it's #72923 (I sent patched binary to crank where I reverted that PR)

| application                             | a                    | b                    |             |
| --------------------------------------- | -------------------- | -------------------- | ----------- |
| CPU Usage (%)                           |                   96 |                   94 |      -2.08% |
| Cores usage (%)                         |                2,693 |                2,644 |      -1.82% |
| Working Set (MB)                        |                  498 |                2,716 |    +445.38% |
| Private Memory (MB)                     |                  516 |                2,742 |    +431.40% |
| Build Time (ms)                         |                1,824 |                1,762 |      -3.40% |
| Start Time (ms)                         |                  454 |                  483 |      +6.39% |
| Published Size (KB)                     |              114,457 |              114,457 |       0.00% |
| .NET Core SDK Version                   | 7.0.100-rc.1.22402.2 | 7.0.100-rc.1.22402.2 |             |
| Max CPU Usage (%)                       |                  104 |                   95 |      -8.65% |
| Max Working Set (MB)                    |                  522 |                2,855 |    +447.35% |
| Max GC Heap Size (MB)                   |                  278 |                  282 |      +1.29% |
| Size of committed memory by the GC (MB) |                  461 |                2,793 |    +506.20% |
| Max Number of Gen 0 GCs / sec           |                12.00 |                14.00 |     +16.67% |
| Max Number of Gen 1 GCs / sec           |                 1.00 |                14.00 |  +1,300.00% |
| Max Number of Gen 2 GCs / sec           |                 0.00 |                 1.00 |         +∞% |
| Max Time in GC (%)                      |                 1.00 |                 1.00 |       0.00% |
| Max Gen 0 Size (B)                      |               23,328 |                    0 |             |
| Max Gen 1 Size (B)                      |           15,939,664 |          197,696,608 |  +1,140.28% |
| Max Gen 2 Size (B)                      |            3,488,576 |        1,362,575,648 | +38,958.22% |
| Max LOH Size (B)                        |              210,896 |              210,896 |       0.00% |
| Max POH Size (B)                        |            2,271,920 |            2,271,920 |       0.00% |
| Max Allocation Rate (B/sec)             |        3,638,533,824 |        3,793,608,368 |      +4.26% |
| Max GC Heap Fragmentation               |                    2 |                   99 |  +4,846.98% |
| # of Assemblies Loaded                  |                  113 |                  113 |       0.00% |
| Max Exceptions (#/s)                    |                  458 |                  464 |      +1.31% |
| Max Lock Contention (#/s)               |                  224 |                  203 |      -9.38% |
| Max ThreadPool Threads Count            |                   48 |                   48 |       0.00% |
| Max ThreadPool Queue Length             |                  173 |                  163 |      -5.78% |
| Max ThreadPool Items (#/s)              |              532,784 |              552,129 |      +3.63% |
| Max Active Timers                       |                    0 |                    0 |             |
| IL Jitted (B)                           |              190,050 |              190,319 |      +0.14% |
| Methods Jitted                          |                2,267 |                2,268 |      +0.04% |

[Maoni0]

I took another look at 72923 and I do see a problem with it for WKS GC. it needs to initialize the saved_allocated in the else case when shigh is 0. but still, this PR should not have any effect on SVR GC. so I'm very curious what's causing what you are seeing. I tried to repro this locally but I can't even get an mvc project to build with the latest preview7 build...

[sebastienros]

Confirming it's running with Server GC, we do output the value during the run to be certain it is doing so:

http://asp-citrine-win:5001/jobs/245/output:

Current directory: C:\Users\Administrator\AppData\Local\Temp\benchmarks-agent\benchmarks-server-7564\r3bvl4oa.3rg\benchmarks\src\Benchmarks\published
AspNetCore version: 7.0.0-rc.1.22401.10+b7b37d1e9d47919c27f1895c3428e3da6ddf86b8
.NET Runtime version: 7.0.0-rc.1.22401.4+e415018a152a4a2e0db7619ceb91a3b3326b217a
EFCore version: 6.0.0
Environment.ProcessorCount: 28
Scenario configuration found in scenarios.json and/or command line args

The following scenarios were enabled:
  MvcJson -> /mvc/json

Database: None
ConnectionString: Server=(localdb)\mssqllocaldb;Database=aspnet5-Benchmarks;Trusted_Connection=True;MultipleActiveResultSets=true
WAL: False
Using server Kestrel
Server GC is currently ENABLED
Using Sockets with 16 threads
Hosting environment: Production
Content root path: C:\Users\Administrator\AppData\Local\Temp\benchmarks-agent\benchmarks-server-7564\r3bvl4oa.3rg\benchmarks\src\Benchmarks\published
Now listening on: http://10.0.0.104:5000
Application started. Press Ctrl+C to shut down.
Application is shutting down...

And the code that displays this line:

https://github.com/aspnet/Benchmarks/blob/main/src/Benchmarks/Program.cs#L197

Console.WriteLine($"Server GC is currently {(GCSettings.IsServerGC ? "ENABLED" : "DISABLED")}");

[Maoni0]

do you know why I'm getting this?

C:\temp\mvc70>dotnet new mvc
The template "ASP.NET Core Web App (Model-View-Controller)" was created successfully.
This template contains technologies from parties other than Microsoft, see https://aka.ms/aspnetcore/7.0-third-
party-notices for details.

Processing post-creation actions...
Restoring C:\temp\mvc70\mvc70.csproj:
  Determining projects to restore...
  Restored C:\temp\mvc70\mvc70.csproj (in 83 ms).
Restore succeeded.

C:\temp\mvc70>dotnet publish -c Release --self-contained -r win-x64
MSBuild version 17.4.0-preview-22368-02+c8492483a for .NET
  Determining projects to restore...
C:\temp\mvc70\mvc70.csproj : error NU1102: Unable to find package Microsoft.NETCore.App.Runtime.win-x64 with v
ersion (= 7.0.0-preview.7.22375.6)
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 92 version(s) in nuget.org [ Nearest version: 7.0.0-previ
ew.6.22324.4 ]
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 0 version(s) in Microsoft Visual Studio Offline Packages
C:\temp\mvc70\mvc70.csproj : error NU1102: Unable to find package Microsoft.WindowsDesktop.App.Runtime.win-x64
 with version (= 7.0.0-preview.7.22377.1)
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 90 version(s) in nuget.org [ Nearest version: 7.0.0-previ
ew.6.22351.3 ]
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 0 version(s) in Microsoft Visual Studio Offline Packages
C:\temp\mvc70\mvc70.csproj : error NU1102: Unable to find package Microsoft.AspNetCore.App.Runtime.win-x64 wit
h version (= 7.0.0-preview.7.22376.6)
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 93 version(s) in nuget.org [ Nearest version: 7.0.0-previ
ew.6.22330.3 ]
C:\temp\mvc70\mvc70.csproj : error NU1102:   - Found 0 version(s) in Microsoft Visual Studio Offline Packages
  Failed to restore C:\temp\mvc70\mvc70.csproj (in 297 ms).

[sebastienros]

Maybe you have installed nightly bits (preview7) but not the full SDK (with aligned runtime/aspnet).

[Maoni0]

I see, that makes sense. next Q is where do I install the full SDK from? I installed preview7 from https://github.com/dotnet/installer.

[jkotas]

If you install nightly SDK builds, you need to manually add nightly nuget feed to your nuget config: https://github.com/dotnet/runtime/blob/main/docs/project/dogfooding.md#obtaining-daily-builds-of-nuget-packages

[mrsharm]

@Maoni0: I was able to repro the issue using (thanks @EgorBo):

crank  --profile aspnet-citrine-win  --application.options.collectCounters True  --application.framework net7.0    --config https://raw.githubusercontent.com/aspnet/Benchmarks/main/scenarios/plaintext.benchmarks.yml  --scenario mvc --application.options.outputFiles C:\runtime\artifacts\bin\coreclr\windows.x64.Release\System.Private.CoreLib.dll --application.options.outputFiles C:\runtime\artifacts\bin\coreclr\windows.x64.Release\coreclr.dll --application.options.outputFiles C:\runtime\artifacts\bin\coreclr\windows.x64.Release\clrjit.dll

and found that reverting the following on line number 28726 in plan_phase

save_allocated(seg1);

back to:

heap_segment_saved_allocated (seg1) = heap_segment_allocated (seg1);

Fixes the memory issue. This is one of the cases that isn't in WKS. Continuing to investigate why this is the case.

[Maoni0]

oh, I see the problem......... you missed an 'S' in the #ifdef

inline void save_allocated(heap_segment* seg)
{
#ifndef MULTIPLE_HEAP
    if (!heap_segment_saved_allocated(seg))
#endif // !MULTIPLE_HEAP
    {
        heap_segment_saved_allocated (seg) = heap_segment_allocated (seg);
    }
}

is supposed to be

inline void save_allocated(heap_segment* seg)
{
#ifndef MULTIPLE_HEAPS
    if (!heap_segment_saved_allocated(seg))
#endif // !MULTIPLE_HEAPS
    {
        heap_segment_saved_allocated (seg) = heap_segment_allocated (seg);
    }
}

this change is supposed to not have any effect on Server GC because saved_allocated is supposed to be

inline void save_allocated(heap_segment* seg)
{
        heap_segment_saved_allocated (seg) = heap_segment_allocated (seg);
}

for Server GC.