公司的产品一直紧跟 .net core 3.0 preview 不断升级, 部署到 Linux 服务器后, 偶尔会出现某个进程CPU占用100%.
由于服务部署在云上, 不能使用远程调试; 在局域网内的Linux 服务器 或 Windows开发机上又不能重现这个问题, 联想到Java的jstack, 很是羡慕啊. 想到.net core 已经出来这么久了, 还是试着找找看吧, 结果还真找到一篇博客Introducing diagnostics improvements in .NET Core 3.0
这篇文章介绍了3个工具
•dotnet-counters: 实时统计runtime的状况, 包括 CPU、内存、GC、异常等
•dotnet-trace: 类似性能探测器
•dotnet-dump: 程序崩溃时使用该工具
这次使用的是dotnet-dump, 即使程序没有崩溃, 也可以dump程序快照, 用于分析
实验环境
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, 好吧, 照着做吧, 记得使用下面的命令使设置立即生效
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)
我们关心的线程3418的16进制是d5a, 也就是最后一行, 它的DBG是7, 我们需要使用 setthread 7, 将其设置为 当前操作的线程
然后使用 clrstack 获取线程调用信息