A curious case: CLR/COM Interop leak
Background
A customer asked me a question last week: in CLR-COM interop case, who is responsible to free up a string returned from COM? My understanding was that the interop layer setup by .NET will automatically take care of this. However, I thought a mock test would not do any harm. To my surprise this test actually opened up the proverbial ‘can of worms’ and I thought I would share my experience with you!
Prerequisite reading
There was a lot of detailed debugging stuff we will cover here, and it assumes some basics. For those who are not aware of the basics, I recommend you first consume the following.
- Free training video series- .NET Debugging for production environments
- Production Debugging for .NET Framework Applications (there was a PDF version of this guide, but the link seems broken – Bing for ‘DBG_download.pdf’ if you want to look for it.)
- For disassembly (e.g. how does ebp+8 map to parameters) please read Under the Hood, MSJ February 1998 – Microsoft Corporation and Annotated x86 Disassembly – Microsoft Corporation- Software
Test setup: COM Server
We have an in-process ATL COM server which exposes an interface and a single method, SayHello. Here is the IDL interface for this method:
interface Imyclass : IDispatch{
[id(1)] HRESULT SayHello([out] BSTR* hellostr);
};
And here is the implementation:
STDMETHODIMP Cmyclass::SayHello(BSTR* hellostr)
{
*hellostr = SysAllocString(L"Hello World");
return S_OK;
}
As you can see, this is no rocket science, we are allocating a BSTR inside the component and returning it to the caller. Therefore as per COM conventions the caller should free this up.
Test setup: C# client
We have a managed client written as a C# console application. A reference is added to the COM library, cominteropLib and that allows us to create instances of myclass:
static void Main(string[] args)
{
Console.ReadKey();
string sout = "";
myclass cls = new myclass();
int i = 0;
while (true)
{
cls.SayHello(ref sout);
if (i % 100000 == 0)
{
System.Threading.Thread.Sleep(1000);
Console.Write(sout);
}i++;
}
Observations
So when we run the C# application, and plot Virtual, Private Bytes and also # Managed bytes for this process, here is the observed trend:
Advertisements REPORT THIS AD
As you can see, the Private Bytes increases steadily, but the amount of managed bytes recorded is not even registering (almost 0 at this scale of the graph.) Generally this indicates the leak is in unmanaged allocations, as you can see in Using Perfmon to Diagnose Application Issues – 02.
Tracking the unmanaged leak
The best way to track down unmanaged leaks is to use DebugDiag 1.2. We did that and ran the Memory Analysis (native code only) to find out the call stacks with the most outstanding unmanaged allocations. Here are the relevant sections from the DebugDiag report:
mscorlib.ni.dll is responsible for 73.24 MBytes worth of outstanding allocations. The following are the top 2 memory consuming functions: mscorlib_ni+2c70aa: 73.24 MBytes worth of outstanding allocations.
Memory manager statistics by allocation size
OLE automation BSTR memory manager : 73.24 MBytes
Heap memory manager : 622.98 KBytes
So from this, it is clear that we are somehow leaking BSTRs. Let us save the call stack of the leaked allocation, and come back to it later (only the top few frames are reproduced for brevity.)
Call stack sample 1
Address 0x00650048
Allocation Time 00:00:10 since tracking started
Allocation Size 24 BytesFunction Source Destination
mscorlib_ni+2c70aa
clr+5d80
mscorlib_ni+2c70aa
clr+5d80
mscorlib_ni+24bc9d
clr+2ec3 0xAC07C8
clr+21db
clr!LogHelp_TerminateOnAssert+301ec
clr!LogHelp_TerminateOnAssert+74a40
0x1DC030
ConsoleApplication1+281e
ConsoleApplication1+281e
ConsoleApplication1+281d
ConsoleApplication1+281b
We will come back to this later.
Manually tracking the leak
Normally, we will just use the above call stack and drill down into the root cause. But I wanted to show you some other debugging methods which can be very useful. First, we will check if SysFreeString() is being called at all. Next, we will also dump the address of the BSTR allocated by SysAllocString() inside the COM component. We will compare these and check if we do release the BSTR which the COM component is allocating.
Checking SysAllocString / SysFreeString pairs
We will use conditional breakpoints in WinDbg to get this debug output. Here are the breakpoints:
- bp `cominterop!myclass.cpp:21` ".echo ‘SysAllocString’; dd poi(hellostr) L1;g"
- bp OLEAUT32!SysFreeString+0x7 ".echo ‘SysFreeString’; dd ebp+8 L1; g"
A quick explanation of these breakpoints is in order. The first one is a normal location breakpoint set on the line number 21 of myclass.cpp. We can easily do this because we have the source code of the COM component. In the case of the second (SysFreeString) breakpoint, we are going as per the disassembly knowledge, and guessing that [ebp+8] is actually the input parameter. Here is the disassembly of oleaut32!SysFreeString for your reference:
0:004> u oleaut32!SysFreeString
OLEAUT32!SysFreeString:
76333e40 8bff mov edi,edi
76333e42 55 push ebp
76333e43 8bec mov ebp,esp
76333e45 51 push ecx
76333e46 56 push esi
76333e47 8b7508 mov esi,dword ptr [ebp+8] <— This is the second breakpoint. We will dump [ebp+8] here.
76333e4a 85f6 test esi,esi
76333e4c 743d je OLEAUT32!SysFreeString+0x6c (76333e8b)
Both breakpoints contain commands to be executed when the breakpoint is hit. For the breakpoint in myclass, we will dump the address of the BSTR being returned by SysAllocString. For the SysFreeString we will dump the contents of location ebp+8 (so that we get the BSTR address being passed in.)
Here is the sample output from these breakpoints (snipped and reformatted to suit this blog post)
‘SysAllocString’ 0029f090 0045705c
‘SysFreeString’ 0029efdc 0045705c
‘SysAllocString’ 0029f090 00457094
‘SysFreeString’ 0029efdc 00457094
‘SysAllocString’ 0029f090 004570cc
‘SysFreeString’ 0029efdc 004570cc
‘SysAllocString’ 0029f090 00457104
‘SysFreeString’ 0029efdc 00457104
‘SysAllocString’ 0029f090 0045713c
‘SysFreeString’ 0029efdc 0045713c
As you can see from the above, we are very clearly freeing up the BSTR which is being returned by the COM component (values which are in bold). Next, let us see who is actually freeing those BSTRs (note: the ‘!clrstack’ and kb commands are executed manually when we hit the breakpoint on SysFreeString+0x7)
0:000> !clrstack;kb
OS Thread Id: 0xad8 (0)
Child SP IP Call Site
0029efe4 76333e47 [InlinedCallFrame: 0029efe4] Microsoft.Win32.Win32Native.SysFreeString(IntPtr)
0029efe0 6ac0c7d5 System.StubHelpers.BSTRMarshaler.ClearNative(IntPtr)
0029f020 002a033e DomainBoundILStubClass.IL_STUB_CLRtoCOM(System.String ByRef)
0029f028 002a0121 [InlinedCallFrame: 0029f028] cominteropLib.Imyclass.SayHello(System.String ByRef)
0029f0c8 002a0121 ConsoleApplication1.Program.Main(System.String[]) [c:TempcominteropConsoleApplication1Program.cs @ 22]
0029f330 6c5421db [GCFrame: 0029f330]
The above is the managed call stack, which seems to suggest that the CLR-COM interop stub is automatically freeing up the BSTR returned by our COM component. FYI, you can look at the implementation of the StubHelpers.BSTRMarshaler class from the .NET Reference Source. FWIW, given below is the native call stack, just for your reference (there is not too much value add from it.)
ChildEBP RetAddr Args to Child
0029efd4 6ac0c7d5 0045713c 7058594b 6c545d80 OLEAUT32!SysFreeString+0x7
WARNING: Stack unwind information not available. Following frames may be wrong.
0029f040 6abf7774 0029f0c0 00000000 000d387c mscorlib_ni+0x26c7d5
0029f104 6c5421db 0029f148 0007281d 0029f190 mscorlib_ni+0x257774
0029f114 6c564a2a 0029f1e0 00000000 0029f1b0 clr+0x21db
0029f190 6c564bcc 0029f1e0 00000000 0029f1b0 clr!CoUninitializeEE+0x6862
0029f2c8 6c564c01 000dc030 0029f394 0029f354 clr!CoUninitializeEE+0x6a04
0029f2e4 6c564c21 000dc030 0029f394 0029f354 clr!CoUninitializeEE+0x6a39
0029f2fc 6c62ce82 0029f354 70d6a23c 00000000 clr!CoUninitializeEE+0x6a59
0029f460 6c62cf90 000d3810 00000001 0029f49c clr!GetCLRFunction+0xc08
0029f6c8 6c62cda4 00000000 70d6adf0 00000000 clr!GetCLRFunction+0xd16
0029fbac 6c62d199 00070000 00000000 70d6aa5c clr!GetCLRFunction+0xb2a
0029fc00 6c62d09a 00070000 70d6aa10 00000000 clr!GetCLRFunction+0xf1f
0029fc4c 6c6aaf00 70d6aad8 00000000 7737903b clr!GetCLRFunction+0xe20
0029fc84 6e2555ab 6c6aaee4 0029fca0 6fb47f16 clr!CorExeMain+0x1c
0029fc90 6fb47f16 00000000 6e250000 0029fcb4 mscoreei!CorExeMain+0x38
0029fca0 6fb44de3 00000000 7737d0e9 7ffda000 mscoree!CreateConfigStream+0x13f
0029fcb4 778919bb 7ffda000 771e5a5e 00000000 mscoree!CorExeMain+0x8
0029fcf4 7789198e 6fb44ddb 7ffda000 ffffffff ntdll!__RtlUserThreadStart+0x23
0029fd0c 00000000 6fb44ddb 7ffda000 00000000 ntdll!_RtlUserThreadStart+0x1b
Clueless?
So, what do we have so far? We know from DebugDiag that somehow we are leaking BSTR memory. But on the other hand from the live debug trace we have also found that the BSTR being returned from the COM component is indeed being freed by the CLR-COM interop layer. So what gives? Who is the other source of the leaked BSTRs?
For answering that, we will go back to our DebugDiag output. In that, it says the function mscorlib_ni+2c70aa was responsible for the native leak. Let us set a breakpoint there and check what that really means in managed code world:
0:000> bp mscorlib_ni+2c70aa
0:000> g
Breakpoint 2 hit
eax=0045713c ebx=00000000 ecx=0041c970 edx=00000006 esi=003e8680 edi=00000000
eip=6ac670aa esp=0029efbc ebp=0029effc iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
mscorlib_ni+0x2c70aa:
6ac670aa c6460801 mov byte ptr [esi+8],1 ds:0023:003e8688=00
Once the above breakpoint is hit, we can view the managed call stack. This time we will view it with local and parameter information (-l and –p).
0:000> !clrstack -l -p
OS Thread Id: 0xad8 (0)
Child SP IP Call Site
0029efbc 6ac670aa DomainNeutralILStubClass.IL_STUB_PInvoke(Byte[], UInt32)
PARAMETERS:
<no data>
<no data>
0029efc0 6abeb1e7 [InlinedCallFrame: 0029efc0] Microsoft.Win32.Win32Native.SysAllocStringByteLen(Byte[], UInt32)
0029f004 6abeb1e7 System.StubHelpers.BSTRMarshaler.ConvertToNative(System.String, IntPtr)
PARAMETERS:
strManaged (<CLR reg>) = 0x01e620a0
pNativeBuffer = <no data>
LOCALS:
<no data>
<CLR reg> = 0x00000000
0x0029f008 = 0x00000016
<no data>
<no data>
<no data>
<no data>
0029f024 002a020e DomainBoundILStubClass.IL_STUB_CLRtoCOM(System.String ByRef)
PARAMETERS:
this = <no data>
<no data>
0029f028 002a0121 [InlinedCallFrame: 0029f028] cominteropLib.Imyclass.SayHello(System.String ByRef)
0029f0c8 002a0121 ConsoleApplication1.Program.Main(System.String[])*** WARNING: Unable to verify checksum for ConsoleApplication1.exe
[c:TempcominteropConsoleApplication1Program.cs @ 22]
PARAMETERS:
args (0x0029f0fc) = 0x01e3af40
LOCALS:
0x0029f0f8 = 0x01e620a0
0x0029f0d0 = 0x01e3bf30
0x0029f0f4 = 0x000010ee
0x0029f0f0 = 0x00000001
0029f330 6c5421db [GCFrame: 0029f330]
What I want to highlight here is that the local variable at stack address 0x0029f0f8 (with a actual object address of 0x01e620a0) is actually our local string sout:
0:000> !do 0x01e620a0
Name: System.String
MethodTable: 6acbf9ac
EEClass: 6a9f8bb0
Size: 36(0x24) bytes
File: C:WindowsMicrosoft.NetassemblyGAC_32mscorlibv4.0_4.0.0.0__b77a5c561934e089mscorlib.dll
String: Hello World
Fields:
MT Field Offset Type VT Attr Value Name
6acc2978 40000ed 4 System.Int32 1 instance 11 m_stringLength
6acc1dc8 40000ee 8 System.Char 1 instance 48 m_firstChar
6acbf9ac 40000ef 8 System.String 0 shared static Empty
>> Domain:Value 003b0c10:01e31228 <<
This local variable is what is finally passed into BSTRMarshaler.ConvertToNative (the strManaged parameter is 0x01e620a0, which is the local sout string itself.)
Eureka!
So this, means that while calling the COM component, the CLR-COM interop layer is ‘helping’ us by wrapping our .NET string (the variable called sout) as a BSTR and then invoking the component. Evidently that is not getting freed up. On source code inspection, it becomes obvious that maybe we are missing a call to set sout = null after the call to the COM component. On fixing the code, the ‘leak’ goes away. Here is a comparison of the IL code before and after the fix.
Before the fix
.method private hidebysig static void Main(string[] args) cil managed
{
.entrypoint
// Code size 56 (0x38)
.maxstack 2
.locals init ([0] string sout,
[1] class cominteropLib.myclass cls,
[2] bool CS$4$0000)
IL_0000: nop
IL_0001: call valuetype [mscorlib]System.ConsoleKeyInfo [mscorlib]System.Console::ReadKey()
IL_0006: pop
IL_0007: ldstr ""
IL_000c: stloc.0
IL_000d: ldstr "8F69F29F-97C3-4228-9D03-6499E88C6F38"
IL_0012: newobj instance void [mscorlib]System.Guid::.ctor(string)
IL_0017: call class [mscorlib]System.Type [mscorlib]System.Type::GetTypeFromCLSID(valuetype [mscorlib]System.Guid)
IL_001c: call object [mscorlib]System.Activator::CreateInstance(class [mscorlib]System.Type)
IL_0021: castclass cominteropLib.myclass
IL_0026: stloc.1
IL_0027: br.s IL_0034
IL_0029: nop
IL_002a: ldloc.1
IL_002b: ldloca.s sout
IL_002d: callvirt instance void cominteropLib.Imyclass::SayHello(string&)
IL_0032: nop
IL_0033: nop
IL_0034: ldc.i4.1
IL_0035: stloc.2
IL_0036: br.s IL_0029
} // end of method Program::Main
After the fix
.method private hidebysig static void Main(string[] args) cil managed
{
.entrypoint
// Code size 58 (0x3a)
.maxstack 2
.locals init ([0] string sout,
[1] class cominteropLib.myclass cls,
[2] bool CS$4$0000)
IL_0000: nop
IL_0001: call valuetype [mscorlib]System.ConsoleKeyInfo [mscorlib]System.Console::ReadKey()
IL_0006: pop
IL_0007: ldstr ""
IL_000c: stloc.0
IL_000d: ldstr "8F69F29F-97C3-4228-9D03-6499E88C6F38"
IL_0012: newobj instance void [mscorlib]System.Guid::.ctor(string)
IL_0017: call class [mscorlib]System.Type [mscorlib]System.Type::GetTypeFromCLSID(valuetype [mscorlib]System.Guid)
IL_001c: call object [mscorlib]System.Activator::CreateInstance(class [mscorlib]System.Type)
IL_0021: castclass cominteropLib.myclass
IL_0026: stloc.1
IL_0027: br.s IL_0036
IL_0029: nop
IL_002a: ldloc.1
IL_002b: ldloca.s sout
IL_002d: callvirt instance void cominteropLib.Imyclass::SayHello(string&)
IL_0032: nop
IL_0033: ldnull
IL_0034: stloc.0
IL_0035: nop
IL_0036: ldc.i4.1
IL_0037: stloc.2
IL_0038: br.s IL_0029
} // end of method Program::Main
The main difference as you can see is the assignment of null to the sout variable (that is what the IL instruction stloc.0 does).
Conclusions
This was a very interesting walkthrough and I would like to summarize the steps:
- Use Performance Monitor to distinguish between a managed and unmanaged origin leak.
- For unmanaged leaks, you need to track those using DebugDiag’s leak tracking rule.
- Normally, for a pure unmanaged origin leak, the output from DebugDiag will give you the offending line of code.
- However in this case because the offending line of code is actually in an auto-generated CLR-COM stub, we cannot resolve it statically.
- Live debugging by setting the breakpoint on the native code address reported by DebugDiag gave us the opportunity to view the managed call stack leading to this unmanaged leak.
Recommendation
If you are reusing BSTRs across COM method calls, always set the strings returned to you by COM components explicitly to null in C# code before calling your COM method. That will allow the CLR-COM interop stub to correctly skip making the ConvertToNative call for the input BSTR, and therefore avoid the leak.
Well, I hope you really enjoyed this post. It was hard work for me but I enjoyed tracking it down. I hope you also enjoyed it as much as I did. Please drop a comment and see you next time!
标签：case,Interop,leak,System,mscorlib,call,IL,SysFreeString,COM From： https://www.cnblogs.com/ioriwellings/p/17745847.html