使用dotnet-dump 查找 .net core 3.0 占用CPU 100%的原因解析
公司的產(chǎn)品一直緊跟 .net core 3.0 preview 不斷升級, 部署到 Linux 服務(wù)器后, 偶爾會出現(xiàn)某個進程CPU占用100%.
由于服務(wù)部署在云上, 不能使用遠(yuǎn)程調(diào)試; 在局域網(wǎng)內(nèi)的Linux 服務(wù)器 或 Windows開發(fā)機上又不能重現(xiàn)這個問題, 聯(lián)想到Java的jstack, 很是羨慕啊. 想到.net core 已經(jīng)出來這么久了, 還是試著找找看吧, 結(jié)果還真找到一篇博客Introducing diagnostics improvements in .NET Core 3.0
這篇文章介紹了3個工具
•dotnet-counters: 實時統(tǒng)計runtime的狀況, 包括 CPU、內(nèi)存、GC、異常等
•dotnet-trace: 類似性能探測器
•dotnet-dump: 程序崩潰時使用該工具
這次使用的是dotnet-dump, 即使程序沒有崩潰, 也可以dump程序快照, 用于分析
實驗環(huán)境
ubuntu-16.04.5-desktop-amd64
SDK 3.0.100-preview6-012264
1. 新建一個簡單Console程序(只能是 .net core 3.0的程序, 不支持 .net core 2.2), 模擬CPU占用100%的情況
mkdir NetCoreDumpTest && cd NetCoreDumpTest dotnet new console
編輯Program.cs
namespace NetCoreDumpTest
{
using System;
using System.Threading.Tasks;
class Program
{
static void Main(string[] args)
{
Task.Factory.StartNew(() => PrintNumber("Print", 5));
Console.WriteLine("Press any key to exit.");
Console.ReadKey();
}
static void PrintNumber(string message, int startNumber)
{
var number = startNumber;
while (true)
Console.WriteLine($"{message} {number++}");
}
}
}
2. 安裝dotnet-dump
dotnet tool install --global dotnet-dump --version 1.0.4-preview6.19311.1
提示
If you are using bash, you can add it to your profile by running the following command:
cat << \EOF >> ~/.bash_profile
# Add .NET Core SDK tools
export PATH="$PATH:/home/****/.dotnet/tools"
EOF
You can add it to the current session by running the following command:
export PATH="$PATH:/home/****/.dotnet/tools"
You can invoke the tool using the following command: dotnet-dump
Tool 'dotnet-dump' (version '1.0.4-preview6.19311.1') was successfully installed.
建議將 $HOME/.dotnet/tools加入到PATH, 好吧, 照著做吧, 記得使用下面的命令使設(shè)置立即生效
source ~/.bash_profile
3. 使用 dotnet NetCoreDumpTest.dll 啟動我們的問題程序, 然后使用 ps -ef | grep dotnet 查看程序的進程ID, 可以看到進程ID是 3411
ps -ef | grep dotnet z*****e 3411 1464 22 07:51 pts/8 00:00:59 dotnet NetCoreDumpTest.dll z*****e 3431 2935 0 07:55 pts/9 00:00:00 grep --color=auto dotnet
針對進程3411, 我們還需要知道是哪個線程占CPU, 使用 top -Hp 3411 可以列出所有線程, 由于top每隔3秒刷新一次, 所以可能需要多觀察幾秒才能看到具體是哪個線程占用CPU比較高, 這里我們可以看到是PID=3418的線程(Linux的進程ID和線程ID請自行了解一下).
top -Hp 3411 PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3418 z*****e 20 0 2997700 29060 22400 R 10.3 1.4 0:20.68 dotnet 3411 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.11 dotnet 3412 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.02 dotnet 3413 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.00 dotnet 3414 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.00 dotnet 3415 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.01 dotnet 3416 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.00 dotnet 3417 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.00 dotnet 3421 z*****e 20 0 2997700 29060 22400 S 0.0 1.4 0:00.00 dotnet
獲取dump, 只能正對進程進行dump, 所以我們輸入的是 3411
dotnet-dump collect -p 3411 Writing minidump with heap to /tmp/core_20190623_075649 Complete
4. 分析
dotnet-dump analyze core_20190623_075649
使用clrthreads 查看所有線程
>clrthreads
ThreadCount: 4
UnstartedThread: 0
BackgroundThread: 3
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
Lock
DBG ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception
0 1 d53 0000000001307D80 20020 Preemptive 0000000000000000:0000000000000000 0000000001306450 1 Ukn
4 2 d57 000000000135BBD0 21220 Preemptive 0000000000000000:0000000000000000 0000000001306450 0 Ukn (Finalizer)
6 3 d59 00007F666C0009F0 1020220 Preemptive 0000000000000000:0000000000000000 0000000001306450 0 Ukn (Threadpool Worker)
7 4 d5a 000000000130DA40 1021220 Preemptive 00007F6678106860:00007F6678106F20 0000000001306450 1 Ukn (Threadpool Worker)
我們關(guān)心的線程3418的16進制是d5a, 也就是最后一行, 它的DBG是7, 我們需要使用 setthread 7, 將其設(shè)置為 當(dāng)前操作的線程
然后使用 clrstack 獲取線程調(diào)用信息
> setthread 7 > clrstack OS Thread Id: 0xd5a (7) Child SP IP Call Site 00007F6715561558 00007f671a2bd4bd [InlinedCallFrame: 00007f6715561558] Interop+Sys.Write(System.Runtime.InteropServices.SafeHandle, Byte*, Int32) 00007F6715561558 00007f669f669a9e [InlinedCallFrame: 00007f6715561558] Interop+Sys.Write(System.Runtime.InteropServices.SafeHandle, Byte*, Int32) 00007F6715561540 00007F669F669A9E ILStubClass.IL_STUB_PInvoke 00007F67155615E0 00007F669F67333E System.ConsolePal.Write(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte*, Int32, Boolean) 00007F67155616A0 00007F669F67360C System.ConsolePal.Write(Microsoft.Win32.SafeHandles.SafeFileHandle, Byte[], Int32, Int32, Boolean) [/_/src/System.Console/src/System/ConsolePal.Unix.cs @ 1236] 00007F67155616C0 00007F669F672B2A System.IO.StreamWriter.Flush(Boolean, Boolean) [/_/src/System.Private.CoreLib/shared/System/IO/StreamWriter.cs @ 261] 00007F6715561710 00007F669F6729F3 System.IO.StreamWriter.WriteLine(System.String) [/_/src/System.Private.CoreLib/shared/System/IO/StreamWriter.cs @ 474] 00007F6715561760 00007F669F6727D3 System.IO.TextWriter+SyncTextWriter.WriteLine(System.String) [/_/src/System.Private.CoreLib/shared/System/IO/TextWriter.cs @ 891] 00007F67155617A0 00007F669F672770 System.Console.WriteLine(System.String) [/_/src/System.Console/src/System/Console.cs @ 550] 00007F67155617C0 00007F669F663791 NetCoreDumpTest.Program.PrintNumber(System.String, Int32) [/home/zhouke/NetCoreDumpTest/Program.cs @ 18] 00007F6715561800 00007F669F6636D9 NetCoreDumpTest.Program+<>c.<Main>b__0_0() 00007F6715561820 00007F669F1872A1 System.Threading.Tasks.Task.InnerInvoke() [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2466] 00007F6715561840 00007F669F18CBC2 System.Threading.Tasks.Task+<>c.<.cctor>b__274_0(System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2445] 00007F6715561850 00007F669F171AF2 System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 289] 00007F6715561890 00007F669F187111 System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2406] 00007F6715561910 00007F669F186F28 System.Threading.Tasks.Task.ExecuteEntryUnsafe(System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2344] 00007F6715561930 00007F669F186EBB System.Threading.Tasks.Task.ExecuteFromThreadPool(System.Threading.Thread) 00007F6715561940 00007F669F17B754 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 663] 00007F67155619C0 00007F669F169A5B System.Threading._ThreadPoolWaitCallback.PerformWaitCallback() [/_/src/System.Private.CoreLib/src/System/Threading/ThreadPool.CoreCLR.cs @ 29] 00007F6715561D50 00007f6718a1ccaf [DebuggerU2MCatchHandlerFrame: 00007f6715561d50]
嘩啦啦一大片, 有點Java調(diào)用堆棧的味道, 不過我們還是找到了我們的問題代碼
NetCoreDumpTest.Program.PrintNumber(System.String, Int32)
有時候我們想知道傳入的什么參數(shù)導(dǎo)致CPU占用高, 可以給clrstack加上參數(shù) -a
> clrstack -a
..............
00007F0DD6FFC7C0 00007F0D6EEF3791 NetCoreDumpTest.Program.PrintNumber(System.String, Int32) [/home/zhouke/NetCoreDumpTest/Program.cs @ 18]
PARAMETERS:
message (0x00007F0DD6FFC7E8) = 0x00007f0d4800b8b0
startNumber (0x00007F0DD6FFC7E4) = 0x0000000000000005
LOCALS:
0x00007F0DD6FFC7E0 = 0x000000000014e42b
0x00007F0DD6FFC7DC = 0x0000000000000001
...............
可以看到PARAMETERS里, startNumber作為值類型, 可以直接看到數(shù)值為5, 而message是引用類型, 指向0x00007f0d4800b8b0, 這時候需要用到 dumpobj 命令
> dumpobj 0x00007f0d4800b8b0
Name: System.String
MethodTable: 00007f0d6ef70f90
EEClass: 00007f0d6eede1c0
Size: 32(0x20) bytes
File: /home/zhouke/dotnet/shared/Microsoft.NETCore.App/3.0.0-preview6-27804-01/System.Private.CoreLib.dll
String: Print
Fields:
MT Field Offset Type VT Attr Value Name
00007f0d6ef6a138 400022b 8 System.Int32 1 instance 5 _stringLength
00007f0d6ef66f38 400022c c System.Char 1 instance 50 _firstChar
00007f0d6ef70f90 400022d 108 System.String 0 static 00007f0d47fff360 Empty
好了, 可以看到它是一個字符串, 內(nèi)容為 "Print"
假如message是一個復(fù)雜類型, 可以查看Fields下面的信息進一步查看
clrstack 還有一個實驗性質(zhì)的參數(shù) -i, 協(xié)助查看各種變量信息, 需要用到lldb, 按照官方教程, 我暫時沒有實驗成功.
查看進程ID和線程ID, 更方便的方法是 htop(需要安裝), 然后按 F4 進行過濾, 輸入dotnet 即可
這張圖是重新運行問題程序的結(jié)果, 進程ID和線程ID與前面不一樣
第二行白色的是進程ID=1650, 第一行CPU占用高, 是問題線程ID=1658
總結(jié)
以上所述是小編給大家介紹的使用dotnet-dump 查找 .net core 3.0 占用CPU 100%的原因解析,希望對大家有所幫助，如果大家有任何疑問請給我留言，小編會及時回復(fù)大家的。在此也非常感謝大家對腳本之家網(wǎng)站的支持！
如果你覺得本文對你有幫助，歡迎轉(zhuǎn)載，煩請注明出處，謝謝！
相關(guān)文章
ASP.NET中實現(xiàn)Form表單字段值自動填充到操作模型中
這篇文章主要介紹了ASP.NET中實現(xiàn)Form表單字段值自動填充到操作模型中,本文模仿MVC模式中的自動映射表單了模型,使用泛型和反射實現(xiàn),需要的朋友可以參考下2015-06-06
ASP.NET中文件上傳下載方法集合...2006-09-09
這篇文章介紹了asp.net讀取磁盤文件、刪除實例代碼，有需要的朋友可以參考一下2013-10-10
System.Data.SqlClient.SqlBulkCopy 對于新手來說還是比較陌生的，這個就是傳說中效率極高的bcp，6萬多數(shù)據(jù)從excel導(dǎo)入到sql只需要4.5秒2014-10-10
今天與大家分享AjaxPro或者Ajax實現(xiàn)機制,需要的朋友可以參考下。2011-12-12
Asp.net內(nèi)置對象之Request對象(概述及應(yīng)用)
Request對象主要用于獲取來自客戶端的數(shù)據(jù)，如用戶填入表單的數(shù)據(jù)、保存在客戶端的Cookie等,本文將圍繞Request對象,講解其的主要作用:讀取窗體變量、讀取查詢字符串變量、取得Web服務(wù)器端的系統(tǒng)信息。取得客戶端瀏覽器信息等等，感興趣的朋友可以了解下2013-02-02
asp.net 計算字符串中各個字符串出現(xiàn)的次數(shù)
比如一個字符串"a,b,a,c,b,b,d"，現(xiàn)在我們要統(tǒng)計每個字符串出現(xiàn)次數(shù)。解決這個問題，我們可以使用泛型集合 Dictionary(TKey,TValue)。它有一個key值用來存儲字符串和一個value值，用來存儲字符串出現(xiàn)的次數(shù)2012-05-05
asp.net調(diào)用系統(tǒng)設(shè)置字體文本框的方法
這篇文章主要介紹了asp.net調(diào)用系統(tǒng)設(shè)置字體文本框的方法,包括設(shè)置文本字體樣式和大小,需要的朋友可以參考下2014-09-09
ASP.NET編譯執(zhí)行常見錯誤及解決方法匯總，開發(fā)asp.net的朋友可以參考下。方便以后解決一些錯誤。2011-12-12
這篇文章主要給大家介紹了關(guān)于asp.net core配置文件加載過程的相關(guān)資料，文中通過示例代碼介紹的非常詳細(xì)，對大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價值，需要的朋友們下面來一起學(xué)習(xí)學(xué)習(xí)吧2018-12-12