最近產品發佈大版本補丁更新,一商超客戶升級後,反饋系統常常奔潰,致使超市的收銀系統沒法正常收銀,現場排隊付款的顧客更是抱怨聲聲。爲了緩解現場的狀況, 客戶都是手動回收IIS應用程序池才能解決。
css
這樣的後果是很嚴重的,接到反饋,第一時間想到的是加內存吧,這樣最快。可是客戶從8G-->16G-->32G,只是延長了每次奔潰的時間,可是並無解決系統卡頓的問題。到這裏,也基本猜想了問題所在了,確定是什麼東西一直在吃內存且得不到釋放。這種問題,也就只能打Dump分析了。html
遠程客戶應用服務器,32G內存佔用已經消耗了78%,而現場已經反饋收銀系統接近奔潰了,要求先強制回收內存。反正也要奔潰了,先打Dump再說吧。
(PS:打Dump會掛起進程,致使應用沒法響應!而打Dump的耗時,也是根據當時進程的內存佔用有關,內存佔用越大,耗時越久。)
打開任務管理器,選擇對應的IIS進程,右鍵建立轉儲文件(Dump)。
數組
結果,Dump文件是生成的,結果當分析的時候,發現Windbg提示Dump無效。說明Dump文件建立的有問題。觀察任務管理器,發現內存佔用一下就降下來了,原來是以前的進程直接奔潰了,重啓了一個W3WP進程。緩存
既然直接從任務管理器沒法建立,就使用第三方工具收集Dump吧。通過Goggle,找到一款很好用的Dump收集工具ProcDump,是一個命令行應用,其主要用途是監視應用程序的CPU或內存峯值並在峯值期間生成Dump。服務器
由於是高內存佔用問題,咱們使用如下命令來抓取dump:
(PS:可使用進程名稱,也可使用進程ID來指定要建立Dump的進程。當有多個相同名稱的進程時,必須使用進程ID來指定!)markdown
procdump w3wp -m 20480 -o D:\Dumps (當內存超過20G時抓取一個w3wp進程的MiniDump)併發
上面就是我踩得第一個坑,由於默認抓取的是MiniDump,很快就抓下來,文件也很小,正在我得意的時候,Windbg加載Dump分析的時候,發現包含的信息不多,根本沒法進行進一步的分析。app
調整建立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終於成功建立了。
分析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以上。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).
從以上輸出能夠看出:
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.
從輸出結果來看:
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
從輸出能夠看出:
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.SqlClient.SqlCommand, System.Data.SqlClient