Using dotnet dump to find the reason why. Net core 3.0 takes up 100% of CPU （实践篇）（转发）

转载

mob60475701b76f 2021-01-14 12:47:00

文章标签 bash microsoft unix 5e linux 文章分类 运维

• dotnet counters: real time statistics of runtime, including CPU, memory, GC, exception, etc

• dotnet trace: similar performance detector

• dotnet dump: use this tool when the program crashes

This time, we use dotnet dump. Even if the program does not crash, we can also dump the program snapshot for analysis

2. Install dotnet dump

dotnet tool install --global dotnet-dump --version 1.0.4-preview6.19311.1

Tips

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.

It is recommended to add $home /. Dotnet / tools to the path, OK, do as you like, and remember to use the following command to make the settings take effect immediately

source ~/.bash_profile

3. Use dotnet NetCoreDumpTest.dll Start our problem program, and then use PS – EF | grep dotnet to view the process ID of the program. You can see that the process ID is 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

For process 3411, we also need to know which thread accounts for the CPU. Using top-hp 3411, we can list all threads. Because top refreshes every 3 seconds, it may take several seconds to see which thread takes up a relatively high CPU. Here we can see the thread with PID = 3418 (please understand the process ID and thread ID of Linux by yourself)

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

To get dump, you can only dump the process, so we input 3411


dotnet-dump collect -p 3411
Writing minidump with heap to /tmp/core_20190623_075649
Complete

4. Analysis

dotnet-dump analyze core_20190623_075649

Use clrthreads to view all threads

>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)

The hexadecimal of thread 3418 that we care about is D5A, that is, the last line. Its DBG is 7. We need to use setthread 7 to set it as the thread of current operation

（3418=13*16*16+5*16+10）

Then use clrstack to get the thread call information


> 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.