記一次 .NET 某智慧物流 WCS系統 CPU 爆高分析

来源:https://www.cnblogs.com/huangxincheng/archive/2022/07/27/16524963.html
-Advertisement-
Play Games

一:背景 1. 講故事 哈哈,再次見到物流類軟體,上個月有位朋友找到我,說他的程式出現了 CPU 爆高,讓我幫忙看下什麼原因,由於那段時間在苦心研究 C++,分析和經驗分享也就懈怠了,今天就給大家安排上。 話不多說,上 windbg 說話。 二:WinDbg 分析 1. CPU 真的爆高嗎 既然說 ...


一:背景

1. 講故事

哈哈,再次見到物流類軟體,上個月有位朋友找到我,說他的程式出現了 CPU 爆高,讓我幫忙看下什麼原因,由於那段時間在苦心研究 C++,分析和經驗分享也就懈怠了,今天就給大家安排上。

話不多說,上 windbg 說話。

二:WinDbg 分析

1. CPU 真的爆高嗎

既然說 CPU 爆高,那就用 !tp 驗證下。


0:000> !tp
    Method table is shared (not implemented): System.Threading.ThreadPool
CPU utilization: 81 Unknown format characterUnknown format control characterWorker Thread: Total: 203 Running: 183 Idle: 0 MaxLimit: 300 MinLimit: 150
Work Request in Queue: 0
--------------------------------------
Number of Timers: 40
--------------------------------------
Completion Port Thread:Total: 21 Free: 21 MaxFree: 80 CurrentLimit: 21 MaxLimit: 300 MinLimit: 150

從卦中看確實 CPU=81%,不過輸出信息很奇怪,方法表都出錯了,猜的不錯應該是觸發 GC 把 托管堆給關閉了,源碼如下:


    GCScan::GcRuntimeStructuresValid (FALSE);
    plan_phase (n);
    GCScan::GcRuntimeStructuresValid (TRUE);

也可以用 !dumpheap -stat 來驗證。


0:000> !dumpheap -stat
The garbage collector data structures are not in a valid state for traversal.
It is either in the "plan phase," where objects are being moved around, or
we are at the initialization or shutdown of the gc heap. Commands related to 
displaying, finding or traversing objects as well as gc heap segments may not 
work properly. !dumpheap and !verifyheap may incorrectly complain of heap 
consistency errors.
Could not request method table data for object 000001E49376D520 (MethodTable: FFFFFFFFFFE026C0).

2. 為什麼會觸發 GC

此時我們已知道是 GC 觸發,接下來可以通過 !t + !clrstack 找到那個觸發 GC 的線程,通過線程棧看看正在幹嘛 ?

0:000> !t 
ThreadCount:      382
UnstartedThread:  0
BackgroundThread: 340
PendingThread:    0
DeadThread:       0
Hosted Runtime:   no
                                                                                                            Lock  
 DBG   ID     OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
   0    1     1ba4 000001E45C018C90    2a020 Preemptive  0000000000000000:0000000000000000 000001e45c368cb0 1     MTA 
 297  286     2144 000001E478521200  1029220 Cooperative 0000000000000000:0000000000000000 000001e45c368cb0 0     MTA (GC) (Threadpool Worker) 

0:297> !clrstack 
OS Thread Id: 0x2144 (297)

        Child SP               IP Call Site
        0e 0000002f`2927ade0 00007ffa`afda2096     coreclr!WKS::gc_heap::garbage_collect+0x2a1 [e:\a\_work\191\s\src\gc\gc.cpp @ 16967] 
