search

dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
16.53k stars 5.05k forks source link

Full GC notify not raised on Server GC #115110

Open hyabean opened 1 month ago

hyabean commented 1 month ago

Description

In server GC mode and concurrent GC mode, GC.WaitForFullGCApproach() does not return when the remaining memory is reduced to zero. The code is based on the example from GC.RegisterForFullGCNotification(Int32, Int32) Method (System).

Reproduction Steps

https://github.com/hyabean/GCNotifyTest

Expected behavior

print "GC Notification raised."

Actual behavior

GC.WaitForFullGCApproach() not return even when the remaining memory is 0%.

2025/4/28 19:41:24:Registered for GC notification. 2025/4/28 19:41:25:Gen 2 collection count: 1 2025/4/28 19:41:25:allocCount: 1000000 2025/4/28 19:41:25:allocCount: 2000000 2025/4/28 19:41:25:allocCount: 3000000 2025/4/28 19:41:25:allocCount: 4000000 2025/4/28 19:41:26:allocCount: 5000000 2025/4/28 19:41:26:allocCount: 6000000 2025/4/28 19:41:26:allocCount: 7000000 2025/4/28 19:41:26:Gen 2 collection count: 2 2025/4/28 19:41:27:allocCount: 8000000 2025/4/28 19:41:27:allocCount: 9000000 2025/4/28 19:41:27:allocCount: 10000000 2025/4/28 19:41:27:allocCount: 11000000 2025/4/28 19:41:28:allocCount: 12000000 2025/4/28 19:41:28:allocCount: 13000000 2025/4/28 19:41:28:Gen 2 collection count: 3 2025/4/28 19:41:28:allocCount: 14000000 2025/4/28 19:41:29:allocCount: 15000000 2025/4/28 19:41:29:allocCount: 16000000 2025/4/28 19:41:29:allocCount: 17000000 2025/4/28 19:41:30:allocCount: 18000000 2025/4/28 19:41:30:Gen 2 collection count: 4 2025/4/28 19:41:32:allocCount: 19000000 2025/4/28 19:41:34:allocCount: 20000000 2025/4/28 19:41:35:allocCount: 21000000 2025/4/28 19:41:35:Gen 2 collection count: 5 2025/4/28 19:41:36:allocCount: 22000000 2025/4/28 19:41:39:allocCount: 23000000 2025/4/28 19:41:43:Gen 2 collection count: 6 2025/4/28 19:41:48:allocCount: 24000000 2025/4/28 19:41:50:allocCount: 25000000 2025/4/28 19:41:52:allocCount: 26000000 2025/4/28 19:41:52:allocCount: 27000000 2025/4/28 19:41:53:Gen 2 collection count: 7 2025/4/28 19:42:34:allocCount: 28000000 2025/4/28 19:42:35:allocCount: 29000000 2025/4/28 19:42:36:Gen 2 collection count: 8 2025/4/28 19:43:16:allocCount: 30000000 2025/4/28 19:43:17:allocCount: 31000000 2025/4/28 19:43:18:allocCount: 32000000 2025/4/28 19:43:19:allocCount: 33000000 2025/4/28 19:43:20:Gen 2 collection count: 9 2025/4/28 19:43:20:allocCount: 34000000 2025/4/28 19:44:21:allocCount: 35000000 2025/4/28 19:44:22:allocCount: 36000000 2025/4/28 19:44:22:Gen 2 collection count: 10

PerfViewData_gcnotify3.etl.zip PerfViewData_gcnotify3.log.txt

Regression?

No response

Known Workarounds

No response

Configuration

.NET 8.0.15 Windows 10 专业版 22H2 x64

Other information

Sometimes, the notification is triggered at the beginning of program execution, but it stops being after a few tens of seconds. The memory remains full, and both garbage collection (GC) and allocations are very slow.

log triggered at begin.txt

