通过

Debugging Your Profiler I: Activation

  • 项目

This is the first of some tips to help you debug your profiler.  Note that these tips assume you're using CLR 2.x (see this entry for info on how CLR version numbers map to .NET Framework version numbers).  In today's post, I address a frequent question from profiler developers and users: "Why didn't my profiler load?".

Event log

In the Application event log, you'll see entries if the CLR attempts, but fails, to load and initialize your profiler.  So this is a nice and easy place to look first, as the message may well make it obvious what went wrong.

The next step is to carefully retrace this chain to make sure everything is registered properly:

Environment variables --> Registry --> Profiler DLL on File system.

The first link in this chain is to check the environment variables inside the process that should be profiled.  If you're running the process from a command-prompt, you can just try a "set co" from the command prompt:

 C:\> set co(blah blah, other vars beginning with "co")
 Cor_Enable_Profiling=0x1COR_PROFILER={C5F90153-B93E-4138-9DB7-EB7156B07C4C}

If your scenario doesn't allow you to just run the process from a command prompt, like say an asp.net scenario, you may want to attach a debugger to the process that's supposed to be profiled, or use IFEO (HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\Image File Execution Options) to force a debugger to start when the worker process starts.  In the debugger, you can then use "!peb" to view the environment block, which will include the environment variables.

Once you verify Cor_Enable_Profiling and COR_PROFILER are ok, it's time to search the registry for the very same GUID set in your COR_PROFILER environment variable.  You should find it at a path like this:

HKEY_LOCAL_MACHINE\SOFTWARE\Classes\CLSID\{C5F90153-B93E-4138-9DB7-EB7156B07C4C}

Note! If you're on a 64 bit box, be aware of the WOW64 redirectors, and ensure you're looking at the proper view of the environment and registry!

If the registry has the GUID value, it's finally time to check out your file system.  Go under the InprocServer32 subkey under the GUID:

HKEY_LOCAL_MACHINE\SOFTWARE\Classes\CLSID\{C5F90153-B93E-4138-9DB7-EB7156B07C4C}\InprocServer32

and look at the default value data.  It should be a full path to your profiler's DLL.  Verify it's accurate.  If not, perhaps you didn't properly run regsvr32 against your profiler, or maybe your profiler's DllRegisterServer had problems.

Time for a debugger

If the above investigation indicates everything's ok, then your profiler is properly registered and your environment is properly set up, but something bad must be happening at run time.  You'll want symbols for the CLR, which are freely available via Microsoft's symbol server.  If you set this environment variable, you can ensure windbg will always use the symbol server:

set _NT_SYMBOL_PATH=srv*C:\MySymbolCache*https://msdl.microsoft.com/download/symbols

Feel free to add more paths (separate them via ";") so you can include your profiler's symbols as well.  Now, from a command-prompt that has your Cor_Enable_Profiling and COR_PROFILER variables set, run windbg against the executable you want profiled.  The debuggee will inherit the environment, so the profiling environment variables will be propagated to the debuggee.

Note: The following contains implementation details of the runtime. While these details are useful as a debugging aid, your profiler code cannot make assumptions about them. These implementation details are subject to change at whim.

Once windbg is running, try setting this breakpoint:

bu mscordbc!EEToProfInterfaceImpl::CreateProfiler

Now go!  If you hit that breakpoint, that verifies the CLR has determined that a profiler has been requested to load from the environment variables, but the CLR has yet to read the registry.  Let's see if your DLL actually gets loaded.  You can use

sxe ld NameOfYourProfiler.dll

or even set a breakpoint inside your Profiler DLL's DllMain.   Now go, and see if your profiler is getting loaded.  If you can verify your profiler's DLL is getting loaded, then you now know your registry is pointing to the proper path, and any static dependencies your profiler has on other DLLs have been resolved.  But will your profiler COM object get instantiated properly?  Set breakpoints in your class factory (DllGetClassObject) and your profiler COM object's QueryInterface to see if you can spot problems there.  For example, if your profiler only works against CLR 1.x, then the CLR's call into your QueryInterface will fail, since you don't implement ICorProfilerCallback2.

If you're still going strong, set a breakpoint in your profiler's Initialize() callback.  Failures here are actually a popular cause for activation problems.  Inside your Initialize() callback, your profiler is likely calling QueryInterface for the ICorProfilerInfoX interface of your choice, and then calling SetEventMask, and doing other initialization-related tasks, like calling SetEnterLeaveFunctionHooks(2).  Do any of these fail?  Is your Initialize() callback returning a failure HRESULT?

Hopefully by now you've isolated the failure point.  If not, and your Initialize() is happily returning S_OK, then your profiler is apparently loading just fine.  At least it is when you're debugging it.  :-)

Comments

  • Anonymous
    December 12, 2007
    Hi David,  thank you for the article. We've been developing .NET monitoring solution based on profiler API for a few years so far and we had a couple of cases when profiler just did not start in the customer environment. Both times we've seen this in MCMS 2002 environment. MCMS installs additional ISAPI filters etc.. So may be that was the reason. It is interesting, though, that both times there were no errors from CLR (and that usually happens when CLR has not enough permissions or it can not find profiler for some other reason). And the last time we have confirmed that both env variables are in w3wp process, mscorlib is there.. And still it looked like CLR did not even try to load the profiler. Any chance you've passed through such a scenario? Thank you, Alex

  • Anonymous
    December 12, 2007
    Hi, Alex!  It's hard for me to imagine likely causes of what you described, other than what's already in this post.  It is true that, in extreme out-of-memory conditions, the CLR won't even bother to try loading your profiler.  But these are really extreme--this is when the OS heap manager simply refuses any more requests.  So I'd expect you'd see much worse problems if that were the case.  Also, I wonder if the CLR itself is simply not loaded into your worker process until the first request it services (I forget if the worker process loads the CLR on startup, or only lazily at first request time).  Certainly, if the CLR isn't loaded yet, then your profiler won't either.

  • Anonymous
    December 12, 2007
    Very nice and informative post. In my experience, the most common causes of profiler load failures are -

  1. Forgetting to register your COM profiler DLL using regsvr32.
  2. Incorrectly implementing your COM profiler DLL's DllRegisterServer() method.
  3. Not setting the required environment variables or setting them incorrectly. Very very rarely have I seen a profiler load failure because of a CLR bug.

  • Anonymous
    January 04, 2008
    Hi David,  Thanks for the answer. I was out for vacation, then Christmas etc.. The interesting thing is that CLR was loaded. We've checked presense of mscorlib.dll in the process so definetely it should be there. Ok.. Hopefully we'll not see this again) -Alex

  • Anonymous
    October 03, 2008
    The comment has been removed

  • Anonymous
    October 03, 2008
    Hello, Sriram.  Would you please post your question on our forum here? http://social.msdn.microsoft.com/forums/en-US/netfxtoolsdev/threads/ That’s the best way to ensure we track your question and get it answered.                                                                Thanks,                                                                Dave

  • Anonymous
    March 07, 2014
    I had a problem with my profiler activation. My COM profiler was in a x64 DLL, and I was trying it on a Any CPU built .net executable. I assumed it would run in 64-bit and everything would be fine. Turns out there was a "Prefer 32-bit" option checked for the .net project. Unchecking that option made my profiler dll load correctly instead of having .NET Runtime version 4.0.30319.34011 - Loading profiler failed during CoCreateInstance.  Profiler CLSID: '{B2308A4F-8CC9-4346-A649-2612FA6337D4}'.  HRESULT: 0x80040154.  Process ID (decimal): 15676.  Message ID: [0x2504].