0f 0000002f`2927aee0 00007ffa`afdbe746     coreclr!WKS::GCHeap::GarbageCollectGeneration+0x156 [e:\a\_work\191\s\src\gc\gc.cpp @ 35107] 
10 (Inline Function) --------`--------     coreclr!WKS::gc_heap::try_allocate_more_space+0x1f5 [e:\a\_work\191\s\src\gc\gc.cpp @ 13197] 
11 0000002f`2927af30 00007ffa`afd80c9f     coreclr!WKS::gc_heap::allocate_more_space+0x216 [e:\a\_work\191\s\src\gc\gc.cpp @ 13490] 
12 (Inline Function) --------`--------     coreclr!WKS::gc_heap::allocate+0x37e [e:\a\_work\191\s\src\gc\gc.cpp @ 13521] 
13 (Inline Function) --------`--------     coreclr!WKS::GCHeap::Alloc+0x3e5 [e:\a\_work\191\s\src\gc\gc.cpp @ 34419] 
14 (Inline Function) --------`--------     coreclr!Alloc+0x4be [e:\a\_work\191\s\src\vm\gchelpers.cpp @ 241] 
15 (Inline Function) --------`--------     coreclr!AllocateObject+0x512 [e:\a\_work\191\s\src\vm\gchelpers.cpp @ 1156] 
16 0000002f`2927af90 00007ffa`51c05122     coreclr!JIT_New+0x5ff [e:\a\_work\191\s\src\vm\jithelpers.cpp @ 2810] 
...
0000002F2927B228 00007ffaafd63aff [HelperMethodFrame: 0000002f2927b228] 
0000002F2927B340 00007ffa51c05122 Jint.Native.Object.ObjectInstance..ctor(Jint.Engine)
0000002F2927B380 00007ffa51c058aa Jint.Native.Array.ArrayConstructor.CreateArrayConstructor(Jint.Engine)
0000002F2927B3D0 00007ffa51c0407c Jint.Engine..ctor(System.Action`1<Jint.Options>)
...

由於信息比較敏感,我就不過多的輸出了,不過可以看出 GC 的引發是由於 Jint 組件,查了下資料是 JavaScript.NET 用來交互的,為了進一步驗證,觀察下此時 GC 觸發的代以及什麼原因。


0:297> dx -r1 (*((coreclr!WKS::gc_mechanisms *)0x7ffab021df90))
(*((coreclr!WKS::gc_mechanisms *)0x7ffab021df90))                 [Type: WKS::gc_mechanisms]
    [+0x000] gc_index         : 0x984ab [Type: unsigned __int64]
    [+0x008] condemned_generation : 0 [Type: int]
    [+0x00c] promotion        : 1 [Type: int]
    [+0x010] compaction       : 1 [Type: int]
    [+0x014] loh_compaction   : 0 [Type: int]
    [+0x018] heap_expansion   : 0 [Type: int]
    [+0x01c] concurrent       : 0x0 [Type: unsigned int]
    [+0x020] demotion         : 1 [Type: int]
    [+0x024] card_bundles     : 1 [Type: int]
    [+0x028] gen0_reduction_count : 0 [Type: int]
    [+0x02c] should_lock_elevation : 0 [Type: int]
    [+0x030] elevation_locked_count : 0 [Type: int]
    [+0x034] elevation_reduced : 0 [Type: int]
    [+0x038] minimal_gc       : 0 [Type: int]
    [+0x03c] reason           : reason_alloc_soh (0) [Type: gc_reason]
    [+0x040] pause_mode       : pause_interactive (1) [Type: WKS::gc_pause_mode]
    [+0x044] found_finalizers : 1 [Type: int]
    [+0x048] background_p     : 0 [Type: int]
    [+0x04c] b_state          : bgc_not_in_process (0) [Type: bgc_state]
    [+0x050] allocations_allowed : 1 [Type: int]
    [+0x054] stress_induced   : 0 [Type: int]
    [+0x058] entry_memory_load : 0x0 [Type: unsigned int]
    [+0x05c] exit_memory_load : 0x0 [Type: unsigned int]

從卦中看,當前觸發的是 0 代GC,觸發原因是 0代 的閾值滿了,這是一個很正常的 GC 操作,理應不會造成 CPU 爆高,除非是那些傷害性比較大的 FULLGC,由於沒有更多的 dump 可以參考,到這裡就沒法更進一步確認了。

3. 還有其他線索嗎

雖然 .NET 程式大多 CPU 爆高是由於 GC 的頻繁觸發所致,但也有其他情況,比如 CPU 密集型操作往往也會,就像我之前解讀 B站的LUA死迴圈導致的CPU爆高場景下如何通過 火焰圖 去尋找熱點函數。

那這個 dump 會不會也存在這種情況呢? 不管有沒有,在一個 dump 的情況下也只能 死馬當作活馬醫 了,可以用 !runaway 查查當前線程運行時間。


