1. 问题简介
最近产品发布大版本补丁更新,一商超客户升级后,反馈系统经常奔溃,导致超市的收银系统无法正常收银,现场排队付款的顾客更是抱怨声声。为了缓解现场的情况, 客户都是手动回收IIS应用程序池才能解决。
这样的后果是很严重的,接到反馈,第一时间想到的是加内存吧,这样最快。但是客户从8G-->16G-->32G,只是延长了每次奔溃的时间,但是并没有解决系统卡顿的问题。到这里,也基本猜测了问题所在了,肯定是什么东西一直在吃内存且得不到释放。这种问题,也就只能打Dump分析了。
2. 打Dump
远程客户应用服务器,32G内存占用已经消耗了78%,而现场已经反馈收银系统接近奔溃了,要求先强制回收内存。反正也要奔溃了,先打Dump再说吧。 (PS:打Dump会挂起进程,导致应用无法响应!而打Dump的耗时,也是根据当时进程的内存占用有关,内存占用越大,耗时越久。) 打开任务管理器,选择对应的IIS进程,右键创建转储文件(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再次创建失败,提示: ProcdumpErrorwritingdumpfile
。再一次感觉到绝望。不过至少有错误提示,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
...
0000021bcbaf5158 00007ffdb9386948 1140
0000021d375d1038 00007ffdb9386948 149698
0000021d375f5920 00007ffdb9386948 149698
0000021d3765b138 00007ffdb9386948 149706
0000021d37f739c8 00007ffdb9386948 217120
0000021d37fa8a08 00007ffdb9386948 190162
0000021d38047330 00007ffdb9386948 1224698
0000021d3829d348 00007ffdb9386948 1224698
0000021d386bd678 00007ffdb9386948 2610994
0000021d38bb8500 00007ffdb9386948 2610994
Statistics:
MT Count TotalSize Class Name
00007ffdb9386948 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.Concurr