记一次 某智能制造MES系统CPU 爆高分析

Posted

tags:

篇首语：本文由小常识网(cha138.com)小编为大家整理，主要介绍了记一次 某智能制造MES系统CPU 爆高分析相关的知识，希望对你有一定的参考价值。

一：背景

1. 讲故事

前段时间有位朋友找到我，说他 docker 中的web服务深夜cpu被打满，让我帮忙看一下，很多朋友问docker中怎么抓dump，我一般都推荐使用 procdump 这款自动化工具，谁用谁知道，有了 dump 之后，接下来就是分析了。

二：WinDbg 分析

1. cpu 真的爆高吗

有很多朋友问 linux 上的dump可以用 windbg 分析吗？这里统一回复下，是可以的，现在的 WinDbg 可以全平台分析，不信看下图：

不过有一点吐槽的是，Linux 不是微软的，所以在 操作系统层级 上的调试支持是不够的，也不是 WinDbg 能力所触及范围之内，所以相比 Windows 有很多的不便。

接下来我们用 !tp 看一下当前的 cpu 到底是多少？


0:000> !tp
CPU utilization: 393 %
Worker Thread: Total: 19 Running: 5 Idle: 10 MaxLimit: 32767 MinLimit: 4
Work Request in Queue: 0
--------------------------------------
Number of Timers: 4
--------------------------------------
Completion Port Thread:Total: 0 Free: 0 MaxFree: 8 CurrentLimit: 0 MaxLimit: 1000 MinLimit: 4

从卦中看当前的 cpu=393% ，这表示什么意思呢？在Linux上是这样的，一个核占用 100%，可以理解成当前有 4 个核被打满。

那当前 docker 中给了多少 cpu 核呢？在 Windows 平台上可以用 !cpuid，在 Linux 上肯定用不了了，没关系，熟悉 CLR 的朋友应该知道，ServerGC 的heap个数默认按照cpu 的个数来的，也就是说当前多少个heap，也就有多少个 cpu core。

有了这个思路，使用 !eeversion 来看下 gc 模式吧。


0:000> !eeversion
4.700.21.56803 (3.x runtime)
4.700.21.56803 @Commit: 28bb6f994c28bc91f09bc0ddb5dcb51d0f066806
Server mode with 4 gc heaps
SOS Version: 7.0.8.10101 retail build

从卦中的 Server mode with 4 gc heaps 来看，当前docker使用 4 个 cpu 核，所以 393% 就表示了当前被完全打满。

2. 为什么会被打满

一般来说cpu的跌宕起伏都是由 thread 诱发的，一个好的思路就是看下此时各个线程都在做什么，可以使用 ~*e !clrstack 观察，经过仔细对比发现有 4 处 SqlDataReader 貌似在读什么东西，刚好对应到了 CPU 核数，输出如下：


0:000> ~*e !clrstack
OS Thread Id: 0x3f89 (24)
        Child SP               IP Call Site