0:297> !runaway
 User Mode Time
  Thread       Time
  269:2354     0 days 0:07:04.171
  274:15d4     0 days 0:06:16.453
  280:1c98     0 days 0:05:32.406
  284:438      0 days 0:04:37.703
  283:183c     0 days 0:04:29.531
  282:122c     0 days 0:04:24.703
  288:2060     0 days 0:03:59.953
  286:28d0     0 days 0:03:56.640
  289:2a84     0 days 0:03:50.859
  290:1224     0 days 0:03:44.640
  291:2e4c     0 days 0:03:29.937
  292:f0c      0 days 0:03:28.656
  293:2454     0 days 0:03:26.640
  275:2810     0 days 0:03:23.828
  294:2f34     0 days 0:03:22.312
  295:24ec     0 days 0:03:17.625
  297:2144     0 days 0:03:16.609
  298:2c34     0 days 0:03:14.609
  299:2480     0 days 0:03:11.218
  ...

線程還是蠻多的,採樣幾個看一下,發現有很多函數與 序列化 有關。


0:269> !clrstack 
OS Thread Id: 0x2354 (269)
       Child SP               IP Call Site
0000002F080FD658 00007ffacb236124 [HelperMethodFrame: 0000002f080fd658] 
0000002F080FD770 00007ffab11d806b System.Runtime.Serialization.Formatters.Binary.SizedArray..ctor() [E:\A\_work\322\s\corefx\src\System.Runtime.Serialization.Formatters\src\System\Runtime\Serialization\Formatters\Binary\BinaryUtilClasses.cs @ 203]
0000002F080FD7A0 00007ffab11d6964 System.Runtime.Serialization.Formatters.Binary.BinaryParser.get_ObjectMapIdTable() [E:\A\_work\322\s\corefx\src\System.Runtime.Serialization.Formatters\src\System\Runtime\Serialization\Formatters\Binary\BinaryParser.cs @ 57]
0000002F080FD7E0 00007ffa515132c1 System.Runtime.Serialization.Formatters.Binary.BinaryParser.ReadObjectWithMapTyped(System.Runtime.Serialization.Formatters.Binary.BinaryObjectWithMapTyped) [E:\A\_work\322\s\corefx\src\System.Runtime.Serialization.Formatters\src\System\Runtime\Serialization\Formatters\Binary\BinaryParser.cs @ 532]
0000002F080FD8B0 00007ffab11d74ed System.Runtime.Serialization.Formatters.Binary.BinaryParser.ReadObjectWithMapTyped(System.Runtime.Serialization.Formatters.Binary.BinaryHeaderEnum) [E:\A\_work\322\s\corefx\src\System.Runtime.Serialization.Formatters\src\System\Runtime\Serialization\Formatters\Binary\BinaryParser.cs @ 504]

0:280> !clrstack 
OS Thread Id: 0x1c98 (280)
       Child SP               IP Call Site
0000002F185FCE38 00007ffacb236124 [HelperMethodFrame: 0000002f185fce38] 
0000002F185FCF30 00007ffaaf59bb61 System.String.Ctor(Char[], Int32, Int32) [E:\A\_work\191\s\src\mscorlib\shared\System\String.cs @ 79]
0000002F185FCF90 00007ffa5033f984 Newtonsoft.Json.JsonTextReader.ParseReadString(Char, Newtonsoft.Json.ReadType)
0000002F185FD040 00007ffa5099cd0b Newtonsoft.Json.JsonTextReader.ReadStringValue(Newtonsoft.Json.ReadType)
0000002F185FD0B0 00007ffa5099cb0e Newtonsoft.Json.JsonTextReader.ReadAsString()
0000002F185FD0E0 00007ffa514c68fc Newtonsoft.Json.JsonReader.ReadForType(Newtonsoft.Json.Serialization.JsonContract, Boolean)

0:284> !clrstack 
OS Thread Id: 0x438 (284)
       Child SP               IP Call Site
