Hi all,
The other day I was working with a customer of mine on a .NET application which was suffering from a memory leak. The weird thing was that the application could run just fine for 10 days in a row before the memory began growing and growing. What was going on? Why was the Garbage Collector suddenly deciding to stop working? Additionally, this issue was happening with both .NET 1.1 and 2.0. Weird.
So we got a dump of a .NET 1.1 version of the application when the issue began. We used Adplus to take a hang dump we could analize (How to use ADPlus to troubleshoot "hangs" and "crashes").
We loaded SOS debugger extension (the one that comes with .NET Framework 1.1):
0:000>.load sos
And we went to check all objects currently on the heap:
0:000> !dumpheap -stat Loaded Son of Strike data table version 5 from "C:\WINNT\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll" Loading the heap objects into our cache. total 1,958,563 objects Statistics: MT Count TotalSize Class Name ...
Almost 2 million objects! That is a lot. Are any of them ready for finalization?
0:000> !finalizequeue Loaded Son of Strike data table version 5 from "C:\WINNT\Microsoft.NET\Framework\v1.1.4322\mscorwks.dll" SyncBlock to be cleaned up: 6371 ---------------------------------- MTA interfaces to be released: 0 Total STA interfaces to be released: 0 ---------------------------------- generation 0 has 215 finalizable objects (0x17daef74->0x17daf2d0) generation 1 has 0 finalizable objects (0x17daef74->0x17daef74) generation 2 has 15,317 finalizable objects (0x17da0020->0x17daef74) Ready for finalization 0 objects (0x17daf2d0->0x17daf2d0) - Freachable queue All Finalizable Objects Statistics: MT Count TotalSize Class Name ...
So apparently there are no objects ready to be finalized, but we have 6371 SyncBlocks ready to be cleaned up. Why? What are those SyncBlocks?
0:000> !finalizequeue -detail To be cleaned Com Data 0x4edc1b8 ComPlusWrapper 0x4edc590 ComPlusWrapper ... 0x4e227b8 ComPlusWrapper SyncBlock to be cleaned up: 6371 ---------------------------------- MTA interfaces to be released: 0 Total STA interfaces to be released: 0 ...
Ok, so those SyncBlocks are related to ComPlusWrappers which need to be cleaned up. It seems the application is referencing some COM objects which are not needed anymore.
And what is the Finalizer thread doing that is not cleaning up those objects? Is it too busy?
0:000> !threads ThreadCount: 23 UnstartedThread: 0 BackgroundThread: 17 PendingThread: 0 DeadThread: 0 PreEmptive GC Alloc Lock ID ThreadOBJ State GC Context Domain Count APT Exception 0 0x7a4 0x0013e1b8 0xa020 Enabled 0x00000000:0x00000000 0x00138fa0 0 MTA 2 0x484 0x0014a508 0xb220 Enabled 0x00000000:0x00000000 0x00138fa0 0 MTA (Finalizer) ... 0:000> ~2s 0:002> kL100 ChildEBP RetAddr 02a5f980 77f8822a NTDLL!ZwWaitForSingleObject+0xb 02a5f9f4 77f8819b NTDLL!RtlpWaitForCriticalSection+0x9e 02a5f9fc 72e55ff1 NTDLL!RtlEnterCriticalSection+0x46 02a5fa08 72e56010 msxml3!X_CRITICAL_SECTION::Enter+0xc 02a5fa10 72e5b735 msxml3!CSMutex::Enter+0xd 02a5fa20 72e5b6fd msxml3!RemovePointerFromCache+0x2e 02a5fa2c 72e55cfe msxml3!GCObject::~GCObject+0x15 02a5fa38 72e55c21 msxml3!_array<_reference >::`vector deleting destructor'+0xd 02a5fa44 72e5b5b6 msxml3!Base::weakRelease+0x19 02a5fa54 72e5b565 msxml3!Base::_release+0x95 02a5fa5c 72e5685d msxml3!DefaultWriter::Release+0xd 02a5fa74 72e60805 msxml3!assign+0x26 02a5fa8c 72e5ff5f msxml3!NodeData::setText+0x1e 02a5fa98 72e5b5a5 msxml3!Node::finalize+0x73 02a5faa8 72e60b7d msxml3!Base::_release+0x76 02a5fac0 72e6098b msxml3!Node::setNodeParent+0x7f 02a5fae0 72e5ff9a msxml3!Node::_remove+0x90 02a5faec 72e5b5a5 msxml3!Node::finalize+0x65 02a5fafc 72e60ae4 msxml3!Base::_release+0x76 02a5fb14 72e5c36e msxml3!Node::_release+0x77 02a5fb2c 72e5c1a7 msxml3!Node::_release+0x8d 02a5fb40 72e5b54e msxml3!Node::Release+0x26 02a5fb4c 72e70e12 msxml3!release+0x17 02a5fb58 72e70ddf msxml3!DOMNodeList::~DOMNodeList+0x16 02a5fb64 72e56962 msxml3!DOMNamedNodeMapList::`vector deleting destructor'+0x16 02a5fba4 72e5b8e3 msxml3!__comexport::Release+0x62 02a5fbac 79221be1 msxml3!_dispatchEx::Release+0x10 02a5fbdc 79232e77 mscorwks!SafeRelease+0x56 02a5fbf8 79232ea8 mscorwks!IUnkEntry::Free+0x7c 02a5fc04 79232f86 mscorwks!ComPlusWrapper::ReleaseAllInterfaces+0xa 02a5fe3c 79232e0d mscorwks!ComPlusWrapper::ReleaseAllInterfacesCallBack+0x135 02a5fe48 7923303c mscorwks!ComPlusWrapper::Cleanup+0x16 02a5fe58 79233302 mscorwks!ComPlusContextCleanupGroup::CleanUpWrappers+0x19 02a5fe64 792335bc mscorwks!ComPlusApartmentCleanupGroup::ReleaseCleanupGroup+0xe 02a5fe74 792325bb mscorwks!ComPlusApartmentCleanupGroup::ReleaseCleanupGroupCallback+0x51 02a5fe98 792324dc mscorwks!ComPlusApartmentCleanupGroup::CleanUpWrappers+0xa8 02a5fed0 791fea3d mscorwks!ComPlusWrapperCleanupList::CleanUpWrappers+0x84 02a5fedc 791fe9cd mscorwks!SyncBlockCache::CleanupSyncBlocks+0x85 02a5fee0 791bbd18 mscorwks!Thread::DoExtraWorkForFinalizer+0x23 02a5ff20 791cf03c mscorwks!GCHeap::FinalizerThreadStart+0xbb 02a5ffb4 7c57b3bc mscorwks!Thread::intermediateThreadProc+0x44 02a5ffec 00000000 KERNEL32!BaseThreadStart+0x52
Interesting. The Finalizer thread is trying to free an MSXML3 object, it entered a critical section and it's waiting for it to be released. We took a few more dumps and the Finalizer thread always stayed the same. It didn't move a bit. It's hung in there. So no wonder Garbage Collector can't free memory.
Why is Finalizer thread hung on a critical section when freeing MSXML objects?
Well, check this:
The use of MSXML is not supported in .NET applications
MSXML uses threading models and garbage-collection mechanisms that are not compatible with the .NET Framework.
Summing up, we fail to garbage-collect msxml objects because of these incompatibilities. This issue affects all versions of the Framework and MSXML. The only alternative we have is to use .Net's System.Xml namespace to work with XML as suggested by previous article.
I hope this helps.
Cheers,
Alex (Alejandro Campos Magencio)