Menu
Our WCF service showed an Instance of large memory usage so we took a full memory dump to identify the issue.
Operating System Windows Server 2008 R2Service Pack 1
Number Of Processors 4
Process Image c:\Windows\System32\inetsrv\w3wp.exe
System Up-Time 40 day(s) 09:23:09
Process Up-Time 14 day(s) 11:49:01
.NET 4.0
Processor Type X64
Process Bitness 64-Bit
Helicopter view of the problem from DebugDiag report.
Process was garbage collecting, so as per warning I should not be trusting all the output from !heap commands.
Gc heap : 1.37 GBytes
.NET Cache size is 750Mb,
Virtual Memory Details : Virtual Allocations : 17.45 Gb Loaded Modules : 208.68 Mb Threads : 25 Mb Native Heaps : 3.06 Gb (I am concerned about this.)
From above 3.02 Gb is present on Heap 0x003f0000 alone.
We have good amount of traffic, that way 1.3 gb Gc heap size feels normal to me. Also we have machine with 32 gb ram and 64bit address space, so Cache size of 750 mb is acceptable. As per the size of Native heap, I feel this is native memory leak.
DebugDiag warning : There are 18149 dynamic assemblies loaded in the dump file.
Help links :
.NET Memory Leak: XmlSerializing your way to a Memory Leak
Analysis - We do use XmlSerialisers but they are cached, that way they are created only once.
.NET Memory Leak: XslCompiledTransform and leaked dynamic assemblies
We seems to have same kind of problem described in this blog post. All these 18149 dynamic assemblies are of 0 sizes. So I cannot dump them to get details. Also we don't use Xsl transform any where in this application. So these assemblies are not due to Xsl transforms.
Some more stats :
Related object counts :
System.Reflection.Emit.InternalModuleBuilder ----- 1.11 MBytes (18149 objects )
System.Reflection.Emit.InternalAssemblyBuilder ----- 992.52 KBytes (18149 objects )
System.Reflection.Emit.__FixupData[] ---------- 595.41 KBytes (752 objects )
System.Reflection.Emit.GenericFieldInfo ---------- 580.03 KBytes (18561 objects )
System.Reflection.RuntimeMethodInfo ---------- 1.2 MBytes (11276 objects )
System.RuntimeType -------------------- 1.13 MBytes (21228 objects )
Top Objects in the Finalizer queue
System.Reflection.Emit.DynamicResolver - 379
System.Reflection.Emit.DynamicResolver+DestroyScout - 271
Application Domain StatisticsDomain - Default - 13 assemblies - size : 89,677,824 (90 Mb ~)
Domain - ROOT/tv/Engine1 - 18236 Assemblies- Size :152,834,048 (150 Mb ~)
I guess these leaked dynamic assemblies accounting for 150 Mb of space. Not sure whether 3 Gb of Native memory is due to these assemblies ?
More digging around with this assemblies :
!dumpdomain give me large Unknown dynamic assemblies as below :
Assembly: 000000000fa9d0d0 (Dynamic) []
ClassLoader: 0000000002be1d40
SecurityDescriptor: 000000000fc08a00
Module Name
000007fe96d38e68 Dynamic Module
and !EEHeap -loader gives same number of 0 sized modules :
Module 000007fea0b7b758: Size: 0x0 (0) bytes.
Module 000007fea0b7c1e8: Size: 0x0 (0) bytes.
Module 000007fea0b7cc78: Size: 0x0 (0) bytes.
Checked for blocked GC Finalizer thread it is not the case, from below stack trace. It is waiting for Finalization event to occur.
0:000> ~20 k
Child-SP RetAddr Call Site
00000000`0eedf3b8 000007fe`fd6f1430 ntdll!ZwWaitForMultipleObjects+0xa
00000000`0eedf3c0 00000000`77501723 KERNELBASE!WaitForMultipleObjectsEx+0xe8
00000000`0eedf4c0 000007fe`f60939d4 kernel32!WaitForMultipleObjectsExImplementation+0xb3
00000000`0eedf550 000007fe`f6094799 clr!SVR::WaitForFinalizerEvent+0xcc
00000000`0eedf590 000007fe`f5f0458c clr!SVR::GCHeap::FinalizerThreadWorker+0x4a
00000000`0eedf5d0 000007fe`f5f0451a clr!Frame::Pop+0x50
Dump has the same number of System.Reflection.Emit.InternalModuleBuilder and System.Reflection.Emit.InternalAssemblyBuilder objects as that of leaked dynamic assemblies.
I noticed System.Reflection.Emit.DynamicResolver in Top finalizer queue and dumped all of them and correlated these to dynamic assembly address as follows.
Dumped around 5 DynamicResolver objects and tracked DynamicResolver -> m_method -> m_module (00000001801728a0)
00000001801728a0 this is the address of one module from list of InternalModuleBuilder list. Most of them was pointing to same module.
0:000> !dumpheap -type System.Reflection.Emit.DynamicResolver
Address MT Size
000000018017d5a8 000007fef4c7c8b0 72
000000018018d5b0 000007fef4c7c8b0 72
00000001801931b0 000007fef4c7c8b0 72
------- and on
0:000> !do 000000018017d5a8
Name: System.Reflection.Emit.DynamicResolver
MethodTable: 000007fef4c7c8b0
EEClass: 000007fef4754300
Size: 72(0x48) 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
000007fef4c44458 4002aaa 8 System.Object[] 0 instance 0000000000000000 m_exceptions
000007fef4c9a690 4002aab 10 System.Byte[] 0 instance 0000000000000000 m_exceptionHeader
000007fef4ca20c0 4002aac 18 ...mit.DynamicMethod 0 instance 0000000180172690 m_method
000007fef4c9a690 4002aad 20 System.Byte[] 0 instance 000000018017d5f0 m_code
000007fef4c9a690 4002aae 28 System.Byte[] 0 instance 000000018017d650 m_localSignature
000007fef4c992b8 4002aaf 38 System.Int32 1 instance 3 m_stackSize
000007fef4c7c788 4002ab0 30 ...Emit.DynamicScope 0 instance 0000000180172b80 m_scope
0:000> !do 0000000180172690
Name: System.Reflection.Emit.DynamicMethod
MethodTable: 000007fef4ca20c0
EEClass: 000007fef475e298
Size: 112(0x70) 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
000007fef4c44458 4002ac6 8 System.Object[] 0 instance 0000000180172700 m_parameterTypes
000007fef4cafa88 4002ac7 10 ...RuntimeMethodInfo 0 instance 000000018017d678 m_methodHandle
000007fef4c987f8 4002ac8 18 System.RuntimeType 0 instance 00000004800e7900 m_returnType
000007fef4c7c578 4002ac9 20 ...ynamicILGenerator 0 instance 0000000180172a30 m_ilGenerator
000007fef4c4eb18 4002aca 28 ...mit.DynamicILInfo 0 instance 0000000000000000 m_DynamicILInfo
000007fef4c97de0 4002acb 60 System.Boolean 1 instance 1 m_fInitLocals
000007fef4c9f1d8 4002acc 30 ...ion.RuntimeModule 0 instance 00000001801728a0 m_module
000007fef4c97de0 4002acd 61 System.Boolean 1 instance 0 m_skipVisibility
000007fef4c987f8 4002ace 38 System.RuntimeType 0 instance 0000000000000000 m_typeOwner
000007fef4c7c330 4002acf 40 ...d+RTDynamicMethod 0 instance 00000001801729d8 m_dynMethod
000007fef4c7c8b0 4002ad0 48 ...t.DynamicResolver 0 instance 000000018017d5a8 m_resolver
000007fef4c97de0 4002ad1 62 System.Boolean 1 instance 0 m_profileAPICheck
000007fef4c99d18 4002ad2 50 ...n.RuntimeAssembly 0 instance 0000000000000000 m_creatorAssembly
000007fef4c97de0 4002ad3 63 System.Boolean 1 instance 1 m_restrictedSkipVisibility
000007fef4c88d70 4002ad4 58 ...g.CompressedStack 0 instance 00000001801729b0 m_creationContext
000007fef4c88020 4002ad5 16b8 ...rnalModuleBuilder 0 shared static s_anonymouslyHostedDynamicMethodsModule
>> Domain:Value 0000000002b66ba0:NotInit 0000000002c24a90:00000001801728a0 <<
000007fef4c96ae8 4002ad6 16c0 System.Object 0 shared static s_anonymouslyHostedDynamicMethodsModuleLock
>> Domain:Value 0000000002b66ba0:NotInit 0000000002c24a90:0000000180172798 <<
Opened log file 'C:\debug\new_dynamic_asm.log'
0:000> !dumpheap -type System.Reflection.Emit.InternalModuleBuilder
Address MT Size
00000001800fe918 000007fef4c88020 64
00000001801728a0 000007fef4c88020 64
000000018017fa88 000007fef4c88020 64
00000001801bee20 000007fef4c88020 64
------- and on
I am not that handy with WinDbg, can somebody give me some clues.
!heap -l gave me 188722 potential unreachable blocks were detected.
Native heap statistics using WinDbg PyKd plugin gave me below stats of native heap.
Notice the values rolling around 18,000
Statistics:
Type name Count Size
clr!RecordPool 817335 Unknown
clr!RegMeta 272445 Unknown
clr!CBlobPoolHash 36326 Unknown
clr!MDInternalRW 36326 Unknown
clr!StgBlobPool 36326 Unknown
clr!CCeeGen 36298 Unknown
clr!PEAssembly 18267 Unknown
clr!AssemblySecurityDescriptor 18249 Unknown
clr!DomainAssembly 18249 Unknown
clr!SharedSecurityDescriptor 18236 Unknown
clr!CStringPoolHash 18163 Unknown
clr!CMiniMdRW 18163 Unknown
clr!StgGuidPool 18163 Unknown
clr!StgStringPool 18163 Unknown
clr!CCustAttrHash 18163 Unknown
clr!CGuidPoolHash 18163 Unknown
clr!PESectionMan 18149 Unknown
clr!CeeSectionString 18149 Unknown
clr!PESection 18149 Unknown
nativerd!CONFIG_ELEMENT 4932 Unknown
nativerd!ATTRIBUTE_VALUE 3912 Unknown
nativerd!SCHEMA_ATTRIBUTE 1473 Unknown
clr!CAssemblyName 1116 Unknown
nativerd!COLLECTION_KEY_ENTRY 919 Unknown
nativerd!SCHEMA_ELEMENT 766 Unknown
clr!AssemblyMDInternalImport 720 Unknown
nativerd!CONFIG_SECTION 652 Unknown
nativerd!CONFIG_COLLECTION 570 Unknown
clr!ListNode<CHashNode * __ptr64> 444 Unknown
778
WCF automatically generates serialization classes in memory for some communication protocols, mostly for XML communication, and seems to create a different class for each possible variation in the message structure; this easily explains the number of assemblies. This behavior is apparently normal for XML-based WCF protocols. If you have control over the protocol, switching to a non-XML communication protocol may resolve this problem.
The 3GB memory consumption is reasonable for this - the dynamic assembly will exist in both MSIL (.NET assembler language) and native versions in memory. The 150MB is probably for the MSIL version that was initially generated by WCF, and does not include the native code that gets generated by the .NET JIT compiler as soon as the MSIL version is "loaded" as a module and made callable.
The 17.45GB virtual space is not real memory, but instead is the distance between the lowest and highest memory locations where those modules get loaded; for example, if the main module loads at offset 0, and the first dynamic assembly loads at 00000000:0b000000, the total listed virtual memory will be about 185MB, even if the main module only takes 2MB and the dynamic assembly takes another 2MB. This is an exaggerated example, since they are usually packed in fairly well, but 1MB is typical between addresses, so 18000 * 1MB = 18000MB, which divided by 1024 gives exactly 17GB of address space (add another half GB for the rest of your system and you have the full virtual address space).
I have also seen one more type of fast-growing memory leak with WCF: if any part of a message is held by a persistent component of the application, the underlying XML COM object will not be garbage-collected, resulting in fairly large amounts of memory leaking. The .NET XML DOM uses the Windows COM XML subsystem, which is native code, and allocates on a native heap. This could explain the difference between managed and native memory heaps. Take a look at the actual memory in the dump (look for a tool that can filter out printable text), and check how much of it is formatted XML.
I have seen both of these leaks occur, and rapidly consume all of the memory on fairly large-scale servers, so I hope my experience provides an answer for you, or at least gives you some additional hints for tracing down your problem.
73
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