0000002F1ED7C9C8 00007ffacb236124 [RedirectedThreadFrame: 0000002f1ed7c9c8] 
0000002F1ED7CA48 00007ffaaf5a6863 System.Buffer.Memmove(Byte*, Byte*, UInt64) [E:\A\_work\191\s\src\mscorlib\src\System\Buffer.cs @ 211]
0000002F1ED7CA50 00007ffaaf59bbb2 System.String.Ctor(Char[], Int32, Int32) [E:\A\_work\191\s\src\mscorlib\shared\System\String.cs @ 83]
0000002F1ED7CAB0 00007ffa5033f984 Newtonsoft.Json.JsonTextReader.ParseReadString(Char, Newtonsoft.Json.ReadType)
0000002F1ED7CB60 00007ffa5099cd0b Newtonsoft.Json.JsonTextReader.ReadStringValue(Newtonsoft.Json.ReadType)
0000002F1ED7CBD0 00007ffa5099cb0e Newtonsoft.Json.JsonTextReader.ReadAsString()

有了線索之後,接下來用 ~*e !clrstack 把所有的線程棧調出來,發現很多的 JsonConvert ,並且還有 5 個線程在做 DeepClone,截圖如下:

接下來把 DeepClone 函數導出來看看,發現是用 BinaryFormatter 來實現對象的深複製。


public static T DeepClone<T>(this T obj) where T : class
{
	BinaryFormatter binaryFormatter = new BinaryFormatter();
	using MemoryStream memoryStream = new MemoryStream();
	binaryFormatter.Serialize(memoryStream, obj);
	memoryStream.Seek(0L, SeekOrigin.Begin);
	return (T)binaryFormatter.Deserialize(memoryStream);
}

把發現的這些線索反饋給朋友後,確實也驗證了是 序列化 造成的。

三:總結

分析完畢,這個 dump 給我們的教訓是:

  1. 對象的深複製慎用 BinaryFormatter 這種流式操作,尤其是在大對象的情況下,它是一種 CPU 密集性的,建議採用 AutoMapper 這類 帶 ILEmit, ExpressionTree 還帶編譯緩存的開源工具包。

  2. 高級調試是一場破案之旅,你第一眼看到的往往是程式故意讓你看到的,需要不斷的積累破案經驗練就一雙慧眼。

圖片名稱
您的分享是我們最大的動力!

