Windbg分析高内存占用问题

最新推荐文章于 2023-05-19 10:30:45 发布

weixin_30632883

最新推荐文章于 2023-05-19 10:30:45 发布

阅读量229

点赞数

文章标签： json runtime

原文链接：http://www.cnblogs.com/zhy-1992/p/9516629.html

版权

1. 问题简介

最近产品发布大版本补丁更新，一商超客户升级后，反馈系统经常奔溃，导致超市的收银系统无法正常收银，现场排队付款的顾客更是抱怨声声。为了缓解现场的情况，客户都是手动回收IIS应用程序池才能解决。
现场排队情况

这样的后果是很严重的，接到反馈，第一时间想到的是加内存吧，这样最快。但是客户从8G-->16G-->32G，只是延长了每次奔溃的时间，但是并没有解决系统卡顿的问题。到这里，也基本猜测了问题所在了，肯定是什么东西一直在吃内存且得不到释放。这种问题，也就只能打Dump分析了。

2. 打Dump

远程客户应用服务器，32G内存占用已经消耗了78%，而现场已经反馈收银系统接近奔溃了，要求先强制回收内存。反正也要奔溃了，先打Dump再说吧。
（PS：打Dump会挂起进程，导致应用无法响应！而打Dump的耗时，也是根据当时进程的内存占用有关，内存占用越大，耗时越久。）
打开任务管理器，选择对应的IIS进程，右键创建转储文件（Dump）。
打Dump

结果，Dump文件是生成的，结果当分析的时候，发现Windbg提示Dump无效。说明Dump文件创建的有问题。观察任务管理器，发现内存占用一下就降下来了，原来是之前的进程直接奔溃了，重启了一个W3WP进程。

既然直接从任务管理器无法创建，就使用第三方工具收集Dump吧。经过Goggle，找到一款很好用的Dump收集工具ProcDump，是一个命令行应用，其主要用途是监视应用程序的CPU或内存峰值并在峰值期间生成Dump。

因为是高内存占用问题，我们使用以下命令来抓取dump：
（PS：可以使用进程名称，也可以使用进程ID来指定要创建Dump的进程。当有多个相同名称的进程时，必须使用进程ID来指定！）

procdump w3wp -m 20480 -o D:\Dumps （当内存超过20G时抓取一个w3wp进程的MiniDump）

上面就是我踩得第一个坑，因为默认抓取的是MiniDump，很快就抓下来，文件也很小，正在我得意的时候，Windbg加载Dump分析的时候，发现包含的信息很少，根本无法进行进一步的分析。

调整创建Dump的命令，添加-ma参数即可创建完整Dump。

procdump w3wp -ma -m 20480 -o D:\Dumps （当内存超过20G时抓取一个w3wp进程的完整Dump）

结果再一次，当内存占用到达20G，占比80%的时候，Dump再次创建失败，提示：Procdump Error writing dump file。再一次感觉到绝望。不过至少有错误提示，Google一把，果然存在天涯沦落人。Procdump Error writing dump file: 0x80070005 Error 0x80070005 (-2147024891): Access is denied。大致的意思是说，当90S内Dump文件没有成功创建的话（也就意外这w3wp进程被挂起了90s），IIS检测到w3wp进程挂起超过90s没有响应就会终止进程，重现创建一个新的进程。好嘛，真是处处是坑。

这个坑，也让我开始真正停下来思考问题。罗马不是一日建成的，内存也不是一下撑爆的。我干嘛死脑筋非要到内存占用超过80%才去打Dump呢呢呢？？？！

焕然大悟，如醍醐灌顶。

procdump w3wp -ma -m 8000 -o D:\Dumps （当内存超过8000M时抓取一个w3wp进程的完整Dump，并输出到D:\Dumps文件夹）

此时内存占用在40%左右，这次Dump终于成功创建了。

3..分析Dump

分析Dump，上WinDbg。如果对WinDbg不理解，可以看我这篇WinDbg学习笔记。

接下来就是一通命令乱敲，我尽量解释清晰。

