一次對pool的誤用導致的.net頻繁gc的診斷分析

dotnet程式故障診斷發表於2023-03-28
GC

(最近有讀者朋友表示，希望能加一些示意圖來描述分析過程中用到的原理知識。好的，之後我會注意，謝謝這位讀者)

背景

有位朋友找我，希望我能幫看一下他的一個service。從他的描述看，並沒有資源方面的洩漏，程式目前也能正常工作。他是在用dotnet-counters moniter時發現gc2、也就是full gc觸發的比較頻繁，頻率超過了他自己的預期，於是他心裡不踏實，所以想找我看一下。

能在沒發生資源或效能異常前自覺monitor .net metrics的人，我跟佩服，這是講究人兒啊。那後面我就管這位朋友叫"精緻大哥"了哈

分析

其實對於這次沒有明確記憶體洩漏跡象的問題，我沒啥把握能給出明確問題點，甚至可能就是沒問題。但，試試吧，拿出windbg準備。

既然是頻繁full gc, 而且還都把記憶體降下來了，那麼最先想到的是會不會在申請大量的大物件。

因為如果有很多小物件在申請記憶體，一般都會在gc0和gc1階段搞定，而無需總勞煩gc2；或者申請很多小物件，而且還一直引用著，這樣也能造成gc2，但那樣的話記憶體應該也會洩漏才對。

帶著這個猜想，先看一下大物件堆LOH的大小:

可以看到很多gc heap的LOH都被申請了4194384 byte大小。

然後去看看heap4裡的LOH存的都是些什麼。根據heap4的LOH segment的起始位置和allocation end 位置，用!dumpheap:

可以看出這裡面只有一個byte array, 而且大小也是約4M。

嘗試用!gcroot看一下這個大物件的引用關係:

這回gcroot無法給出想要的答案。這是因為引用它的引用鏈的head沒有了引用根，畫個示意圖:

(這樣一來，下次同代gc觸發時，這個大物件的記憶體也就真的被釋放了)

引用鏈找不到，線索斷了。別急，既然sos不能幫助我們了，可以試試耐下心手動找引用鏈。我們知道一個物件的地址的值通常會存在某個物件所佔用記憶體的"身上"，如圖所示:

那麼就可以先從當前gc heap的起始位置找一下這個大物件的地址值所在的記憶體位置。考慮到當前程式是小端模式，所以用如下命令:

1 0:000> s -b 0000021000000000 L?2000000000 38 10 95 32 1e 02
2 00000218`f29c9b38  38 10 95 32 1e 02 00 00-00 00 00 00 00 00 00 00

在記憶體位置218`f29c9b38找到了物件的地址值，接著找一下“包含”這個位置的物件：

1 Before:  00000218f29c9b28         4024 (0xfb8)  System.Byte[][]
2 After:   00000218f29caae0           72 (0x48)  System.Threading.Tasks.Task+DelayPromise

看來我們已經到了一個System.Byte[][]物件的位置了。按上面的思路繼續搜尋218f29c9b28這個值：

1 0:000> s -b 0000021000000000 L?2000000000 28 9b 9c f2 18 02
2 00000218`f29c9ae8  28 9b 9c f2 18 02 00 00-00 00 40 00 db 52 a1 03  (.........@..R..

再找“包含”這個位置的物件：

1 Before:  00000218f29c9ae0           48 (0x30)  System.Buffers.ConfigurableArrayPool`1+Bucket[[System.Byte, System.Private.CoreLib]]
2 After:   00000218f29c9b10           24 (0x18)  Free

以此類推，又經過一系列搜尋，最後找到了這個物件，它的地址值在這個程式空間中無法被找到了:

Before:  00000218f29b7af0           24 (0x18)  System.Buffers.ConfigurableArrayPool`1[[System.Byte, System.Private.CoreLib]]

於是認為已經找到了整個引用鏈的"臨時"head。說它是"臨時"的，是因為沒有gc root引用著它。

有了這些資料，我們便可以用常規的sos指令進行一下正向的驗證，從head 218f29b7af0 開始往下驗證吧：

可以看到它確實引用著218f29b7b08 _buckets，

可以看到_buckets這個Bucket<byte>[]有19個元素，第18個元素確實就是上面推導的Bucket instance，繼續看：

可以看到這個bucket instance（00000218f29c9ae0）確實hold著218f29c9b28 這個byte[][]，而這個byte[][]裡也確實包含了我們最初要找的那個大物件byte[]：

好了，現在可以畫個逆向診斷的引用復原圖:

如果大家看過ArrayPool的一些基本實現，就知道這個ConfigurableArrayPool`1其實是ArrayPool.Create(config)建立出來的，所以我們調研的那個大物件byte[]其實是ArrayPool裡維護的buffer。

又看了一下，程式中當時有18個這樣大小的大byte[]：

按上面類似的推導，隨機看了其他幾個byte[]，其引用鏈的head都是不同的ConfigurableArrayPool`1 instances，所以對了一下ConfigurableArrayPool`1的數量，用!dumpheap:

也是18個。所以說，貌似每個Pool只管理了1個byte[] ?? 這樣就有問題了，因為這樣的話相當於每個pool都不能reuse 已有的其他pool的buffers，pool沒有起到pool的作用。所以每次需要用buffer時，只能不斷申請新的大byte[]，導致大物件數量增長。

後記

把這個分析結果告訴了那位“精緻大哥”後，“精緻大哥”找到了建立pool的程式碼，簡化後是這樣的：

 1         private DigestSummary CalculateDigestSummary(NotificationEvent notificationEvent)
 2         {
 3             var bytesPool = ArrayPool<byte>.Create(4 * 1024 * 1024, 500);
 4             byte[] buf = bytesPool.Rent(4 * 1024 * 1024);
 5 ​
 6             try
 7             {
 8                 return CalculateWithBuffer(buf);
 9             }
10             finally
11             {
12                 bytesPool.Return(buf);
13             }
14         }

看第3行，每次需要byte[]時，都先建立一個pool，下次又重新用新pool。於是效果就是沒有pool啦。

總結

應該在使用buffer的scope中儘量reuse pool instance, 或者也可以用

var bytesPool = ArrayPool<byte>.Shared;

這次gc問題的診斷分析，需要脫離sos，手動找引用關係，從而獲得了“這次大物件是ArrayPool掛著”這層資訊，進而找出了ArrayPool instances與大byte[] instances一對一的不正常關係。

相關文章