00007F9FA14A0628 00007fa4803e2a93 System.Data.SqlClient.TdsParser.TrySkipValue(System.Data.SqlClient.SqlMetaDataPriv, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4399]
00007F9FA14A0640 00007fa47f9a5e03 System.Data.SqlClient.TdsParser.TrySkipRow(System.Data.SqlClient._SqlMetaDataSet, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4334]
00007F9FA14A0670 00007fa4803d2fba System.Data.SqlClient.SqlDataReader.TryCleanPartialRead() [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 760]
00007F9FA14A0690 00007fa47f99e424 System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean, Boolean ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 3286]
00007F9FA14A06F0 00007fa4804742e5 System.Data.SqlClient.SqlDataReader+c__DisplayClass190_0.b__1(System.Threading.Tasks.Task) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 4448]
00007F9FA14A0720 00007fa480a239ea System.Data.SqlClient.SqlDataReader+c__DisplayClass194_0`1[[System.Boolean, System.Private.CoreLib]].b__0(System.Threading.Tasks.Task`1<System.Object>) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 4804]
00007F9FA14A0770 00007fa4803fa6ce System.Threading.Tasks.ContinuationResultTaskFromResultTask`2[[System.__Canon, System.Private.CoreLib],[System.__Canon, System.Private.CoreLib]].InnerInvoke() [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/TaskContinuation.cs @ 191]
00007F9FA14A07B0 00007fa4803d5551 System.Threading.ExecutionContext.RunFromThreadPoolDispatchLoop(System.Threading.Thread, System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/System.Private.CoreLib/shared/System/Threading/ExecutionContext.cs @ 315]
00007F9FA14A07F0 00007fa4803d1c2c System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2421]
00007F9FA14A0870 00007fa4803b99a9 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 699]
00007F9FA14A0C80 00007fa4f11512df [DebuggerU2MCatchHandlerFrame: 00007f9fa14a0c80] 
OS Thread Id: 0x3f8a (25)
        Child SP               IP Call Site
00007F9FA3154580 00007fa4803bc857 System.Data.SqlClient.TdsParser.TryGetTokenLength(Byte, System.Data.SqlClient.TdsParserStateObject, Int32 ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 5889]
...
00007F9FA3154670 00007fa4803d2fba System.Data.SqlClient.SqlDataReader.TryCleanPartialRead() [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 760]
00007F9FA3154690 00007fa47f99e424 System.Data.SqlClient.SqlDataReader.TryReadInternal(Boolean, Boolean ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 3286]
...
00007F9FA3154870 00007fa4803b99a9 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 699]
00007F9FA3154C80 00007fa4f11512df [DebuggerU2MCatchHandlerFrame: 00007f9fa3154c80] 
OS Thread Id: 0x5211 (37)
        Child SP               IP Call Site
00007F9FD2FFC570 00007fa4803bc921 System.Data.SqlClient.TdsParserStateObject.TryReadUInt16(UInt16 ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParserStateObject.cs @ 1519]
00007F9FD2FFC580 00007fa4803bc891 System.Data.SqlClient.TdsParser.TryGetTokenLength(Byte, System.Data.SqlClient.TdsParserStateObject, Int32 ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 5889]
00007F9FD2FFC5C0 00007fa4803e2c06 System.Data.SqlClient.TdsParser.TrySkipValue(System.Data.SqlClient.SqlMetaDataPriv, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4399]
00007F9FD2FFC640 00007fa47f9a5e03 System.Data.SqlClient.TdsParser.TrySkipRow(System.Data.SqlClient._SqlMetaDataSet, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4334]
...
00007F9FD2FFC870 00007fa4803b99a9 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 699]
00007F9FD2FFCC80 00007fa4f11512df [DebuggerU2MCatchHandlerFrame: 00007f9fd2ffcc80] 
OS Thread Id: 0x5212 (38)
        Child SP               IP Call Site
00007F9FB3FFE580 00007fa4803bc839 System.Data.SqlClient.TdsParser.TryGetTokenLength(Byte, System.Data.SqlClient.TdsParserStateObject, Int32 ByRef) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 5889]
00007F9FB3FFE5C0 00007fa4803e2c06 System.Data.SqlClient.TdsParser.TrySkipValue(System.Data.SqlClient.SqlMetaDataPriv, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4399]
00007F9FB3FFE640 00007fa47f9a5e03 System.Data.SqlClient.TdsParser.TrySkipRow(System.Data.SqlClient._SqlMetaDataSet, Int32, System.Data.SqlClient.TdsParserStateObject) [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/TdsParser.cs @ 4334]
00007F9FB3FFE670 00007fa4803d2fba System.Data.SqlClient.SqlDataReader.TryCleanPartialRead() [/_/src/System.Data.SqlClient/src/System/Data/SqlClient/SqlDataReader.cs @ 760]
...
00007F9FB3FFE7F0 00007fa4803d1c2c System.Threading.Tasks.Task.ExecuteWithThreadLocal(System.Threading.Tasks.Task ByRef, System.Threading.Thread) [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/Task.cs @ 2421]
00007F9FB3FFE870 00007fa4803b99a9 System.Threading.ThreadPoolWorkQueue.Dispatch() [/_/src/System.Private.CoreLib/shared/System/Threading/ThreadPool.cs @ 699]
00007F9FB3FFEC80 00007fa4f11512df [DebuggerU2MCatchHandlerFrame: 00007f9fb3ffec80]

从卦中看，虽然异步写的很爽，可逆向分析起来真的是上刀山下火海。。。 接下来思路在哪里呢？可以这么想，既然是和 SqlDataReader 有关系，那就挖一挖，看看里面有什么sql。


0:025> !dso
OS Thread Id: 0x3f8a (25)
RSP/REG          Object           Name
rdx              00007fa128ad9c08 System.Data.SqlClient.SNI.TdsParserStateObjectManaged
rdi              00007fa128ad9c08 System.Data.SqlClient.SNI.TdsParserStateObjectManaged
r9               00007fa128ad9c08 System.Data.SqlClient.SNI.TdsParserStateObjectManaged
r12              00007fa128ad9c08 System.Data.SqlClient.SNI.TdsParserStateObjectManaged
r13              00007fa128ad9b70 System.Data.SqlClient.TdsParser
...
00007F9FA31546B0 00007fa3297b8fb8 System.Data.SqlClient.SqlDataReader
...

0:025> !DumpObj /d 00007fa3297b84d0
Name:        System.String
MethodTable: 00007fa477db0f90
EEClass:     00007fa477d1e230
Size:        2496(0x9c0) bytes
File:        /usr/share/dotnet/shared/Microsoft.NETCore.App/3.1.22/System.Private.CoreLib.dll
String:      select xxx,xxx,xxx,xxx from template_xxxreport where 1=1 
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007fa477daa0e8  400022a        8         System.Int32  1 instance             1237 _stringLength
00007fa477da6f00  400022b        c          System.Char  1 instance               73 _firstChar
00007fa477db0f90  400022c      108        System.String  0   static 00007fa027fff360 Empty

从 sql 看貌似是读了 template_xxxreport 表, 而且还没有筛选条件，看样子是深夜跑什么数据把 CPU 给抬起来了，那接下里的问题是什么地方会执行这条sql呢？

3. 到底在哪里执行的

刚才的线程栈看不到一句用户代码，我们还可以用 !gcroot 追踪下这个 sql 的祖宗，可能会有新的发现哦。


0:025> !gcroot 00007fa3297b84d0
    00007F9FA3154770 00007FA4803FA6CE System.Threading.Tasks.ContinuationResultTaskFromResultTask`2[[System.__Canon, System.Private.CoreLib],[System.__Canon, System.Private.CoreLib]].InnerInvoke() [/_/src/System.Private.CoreLib/shared/System/Threading/Tasks/TaskContinuation.cs @ 191]
        rbx: 
            ->  00007FA233579680 System.Threading.Tasks.ContinuationResultTaskFromResultTask`2[[System.Object, System.Private.CoreLib],[System.Threading.Tasks.Task`1[[System.Boolean, System.Private.CoreLib]], System.Private.CoreLib]]
            ->  00007FA233579748 System.Threading.Tasks.UnwrapPromise`1[[System.Boolean, System.Private.CoreLib]]
            ...
            ->  00007FA329BE4BB0 System.Threading.Tasks.StandardTaskContinuation
            ->  00007FA329BE4B18 System.Threading.Tasks.ContinuationTaskFromResultTask`1[[System.Boolean, System.Private.CoreLib]]
            ->  00007FA329BE4AD8 System.Action`1[[System.Threading.Tasks.Task`1[[System.Boolean, System.Private.CoreLib]], System.Private.CoreLib]]
            ->  00007FA329BE2AE8 System.Data.SqlClient.SqlDataReader+<>c__DisplayClass195_0`1[[System.Boolean, System.Private.CoreLib]]
            ->  00007FA32982AE50 System.Threading.Tasks.TaskCompletionSource`1[[System.Boolean, System.Private.CoreLib]]
            ->  00007FA32982AE68 System.Threading.Tasks.Task`1[[System.Boolean, System.Private.CoreLib]]
            ->  00007FA3297B91B0 System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[xxx.xxx.Template_xxxxReport, xxx.xxx],[Dapper.SqlMapper+<QueryRowAsync>d__34`1[[xxx.xxxx.Template_xxxxReport, xxx.xxxx]], Dapper]]
            ->  00007FA3297B84D0 System.String

