记一次某制造业ERP系统 CPU打爆事故分析

科技资讯 投稿 27300 0 评论

记一次某制造业ERP系统 CPU打爆事故分析

一:背景

1.讲故事

CPU 密集型运算,所以让朋友在 CPU 高的时候间隔 5~10s 抓两个 dump 下来,然后就是用 WinDbg 分析。

二:WinDbg 分析

1. CPU 真的爆高吗

!tp 观察下当前的CPU情况。

0:000> !tp
CPU utilization: 100%
Worker Thread: Total: 16 Running: 2 Idle: 14 MaxLimit: 32767 MinLimit: 2
Work Request in Queue: 0
--------------------------------------
Number of Timers: 2
--------------------------------------
Completion Port Thread:Total: 2 Free: 2 MaxFree: 4 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 2

果不其然,CPU直接打满,接下来就是看看当前有几个CPU逻辑核,这么不够扛。

0:000> !cpuid
CP  F/M/S  Manufacturer     MHz
 0  6,106,6  <unavailable>   2700
 1  6,106,6  <unavailable>   2700

我去,一个生产环境居然只有两个核。果然这大环境下公司活着都不够滋润。

2. 到底是谁引发的

~*e !clrstack 命令即可,因为只有两核,所以理论上两个线程就可以把 CPU 干趴下,扫了一下线程栈,果然有对号入座的,输出信息如下:

