Some time ago I got this error on my machine: “TFS Power Tool Shell Extension (TfsComProviderSvr) has stopped working”. My first reaction to handle this problem would be to reinstall TFS Power Tools 2010 where the problem was obviously located. However I decided to leave the problem so I can write this blog post.
It took few months and hundreds instances of the dialog box below though:
This dialog box is part of Windows Error Reporting (WER) which I am about to cover in additional post. One thing you should really do when you see this message is to open the details using the “View problem details” panel at the bottom of the dialog box. In my case this provided me with the following information:
Problem signature:
Problem Event Name: CLR20r3
Problem Signature 01: tfscomprovidersvr.exe
Problem Signature 02: 10.0.30319.0
Problem Signature 03: 4d6d4f92
Problem Signature 04: JOPSJ0BBDPTVPWWFWUIIWQ2SYBSSFGDF
Problem Signature 05: 10.0.0.0
Problem Signature 06: 4d6d4f78
Problem Signature 07: 4b
Problem Signature 08: 24
Problem Signature 09: System.NullReferenceException
OS Version: 6.1.7601.2.1.0.256.4
Locale ID: 1033
Additional Information 1: 0a9e
Additional Information 2: 0a9e372d3b4ad19135b953a78882e789
Additional Information 3: 0a9e
Additional Information 4: 0a9e372d3b4ad19135b953a78882e789
There is some vital information we can gather here. That is process name (tfscomprovidersvr.exe), process version (10.0.30319.0) and exception type (System.NullReferenceException). It is good enough to pass this information to the support team and request support. This is not our goal here though.
Let’s go ahead and debug the crashed program instead. You can see there is a Debug button as part of the dialog box. When click it, you will be presented with options to select a debugger by your choice. I have Visual Studio installed so I selected it and I got the Disassembly window opened in Visual Studio.
This window shows us one really important piece of information – the location where the exception has been thrown. The faulting method is Microsoft.TeamFoundation.PowerTools.TfsComProvider.Core.TfsCache.CachedServer.Dispose(). Unfortunately we do not have the pdb and source files (more on this in later post) so we can only see the assembly code. Unless we do some tricks.
Some debugging pros my ask – why in the world you did not use WinDbg to debug this managed code instead. I personally also like WinDbg much more when it comes to debugging IL and assembly code. There is one thing that is really easy and straightforward to get from within Visual Studio. Just see the Locals window below:
We can now browse through the exception and this objects and see their member variable values. Also hovering over a symbol name, if resolved, will show its value in a tooltip. Pretty easy, right?
Open the Threads window to see where our code is executed. If Threads window is missing for you, go to DebugWindows and select Threads.
Similarly you can open Parallel Stacks window:
And also the Call Stack window:
All these windows come to show you that the code is currently executed in the CLR Finalizer Thread.
So we’ve seen the assembly code, local variables and stack info. What should we do next? We can give Visual Studio debugger some help in order to digest the assembly code and make it more meaningful to us.There it comes SOS.dll. SOS is a debugger extension that have the capability to read and parse CLR structures and IL code. It is intended to be used with WinDbg however since Visual Studio 2010 it can be also loaded inside Visual Studio also.
Open the Immediate Windows and type .load sos. Type !help to see the list of all SOS commands. Tip: Right click on the Immediate window and select Dock as Tabbed Document to open the window using the full IDE size. Now that we have SOS loaded, lets try to find more information about the code being executed.
Now let’s get the value of IP (Instruction Pointer) register using the Register window:
The IP register contains the address of the instruction currently being executed. Now that we have it, we can call SOS method !ip2md that will convert our currently executing address into a CLR method description object:
!ip2md 001E3EF9
MethodDesc: 00139b18
Method Name: Microsoft.TeamFoundation.PowerTools.TfsComProvider.Core.TfsCache+CachedServer.Dispose()
Class: 001b4ab4
MethodTable: 00139b74
mdToken: b18800b20600004b
Module: 00135614
IsJitted: yes
CodeAddr: 001e3ec0
Transparency: Safe critical
Now we have the MethodDesc address that we can use to decompile this method to IL using the !DumpIL command.
!DumpIL 00139b18
ilAddr = 003c38cc
IL_0000: ldarg.0
IL_0001: call CachedServer::get_IsDisposed
IL_0006: brtrue IL_0092
IL_000b: ldarg.0
IL_000c: ldc.i4.0
IL_000d: call CachedServer::set_IsConnected
IL_0012: ldarg.0
IL_0013: ldfld CachedServer::m_vcServer
IL_0018: ldarg.0
IL_0019: ldftn CachedServer::VCServer_PendingChangesChanged
IL_001f: newobj Microsoft.TeamFoundation.VersionControl.Client.Wo::.ctor
IL_0024: callvirt Microsoft.TeamFoundation.VersionControl.Client.Ve::remove_PendingChangesChanged
IL_0029: ldarg.0
IL_002a: ldfld CachedServer::m_vcServer
In case your IL skills are fading, another option is just to use Telerik’s amazing FREE tool JustDecompile (pun intended). It will show us the originating C# code instead and it will help you better understand the IL code above.
public void Dispose()
{
if (!this.IsDisposed)
{
this.IsConnected = false;
this.m_vcServer.PendingChangesChanged -= new WorkspaceEventHandler(this.VCServer_PendingChangesChanged);
this.m_vcServer.GetCompleted -= new WorkspaceEventHandler(this.VCServer_GetCompleted);
this.m_vcServer.CreatedWorkspace -= new WorkspaceEventHandler(this.VCServer_CreatedWorkspace);
this.m_vcServer.DeletedWorkspace -= new WorkspaceEventHandler(this.VCServer_DeletedWorkspace);
this.m_vcServer.UpdatedWorkspace -= new WorkspaceEventHandler(this.VCServer_UpdatedWorkspace);
GC.SuppressFinalize(this);
this.m_isDisposed = true;
}
}
Ok, so far so good. But how do we find out where exactly this application crashed? Here it gets a little hairy as there is no 1:1 way to tell that. The best thing we can do is to compare the source code (IL or C#) with the actually assembly code. Here is part of the assembly output taken from the Disassembly window:
00000000 push ebp
00000001 mov ebp,esp
00000003 push edi
00000004 push esi
00000005 mov esi,ecx
00000007 cmp byte ptr [esi+1Dh],0
0000000b jne 000000FC
00000011 mov ecx,esi
00000013 xor edx,edx
00000015 call FFFFF130
0000001a mov ecx,71F8F8B0h
0000001f call FFF3E1E4
00000024 mov edi,eax
00000026 mov ecx,dword ptr [esi+14h]
00000029 lea edx,[edi+4]
0000002c call 701EF170
00000031 mov eax,13CAF8h
00000036 mov dword ptr [edi+0Ch],eax
00000039 mov ecx,dword ptr [ecx+34h]
0000003c mov edx,edi
0000003e cmp dword ptr [ecx],ecx
00000040 call 71D18A10
00000045 mov ecx,71F8F8B0h
0000004a call FFF3E1E4
The highlighted line is where the debugger says the exception has occurred. That is instruction located at address 00000039. Based on the instruction located on this address, we can safely assume that the address referenced [ecx+34h] is not valid and that is the cause of the exception.
Now that we have the IL and C# source code, let’s try to map them to the faulting instruction using some simple and well known code constructions. This way we can see where ECX is being initialized and with what.
| 00000000 push ebp 00000001 mov ebp,esp 00000003 push edi 00000004 push esi |
public void Dispose() { |
|
| 00000005 mov esi,ecx 00000007 cmp byte ptr [esi+1Dh],0 0000000b jne 000000FC |
IL_0000: ldarg.0 IL_0001: call CachedServer::get_IsDisposed IL_0006: brtrue IL_0092 |
if (!this.IsDisposed) { |
| 00000011 mov ecx,esi 00000013 xor edx,edx 00000015 call FFFFF130 |
IL_000b: ldarg.0 IL_000c: ldc.i4.0 IL_000d: call CachedServer::set_IsConnected |
this.IsConnected = false; |
| 0000001a mov ecx,71F8F8B0h 0000001f call FFF3E1E4 |
IL_0012: ldarg.0 IL_0013: ldfld CachedServer::m_vcServer |
this.m_vcServer … |
| 00000024 mov edi,eax 00000026 mov ecx,dword ptr [esi+14h] 00000029 lea edx,[edi+4] 0000002c call 701EF170 00000031 mov eax,13CAF8h 00000036 mov dword ptr [edi+0Ch],eax 00000039 mov ecx,dword ptr [ecx+34h] 0000003c mov edx,edi 0000003e cmp dword ptr [ecx],ecx 00000040 call 71D18A10 |
IL_0018: ldarg.0 IL_0019: ldftn CachedServer::VCServer_PendingChangesChanged IL_001f: newobj Microsoft.TeamFoundation.VersionControl.Client.Wo::.ctor IL_0024: callvirt Microsoft.TeamFoundation.VersionControl.Client.Ve::remove_PendingChangesChanged |
… .PendingChangesChanged -= new WorkspaceEventHandler(this.VCServer_PendingChangesChanged); |
| 00000045 mov ecx,71F8F8B0h 0000004a call FFF3E1E4 |
IL_0029: ldarg.0 IL_002a: ldfld CachedServer::m_vcServer |
this.m_vcServer… |
| … | … | … |
As you can see here, ECX is being initialized as part of the following statement:
this.m_vcServer.PendingChangesChanged -= new WorkspaceEventHandler(this.VCServer_PendingChangesChanged);
More specifically it holds the value for m_vcServer. Now if we go back to Visual Studio and hover at m_vcServer variable in the output of DumpIL command that we executed above, we will see that it is actually null.
At this point, if you are still reading this, let’s lean back and rethink. We have the Dispose method called by the Finalize method in a GC Finalizer Thread. Inside the Dispose method an object is being referenced and it is already null. Of course there is always possibility that someone just nulled this object explicitly. I do tend to believe that if this was the case, the programmer should also implemented the necessary null validation checks inside the Dispose method. Or may the object is not nulled explicitly but the GC already has collected it. I went ahead and refreshed my memory on Disposable pattern. And then it stoke me!
The IDisposable pattern is used to free managed and unmanaged resources. In order to allow code reuse a single method Dispose is usually implemented. The Dispose method gets invoked with a boolean parameter disposing to show if the method is called from Dispose directly or through Finalize method. If Dispose is called from Finalize, you are not allowed to call any managed objects as they might not longer exist. In our case the Dispose method neither has the parameter disposing implemented. As a result it ends up calling managed objects during finalization process and that generates the NullReferenceException.
Next steps – I am going to install the latest version available Team Foundation Server Power Tools August 2011 and will see if the Dispose pattern is implement correctly there. If not – I will use my MVP powers to reach the TFS product team at Microsoft and report the problem. I will keep you updated.
Tip: If you want to save the current program state and resume the debugging at some time later, you can do that by saving a memory dump file. Do that by opening DebugSave Dump As… menu and select folder where to store the .dmp file. You can then open the saved .dmp file using Visual Studio 2010 FileOpen menu. You will find out there is a nice Minidump File Summary window that was not available before. This type of debugging of the .dmp file is called postmortem debugging as opposed to the live debugging session that I did above. There are few things you should know about postmortem debugging like IL Interpreter for example. I will try to cover those in a separate post.
What does this mean to you as developer – read and learn the correct way of implementing IDisposable pattern. Go back to the books if you do not recall how it should be done. There is nothing wrong repeating what you have already learnt. The article DG Update: Dispose, Finalization, and Resource Management from Joe Duffy is the most comprehensive that I have read so far. It is great if you want to really go deep. If you just want to refresh your memory this blog post Notes on the CLR Garbage Collector from Vineet Gupta has a really nice recap of how GC works in CLR. It also have correct implementation of IDisposable pattern shown. At the end of the you will find tons (really tons) of resources on the memory management in CLR. Funny enough I even found IDisposable implementation in the Programming .NET Framework book that we did in Bulgarian back in 2005. The chapter of Memory and Resource Management was written by George Ivanov, fellow community lead who is now working at Microsoft Corp.