-Advertisement-
Play Games
更多相關文章
  • 兄弟們,今天我們來用Python生成隨機密碼試試~ 知識點 文件讀寫 基礎語法 字元串處理 字元拼接 代碼解析 導入模塊 import platform import string import random # 我還給大家準備了這些資料:Python視頻教程、100本Python電子書、基礎、爬蟲 ...
  • likeshop外賣點餐系統適用於茶飲類的外賣點餐場景,搭建自己的一點點、奈雪、喜茶點餐系統。 系統基於總部+多門店的連鎖模式,擁有門店獨立管理後臺,支持總部定價和門店定價。LBS定位點餐,可堂食可外賣。無論運營還是二開都是性價比極高的100%開源商城系統。 適用場景 系統適用於茶飲類的外賣點餐場景 ...
  • 俗話話說的號,沒有金剛鑽,也不攬那瓷器活;日誌分析可以說是所有大小系統的標配了,不知道有多少菜鳥程式員有多喜歡日誌,如果沒了日誌,那自己寫的bug想不被別人發現,可就難了; 有了它,就可將bug們統統消化在自己手裡。 當然了,作為一個架構師搭建動手搭建一個日誌平臺也基本是必備技能了,雖然我們說架構師 ...
  • 一、Type介紹 在Python中一切皆對象,類它也是對象,而元類其實就是用來創建類的對象(由於一切皆對象,所以元類其實也是一個對象)。 先來看這幾個例子: 例1: In [1]: type(12) Out[1]: int 通過 type 可以查看對象的類型,也就是查看對象是那一類的,這裡可以看出來 ...
  • 前言 本文基於Dubbo2.6.x版本,中文註釋版源碼已上傳github:xiaoguyu/dubbo 上一篇文章,講了Dubbo的服務導出: Dubbo源碼(三) - 服務導出(生產者) 本文,咱們來聊聊Dubbo的服務引用。 本文案例來自Dubbo官方Demo,路徑為: dubbo/dubbo- ...
  • 大家好,我是二哥呀! 昨天,一位球友問我能不能給他解釋一下 @SpringBootApplication 註解是什麼意思,還有 Spring Boot 的運行原理,於是我就帶著他扒拉了一下這個註解的源碼,還有 SpringApplication 類的 run() 方法的源碼,一下子他就明白了。 你別 ...
  • anonfiles網盤比較特殊,連接的地址經常會變,所以目前市面上的下載器基本都下載不了這上面的大文件,作為一個程式員,必須以身作則,做一個下載器,當然,我也不是某雷之類的這種大公司的下載器引擎的開發者,用Csharp寫的一個簡單的下載器,下載速度比較感人,還看網路條件,我自己下載的時候好的時候單個 ...
  • 一 創建對象時考慮實現比較器 假設有這樣的場景,有一個40個人的學生列表,業務中需針對學生的成績來進行排序。 可以考慮用IComparable介面和ICompare介面實現: class Program { static void Main(string[] args) { var stus = n ...
一周排行
    -Advertisement-
    Play Games
  • 在本篇教程中,我們學習瞭如何使用 Taurus.MVC WebMVC 框架創建一個簡單的頁面。 我們創建了一個控制器並編寫了一個用於呈現頁面的方法,然後創建了對應的視圖,並最終成功運行了應用程式。 在下一篇教程中,我們將繼續探索 Taurus.MVC WebMVC 框架的更多功能和用法。 ...
  • 一:背景 1. 講故事 很多.NET開發者在學習高級調試的時候,使用sos的命令輸出會發現這裡也看不懂那裡也看不懂,比如截圖中的這位朋友。 .NET高級調試屬於一個偏冷門的領域,國內可觀測的資料比較少,所以很多東西需要你自己去探究源代碼,然後用各種調試工具去驗證,相關源代碼如下: coreclr: ...
  • 我一直都以為c中除以2的n次方可以使用右移n位代替,然而在實際調試中發現並不都是這樣的。是在計算餘數是發現了異常 被除數:114325068 右移15計算結果:3488 除法取整計算結果:3489 右移操作計算餘數:33772 除法取整計算餘數:1005 顯然:這是不一樣的。 移位操作是一條cpu指 ...
  • 在上一篇文章中,我們介紹了ReentrantLock類的一些基本用法,今天我們重點來介紹一下ReentrantLock其它的常用方法,以便對ReentrantLock類的使用有更深入的理解。 ...
  • Excelize 是 Go 語言編寫的用於操作電子錶格辦公文檔的開源基礎庫,2024年2月26日,社區正式發佈了 2.8.1 版本,該版本包含了多項新增功能、錯誤修複和相容性提升優化。 ...
  • 雲採用框架(Cloud Adoption Framework,簡稱CAF)為企業上雲提供策略和技術的指導原則和最佳實踐,幫助企業上好雲、用好雲、管好雲,併成功實現業務目標。本雲採用框架是基於服務大量企業客戶的經驗總結,將企業雲採用分為四個階段,並詳細探討企業應在每個階段採取的業務和技術策略;同時,還 ...
  • 與TXT文本文件,PDF文件更加專業也更適合傳輸,常用於正式報告、簡歷、合同等場合。項目中如果有使用Java將TXT文本文件轉為PDF文件的需求,可以查看本文中介紹的免費實現方法。 免費Java PDF庫 本文介紹的方法需要用到Free Spire.PDF for Java,該免費庫支持多種操作、轉 ...
  • 指針和引用 當我們需要在程式中傳遞變數的地址時,可以使用指針或引用。它們都可以用來間接訪問變數,但它們之間有一些重要的區別。 指針是一個變數,它存儲另一個變數的地址。通過指針,我們可以訪問存儲在該地址中的變數。指針可以被重新分配,可以指向不同的變數,也可以為NULL。指針使用*運算符來訪問存儲在地址 ...
  • 即使再小再簡單的需求,作為研發開發完畢之後,我們可以直接上線麽?其實很多時候事故往往就是由於“不以為意”發生的。事故的發生往往也遵循“墨菲定律”,這就要求我們更要敬畏線上,再小的需求點都需要經過嚴格的測試驗證才能上線。 ...
  • 這裡給大家分享我在網上總結出來的一些知識,希望對大家有所幫助 一、是什麼 許可權是對特定資源的訪問許可,所謂許可權控制,也就是確保用戶只能訪問到被分配的資源 而前端許可權歸根結底是請求的發起權,請求的發起可能有下麵兩種形式觸發 頁面載入觸發 頁面上的按鈕點擊觸發 總的來說,所有的請求發起都觸發自前端路由或 ...