0:000> ~*e !clrstack 
OS Thread Id: 0x146c (42
        Child SP               IP Call Site
00000089abcfca18 00007ffc4baffdb4 [InlinedCallFrame: 00000089abcfca18] System.Drawing.SafeNativeMethods+Gdip.IntGdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089abcfca18 00007ffbdd4a7a48 [InlinedCallFrame: 00000089abcfca18] System.Drawing.SafeNativeMethods+Gdip.IntGdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089abcfc9f0 00007ffbdd4a7a48 DomainNeutralILStubClass.IL_STUB_PInvoke(System.Runtime.InteropServices.HandleRef
00000089abcfcaa0 00007ffbdd52ad0a System.Drawing.SafeNativeMethods+Gdip.GdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089abcfcae0 00007ffbdd52ac3f System.Drawing.Image.Dispose(Boolean
00000089abcfcb30 00007ffbdd556b5a System.Drawing.Image.Dispose(
00000089abcfcb60 00007ffbe39397c7 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089abcfcc00 00007ffbe3939654 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089abcfcd30 00007ffbe39382e1 NPOI.SS.Util.SheetUtil.GetColumnWidth(NPOI.SS.UserModel.ISheet, Int32, Boolean
00000089abcfcdc0 00007ffbe39380bc NPOI.XSSF.UserModel.XSSFSheet.AutoSizeColumn(Int32, Boolean
...

OS Thread Id: 0x1c8c (46
        Child SP               IP Call Site
00000089ad43dba8 00007ffc4baffdb4 [InlinedCallFrame: 00000089ad43dba8] System.Drawing.SafeNativeMethods+Gdip.IntGdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089ad43dba8 00007ffbdd4a7a48 [InlinedCallFrame: 00000089ad43dba8] System.Drawing.SafeNativeMethods+Gdip.IntGdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089ad43db80 00007ffbdd4a7a48 DomainNeutralILStubClass.IL_STUB_PInvoke(System.Runtime.InteropServices.HandleRef
00000089ad43dc30 00007ffbdd52ad0a System.Drawing.SafeNativeMethods+Gdip.GdipDisposeImage(System.Runtime.InteropServices.HandleRef
00000089ad43dc70 00007ffbdd52ac3f System.Drawing.Image.Dispose(Boolean
00000089ad43dcc0 00007ffbdd556b5a System.Drawing.Image.Dispose(
00000089ad43dcf0 00007ffbe39397c7 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089ad43dd90 00007ffbe3939654 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089ad43dec0 00007ffbe39382e1 NPOI.SS.Util.SheetUtil.GetColumnWidth(NPOI.SS.UserModel.ISheet, Int32, Boolean
00000089ad43df50 00007ffbe39380bc NPOI.XSSF.UserModel.XSSFSheet.AutoSizeColumn(Int32, Boolean
...
00000089ad43e460 00007ffbe115b193 System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(System.Web.Mvc.ControllerContext, System.Web.Mvc.ActionDescriptor, System.Collections.Generic.IDictionary`2<System.String,System.Object>
...
00000089abcfd310 00007ffbe115b147 System.Web.Mvc.Async.AsyncControllerActionInvoker+c.b__9_0(System.IAsyncResult, ActionInvocation
...

有些朋友要问了,你是怎么确定就是这两个线程呢? 其实有两个方法可以验证。

  1. 使用 !whttp 看http请求

HttpContext,这里面记录着当前请求的运行时间,这个信息非常重要,截图如下:

xxxx/Export 请求运行时间非常高,一个是 4min30s,一个是 50s,刚好落在了 4246 号线程上。

  1. 借助第二个 dump 文件

!whttp 验证。

3. 为什么会运行这么久

既然是 Export 导出文件,第一时间就应该想到是不是和数据量有关?通过线程栈上的方法,发现是一个List 集合,接下来用 !dso 命令找出来看看。

0:042> !dso
OS Thread Id: 0x146c (42
RSP/REG          Object           Name
00000089ABCFCAC8 0000020683b7c128 System.Drawing.Bitmap
00000089ABCFCAF8 0000020683b7c158 System.Drawing.Graphics
00000089ABCFCB10 0000020683b7c128 System.Drawing.Bitmap
00000089ABCFCB30 0000020683b7c128 System.Drawing.Bitmap
00000089ABCFCB40 0000020683b7c4d0 NPOI.XSSF.UserModel.XSSFCellStyle
00000089ABCFCB50 0000020683b7c198 NPOI.XSSF.UserModel.XSSFRichTextString
00000089ABCFCB68 0000020683b7c198 NPOI.XSSF.UserModel.XSSFRichTextString
00000089ABCFCBC0 0000020683b7c198 NPOI.XSSF.UserModel.XSSFRichTextString
00000089ABCFCBC8 0000020683b7c2e8 System.String[]
00000089ABCFCBD0 0000020683b7c360 System.Drawing.Font
00000089ABCFCDE8 0000020666501240 System.Collections.Generic.List`1[[System.Collections.Generic.List`1[[System.Object, mscorlib]], mscorlib]]
...

0:042> !do 0000020666501240
Name:        System.Collections.Generic.List`1[[System.Collections.Generic.List`1[[System.Object, mscorlib]], mscorlib]]
MethodTable: 00007ffbde342440
EEClass:     00007ffc36fc2af8
Size:        40(0x28 bytes
File:        C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ffc36e4e250  40018a0        8     System.__Canon[]  0 instance 00000207658592d8 _items
00007ffc36e385a0  40018a1       18         System.Int32  1 instance            44906 _size
00007ffc36e385a0  40018a2       1c         System.Int32  1 instance            44906 _version
00007ffc36e35dd8  40018a3       10        System.Object  0 instance 0000000000000000 _syncRoot
00007ffc36e4e250  40018a4        0     System.__Canon[]  0   shared           static _emptyArray
                                 >> Domain:Value dynamic statics NYI 0000020563eec3c0:NotInit dynamic statics NYI 0000020795f5b9a0:NotInit  <<

可以清楚的看到,这个list高达 4.5w,这个量级说多也不多,说少也不少,言外之意就是代码写的也不好不到哪里去。

4. 用户代码要承担责任吗

AutoSizeColumn 方法有关。

00000089abcfcae0 00007ffbdd52ac3f System.Drawing.Image.Dispose(Boolean
00000089abcfcb30 00007ffbdd556b5a System.Drawing.Image.Dispose(
00000089abcfcb60 00007ffbe39397c7 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089abcfcc00 00007ffbe3939654 NPOI.SS.Util.SheetUtil.GetCellWidth(NPOI.SS.UserModel.ICell, Int32, NPOI.SS.UserModel.DataFormatter, Boolean
00000089abcfcd30 00007ffbe39382e1 NPOI.SS.Util.SheetUtil.GetColumnWidth(NPOI.SS.UserModel.ISheet, Int32, Boolean
00000089abcfcdc0 00007ffbe39380bc NPOI.XSSF.UserModel.XSSFSheet.AutoSizeColumn(Int32, Boolean

从名字看是 NOPI 提供的自动调整列宽 的方法,那是不是这个方法的单次性能很慢呢?要寻找答案,只能求助百度啦。

5min + 的诱因大概有三个。

  1. AutoSizeColumn 速度慢

  2. 跟朋友沟通后,朋友说这块请求中的 AutoSizeColumn方法忘了改掉。

三:总结

AutoSizeColumn 方法,弄不好就得出个生产事故!

编程笔记 » 记一次某制造业ERP系统 CPU打爆事故分析

赞同 (31) or 分享 (0)
游客 发表我的评论   换个身份
取消评论

表情
(0)个小伙伴在吐槽