Use Capped collection on MongoAppender for Log4Net

One of the coolest feature of Mongo is the concept of Capped Collection, or “fixed size” collection. They are based on a FIFO queue where the first record to be discharded is the first inserted, and this is exceptional to create a log-collection that automatically purge all old logs without any user intervention.

To be able to automatically enable this feature on the Log4Net Mongo appender you need to do a little modification to the code, this is because the original code simply gets a reference to the collection with this code.

connection = MongoServer.Create(mongoConnectionString.ToString());
connection.Connect();
var db = connection.GetDatabase(DatabaseName);
collection = db.GetCollection(CollectionName);

C# drivers for Mongo automatically creates a collection if it is not present, this means that when you call db.GetCollection if the collection is not present it will be automatically created, but it is not capped. To solve this problem you can modify the initialization code with this code.

if (!db.CollectionExists(collectionName)) { 
    var options =  CollectionOptions
        .SetCapped(true)
        .SetMaxSize(CappedSize);
    db.CreateCollection(collectionName, options);
}
collection = db.GetCollection(CollectionName);

MongoDb C# drivers has a class called CollectionOptions used to setup options to create a new MongoCollection and it can be accessed with a really easy Fluent-Interface, in my example I call SetCapped(true) to enable a capped collection and SetMaxSize() to setup the maximum size in bytes. The size of the capped-collection is stored in the appender property called CappedSize, the default is 500MB, but you can setup any size you likes in standard log4Net configuration.

Gian Maria.

Using Mongo Database to store Log4Net logs

One of the most simple and useful way to introduce a Documents Database like Mongo in your organization is to use as Log Storage. If you use log4Net you can download a Mongo appender capable of storing logs inside mongo with few lines of code and you are ready to go.

The original appender is really good but I’ve done a little modification to make it capable of storing complex item in extended properties, just locate the function LogginEventToBSON and modify the section that stores Composite Properties with following code

if (compositeProperties != null && compositeProperties.Count > 0)
{
    var properties = new BsonDocument();
    foreach (DictionaryEntry entry in compositeProperties)
    {
        BsonValue value;
        if (!BsonTypeMapper.TryMapToBsonValue(entry.Value, out value))
        {
            properties[entry.Key.ToString()] = entry.Value.ToBsonDocument();
        }
        else
        {
            properties[entry.Key.ToString()] = value;
        }
    }
    toReturn["customproperties"] = properties;
}

The only modification I did to the original code is trying to convert the value stored in Composite properties to a BsonValue and if the conversion does not succeeds I convert the entire object to a BsonDocument and store the entire object to Mongo. The original code stores extended properties with ToString(), this has two disadvantages, the first is that you are actually losing the type of the data and you are not able to store complex objects. With this modification if you add an Int32 as extended property, it will be stored as numeric value inside the database.

Using Mongo as Log Storage gives you lots of advantages, first of all Document Databases are really fast in inserting stuff, then they are Not Schema Bound so you do not need to define a schema to contain your logs. This feature in conjunction with the ability of Log4Net to store extended properties in the context permits you to write code like this one.

log4net.GlobalContext.Properties["CurrentItem"] = item;

With this simple line of code each subsequent log will have in Mongo Database an associated object of type item, until you will not remove the object from the GlobalContext.

Complex objects are stored inside the log

Figure 1: Your log contains all data from extended properties

As you can see from Figure 1 the log has now a complex object associated with it. This capability is awesome because you simply need to store complex objects inside GlobalContext and they will be stored inside the log as customproperties without needing additional lines of code.

Clearly you can now use all the advanced query capability of Mongo to view/filter/mapreduce logs using these additional properties.

Gian Maria.

Managing remote logging with Log4net and WCF

I’ve applications that can work in two distinct configuration, they are based on WPF and MVVM, where the VM communicates with the Domain / Business Logic through services like IXxxxService. All View Models depends from one or more services and thanks to Castle I can decide with configuration file which concrete class to use for each service.

