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

2023-03-28 12:02:49

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

背景

有位朋友找我,希望我能幫看一下他的一個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  ([email protected]..

再找「包含」這個位置的物件:

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一對一的不正常關係。