异族苗雄 发表于 2023-7-31 15:39:46

记一次 .NET 某物流API系统 CPU爆高分析

一:背景

1. 讲故事

前段时间有位朋友找到我,说他程序CPU直接被打满了,让我帮忙看下怎么回事,截图如下:

看了下是两个相同的程序,既然被打满了那就抓一个 dump 看看到底咋回事。
二:为什么会打满

1. 真的被打满了吗

凡事都要用数据说话,我们使用 !tp 命令观察一下。
0:014> !tp
logStart: 62
logSize: 200
CPU utilization: 100 %
Worker Thread: Total: 16 Running: 0 Idle: 16 MaxLimit: 32767 MinLimit: 8
Work Request in Queue: 0
--------------------------------------
Number of Timers: 8
--------------------------------------
Completion Port Thread:Total: 9 Free: 2 MaxFree: 16 CurrentLimit: 9 MaxLimit: 1000 MinLimit: 8从卦象看果然是被打满了,那为什么会满呢?一般来说CPU高是线程抬起来的,接下来我们就从线程入手。
2. 线程都在做什么事情

要想观察每个线程都在做什么,可以使用 ~*e !clrstack 命令,打完所有的线程栈后,明显发现有 6 处在 System.Text.RegularExpressions.RegexReplacement.Replace 正则替换这里,截图如下:

0:021> ~14s
ntdll!NtWaitForSingleObject+0x14:
00007ff9`c5d4fa74 c3            ret
0:014> !clrstack
OS Thread Id: 0x6ee0 (14)
      Child SP               IP Call Site
000000AC6CBF99C8 00007ff9c5d4fa74
000000AC6CBF9AC0 00007ff942416c05 System.String.Create[](Int32, System.Text.SegmentStringBuilder, System.Buffers.SpanAction`2<Char,System.Text.SegmentStringBuilder>)
000000AC6CBF9B20 00007ff942416aeb System.Text.SegmentStringBuilder.ToString()
000000AC6CBF9BA0 00007ff9422e62ac System.Text.RegularExpressions.RegexReplacement.Replace(System.Text.RegularExpressions.Regex, System.String, Int32, Int32)
000000AC6CBF9C70 00007ff9422e4ec6 System.Text.RegularExpressions.Regex.Replace(System.String, System.String, System.String, System.Text.RegularExpressions.RegexOptions)
000000AC6CBF9CD0 00007ff941e157aa SqlSugar.UtilMethods.ReplaceSqlParameter(System.String, SqlSugar.SugarParameter, System.String)
000000AC6CBF9F80 00007ff941e42990 SqlSugar.SqlSugarProvider+d__245`1[].MoveNext()
000000AC6CBFA300 00007ff94190e93c System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[](System.__Canon ByRef)
000000AC6CBFA360 00007ff941e420bd SqlSugar.SqlSugarProvider.SaveQueuesProviderAsync[](Boolean, System.Func`3<System.String,System.Collections.Generic.List`1<SqlSugar.SugarParameter>,System.Threading.Tasks.Task`1>)
000000AC6CBFA3D0 00007ff941e41a52 SqlSugar.SqlSugarProvider+d__224.MoveNext()
000000AC6CBFA480 00007ff94190e93c System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[](System.__Canon ByRef)
000000AC6CBFA4E0 00007ff941e418f4 SqlSugar.SqlSugarProvider.SaveQueuesAsync(Boolean)
000000AC6CBFA550 00007ff941e417fe SqlSugar.SqlSugarClient.SaveQueuesAsync(Boolean)
000000AC6CBFA5A0 00007ff941e4177e SqlSugar.SqlSugarScope.SaveQueuesAsync(Boolean)
000000AC6CBFA5F0 00007ff941e40fce xxx.Repository.BaseRepository`1+d__76[].MoveNext()
...
000000AC6D4FAAF0 00007ff9422c9d0c xxx.xxxService+d__15.MoveNext()
...从上面的 MoveNext 和 AsyncMethodBuilder 来看,这里用的是全异步写法,分析起来那是一个头大哈。。。不过仔细观察是 SqlSugar 在替换sql参数的时候引发的,一般来说和 Regular 有关的操作都是蛮耗 CPU 的,然后顺手看了下cpu配置也才 8 核,难怪 CPU 直接 100% 了。
0:014> !cpuid
CPF/M/SManufacturer   MHz
06,85,7<unavailable>   2500
16,85,7<unavailable>   2500
26,85,7<unavailable>   2500
36,85,7<unavailable>   2500
46,85,7<unavailable>   2500
56,85,7<unavailable>   2500
66,85,7<unavailable>   2500
76,85,7<unavailable>   25003. SqlSugar 到底在做什么

要想知道做什么,逆向一下代码就好,截图如下:

这种写法好不好我就不评价了,至少简单粗暴,那为什么会很耗时呢?这就要扒一下 ReplaceSqlParameter 方法中的三个参数,尤其是 itemSql 字段,然后使用 !clrstack -a。
0:014> !clrstack -a
OS Thread Id: 0x6ee0 (14)
      Child SP               IP Call Site
000000AC6CBF9CD0 00007ff941e157aa SqlSugar.UtilMethods.ReplaceSqlParameter(System.String, SqlSugar.SugarParameter, System.String)
    PARAMETERS:
      itemSql (0x000000AC6CBF9F80) = 0x0000023d802e1020
      itemParameter (0x000000AC6CBF9F88) = 0x0000023c4bd3ae58
      newName (0x000000AC6CBF9F90) = 0x0000023ca9dd3328
    LOCALS:
      0x000000AC6CBF9F68 = 0x0000000000000000

0:014> !do 0x0000023d802e1020
Name:      System.String
MethodTable: 00007ff93caad698
EEClass:   00007ff93ca89d60
Tracked Type: false
Size:      21391508(0x1466894) bytes
File:      C:\Program Files\dotnet\shared\Microsoft.NETCore.App\6.0.12\System.Private.CoreLib.dll
String:      <String is invalid or too large to print>

Fields:
            MT    Field   Offset               Type VT   Attr            Value Name
00007ff93ca9948040002f2      8         System.Int321 instance         10695743 _stringLength
00007ff93c9fea1040002f3      c          System.Char1 instance               49 _firstChar
00007ff93caad69840002f1       e8      System.String0   static 0000023c3f5613a0 Empty

0:014> ?0n21391508 /0x400
Evaluate expression: 20890 = 00000000`0000519a
从卦中看,简直是吓一跳,这个 sql 居然高达 20M,
来源:https://www.cnblogs.com/huangxincheng/archive/2023/07/31/17593608.html
免责声明:由于采集信息均来自互联网,如果侵犯了您的权益,请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容,谢谢合作!
页: [1]
查看完整版本: 记一次 .NET 某物流API系统 CPU爆高分析