Dynamic log file Names with log4net

If you needed to generate dynamic logfile names with log4net then you can use the following config

   1: <appender name="RollingFileAppenderV1" type="log4net.Appender.RollingFileAppender">

   2:     <file type="log4net.Util.PatternString" value="F:\HornetFeed\%property{LogName}" />

   3:     <appendToFile value="true" />

   4:     <rollingStyle value="Size" />

   5:     <maxSizeRollBackups value="-1" />

   6:     <maximumFileSize value="5000KB" />

   7:     <staticLogFileName value="true" />

   8:     <countDirection value="1"/>

   9:     <layout type="log4net.Layout.PatternLayout">

  10:         <conversionPattern value="%m%n" />

  11:     </layout>

  12:     <filter type="log4net.Filter.PropertyFilter">

  13:         <Key value="Version" />

  14:         <StringToMatch value="1" />

  15:     </filter>

  16:     <filter type="log4net.Filter.DenyAllFilter" />

  17: </appender>

Note the %property{LogName} this is a log4net Property which we can set at runtime using C# code.

   1: log4net.GlobalContext.Properties["LogName"] = "file1.log";

Remember to set the GlobalContext Properties before instantiating the log4net logger. i.e. before this call:

   1: log4net.ILog log = LogManager.GetLogger(typeof(Program));

Also note the “PropertyFilter”

   1: <filter type="log4net.Filter.PropertyFilter">

   2:     <Key value="Version" />

   3:     <StringToMatch value="1" />

   4: </filter>

This Property is also set dynamically at runtime using C# code. We can use ThreadContext to determine which logfile the log entry will be written to. Thus if you wanted that the RollingFileAppenderV1 was used for writing insure that the Thread calling the log.Warn method precedes the call with this following line

   1: log4net.ThreadContext.Properties["Version"] = "1";

If you wanted to use RollingFileAppenderV1 always for logging all messages other than Exception messages then use the following

   1: try

   2: {

   3:     log4net.GlobalContext.Properties["Version"] = "1";

   4:     //Business logic with many log.Warn calls

   5: }

   6: catch (Exception ex)

   7: {

   8:     LogError(ex);

   9: }

  10:  

  11: ///Helper method to log errors:

  12: internal static void LogError(Exception ex)

  13: {

  14:     string state = "1";

  15:     if(log4net.ThreadContext.Properties["Version"] != null)

  16:         state = log4net.ThreadContext.Properties["Version"].ToString();

  17:     log4net.ThreadContext.Properties["Version"] = "0";

  18:     logger.HandleException(ex, "Error");

  19:     log4net.ThreadContext.Properties["Version"] = state;

  20: }

Note I am using GlobalContext and hence all threads will use this setting to write to log files. No need to set the TrheadContext.Properties on individual threads.

But I prefer to use ThreadContext so that we can control the setting on each thread level.