When the software is used internally, it has direct access to the Database, so I configure castle to use the concrete class of the various services, but when the software is deployed to external users,  who have no access to the intranet, all communication is done through WCF. This is done transparently because I have a facility that resolve the various IXxxxService with WCF Proxy classes.

All software logs a lot, to be able to diagnostic errors as soon as possible, and I have a IManagement service that has a method dedicated to logging.

   1: [OperationContract(IsOneWay=true, ProtectionLevel=ProtectionLevel.EncryptAndSign)]

   2: void Log(LogDto log);

The implementation of this method is really really simple.

   1: public void Log(Dto.LogDto log)

   2: {

   3:     log.Log(Logger);

   4: }

The LogDto has a method Log, that is able to log everything to an ILogger Castle standard logger that in turns uses Log4Net, so remote program can send log through WCF.

My problem is that the various ViewModels are using classes from a shared library and those classes uses Log4Net internally to log stuff. If the software is deployed in internal network I have no problem because I can redirect logging in a log database, but when the software is used by external user how can I send all those log to the server?

The solution is simple I need to create a custom Log4Net appender to intercept Log4Net logs and redirect them to IManagementService.

   1: class ManagementLogAppender : AppenderSkeleton

   2:  {

   3:      private IManagementService _managementService;

   4:  

   5:  

   6:      public ManagementLogAppender(IManagementService managementService)

   7:      {

   8:          _managementService = managementService;

   9:      }

  10:  

  11:      protected override void Append(log4net.Core.LoggingEvent loggingEvent)

  12:      {

  13:          LogDto logDto = new LogDto();

  14:          logDto.Message = loggingEvent.MessageObject.ToString();

  15:          if (loggingEvent.ExceptionObject != null)

  16:          {

  17:              logDto.FullExceptionData = loggingEvent.ExceptionObject.ToString();

  18:          }

  19:          logDto.LoggerName = loggingEvent.LoggerName;

  20:          _managementService.Log(logDto);

  21:      }

  22:  }

This appender simply send the log to the IManagementService so I have a centralized point where all the remote logging takes place. Since I have more than one custom appender, I usually register all of them inside Castle Windsor Configuration and add all registered one with this simple snippet of code, that is run from the bootstrapper.

   1: var allAppender = IoC.ResolveAll<IAppender>();

   2: Hierarchy repository = LogManager.GetRepository() as Hierarchy;

   3: foreach (IAppender appender in allAppender)

   4: {

   5:     repository.Root.AddAppender(appender);

   6: }

   7: repository.RaiseConfigurationChanged(EventArgs.Empty);

This permits me to have appenders that can declare dependencies, like the ManagementLogAppender that is depending from IManagementService. Thanks to the same facility I can use the concrete class in intranet (direct use of log4net) or the dynamic generated proxy that send log through WCF.

Gian Maria.

Intercept Log4Net message in a Windows application

Scenario: I have some service that runs in the background, but I want the user to be able to launch interactively with a  windows form application and I want to intercept all log4net messages issued by the various components that works in the background.

Thanks to the supereasy way to write an appender in log4net, obtaining this result is really simple..

   1: public class Log4NetLogEventSourceAppender : AppenderSkeleton

   2:    {

   3:        private Object _syncRoot;

   4:  

   5:        public Log4NetLogEventSourceAppender()

   6:        {

   7:            _syncRoot = new object();

   8:        }

   9:  

  10:        /// <summary>

  11:        /// Occurs when [on log].

  12:        /// </summary>

  13:        public static event EventHandler<OnLog4NetLogEventArgs> OnLog;

  14:  

  15:        protected override void Append(LoggingEvent loggingEvent)

  16:        {

  17:            EventHandler<OnLog4NetLogEventArgs> temp = OnLog;

  18:            if (temp != null)

  19:            {

  20:                lock (_syncRoot)

  21:                {

  22:                    temp(null, new OnLog4NetLogEventArgs(loggingEvent));

  23:                }

  24:            }

  25:        }

  26:  

  27:    }

  28:  

  29:    public class OnLog4NetLogEventArgs : EventArgs

  30:    {

  31:        public LoggingEvent LoggingEvent { get; private set; }

  32:  

  33:        public OnLog4NetLogEventArgs(LoggingEvent loggingEvent)

  34:        {

  35:            LoggingEvent = loggingEvent;

  36:        }

  37:    }

