Strange Registry Behaviour with log4net key

Topics: General Questions
Jan 17, 2011 at 5:18 PM

Hi Guys,

Wonder if you can shed some light on what may be happening here?

I am porting some BizTalk 2006 Applications to BizTalk 2010. These apps were developed using an earlier (v5.0.9) version of the Deployment Framework as 32-bit Applications on a 64-bit OS (Windows Server 2003 64-bit).

These Apps are in production and working well and the Deployment Framework was a great aide in this. The one thing I had to do was to add some custom Registry work in the custom deploy/undeploy targets of my build file to manage both the Wow6432 issues and also creating/deleting Event Sources for the log4net EventLog Appender.

Now we are moving to BizTalk 2010 I've upgraded to V5.0.25RC of the Framework. In doing some I wanted to clean up, and possibly remove, my custom Registry Handling code because I understood that the previous 32-bit/64-bit Registry issues had been addressed. I'm not sure whether this is a misconception on my part or whether I've stumbled on a bug. Here's my problem.

While working with the new version of the Deployment Framework I noted that there were still some problems with Registry Handling to do with using the correct script interpreter: Cscript.exe or Cscript64.exe.

To get around this I modified the Frameworks BizTalkDeploymentFramework.targets file (excuse the liberty) to select the correct version of Cscript as follows:

    <!-- Use 32 bit cscript.exe if on 32 bit windows -->

    <CreateProperty Value="cscript.exe" Condition="'$(Is64bitOS)' == 'false' and '$(Cscript)' == ''">

        <Output TaskParameter="Value" PropertyName="Cscript" />

    </CreateProperty> 

   <!-- Use 32 bit cscript.exe if on 64 bit windows and using 32 bit App Hosts -->

    <CreateProperty Value="cscript.exe" Condition="'$(Is64bitOS)' == 'true' and '$(Is32BitAppHost)' == 'true' and '$(Cscript)' == ''">

        <Output TaskParameter="Value" PropertyName="Cscript" />

    </CreateProperty>

    <!-- Use 64 bit cscript.exe if on 64 bit windows and using 64 bit App Hosts -->

    <CreateProperty Value="$(DeployTools)\cscript64.exe" Condition="'$(Is64bitOS)' == 'true' and '$(Is32BitAppHost)' == 'false' and '$(Cscript)' == ''">

        <Output TaskParameter="Value" PropertyName="Cscript" />

    </CreateProperty>

 

'Is32BitAppHost' is an extra property set in my build script to either true or false. Now when I run my build script I get the Application Key (holding the log4netConfig file path) in the correct SOFTWARE hive depending on the value I've set in my build script for the 'Is32BitAppHost' property. Job done, or so I thought...

When I execute a simple C# NUnit Test method from within VS.NET (via ReSharper) that exercises a simple C# Helper function (which utilises log4net for application logging) I get the following error:

"log4netConfigHelper: Unable to read registry key for log4net configuration location."

Checking the Registry I can see the Application Key for my application correctly located in the Wow6432 Node of the SOFTWARE Hive, and as expected there is no entry in the SOFTWARE Hive as this Application will run only on 32-bit Hosts - at least for the time being.

I've traced that error message text to the Getlog4netConfigLocation method of the log4net.Ext.Serializable assembly, this is implemented as follows:

private static string Getlog4netConfigLocation(string registryPath)

{

    RegistryKey localMachine = Registry.LocalMachine;

    string str = string.Empty;

    try

    {

        str = (string) localMachine.OpenSubKey(@"SOFTWARE\" + registryPath).GetValue(RegValue);

    }

    catch

    {

        throw new Exception("log4netConfigHelper: Unable to read registry key for log4net configuration location.");

    }

    return str;

}

This code appears to be looking in the 64-bit SOFTWARE Hive even though the test is executing from Visual Studio.NET 2010 which is running as a 32-bit process (so it doesn't seem to be behaving in the same way as Cscript.exe/Cscript64.exe). I also saw this same error message when I ran another test were the call to configure log4net was being made from code inside the 32-bit BizTalk Application Host. So despite running in 32-bit hosting processes the Getlog4netConfigLocation appears to be looking in the 64-bit Software Hive.

The work-around for this appears to be having an identical Application key setup in both the 64-bit and 32-bit SOFTWARE Hives. While this works it doesn't feel right - this application is expected to only run as a 32-bit application so why the need for entries in the 64-bit Registry entry?

Am I missing something here or is there a fix that needs to be applied to the log4net.Ext.Serializable assembly to make it aware of the bit-size of its hosting process and to look in the appropriate Registry Hive?

Thanks in advance.

 

 

 

Jan 18, 2011 at 4:06 PM

Ok, some further testing has revealed some interesting behaviour.

First off, I now think there is no problem with the way Getlog4netConfigLocation is handling the Registry (not too surprised about that, but when these things bite you start questioning everything!). I think the problem is very much down to the bit-size of the host actually executing the test.

The Red-Herring here is the fact that since VS.NET 2010 is running as a 32-bit process my tests should access the settings in the Wow6432 SOFTWARE Hive. This statement is true, but it's not the full picture. Remember I said that I was using ReSharper 5.x to execute my NUnit unit test. It would appear that when you run a test this way ReSharper executes a shell process to run the NUnit test. Its details are as follows:

 - JetBrains.ReSharper.TaskRunner.CLR4.MSIL.exe

 - Located at C:\Program Files (x86)\JetBrains\ReSharper\v5.1\Bin.

 - This file shows a product version of v5.1.1753.4.

 - There is no '*32' at the side of it in Task Manager so I'm guessing this is running as a 64-bit process (someone please correct me if I've got this wrong).

 - I've watched it in Task Manager but I couldn't see any version of NUnit being launched (I ran the test in Debug mode and blocked execution on a breakpoint so if one of the NUnit console apps was being executed I should have seen it and I didn't), so I assume this ReSharper helper is executing the test directly.

Anyway, if I remove the Registry Key from the 64-bit SOFTWARE Hive and run the test from VS.NET 2010 via ReSharper 5.x it fails. If I put the entry back it passes.

If I once again remove the Registry Key from the 64-bit SOFTWARE Hive but this time I run the test directly from the 32-bit and 64-bit versions of the NUnit GUI (upgraded to version 2.5.9 due to .NET 4.0 issues), it fails to find the Registry Key from the 64-bit NUnit GUI but succeeds from the 32-bit NUnit GUI. Put the key back in the 64-bit SOFTWARE Hive and both the 32-bit and the 64-bit versions successfully find the Registry Key. I draw three conclussions from this:

1) Getlog4netConfigLocation is correctly adapting to the bit-size of the hosting process.

2) NUnit tests executed from VS.NET 2010 by ReSharper 5.x are run from within a 64-bit process even though VS.NET itself is running as a 32-bit process.