Also make sure the log4net XML config is set as follows:

   1: <log4net>

   2: // the following logs only those logs when the Property Version is set to 1 i.e.

   3: // if Version =1  then log.Warn calls are logged to this dynamically named file

   4:     <appender name="RollingFileAppenderV1" type="log4net.Appender.RollingFileAppender">

   5:         <file type="log4net.Util.PatternString" value="F:\HornetFeed\%property{LogName}" />

   6:         <appendToFile value="true" />

   7:         <rollingStyle value="Size" />

   8:         <maxSizeRollBackups value="-1" />

   9:         <maximumFileSize value="5000KB" />

  10:         <staticLogFileName value="true" />

  11:         <countDirection value="1"/>

  12:         <layout type="log4net.Layout.PatternLayout">

  13:             <conversionPattern value="%m%n" />

  14:         </layout>

  15:         <filter type="log4net.Filter.PropertyFilter">

  16:             <Key value="Version" />

  17:             <StringToMatch value="1" />

  18:         </filter>

  19:         <filter type="log4net.Filter.DenyAllFilter" />

  20:     </appender>

  21:  

  22: //The following matches and logs all events except Version=1 and Version=2 and strings containing CACHE_CALL_LOG

  23:  

  24:     <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">

  25:         <file type="log4net.Util.PatternString" value="F:\logfiles\trace.log" />

  26:         <appendToFile value="true" />

  27:         <rollingStyle value="Size" />

  28:         <maxSizeRollBackups value="10" />

  29:         <maximumFileSize value="3000KB" />

  30:         <staticLogFileName value="true" />

  31:         <countDirection value="1"/>

  32:         <layout type="log4net.Layout.PatternLayout">

  33:             <conversionPattern value="%d [%t] %-5p %c [%x] - %m%n" />

  34:         </layout>

  35:         <filter type="log4net.Filter.PropertyFilter">

  36:             <Key value="Version" />

  37:             <StringToMatch value="1" />

  38:             <acceptOnMatch value="false" />

  39:         </filter>

  40:         <filter type="log4net.Filter.PropertyFilter">

  41:             <Key value="Version" />

  42:             <StringToMatch value="2" />

  43:             <acceptOnMatch value="false" />

  44:         </filter>

  45:         <filter type="log4net.Filter.StringMatchFilter">

  46:             <stringToMatch value="CACHE_CALL_LOG" />

  47:             <acceptOnMatch value="false" />

  48:         </filter>

  49:     </appender>

Posted in: programming asp.net | Tags: log4net dynamic log file file name path log path

---

Log4Net, Log Event Context

There are times when your log messages need some context to be most useful.  For example, if your application supports multiple concurrent clients, it would be helpful to know the client to which each log statement applies.  If a piece of code is used by several components, it would be nice for the log messages to reflect which component is calling the code.  log4net provides a very simple mechanism to accommodate such needs.

Open Visual Studio, create a new console project, and add a reference to the log4net assembly.  Add the following code to your program.cs file:

 

1. namespace Tutorial6_Context 
2. { 
3. class Program 
4.     { 
5. private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType ); 
7. static void Main( string[] args ) 
8.         { 
9.             log4net.Config.XmlConfigurator.Configure(); 
10.             log4net.ThreadContext.Properties[ "myContext" ] = "Logging from Main"; 
11.             Log.Info( "this is an info message" ); 
12.             Console.ReadLine(); 
13.         } 
14.     } 
15. } 

namespace Tutorial6_Context
{     class Program     {         private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );         static void Main( string[] args )         {             log4net.Config.XmlConfigurator.Configure();             log4net.ThreadContext.Properties[ "myContext" ] = "Logging from Main";             Log.Info( "this is an info message" );             Console.ReadLine();         }     }
}

Note line 10, where a property named "myContext" is added to the ThreadContext static class and assigned a simple string value.  Next add the following application configuration file to the project:

 

1. <configuration>
2. <configSections>
3. <section name="log4net"
4. type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>
5. </configSections>
7. <log4net>
9. <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
10. <layout type="log4net.Layout.PatternLayout">
11. <conversionPattern value="%logger (%property{myContext}) [%level]- %message%newline" />
12. </layout>
13. </appender>
15. <root>
16. <level value="ALL" />
17. <appender-ref ref="ConsoleAppender" />
18. </root>
19. </log4net>
20. </configuration>

<configuration>   <configSections>     <section name="log4net"       type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>   </configSections>   <log4net>       <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">       <layout type="log4net.Layout.PatternLayout">         <conversionPattern value="%logger (%property{myContext}) [%level]- %message%newline" />       </layout>     </appender>     <root>       <level value="ALL" />       <appender-ref ref="ConsoleAppender" />     </root>   </log4net>
</configuration>

Line 11 contains the layout pattern for our log; the %property{myContext} format specifier will be replaced with the value of the "myContext" property at the time the message is logged.

Compile and run; the context value is reflected in the log output:

 