This is a quick and dirty approach, a _syncRoot object will serialize all events because this is a shared event I want to prevent multiple threads to messup logging. Thanks to the shared event you can simply add this appender to the list of enabled appender.

   1: <appender

   2:     name="Interceptor"

   3:     type="xxx.Log4NetLogEventSourceAppender, xxx">

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

   5:       <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline %property{analyzing_url}" />

   6:     </layout>

   7:   </appender>

Now in code you should simply subscribe to appender event.

   1: Log4NetLogEventSourceAppender.OnLog += Log4NetLogEventSourceAppender_OnLog;

And do something useful in the event handler, in my program I have a custom MVP pattern, and I simply add the log the to the view (that in turn shows a grid with all the logs with filtering and sorting capabilities).

   1: void Log4NetLogEventSourceAppender_OnLog(object sender, OnLog4NetLogEventArgs e)

   2: {

   3:      View.AppendLog(e.LoggingEvent);

   4: }

Thanks to the extremely flexibility of log4net it is possible to manage logs in a great variety of locations, and with this simple interceptor you can propagate logging wherever you want.

Another useful application of this logger was made in a scheduled service,

   1: private void ReactToLogMessages(OnLog4NetLogEventArgs e, StringBuilder log4netLogs, ScanLog scanLog)

   2: {

   3:     if (e.LoggingEvent.Level >= log4net.Core.Level.Info)

   4:     {

   5:         log4netLogs.AppendLine(e.LoggingEvent.RenderedMessage);

   6:     }

   7:     //ora capire il livello di errore

   8:     if (e.LoggingEvent.Level == log4net.Core.Level.Warn)

   9:     {

  10:         scanLog.NumOfWarnings++;

  11:     }

  12:     else if (e.LoggingEvent.Level == log4net.Core.Level.Error)

  13:     {

  14:         scanLog.NumOfErrors++;

  15:     }

  16: }

This function simply append all info or greater logs to a string, but the most important fact is that he count the number of warning and errors, and after the task finish, it warn the administrator if there are errors or more than a certain number of warning. This will make simple to react to task that have problems.

Alk.

Extremely slow operation and log4net

 

I’m currently profiling a web application, and I noticed that for some combination of input, a specific search into the database is really really slow. After verifying that the query is not responsible for this problem I fire a profiler, load the page, issue the search and then verify with ant profiler the method that need more time to be executed. The result was that the method that needs more time to be executed is one called Send Alert, that simply logs with log4net to a specific logger called Alert.

I noticed a lot of SocketException, so I verify the configuration, and find that the Alert logger has a reference to a SmtpAppender that points to a wrong smtp server. The page was slow because it is waiting to send an alert with a wrong mailserver, then it waits for timeout before proceeding on.

Ok, this is a configuration problem, but I do not want my email alert to be sent synchronously, because there is no point in slowing the application if I need to send an alert. Remember that sending an E-Mail is a slow operation even if the smtp is ok. In this situation Log4Net has a specific appender called AsyncAppender that can be used to solve this problem. The AsyncAppender is a specific appender that is used to wrap any other appender, and make the log asyncronous. The only part I need to change is to add this to configuration

   1: <appender name="AsyncSmtpAppender"

   2: type="SampleAppendersApp.Appender.AsyncAppender,SampleAppendersApp">

   3:   <appender-ref ref="SmtpAppender" />

   4: </appender>

and use the AsyncSmtpAppender in logger definition.

   1: <logger name="Alerter" additivity="false">

   2:     <level value="WARN" />

   3:     <appender-ref ref="AsyncSmtpAppender" />

   4: </logger>

Then I reload the page again, and now, even with a wrong smtp server, the page loads almost instantaneously.

Alk.