記一次 .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生成隨機密碼，灰常簡單
    兄弟們，今天我們來用Python生成隨機密碼試試~ 知識點 文件讀寫 基礎語法 字元串處理 字元拼接 代碼解析 導入模塊 import platform import string import random # 我還給大家準備了這些資料：Python視頻教程、100本Python電子書、基礎、爬蟲 ...
  • slf4j如何進行logback配置呢?
    likeshop外賣點餐系統適用於茶飲類的外賣點餐場景，搭建自己的一點點、奈雪、喜茶點餐系統。 系統基於總部+多門店的連鎖模式，擁有門店獨立管理後臺，支持總部定價和門店定價。LBS定位點餐，可堂食可外賣。無論運營還是二開都是性價比極高的100%開源商城系統。 適用場景 系統適用於茶飲類的外賣點餐場景 ...
  • Elasticsearch + Logstash + Filebeat + Kibana搭建ELK日誌分析平臺（官方推薦的BEATS架構）
    俗話話說的號，沒有金剛鑽，也不攬那瓷器活；日誌分析可以說是所有大小系統的標配了，不知道有多少菜鳥程式員有多喜歡日誌，如果沒了日誌，那自己寫的bug想不被別人發現，可就難了； 有了它，就可將bug們統統消化在自己手裡。 當然了，作為一個架構師搭建動手搭建一個日誌平臺也基本是必備技能了，雖然我們說架構師 ...
  • Python 元類詳解
    一、Type介紹 在Python中一切皆對象，類它也是對象，而元類其實就是用來創建類的對象（由於一切皆對象，所以元類其實也是一個對象）。 先來看這幾個例子： 例1： In [1]: type(12) Out[1]: int 通過 type 可以查看對象的類型，也就是查看對象是那一類的，這裡可以看出來 ...
  • Dubbo源碼(四) - 服務引用（消費者）
    前言 本文基於Dubbo2.6.x版本，中文註釋版源碼已上傳github：xiaoguyu/dubbo 上一篇文章，講了Dubbo的服務導出： Dubbo源碼(三) - 服務導出（生產者） 本文，咱們來聊聊Dubbo的服務引用。 本文案例來自Dubbo官方Demo，路徑為： dubbo/dubbo- ...
  • 別再用 System.currentTimeMillis 統計耗時了，太 Low，試試 Spring Boot 源碼在用的 StopWatch吧，夠優雅！
    大家好，我是二哥呀！ 昨天，一位球友問我能不能給他解釋一下 @SpringBootApplication 註解是什麼意思，還有 Spring Boot 的運行原理，於是我就帶著他扒拉了一下這個註解的源碼，還有 SpringApplication 類的 run() 方法的源碼，一下子他就明白了。 你別 ...
  • 國外anonfiles網盤大文件下載器
    anonfiles網盤比較特殊，連接的地址經常會變，所以目前市面上的下載器基本都下載不了這上面的大文件，作為一個程式員，必須以身作則，做一個下載器，當然，我也不是某雷之類的這種大公司的下載器引擎的開發者，用Csharp寫的一個簡單的下載器，下載速度比較感人，還看網路條件，我自己下載的時候好的時候單個 ...
  • 改善C#程式的方法-(3)比較器和LINQ排序
    一 創建對象時考慮實現比較器 假設有這樣的場景，有一個40個人的學生列表，業務中需針對學生的成績來進行排序。 可以考慮用IComparable介面和ICompare介面實現： class Program { static void Main(string[] args) { var stus = n ...
一周排行
    -Advertisement-
    Play Games
  • 通過圖片流來返回圖片
    # 通過圖片流來返回圖片 # 前言 之前寫了個圖片介面，然後做了個授權，但是光返回圖片地址雖然能適應大部分需求，但是考慮到有些人不想去處理返回值，也是做了個直接返回圖片流的介面。 # 介面展示 ## 返回指定寬度和高度圖片流 ![image](https://img2023.cnblogs.com/ ...
  • .NET使用System.Speech輕鬆讀取文本
    System.Speech是.NET框架的一部分，提供了語音識別和語音合成的功能。通過使用System.Speech命名空間中的類，開發人員可以在.NET應用程式中實現語音識別功能。 在本文中，我將演示如何使用 System.Speech.NET，這是開發語音應用程式比較牛逼的內庫。它適用於 .NE ...
  • .NET ORM核心功能之導航屬性- EFCore和 SqlSugar
    導航屬性 導航屬性是作為.NET ORM核心功能中的核心，在SqlSugar沒有支持導航屬性前，都說只是一個高級DbHelper, 經過3年的SqlSugar重構已經擁有了一套 非常成熟的導航屬性體系，本文不是重點講SqlSugar而是重點講導航屬性的作用，讓更多寫Sql人還未使用ORM的人瞭解到O ...
  • C# SM2加解密
    SM2是國家密碼管理局於2010年12月17日發佈的橢圓曲線公鑰密碼演算法。 產生背景： 隨著密碼技術和電腦技術的發展，目前常用的1024位RSA演算法面臨嚴重的安全威脅，我們國家密碼管理部門經過研究，決定採用SM2橢圓曲線演算法替換RSA演算法。 SM2演算法和RSA演算法都是公鑰密碼演算法，SM2演算法是一種 ...
  • 使用c#實現23種常見的設計模式
    # 使用c#實現23種常見的設計模式 設計模式通常分為三個主要類別： - 創建型模式 - 結構型模式 - 行為型模式。 這些模式是用於解決常見的對象導向設計問題的最佳實踐。 以下是23種常見的設計模式並且提供`c#代碼案例`： ## 創建型模式： ### 1. 單例模式（Singleton） ``` ...
  • 如何獲取 C#程式 內核態線程棧
    ## 一：背景 ### 1. 講故事 在這麼多的案例分析中，往往會發現一些案例是卡死線上程的內核態棧上，但拿過來的dump都是用戶態模式下，所以無法看到內核態棧，這就比較麻煩，需要讓朋友通過其他方式生成一個藍屏的dump，這裡我們簡單彙總下。 ## 二：如何生成內核態dump ### 1. 案例代碼 ...
  • 在DevExpress的GridView的列中，使用RepositoryItemSearchLookUpEdit控制項實現產品列表信息的展示和選擇
    有時候，我們為了方便，我們往往使用擴展函數的代碼方式創建很多GridView的操作功能，如在隨筆《在DevExpress中使用BandedGridView表格實現多行表頭的處理》中介紹過多行表頭的創建及綁定處理，在《基於DevExpress的GridControl實現的一些界面處理功能》也介紹了一些... ...
  • hdfs中acl許可權管理的簡單實用
    # 1、背景 在我們開發的過程中有這麼一種場景， `/projectA` 目錄是 `hadoopdeploy`用戶創建的，他對這個目錄有`wrx`許可權，同時這個目錄屬於`supergroup`，在這個組中的用戶也具有這個目錄的`wrx`許可權，對於其他人,不可訪問這個目錄。現在有這麼一個特殊的用戶`r ...
  • 41基於java的倉庫管理系統設計與實現
    基於java的倉庫管理系統設計與實現，可適用於出庫、入庫、庫存管理，基於java的出入庫管理，java出入庫管理系統,基於java的WMS倉庫管理系統,庫存物品管理系統。 ...
  • PyInstaller 完美打包 Python 腳本，輸出結構清晰、便於二次編輯的打包程式
    清醒點[toc] # Java虛擬線程 > 翻譯自 screencapture-pradeesh-kumar-medium-an-era-of-virtual-threads-java ```mermaid flowchart LR introduction-->a(why thread)-->b( ...
所有分類