3) If point 2) above is true (and I believe it is) then it would appear that the only solution to this is in fact to have both 32-bit and 64-bit versions of the Application Registry Key in the Registry.

 

The best way to address point 3) is probably for me to revert the 'Cscript' property creation code (see first posting) to it's original form, forget about the 'Is32BitAppHost' property and modify the PreprocessAndConfigureLog4net target so that the Cscript is executed twice (once for 32-bit and once for 64-bit - if on a 64-bit OS) to call WriteRegValue.vbs to write the Log4netRegKey to the correct SOFTWARE Hive.

Any thoughts?

Coordinator
Jan 18, 2011 at 4:55 PM

Hi, thanks for all of the detailed analysis.  That helps out a lot in diagnosing these issues.

To go back to your initial post, the log4net 32/64-bit registry issue has NOT been addressed.  (http://biztalkdeployment.codeplex.com/workitem/4788)

You're correct on the *32 in Task Manager -- that means a 32-bit process, so if the test runner doesn't have that then it's definitely running as 64-bit even though VS 2010 is 32-bit.

To your last point, you'll see in the Issue Tracker that my plan to fix this was essentially the same as your conclusion -- write the same registry key into both the 32-bit and 64-bit registry locations.  In .NET 4.0 one can program against either view of the registry, so it's easy to do it in a clean way.  Unfortunately that doesn't exist in .NET 2.0 (our target for backwards compatibility).  Maybe I will just have to address it by opening and writing directly to the WOW6432 hive instead of going through the API.  Anyhow, you could probably get away with using a .reg file that includes both keys and running it with regedit /S, or something along the lines of your suggestion.

I tend to think that this will not be addressed for the 5.0 final release, so you should proceed with a workaround for now.

Thanks!
Tom

Jan 19, 2011 at 7:19 AM

Hi Thomas,

Thanks for the, as always, prompt response.

That clears things up a bit. I think I will progress along the lines I have suggested for now. If the ReSharper Test Runner is going to behave in this way then I don't see an alternative to having copies of the Application Registry Entry in both the 64-bit and 32-bit Registry's. It's a bind and if any manual Registry tweaks need to be performed by Ops then procedures will need to ensure they change both sets - a situation I'd prefer to avoid but I don't see an alternative.

There's one final test I want to perform with ReSharper; my C# and BizTalk assemblies are compiled as 'Any CPU'. I'm curious to see if compiling them as 32-bit only affects what ReSharper does. I'll let you know the outcome.

Regards,

Simon

 

Jan 19, 2011 at 9:42 AM

Hi Thomas,

So, as I suspected, ReSharper is actually acting rather sensibly - can't say I'm surprised as this tool has been my constant development companion and it has never let me down!

My original C# and BizTalk Assemblies were compiled in VS.NET 2010 for 'Any CPU'. In this situation ReSharper is executing my test using its x64 Test Runner because it can - I'm on a 64-bit OS, my code is compiled for Any CPU so it not unreasonably infers that's what I want.

When I re-build my assemblies as 'x86', ReSharper executes my test using its 32-bit Test Runner because that's the logical thing to do - and now my test passes and the log4net config file entry can be found when the x64 SOFTWARE Hive Registry Entry is absent.

So where from here? Clearly I can build my assemblies as 'x86' to force the issue since they are only intended to run in 32-bit hosts at the moment. However, given the move to Windows Server 2008 and BizTalk 2010 I can see that changing (my client avoided using 64-bit hosts with BizTalk 2006 because of problems they encountered) and I'd rather not re-work my work around in the not too distant future.

My intended approach will therefore be to revert my assembles to 'Any CPU' and follow the workaround I noted earlier:

  • Revert the 'Cscript' property creation code (see first posting) to it's original form
  • Forget about the 'Is32BitAppHost' property creation and handling
  • Modify the PreprocessAndConfigureLog4net target so that the Cscript is executed twice (once for 32-bit and once for 64-bit - if on a 64-bit OS) to call WriteRegValue.vbs to write the Log4netRegKey to the correct SOFTWARE Hive.

This way my code is ready for 64-bit BizTalk hosts and my deployment process supports 32-bit and 64-bit execution hosts - meaning my NUnit tests continue to run under ReSharper control within VS.NET.

 

Regards,

Simon