Investigating & Resolving Message Delays in Outlook with WinDbg

The problem starts after the user has had their Windows profile recreated but continues to experience some Outlook performance issues. Each time she clicks the New button in Outlook to create a new message, there is a 5 to 10 second delay before the blank message opens. There is also a 10+ second delay after she clicks send and Outlook becomes unresponsive for that time. I connect to her and quickly look at the Office Outlook registry for any unapproved 3rd party add-ins and see nothing out of the ordinary. I decide to dump the Outlook process when the hang is encounter and turn to Process Explorer. This is a simple matter of right-clicking the process and choosing Create Dump when it is in an unresponsive state. Actually, I collect two dumps, the other with Procdump in hang mode. I do this to ensure that the dumps are consistent; if the dumps are not similar then I may need to collect more until a pattern emerges.

I copied the dumps to my workstation and opened them with WinDbg and run the !analyze –v –hang command. The stack for both dumps are similar. With the exception of the NRTExchn component (our DMS add-in for Outlook), these are all MS modules. Normally, this wouldn’t excite me but something stands out like a sore thumb as I move up the stack, the presence of msi.dll in the stack of the current examine thread.

Admittedly, this makes no sense to me. You normally see the Windows Installer kick in when something is being installed or uninstalled. Why it’s doing this in the process of Outlook opening new messages or sending messages is a mystery. But I should be able to get a clue as to what’s happening during this delay by looking up one of functions, specifically GetComponentPath. Looking up msi!GetComponentPath, MSDN states:

The MsiGetComponentPath function returns the full path to an installed component. If the key path for the component is a registry key then the registry key is returned.

I get the feeling that the delay/hang in Outlook is the result of various file query operations. Another clue are the frames that follow, also a file query type function:

CLR is the Common Language Runtime, a component of the .NET Framework which is responsible for the execution of applications that are built on .NET. Maybe if I dump one of the parameters in the arguments I can see what file or keys are being looked at:

ITSM stands out: this is our incident tracking client software and it is also a .NET application. There’s also a few guids here. Searching the first one confirms it is the product guid for ITSM: Searching the registry for the partial guid, {741BEFED-AEC0-4AFF-84AF-4F61D15F5526}, reveals this is otherwise known as the Safe Replica of the Outlook’s MailItem. Looking inside it points to the ITSM Redemption DLL: I happen to know that we also have a DLL of a same name but different version for another product that is also a .NET application, both of which are an application extension for Outlook. I compare this with another workstation that has ITSM installed, but here the other application (WorkShare) has populated InprocServer32 instead: Although it shouldn’t matter which version of the DLL is being used to populate this key, as an experiment I decide to edit the registry of the workstation with the Outlook delay with the information of the WorkShare product. Interestingly, upon opening a new message, there was no longer a delay. There was, however, still a noticeable hang when sending an email; there were probably some additional guids or reg keys that are involved, but at this point it was no longer necessary to track them down. Instead, I should be able to resolve the issue by uninstalling ITSM. Upon doing so, it deleted the guid above. However, since this guid exists with the WorkShare product, running a scripted fix of WorkShare recreated the key. Afterwards, I was able to open a new message promptly and send it with no further delays. The real moment of truth, however, was to reinstall ITSM and then ensure the hangs did, in fact, not come back, and I was happy to see they didn’t.

I also took a look with Process Monitor just to see what files were also being queried during the new message delay. The dumped functions already alluded to this but you can specifically see 2500+ file operations in the .NET Global Assembly Cache (C:\Windows\Assembly), which accounts for 5 seconds of delay each time a new message was being opened in Outlook: Looking at the stack of any of these operations produces a similar stack to that of the dump in WinDbg:

And finally, 100s of registry operations for installation data of the installed applications on the workstation: