How to silence Log4Net upon startup

Say you have a command line tool that outputs helpful information when run without any parameters upon startup such as:

=====================================================
Ninja Parser v1.1.1.1
=====================================================
For help, run the tool again with parameter -h
Input parameters are as follows:
-k kick
-j jump
-p punch
-bf backflip

Tool works great but you wanted to add some logging and decided to use Log4Net.

With Log4Net, integration is easy. All you do is add the NuGet package log4net, configure app.config to include a log4net section like so

<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" />
  </configSections>
  <log4net debug="true">
    <appender name="Console" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%5level - %message%newline" />
      </layout>
    </appender>
    <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
      <file value="ninja-parser.log" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="10MB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-5p %d %5rms %-22.22c{1} %-18.18M - %m%n" />
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
      </layout>
    </appender>
    <root>
      <level value="ALL" />
      <appender-ref ref="Console" />
      <appender-ref ref="RollingFile" />
    </root>
  </log4net>
</configuration>

and call XmlConfigurator.Configure() in your application’s main entry point as follows:

 public static void Main(string[] args)
        {
            XmlConfigurator.Configure();
            // your other startup code goes here
        }

All well, good and straight forward. However integrating Log4Net and you run the tool without any parameters as before you get the following noise that completely masks the original tool’s output:

log4net: Configuration update mode [Merge].
log4net: Logger [root] Level string is [ALL].
log4net: Logger [root] level set to [name=”ALL”,value=-2147483648].
log4net: Loading Appender [Console] type: [log4net.Appender.ConsoleAppender]
log4net: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [ConversionPattern] to String value [%5level – %message%newline]
log4net: Converter [level] Option [] Format [min=5,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [ – ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [Layout] to object [log4net.Layout.PatternLayout]
log4net: Created Appender [Console]
log4net: Adding appender named [Console] to logger [root].
log4net: Loading Appender [RollingFile] type: [log4net.Appender.RollingFileAppender]
log4net: Setting Property [File] to String value [migrator.log]
log4net: Setting Property [AppendToFile] to Boolean value [True]
log4net: Setting Property [RollingStyle] to RollingMode value [Size]
log4net: Setting Property [MaxSizeRollBackups] to Int32 value [10]
log4net: Setting Property [MaximumFileSize] to String value [10MB]
log4net: Setting Property [StaticLogFileName] to Boolean value [True]
log4net: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [ConversionPattern] to String value [%-5p %d %5rms %-22.22c{1} %-18.18M – %m%n]
log4net: Setting Property [ConversionPattern] to String value [%date [%thread] %-5level %logger – %message%newline]
log4net: Converter [date] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [ [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [thread] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [] ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [level] Option [] Format [min=5,max=2147483647,leftAlign=True]
log4net: Converter [literal] Option [ ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [logger] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [literal] Option [ – ] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [message] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Converter [newline] Option [] Format [min=-1,max=2147483647,leftAlign=False]
log4net: Setting Property [Layout] to object [log4net.Layout.PatternLayout]
log4net: Searched for existing files in [C:\dev\src\SAS-3.4\code\importers\Migrator\Migrator\bin\Release]
log4net: curSizeRollBackups starts at [0]
log4net: Opening file for writing [C:\dev\src\SAS-3.4\code\importers\Migrator\Migrator\bin\Release\migrator.log] append [True]
log4net: Created Appender [RollingFile]
log4net: Adding appender named [RollingFile] to logger [root].
log4net: Hierarchy Threshold []=====================================================
Ninja Parser v1.1.1.1
=====================================================
For help, run the tool again with parameter -h
Input parameters are as follows:
-k kick
-j jump
-p punch
-bf backflip

Can you find the original message? It is still there!

While this additional information may contain useful technical jargon for developers, it offers zero additional value for a typical end user of the tool. These messages, therefore, immediately affect the tool’s usability and unless your users are technically savvy or have come around to trusting the quality of your deliverables, there will be an immediate knee-jerk hesitation in adopting the “new” tool since its behavior has “changed”.

So what do we fix this? We definitely want logging capability but not at the expense of usability.

One of my smarter colleagues proposed we use some sort of stream redirection and this is the code he whipped up in less than 10 minutes (I post this with his permission):

   private static void TemporarilyHideLog4NetOnConsoleMessagesOnStartup()
        {
            var consoleOut = Console.Out;
            var memoryStream = new MemoryStream();
            var redirection = new StreamWriter(memoryStream );
            Console.SetOut(redirection );
            XmlConfigurator.Configure();
            Console.SetOut(consoleOut );
        }

Effectively, we temporarily set Console.Out to a fake memory stream. Then call XmlConfigurator.Configure(). What this achieves is a redirection of messages from Console.Out to the temporary memory stream. Then we switch back out to original Console.Out and we are back in business. When you run the program in your debug, you will see that the redirection variable now contains all of the stuff we did not want to see.

Brilliant, gets the job done and makes everyone a happy camper. BTW, this is why your surround yourself with smart developers smarter than yourself.

One can possibly extend this idea it does the job. If anyone knows of a proper way to silent Log4Net upon startup, please let us know.

After posting this question on StackOverflow, it turns out that these messages are being generated because Log4Net is configured to debug mode in app.config.

  <log4net debug="true">

Happy Coding.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s