2025/4/28 19:57:45:Registered for GC notification. 2025/4/28 19:57:45:Gen 2 collection count: 1 2025/4/28 19:57:45:allocCount: 1000000 2025/4/28 19:57:45:allocCount: 2000000 2025/4/28 19:57:46:allocCount: 3000000 2025/4/28 19:57:46:allocCount: 4000000 2025/4/28 19:57:46:allocCount: 5000000 2025/4/28 19:57:46:allocCount: 6000000 2025/4/28 19:57:47:allocCount: 7000000 2025/4/28 19:57:47:GC Notification raised. 2025/4/28 19:57:47:Gen 2 collection count: 2 2025/4/28 19:57:47:Redirecting requests. 2025/4/28 19:57:47: bAllocate : False ... 2025/4/28 19:57:47: bAllocate : False 2025/4/28 19:57:47:Induced a collection. 2025/4/28 19:57:47: bAllocate : False 2025/4/28 19:57:47: bAllocate : False 2025/4/28 19:57:47:GC Notification not applicable 2. 2025/4/28 19:57:47: bAllocate : False 2025/4/28 19:57:47:Accepting requests again. 2025/4/28 19:57:47:Gen 2 collection count: 3 2025/4/28 19:57:47:allocCount: 8000000 2025/4/28 19:57:47:allocCount: 9000000 2025/4/28 19:57:47:allocCount: 10000000 2025/4/28 19:57:47:allocCount: 11000000 2025/4/28 19:57:47:allocCount: 12000000 2025/4/28 19:57:47:allocCount: 13000000 2025/4/28 19:57:47:allocCount: 14000000 2025/4/28 19:57:48:GC Notification raised. 2025/4/28 19:57:48:Redirecting requests. 2025/4/28 19:57:48: bAllocate : False ... 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:Induced a collection. 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:GC Notification raised. 2025/4/28 19:57:48:Accepting requests again. 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:Gen 2 collection count: 4 2025/4/28 19:57:48:allocCount: 15000000 2025/4/28 19:57:48:allocCount: 16000000 2025/4/28 19:57:48:allocCount: 17000000 2025/4/28 19:57:48:allocCount: 18000000 2025/4/28 19:57:48:allocCount: 19000000 2025/4/28 19:57:48:GC Notification raised. 2025/4/28 19:57:48:Redirecting requests. 2025/4/28 19:57:48: bAllocate : False ... 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:Induced a collection. 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:GC Notification raised. 2025/4/28 19:57:48:Accepting requests again. 2025/4/28 19:57:48: bAllocate : False 2025/4/28 19:57:48:Gen 2 collection count: 5 2025/4/28 19:57:48:allocCount: 20000000 2025/4/28 19:57:48:allocCount: 21000000 2025/4/28 19:57:48:allocCount: 22000000 2025/4/28 19:57:48:allocCount: 23000000 2025/4/28 19:57:48:allocCount: 24000000 2025/4/28 19:57:48:allocCount: 25000000 2025/4/28 19:57:49:GC Notification raised. 2025/4/28 19:57:49:Redirecting requests. 2025/4/28 19:57:49: bAllocate : False ... 2025/4/28 19:57:49: bAllocate : False 2025/4/28 19:57:49:Induced a collection. 2025/4/28 19:57:49: bAllocate : False ... 2025/4/28 19:57:49: bAllocate : False 2025/4/28 19:57:49:GC Notification raised. 2025/4/28 19:57:49: bAllocate : False 2025/4/28 19:57:49:Accepting requests again. 2025/4/28 19:57:49:Gen 2 collection count: 6 2025/4/28 19:57:49:allocCount: 26000000 2025/4/28 19:57:49:allocCount: 27000000 2025/4/28 19:57:49:allocCount: 28000000 2025/4/28 19:57:49:allocCount: 29000000 2025/4/28 19:57:49:allocCount: 30000000 2025/4/28 19:57:49:allocCount: 31000000 2025/4/28 19:57:49:Gen 2 collection count: 7 2025/4/28 19:57:49:allocCount: 32000000 2025/4/28 19:57:49:allocCount: 33000000 2025/4/28 19:57:50:allocCount: 34000000 2025/4/28 19:57:50:allocCount: 35000000 2025/4/28 19:57:50:allocCount: 36000000 2025/4/28 19:57:50:allocCount: 37000000 2025/4/28 19:57:51:allocCount: 38000000 2025/4/28 19:57:51:allocCount: 39000000 2025/4/28 19:57:52:allocCount: 40000000 2025/4/28 19:57:52:allocCount: 41000000 2025/4/28 19:57:52:allocCount: 42000000 2025/4/28 19:57:53:Gen 2 collection count: 8 2025/4/28 19:57:54:allocCount: 43000000 2025/4/28 19:57:54:Gen 2 collection count: 9 2025/4/28 19:57:56:allocCount: 44000000 2025/4/28 19:57:56:allocCount: 45000000 2025/4/28 19:57:57:Gen 2 collection count: 10 2025/4/28 19:57:57:allocCount: 46000000 2025/4/28 19:57:58:allocCount: 47000000 2025/4/28 19:58:05:allocCount: 48000000 2025/4/28 19:58:07:Gen 2 collection count: 11 2025/4/28 19:58:07:allocCount: 49000000 2025/4/28 19:58:26:allocCount: 50000000 2025/4/28 19:58:27:allocCount: 51000000 2025/4/28 19:58:28:Gen 2 collection count: 12 2025/4/28 19:59:05:allocCount: 52000000 2025/4/28 19:59:05:allocCount: 53000000 2025/4/28 19:59:07:Gen 2 collection count: 13 2025/4/28 19:59:07:allocCount: 54000000 2025/4/28 19:59:46:allocCount: 55000000 2025/4/28 19:59:46:allocCount: 56000000 2025/4/28 19:59:47:Gen 2 collection count: 14 2025/4/28 20:00:42:allocCount: 57000000 2025/4/28 20:00:43:allocCount: 58000000 2025/4/28 20:00:44:Gen 2 collection count: 15 2025/4/28 20:00:44:allocCount: 59000000 2025/4/28 20:01:45:allocCount: 60000000 2025/4/28 20:01:45:allocCount: 61000000 2025/4/28 20:01:46:Gen 2 collection count: 16 2025/4/28 20:02:46:allocCount: 62000000 2025/4/28 20:02:47:allocCount: 63000000 2025/4/28 20:02:48:Gen 2 collection count: 17 2025/4/28 20:02:48:allocCount: 64000000 2025/4/28 20:04:01:allocCount: 65000000 2025/4/28 20:04:02:allocCount: 66000000 2025/4/28 20:04:03:Gen 2 collection count: 18 2025/4/28 20:04:03:allocCount: 67000000 2025/4/28 20:05:23:allocCount: 68000000 2025/4/28 20:05:24:allocCount: 69000000 2025/4/28 20:05:25:Gen 2 collection count: 19 2025/4/28 20:06:50:allocCount: 70000000 2025/4/28 20:06:51:allocCount: 71000000 2025/4/28 20:06:52:allocCount: 72000000 2025/4/28 20:06:53:allocCount: 73000000 2025/4/28 20:06:54:Gen 2 collection count: 20 2025/4/28 20:06:54:allocCount: 74000000 2025/4/28 20:08:35:allocCount: 75000000 2025/4/28 20:08:36:allocCount: 76000000 2025/4/28 20:08:37:allocCount: 77000000 2025/4/28 20:08:37:allocCount: 78000000 2025/4/28 20:08:38:Gen 2 collection count: 21 2025/4/28 20:10:21:allocCount: 79000000 2025/4/28 20:10:21:allocCount: 80000000 2025/4/28 20:10:23:allocCount: 81000000 2025/4/28 20:10:23:Gen 2 collection count: 22

dotnet-policy-service[bot] commented 1 month ago

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

hyabean commented 1 month ago

There might be an issue with the example of GC.RegisterForFullGCNotification. Because the memory is being referenced by List<byte[]> load, the GC might assume that even performing a FULL GC cannot clean up the heap. If we regularly clear half of the 'load' objects, notification triggering should work as expected.