1. Tutorial6_Context.Program (Logging from Main) [INFO]- this is an info message 

Tutorial6_Context.Program (Logging from Main) [INFO]- this is an info message

Context Scopes

There are actually three logging contexts available in log4net.  Like the logger architecture, contexts are organized into a hierarchy where properties in the more granular contexts override property values in less granular contexts.

Context
Description

log4net.GlobalContext
A global context shared across all application threads and app domains. If two threads set the same property on the GlobalContext, one value will overwrite the other.

log4net.ThreadContext
Any properties set in this context are scoped to the calling thread. In other words, in this context two threads can set the same property to different values without stomping on each other.

log4net.ThreadLogicalContext
This context behaves similarly to the ThreadContext, except that the scope is defined by logical thread boundaries. I'll be honest and say that I've never used the ThreadLogicalContext in my career, but if you're working with a custom thread pool algorithm or hosting the CLR, you may find some use for this one.

Calculated Context Values

Context property values don't have to be strings.  You can set the value of a context property to any object reference; the value of the object's ToString method will be used to obtain the context property value when a logging event occurs.  This can be useful when you need a context property to represent a calculated state at the time of each logging event.  For instance, perhaps you want to track your application's use of the CPU:

 

1. namespace Tutorial6_Context 
2. { 
3. public class CalcualtedContextProperty 
4.     { 
5. public override string ToString() 
6.         { 
7. return Process.GetCurrentProcess().TotalProcessorTime.ToString(); 
8.         } 
9.     } 
10. } 

namespace Tutorial6_Context
{     public class CalcualtedContextProperty     {         public override string ToString()         {             return Process.GetCurrentProcess().TotalProcessorTime.ToString();         }     }
}

Set a context property value to an instance of this new class:

 

1. namespace Tutorial6_Context 
2. { 
3. class Program 
4.     { 
5. private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType ); 
7. static void Main( string[] args ) 
8.         { 
9.             log4net.Config.XmlConfigurator.Configure(); 
10.             log4net.ThreadContext.Properties[ "myContext" ] = new CalculatedContextProperty(); 
11.             Log.Info( "this is an info message" ); 
12.             Console.ReadLine(); 
13.         } 
14.     } 
15. } 

namespace Tutorial6_Context
{     class Program     {         private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );         static void Main( string[] args )         {             log4net.Config.XmlConfigurator.Configure();             log4net.ThreadContext.Properties[ "myContext" ] = new CalculatedContextProperty();             Log.Info( "this is an info message" );             Console.ReadLine();         }     }
}

The result is each log entry containing the application's total CPU time at the time the log entry was made:

 

1. Tutorial6_Context.Program (00:00:00.2968750) [INFO]- this is an info message 

Tutorial6_Context.Program (00:00:00.2968750) [INFO]- this is an info message

ThreadContext Stacks

ThreadContext and ThreadLogicalContext can store property values in stacks (available via the Stacks static property of each class).  These stacks are very handy, as they allow you to track program states in the context of a log message:

 

1. namespace Tutorial6_Context 
2. { 
3. class Program 
4.     { 
5. static log4net.ILog Log = null; 
7. static void Main( string[] args ) 
8.         { 
9.             log4net.Config.XmlConfigurator.Configure(); 
10.             Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType ); 
11. using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "outer" ) ) 
12.             { 
13.                 Log.Info( "this is the first message" ); 
14. using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "inner" ) ) 
15.                 { 
16.                     Log.Info( "this is the second message" ); 
17.                 } 
18.             } 
19.             Log.Info( "this is the third message" ); 
20.             Console.ReadLine(); 
21.         } 
22.     } 
23. } 

namespace Tutorial6_Context
{     class Program     {         static log4net.ILog Log = null;         static void Main( string[] args )         {             log4net.Config.XmlConfigurator.Configure();             Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );             using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "outer" ) )             {                 Log.Info( "this is the first message" );                 using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "inner" ) )                 {                     Log.Info( "this is the second message" );                 }             }             Log.Info( "this is the third message" );             Console.ReadLine();         }     }
}

