I don’t know about you lot, but logging is something that one simply can’t avoid. We kind of rely on it a lot (too much probably).
Well today we were trying to find a problem with something we had written which spawns a new AppDomain which does some stuff and is torn down again. The code was working fine in one environment but not in another, so we thought no problem, we’ll just crack open the log files on offending box and take a peek, see what’s up.
I should mention we use Log4Net so this post is only applicable if you use Log4Net.
Turns out we did not have that much to go by in the logs, they were kind of sparse. Now all the logging was in place, mmm what could be up. Turns out we were stupid.
Truth is we had never noticed that when the new AppDomain was created we saw no logging from log entries created in the new AppDomain. Strange, or was it.
Turns out there is some things you need to do with Log4Net. I will of course, talk about these, but first lets see some setup code, suppose I have a Log4Net ILog helper that looks like this:
public static class LogManager
{
private static ILog log = null;
public static ILog Log
{
get { return log ?? (log = log4net.LogManager.GetLogger(
MethodBase.GetCurrentMethod().DeclaringType)); }
}
}
And I have some logging in my 1st AppDomain (where this is a EXE) like this
{
static void Main(string[] args)
{
XmlConfigurator.Configure();
LogManager.Log.InfoFormat(
"Main method of Log4NetAcrossAppDomain.Program");
SeperateAppDomainAssemblyLoader loader =
new SeperateAppDomainAssemblyLoader();
loader.DoSomethingInNewAppDomain();
Console.ReadLine();
}
}
Where my App.Config looks like this
<?xml version="1.0"?>
<configuration>
<configSections>
<section name="log4net"
type="log4net.Config.Log4NetConfigurationSectionHandler,
log4net"/>
</configSections>
<!-- Log4net -->
<log4net>
<appender name="ConsoleAppender"
type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<param name="ConversionPattern"
value="%d [%t] %-5p [%x] - %m%n"/>
</layout>
</appender>
<appender name="RollingFileAppender"
type="log4net.Appender.RollingFileAppender">
<file type="log4net.Util.PatternString"
value="Log4NetAcrossAppDomain.log"/>
<rollingStyle
value="Composite"/>
<datePattern
value="yyyyMMdd"/>
<maxSizeRollBackups
value="100"/>
<maximumFileSize
value="15MB"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern
value="%date %-5level %logger: %message%newline"/>
</layout>
</appender>
<appender name="TraceAppender"
type="log4net.Appender.TraceAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern
value="%date [%thread] %-5level
%logger [%property{NDC}] - %message%newline"/>
</layout>
</appender>
<!-- On Win7 you need to some trickery to ensure the eventlog is already created -->
<appender name="EventLogAppender"
type="log4net.Appender.EventLogAppender">
<param name="LogName"
value="Application"/>
<param name="ApplicationName"
value="Log4NetAcrossAppDomain Program"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern
value="%date [%thread] %-5level
%logger [%property{NDC}] - %message%newline"/>
</layout>
</appender>
<root>
<level value="ALL"/>
<appender-ref ref="RollingFileAppender"/>
<appender-ref ref="ConsoleAppender"/>
<appender-ref ref="TraceAppender"/>
<appender-ref ref="EventLogAppender"/>
</root>
</log4net>
</configuration>
And I have a new AppDomain which is created like this
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using log4net.Config;
using System.Security.Policy;
using Common;
namespace SeperateAppDomain
{
public class SeperateAppDomainAssemblyLoader
{
public bool DoSomethingInNewAppDomain()
{
AppDomain childDomain = null;
try
{
childDomain = BuildChildDomain(AppDomain.CurrentDomain);
Type loaderType = typeof(AssemblyLoader);
if (loaderType.Assembly != null)
{
var loader = (AssemblyLoader)childDomain.CreateInstanceFrom(
loaderType.Assembly.Location, loaderType.FullName).Unwrap();
return loader.DoSomething();
}
return false;
}
catch (Exception ex)
{
LogManager.Log.Error("Problem in SeperateAppDomainAssemblyLoader DoSomethingInNewAppDomain", ex);
return false;
}
finally
{
if (childDomain != null)
AppDomain.Unload(childDomain);
}
}
private AppDomain BuildChildDomain(AppDomain parentDomain)
{
Evidence evidence = new Evidence(parentDomain.Evidence);
AppDomainSetup setup = parentDomain.SetupInformation;
return AppDomain.CreateDomain("DiscoveryRegion", evidence, setup);
}
}
public class AssemblyLoader : MarshalByRefObject
{
public bool DoSomething()
{
for (int i = 0; i < 10; i++)
{
LogManager.Log.InfoFormat(
"AssemblyLoader DoSomething is logging {0}", i.ToString());
}
return true;
}
}
}
When I run this code, I will not see anything logged from the newly created AppDomain.
Now why is this, there are several things wrong here, but luckily we can fix them all. Lets see what they are and how we can fix them.
STEP 1 : Fix the LockingModel for the RollingFileAppender
Log4Net actually comes with something that helps us out, which is that we can specify what sort of LockingModel to use for the RollingFileAppender which is the one that would typically have problems.
To fix it simply add this line to the RollingFileAppender Log4Net config
<lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>
So now your full “RollingFileAppender†Log4Net config should look like this
<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
<file type="log4net.Util.PatternString" value="Log4NetAcrossAppDomain.log"/>
<lockingModel type="log4net.Appender.FileAppender+MinimalLock"/>
<rollingStyle value="Composite"/>
<datePattern value="yyyyMMdd"/>
<maxSizeRollBackups value="100"/>
<maximumFileSize value="15MB"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %-5level %logger: %message%newline"/>
</layout>
</appender>
STEP 2 : Make sure the new AppDomain picks up configuration
I don’t know about you but when we do any separate AppDomain stuff, we always have that in a separate Dll. Now what that means is that the new AppDomain will be created correctly, but there is no way it picks up the original AppDomain (I am assuming something that already has working Web.Config|App.Config file) config file.
What can we do about this. Again the answer is pretty simple, we just need to carry out an extra step when we create the new AppDomain. Here is the revised new AppDomain creation code
private AppDomain BuildChildDomain(AppDomain parentDomain)
{
Evidence evidence = new Evidence(parentDomain.Evidence);
AppDomainSetup setup = parentDomain.SetupInformation;
//The next line is important as it tells this AppDomain to use the original
//AppDomains config file settings, you know things like log4Net config settings
setup.ConfigurationFile = parentDomain.SetupInformation.ConfigurationFile;
return AppDomain.CreateDomain("DiscoveryRegion", evidence, setup);
}
See the line where we grab the ConfigurationFile from the parent AppDomain, that allows new AppDomain to see the spawning AppDomain config values. Since the parent AppDomain contained all the Log4Net config, this is getting us a step close to fixing our missing Log4Net logging.
STEP 3 : Make sure the new AppDomain configures the Logger
The last piece of the puzzle is to ensure that the new AppDomain also configures its own logger. Here is that code.
public class AssemblyLoader : MarshalByRefObject
{
public AssemblyLoader()
{
XmlConfigurator.Configure();
}
}
That’s it we now have fully working Log4Net logging in 2 AppDomains (that is what the demo app shows anyway).
Don’t believe me, well here is a screen shot:
NOTE : The demo app uses the EventLog as an Appender too, and on Windows7 you need to ensure this EventSource is already setup.
As always here is a small demo project that illustrates this
http://dl.dropbox.com/u/2600965/Blogposts/2011/12/Log4NetAcrossAppDomain.zip
Sacha's Blog 
can we do this with nlog?
I haven’t used NLog so I cant comment on that one