Search code examples
.net.net-4.0clrngenclr-profiling-api

Why do plain, non-profile-optimized native images aren't loaded by my CLR profiler?


I'm developing a CLR profiler, using the CLR profiling interfaces, and having a hard time getting the CLR to load plain, non-profile-optimized native images (that were compiled with ngen.exe without the /profile option) when running my profiler (or at least, it seems that such images are not loaded, but for now I can't tell for sure). What am I doing wrong?

I have verified that the COR_PRF_USE_PROFILE_IMAGES flag (which will only allow for profile optimized native images) is not set in my profiler.

Below is what I've tried. Any help/tips are much appreciated!

FUSLOGVW outputs:

I've been inspecting the native image binder logs (in FUSLOGVW.exe) trying to figure out whether images are loaded or not:

  • When running HelloWorld.exe with a "plain" native image - that was NGEN'd with ngen.exe install HelloWorld.exe with profiler enabled - the assembly binder log (ExplicitBind!FileName=(HelloWorld.exe).HTM) shows:

    Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
    Running under executable  d:\work\dotnet\projects\HelloWorld\HelloWorld\bin\x64\Debug\HelloWorld.exe  
    --- A detailed error log follows. 
    
    WRN: Native image compile options do not match request. Looking for next native image.
    

    So it seems, based on that warning, that the native image wasn't loaded.

  • When running with a profile image, NGEN'd with ngen.exe install HelloWorld.exe /Profile, the image seems to be loaded successfully, and the assembly binder output is:

    LOG: Start validating all the dependencies.  
    LOG: [Level 1]Start validating native image dependency mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089.
    Native image has correct version information.  
    LOG: Validation of dependencies succeeded.  
    LOG: Bind to native image succeeded.  
    Attempting to use native image C:\WINDOWS\assembly\NativeImages_v4.0.30319_64\HelloWorld\5647de1868c93e9132a1952a34e0a785\HelloWorld.ni.exe.  
    Native image successfully used.
    

    So it seems that this time, the image was loaded.

  • Just for making sure, between each ngen step I removed c:\Windows\assembly\NativeImages_v4.0.30319_32\mscorlib for all images to agree on used settings (there are no additional dependencies to HelloWorld.exe).

Additional Information:

  • I'm using .NET 4.0, so I don't have access to COR_PRF_DISABLE_ALL_NGEN_IMAGES, which disables native images altogether (described in this blog post from David Broman). This could have been helpful for troubleshooting.

Solution

  • Coming back to answer my own question, it seems that the native images were indeed loaded! (both kinds - plain and profile optimized). The problem was my understanding that this was indeed the case.

    The source of my consufion was misreading FUSLOGVW log outputs. Specifically, somehow I missed to see that WRN: Native image compile options do not match request. Looking for next native image was given for the /profile image, but image search continued and found the plain, non profile image, and succeeded.

    What helped my understanding eventually was Visual Studio. When debugging the CLR profiler in Visual Studio, the binding of native images was displayed in the Debug Output window, where it also showed the DLLs being loaded:

    'CSharpTestProgram.exe' (Win32): Loaded 'C:\Windows\assembly\NativeImages_v4.0.30319_64\mscorlib\2ef49acbb43c068f6ddf1587283b5f29\mscorlib.ni.dll'. 
    

    Visual Studio - Output - Native Image

    Once I got this, FUSLOGVW logs started to make more sense, and I could understand exactly which image is loaded and when.

    Another observation was that the mscorlib /profile image takes up more disk space than the plain native image (30% larger in my case), which also helped me correlate between the image path and whether it's /profile or not.