Pushing a property value onto a stack returns an IDisposable that, when disposed, pops the property value off of the stack.  The logging output reflects the state of the context stack at each logging event; the stack is represented as a space-delimited list, with newer items appearing later in the list:

Tutorial6_Context.Program (outer) [INFO]- this is the first message 

1. Tutorial6_Context.Program (outer inner) [INFO]- this is the second message 
2. Tutorial6_Context.Program ((null)) [INFO]- this is the third message 

Tutorial6_Context.Program (outer) [INFO]- this is the first message
Tutorial6_Context.Program (outer inner) [INFO]- this is the second message
Tutorial6_Context.Program ((null)) [INFO]- this is the third message

Context stacks are incredibly useful for wrapping access to a shared piece of code.  For example, in the following code two methods call the same utility routine; a marker is pushed onto the property stack before each call: namespace Tutorial6_Context 

1. { 
2. class Program 
3.     { 
4. static log4net.ILog Log = null; 
6. static void Main( string[] args ) 
7.         { 
8.             log4net.Config.XmlConfigurator.Configure(); 
9.             Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType ); 
11.             FirstAction(); 
12.             SecondAction(); 
14.             Console.ReadLine(); 
16.         } 
18. static void FirstAction() 
19.         { 
20. using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "FirstAction" ) ) 
21.             { 
22.                 UtilityRoutine(); 
23.             } 
24.         } 
26. static void SecondAction() 
27.         { 
28. using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "SecondAction" ) ) 
29.             { 
30.                 UtilityRoutine(); 
31.             } 
32.         } 
34. static void UtilityRoutine() 
35.         { 
36.             Log.Info( "this is an info message" ); 
37.         } 
38.     } 
39. } 

namespace Tutorial6_Context
{     class Program     {         static log4net.ILog Log = null;         static void Main( string[] args )         {             log4net.Config.XmlConfigurator.Configure();             Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );             FirstAction();             SecondAction();             Console.ReadLine();         }         static void FirstAction()         {             using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "FirstAction" ) )             {                 UtilityRoutine();             }         }         static void SecondAction()         {             using( log4net.ThreadContext.Stacks[ "myContext" ].Push( "SecondAction" ) )             {                 UtilityRoutine();             }         }                  static void UtilityRoutine()         {             Log.Info( "this is an info message" );         }     }
}

Posted in: programming asp.net | Tags: log4net log event context

---

log4net Dynamic Properties in XML Configuration.

I just learned about a new feature today of log4net that would have saved me a few hours of time had I known or been able to find this earlier.  I learned that you can have dynamic properties stored into log4net’s global context from code and then access them from the XML configuration file. This is useful in the case where dynamic configuration of log4net is needed.

My Case: I have been building console application that will run nightly to sync some integration records and I wanted to setup logging in order to see that status of the job and gather some reporting information (counts, time run, etc).  There was a catch though this process would run multiple times in a night but each time for a different customer.  This would make it difficult to read the logs for a particular customer as all I would have to go on is the file date and time.

I needed a way to break my log files into different customers yet retain the rolling file appender features of log4net.  My first pass at with was to configure log4net using the basic configurator all in code and create the appender, with a dynamic file name, and set the level of the logger programitacally. This was not my preferred way but was my only hope to getting the application out of developement. Then I found how to set properties into log4net’s global context and access them through the configuration file. I did run into a small problem that my app.config file was not being read in so I had to add these two variable to my assembly.

[assembly: log4net.Config.XmlConfigurator(Watch = true)]
[assembly: log4net.Config.Repository]

My goal was to make the file name dynamic based on the CustomerID passed into the application. Please not the file tag as it is the ticket to my case.