从引用链条看，这条sql使用 Dapper 的 QueryRowAsync 查询，实体类是 xxx.xxxx.Template_xxxxReport，有了这些信息就好办了，反馈给朋友后，让朋友看下这是哪里的sql和model。

据朋友调查后，说是用的某商业数据访问sdk 内部逻辑不严谨造成的，参考代码如下：


    public async Task<T> FindEntity<T>(object param) where T : class
    
        //核心问题
        if (param == null)
        
            param = new  ;
        

        var parameters = param.ToObject();

        //参数拼接
        foreach (var item in parameters)
        
            // xxxxx

当 param =null 时，底层用 param = new ; 当无参数处理，这就导致全表sql的发生，朋友说现在想想都有点后怕。。。

三：总结

这次事故主要是由 某商业数据访问sdk 在异常参数处理时逻辑不严谨所致，毕竟 抛异常 比 全量查询 要好得多，大家在买商业组件的时候，且行且珍惜。

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

一：背景 1. 讲故事 哈哈，再次见到物流类软件，上个月有位朋友找到我，说他的程序出现了 CPU 爆高，让我帮忙看下什么原因，由于那段时间在苦心研究 C++，分析和经验分享也就懈怠了，今天就给大家安排上。 话不多说，上 windbg 说话。 二：WinDbg 分析 1. CPU 真的爆高吗 既然说

以上是关于记一次 某智能制造MES系统CPU 爆高分析的主要内容，如果未能解决你的问题，请参考以下文章

记一次 .NET 某机械臂智能机器人控制系统MRS CPU爆高分析

记一次 .NET 某机械臂智能机器人控制系统MRS CPU爆高分析

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

记一次 .NET 某医院HIS系统 CPU爆高分析

记一次.NET 某安全生产系统 CPU爆高分析

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