0:000> !dumpheap -stat //检查当前所有托管类型的统计信息
....
00007ffdb9387a98   777101     69462436 System.Char[]
00007ffdb938c988   588917    115563505 System.Byte[]
00007ffdb9389220  1026406    119828936 System.Int32[]
00007ffdb93516a8   663559    128819040 System.Collections.Generic.Dictionary`2+Entry[[System.String, mscorlib],[System.Object, mscorlib]][]
00000218c6c30a80  6436865    197832116      Free
00007ffdae9cc240    23171    273333144 System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]][]
00007ffdb9391f28 13885170    333244080 System.Boolean
00007ffd5c24a068 14003455    560138200 Kingdee.BOS.JSON.JSONArray
00007ffdb9386fc0 14373648   1393615400 System.Object[]
00007ffdb9386948 76146065   4000287202 System.String
Total 138435970 objects

使用dumpheap -stat命令查看当前所有托管类型的统计信息。从输出的结果来看：

其中占用内存最多当属System.String类型，接近4G的大小（是不是很吃惊？!）。
其次System.Object[]类型占有1.3G大小。
Kingdee.BOS.JSON.JSONArray类型也大概占用了560M。

我们首先来分析占用最多的System.String类型，看看有什么发现。

0:000> !dumpheap -mt 00007ffdb9386948 -min 200 //查看200byte以上的string
Address               MT     Size
...
000021bcbaf5158 0007ffdb9386948     1140 000021d375d1038 0007ffdb9386948 149698 000021d375f5920 0007ffdb9386948 149698 000021d3765b138 0007ffdb9386948 149706 000021d37f739c8 0007ffdb9386948 217120 000021d37fa8a08 0007ffdb9386948 190162 0000021d38047330 0007ffdb9386948 1224698 000021d3829d348 0007ffdb9386948 1224698 000021d386bd678 0007ffdb9386948 2610994 000021d38bb8500 0007ffdb9386948 2610994 Statistics: MT Count TotalSize Class Name 0007ffdb9386948 10991 76632628 System.String Total 10991 objects

从上面的输出可以发现：

单个System.String类型最大占用2M以上。
超过200byte的字节的大小的System.String总大小也不过76M。（所以我们也不必深究大的String对象。）

那我们索性挑一个小点的对象来看看存储的是什么字符串，来满足一下我们的好奇心。

0.000> !do 0000021bcbaf5158 //使用!do命令查看一个对象的内容
Name:        System.String
MethodTable: 00007ffdb9386948 EEClass: 00007ffdb8c850e0 Size: 1140(0x474) bytes File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll String: 5b13710029d012False2052_T_BD_MATERIAL_MATERIAL.FAuxPropertyIdFBaseUnitIdFCategoryIDFChargeIDFCheckIncomingFDefaultVendorFErpClsIDFInvPtyIdFIsAffectPlanFIsAffectPlan1FIsBatchManageFIsComControlFIsEnableFIsEnable1FIsExpParToFlotFIsInventoryFIsPRFIsReturnMaterialFIsSourceControlFIsVmiBusinessFNameFNumberFPlanModeFPurchasePriceUnitIdFPurchaseUnitIdFPurPriceURNomFPurPriceURNumFPurURNomFPurURNumFReceiveAdvanceDaysFReceiveDelayDaysFReceiveMaxScaleFReceiveMinScaleFSalePriceUnitIdFSaleUnitIdFSpecificationFStockIdFStockPlaceIdFStoreUnitIDFTaxTypeFUseOrgId111193 Fields: MT Field Offset Type VT Attr Value Name 00007ffdb9389288 400026f 8 System.Int32 1 instance 557 m_stringLength 00007ffdb9387b00 4000270 c System.Char 1 instance 35 m_firstChar 00007ffdb9386948 4000274 90 System.String 0 shared static Empty >> Domain:Value 00000218c6c4d220:NotInit 0000021d52d81840:NotInit <<

似乎是基础资料字段信息。那接下来使用!gcroot命令查看其对应的GC根，看看到底是什么对象持有其引用，导致占用内存得不到释放。

0:000> !gcroot 0000021bcbaf5158 //使用!gcroot 查看一个对象的gc根
HandleTable:
    00000218c6ff15e8 (pinned handle)
    -> 0000021cc75ebe68 System.Object[] -> 0000021bc7629a10 Kingdee.BOS.Cache.KCacheManagerFactory -> 0000021bc7629ab8 System.Collections.Generic.Dictionary`2[[System.String, mscorlib],[Kingdee.BOS.Cache.AbstractKCacheManager, Kingdee.BOS]] -> 0000021c4da6fa48 System.Collections.Generic.Dictionary`2+Entry[[System.String, mscorlib],[Kingdee.BOS.Cache.AbstractKCacheManager, Kingdee.BOS]][] -> 00000218c83861b8 Kingdee.BOS.Cache.KCacheManager -> 00000218c8386630 Kingdee.BOS.Cache.ECache.ECacheManager -> 00000218c83866e8 System.Collections.Concurrent.ConcurrentDictionary`2[[System.String, mscorlib],[System.Collections.Generic.HashSet`1[[System.String, mscorlib]], System.Core]] -> 0000021bcbae0c70 System.Collections.Concurrent.ConcurrentDictionary`2+Tables[[System.String, mscorlib],[System.Collections.Generic.HashSet`1[[System.String, mscorlib]], System.Core]] -> 0000021bcbad0128 System.Collections.Concurrent.ConcurrentDictionary`2+Node[[System.String, mscorlib],[System.Collections.Generic.HashSet`1[[System.String, mscorlib]], System.Core]][] -> 0000021bcbb34bf8 System.Collections.Concurrent.ConcurrentDictionary`2+Node[[System.String, mscorlib],[System.Collections.Generic.HashSet`1[[System.String, mscorlib]], System.Core]] -> 0000021bcbada790 System.Collections.Concurrent.ConcurrentDictionary`2+Node[[System.String, mscorlib],[System.Collections.Generic.HashSet`1[[System.String, mscorlib]], System.Core]] -> 0000021a49766460 System.Collections.Generic.HashSet`1[[System.String, mscorlib]] -> 00000219540976b0 System.Collections.Generic.HashSet`1+Slot[[System.String, mscorlib]][] -> 0000021bcbaf5158 System.String Found 1 unique roots (run '!GCRoot -all' to see all roots).

从以上输出可以看出：

该String类型被一个Hashset所持有。
从Cache关键字可以看出该String类型是被缓存所持有。

分析到这里，我们大致可以得出一个结论：

String类型占用4G内存，绝大多数是由缓存所占用，才导致String类型得不到释放。

那我们是不是可以猜测内存占用持续走高是不是被缓存撑爆的呢？。

带着这个疑问我们来继续分析下Kingdee.BOS.JSON.JSONArray类型。

0:000> !dumpheap -mt 00007ffd5c24a068 //输出托管堆上的所有JSONArray对象
         Address MT Size .... 0000021975972b48 00007ffd5c24a068 40 00000218c933f060 00007ffd5c24a068 40 00000218c7605990 00007ffd5c24a068 40 00000218c7605af0 00007ffd5c24a068 40 00000218c7605c50 00007ffd5c24a068 40 00000218c7605e18 00007ffd5c24a068 40 00000218c7605fa0 00007ffd5c24a068 40 00000218c7606198 00007ffd5c24a068 40 00000218c7606338 00007ffd5c24a068 40 00000218c76064b0 00007ffd5c24a068 40 User interrupt.

从输出结果来看：

满屏都是40byte的JSONArray。只能使用Ctrl+Break命令中止输出。

但为了保险期间，我们来验证下有没有100byte以上的JSONArray。

0:000> !dumpheap -mt 00007ffd5c24a068 -min 100
         Address               MT     Size

Statistics:
              MT    Count TotalSize Class Name Total 0 objects

这时我们可以大胆猜测所有的JSONArray对象都是40byte。从而可以得出另一个猜测占用560M内存的JSONArray，都具有相似的对象结构。接下来我们来验证这个猜测。随机选择几个对象，看看其内容具体是什么。

0:000> !DumpObj /d 0000021975972b48  //查看第一个JSONArray
Name:        System.Object[] MethodTable: 00007ffdb9386fc0 EEClass: 00007ffdb8d4aa00 Size: 88(0x58) bytes Array: Rank 1, Number of elements 8, Type CLASS (Print Array) Fields: None

从输出可以看出：

JSONArray实质是System.Object[]类型。
对应的MethodTable: 00007ffdb9386fc0。

如果你记性好的话，我们应当还记得占用内存第二多的就是这个System.Object[]类型，占用1.3G。翻到上面，你可以发现其MethodTable和上面的统计信息是一致的。
（PS：到这里我们是不是可以猜测：System.Object[]占用的内存无法释放，就是由于被JSONArray持有引用导致的呢？）

既然是数组，就使用!DumpArray 命令来解开数组的面纱。

0:000> !DumpArray /d 0000021975972b48 
Name:        System.Object[]
MethodTable: 00007ffdb9386fc0 EEClass: 00007ffdb8d4aa00 Size: 88(0x58) bytes Array: Rank 1, Number of elements 8, Type CLASS Element Methodtable: 00007ffdb9386f28 [0] 0000021975972a08 [1] 0000021975972a70 [2] 0000021975972a40 [3] 0000021ac75e87b8 [4] 0000021975972b10 [5] 0000021975972ba0 [6] null [7] null 0:000> !DumpObj /d 0000021975972a08 Name: System.String MethodTable: 00007ffdb9386948 EEClass: 00007ffdb8c850e0 Size: 54(0x36) bytes File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll String: 555d8ca25a6261 Fields:7 MT Field Offset Type VT Attr Value Name 00007ffdb9389288 400026f 8 System.Int32 1 instance 14 m_stringLength 00007ffdb9387b00 4000270 c System.Char 1 instance 35 m_firstChar 00007ffdb9386948 4000274 90 System.String 0 shared static Empty >> Domain:Value 00000218c6c4d220:NotInit 0000021d52d81840:NotInit <<

从以上输出可以看出，其共有8个子项，我们再随机挑几个子项看看是什么内容。

0:000> !DumpObj /d 0000021975972a70
Name:        System.String
MethodTable: 00007ffdb9386948 EEClass: 00007ffdb8c850e0 Size: 42(0x2a) bytes File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll String: FHTZDLB Fields: MT Field Offset Type VT Attr Value Name 00007ffdb9389288 400026f 8 System.Int32 1 instance 8 m_stringLength 00007ffdb9387b00 4000270 c System.Char 1 instance 50 m_firstChar 00007ffdb9386948 4000274 90 System.String 0 shared static Empty >> Domain:Value 00000218c6c4d220:NotInit 0000021d52d81840:NotInit << 0:000> !DumpObj /d 0000021975972a40 Name: System.String MethodTable: 00007ffdb9386948 EEClass: 00007ffdb8c850e0 Size: 42(0x2a) bytes File: C:\Windows\Microsoft.Net\assembly\GAC_64\mscorlib\v4.0_4.0.0.0__b77a5c561934e089\mscorlib.dll String: 发货通知单列表 Fields: MT Field Offset Type VT Attr Value Name 00007ffdb9389288 400026f 8 System.Int32 1 instance 8 m_stringLength 00007ffdb9387b00 4000270 c System.Char 1 instance 6279 m_firstChar 00007ffdb9386948 4000274 90 System.String 0 shared static Empty >> Domain:Value 00000218c6c4d220:NotInit 0000021d52d81840:NotInit <<

我们可以看到一个字符串内容是FHTZDLB，另一个是发货通知单列表。看到这，我立马就条件反射的想到，这不就是我们的菜单信息嘛。为了验证我的想法，连续查看几个JSONArray，都是相似的内容。

这时，我们继续发扬敢猜敢做的精神。是不是内存被菜单缓存撑爆的？！

为了验证这一猜测，我们继续从Dump中寻找佐证。使用~* e!clrstack来看看所有线程的调用堆栈吧。

0:000> ~* e!clrstack
OS Thread Id: 0x11dc (0) Unable to walk the managed stack. The current thread is likely not a managed thread. You can run !threads to get a list of managed threads in the process Failed to start stack walk: 80070057 OS Thread Id: 0x2b2c (28) Child SP IP Call Site 00000076cff7ecc8 00007ffdca2e6bf4 [HelperMethodFrame_1OBJ: 00000076cff7ecc8] System.Threading.WaitHandle.WaitMultiple(System.Threading.WaitHandle[], Int32, Boolean, Boolean) 00000076cff7ee00 00007ffdb91af67c System.Threading.WaitHandle.WaitAny(System.Threading.WaitHandle[], Int32, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\waithandle.cs @ 454] 00000076cff7ee60 00007ffdb201b2fb System.Net.TimerThread.ThreadProc() 00000076cff7ef10 00007ffdb915ca72 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 954] 00000076cff7efe0 00007ffdb915c904 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 902] 00000076cff7f010 00007ffdb915c8c2 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [f:\dd\ndp\clr\src\BCL\system\threading\executioncontext.cs @ 891] 00000076cff7f060 00007ffdb9196472 System.Threading.ThreadHelper.ThreadStart() [f:\dd\ndp\clr\src\BCL\system\threading\thread.cs @ 111] 00000076cff7f2b8 00007ffdbb4f6793 [GCFrame: 00000076cff7f2b8] 00000076cff7f608 00007ffdbb4f6793 [DebuggerU2MCatchHandlerFrame: 00000076cff7f608] 00000076cff7f798 00007ffdbb4f6793 [ContextTransitionFrame: 00000076cff7f798] 00000076cff7f9c8 00007ffdbb4f6793 [DebuggerU2MCatchHandlerFrame: 00000076cff7f9c8] OS Thread Id: 0x1bd4 (133) Child SP IP Call Site GetFrameContext failed: 1 0000000000000000 0000000000000000 OS Thread Id: 0x1a98 (134) Child SP IP Call Site 00000076dbdbcc88 00007ffdca2e6124 [InlinedCallFrame: 00000076dbdbcc88] .SNIReadSyncOverAsync(SNI_ConnWrapper*, SNI_Packet**, Int32) 00000076dbdbcc88 00007ffdaaaf5dd4 [InlinedCallFrame: 00000076dbdbcc88] .SNIReadSyncOverAsync(SNI_ConnWrapper*, SNI_Packet**, Int32) 00000076dbdbcc60 00007ffdaaaf5dd4 DomainNeutralILStubClass.IL_STUB_PInvoke(SNI_ConnWrapper*, SNI_Packet**, Int32) 00000076dbdbcd10 00007ffdaab08fe3 SNINativeMethodWrapper.SNIReadSyncOverAsync(System.Runtime.InteropServices.SafeHandle, IntPtr ByRef, Int32) 00000076dbdbcd70 00007ffdaabe0ae0 System.Data.SqlClient.TdsParserStateObject.ReadSniSyncOverAsync() 00000076dbdbcdd0 00007ffdaabe09dd System.Data.SqlClient.TdsParserStateObject.TryReadNetworkPacket() 00000076dbdbce10 00007ffdaabdf7f5 System.Data.SqlClient.TdsParserStateObject.TryPrepareBuffer() 00000076dbdbce50 00007ffdaabdfa0e System.Data.SqlClient.TdsParserStateObject.TryReadByte(Byte ByRef) 00000076dbdbce90 00007ffdaabc7daa System.Data.SqlClient.TdsParser.TryRun(System.Data.SqlClient.RunBehavior, System.Data

转载于:https://www.cnblogs.com/zhy-1992/p/9516629.html

weixin_30632883

关注

0
点赞
踩
0

收藏

觉得还不错? 一键收藏
0
评论
Windbg分析高内存占用问题

1. 问题简介最近产品发布大版本补丁更新，一商超客户升级后，反馈系统经常奔溃，导致超市的收银系统无法正常收银，现场排队付款的顾客更是抱怨声声。为了缓解现场的情况，客户都是手动回收IIS应用程序池才能解决。这样的后果是很严重的，接到反馈，第一时间想到的是加内存吧，这样最快。但是客户从8G-->16G-->32G，只是延长了每次奔溃的时间，但是并没有解决系统卡顿的问题。到这里...
复制链接

扫一扫