<log4net>
    <root>
        <level value="INFO" />
        <appender-ref ref="RollingLogFileAppender" />
    </root>   <!-- New Log File once per execution -->
    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
        <file type="log4net.Util.PatternString" value="logs\logFile_%property{BrokerID}.txt" /> <!-- Awesomeness -->
        <appendToFile value="false" />
        <rollingStyle value="Size" />
        <maxSizeRollBackups value="-1" />
        <maximumFileSize value="50GB" />
        <layout type="log4net.Layout.PatternLayout">
            <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
        </layout>
    </appender>
</log4net>

Here is a sample of my log4net configuration section. Please note the file tag and type attribute to be log4net.Util.PatternString. The pattern of the value is important to, it must be %property{property_name} to get the right replacement. This is the ticket to dynamic values.

private static void InitLogger()
{
    //This is freaking awesome, put a property into the log4net context and using the 
    //  log4net.Util.PatternString type you can dynamically set values for the logging context from code.
    log4net.GlobalContext.Properties["CustomerID"] = (CustomerID!= 0) ? CustomerID.ToString() : "Error";
}

Here is an example of my small InitLogger. This method is the very first item to be called when the main routine starts up. All that needs to be done now is get a logger and start logging. A file will be created based on the CustomerID which in this case is retrieved from the command line arguments before InitLogger is called. If no CustomerID is passed in than the file will be to logFile_Error.txt

private static ILog Logger;   static void Main(string[] args)
{
    if (args.Length > 0)
        CustomerID= Util.GetInt(args[0]);   InitLogger();
    Logger = LogManager.GetLogger("Process");
}

Pretty cool I think, I hope this saves people some headaches. I wish I would have found this a few days ago. Oh well it is to my benefit to learn. Happy coding.

Posted in: programming problems and solutions | Tags: log4net dynamic dynamic properties dynamic property xml configuration configurator programitacally

---

Additional Adapters in Spring - log4net

As log4net is a widely using logging framework, there are 2 additional adapters for log4net:

• Common.Logging.Log4Net
  is linked against log4net 1.2.10.0

• Common.Logging.Log4Net129
  is linked against log4net 1.2.9.0

2 different Adapters are necessary because log4net unfortunately changed it's public key from 1.2.9.0 to 1.2.10.0 (which was the primary reason for introducing Common.Logging)

Both Adapters accept the following configuration properties:

Key	Possible Value(s)	Description
configType	FILE FILE-WATCH INLINE EXTERNAL	INLINE will simply call XmlConfigurator.Configure() EXTERNAL expects log4net being configured somewhere else in your code and does nothing. FILE, FILE-WATCH: see property "configFile" below.
configFile	<path to your log4net.config file>	if configType is FILE or FILE-WATCH, the value of "configFile" is passed to XmlConfigurator.Configure (FileInfo) / ConfigureAndWatch(FileInfo) method.

Example:

<common>
<logging>
<factoryAdapter type="Common.Logging.Log4Net.Log4NetLoggerFactoryAdapter, Common.Logging.Log4net">
<arg key="configType" value="FILE-WATCH" />
<arg key="configFile" value="~/log4net.config" />
</factoryAdapter>
</logging>
</common>

will configure log4net 1.2.10.0 using the file log4net.config from your application's root directory by calling XmlConfigurator.ConfigureAndWatch().

Advanced Logging Tasks

Implementing your own FactoryAdapter

If you need to implement your own FactoryAdapter, you need to implement the Common.Logging.ILoggerFactoryAdapter interface. An implementation must provide a public constructor accepting a NameValueCollection parameter:

public class MyLoggingFactoryAdapter : ILoggerFactoryAdapter
{
public MyLoggingFactoryAdapter(NameValueCollection properties)
{
// configure according to properties
}
public ILog GetLogger(Type type) { ... }
public ILog GetLogger(string name) { ... }
}

Posted in: programming | Tags: log4net spring factoryadapter adapters common.logging common.logging.log4net configtype configfile xmlconfigurator

---