Thursday, July 29, 2010

Sitecore Logging Part 3. Adding custom parameters to the log.


Summer…I am on a blog posting spree :-)

This is a continuation of the sage about SQL logging for Sitecore CMS. As I previously blogged, you can easily have Sitecore log to a SQL database instead of a flat text file.
Now what if we take it one step forward and have Sitecore output more information than we had before, including Sitecore Context User, Sitecore Context Item Id and raw server URL?
Well, after some digging, here is the solution for you.

First of all, we need to add those columns to the actual table that we are going to use for storage.
Here is how your “Log” table could look like:
CREATE TABLE [dbo].[Log](
 [ID] [int] IDENTITY(1,1) NOT NULL,
 [Date] [datetime] NOT NULL,
 [Thread] [varchar](255) NOT NULL,
 [Level] [varchar](20) NOT NULL,
 [Logger] [varchar](255) NOT NULL,
 [Message] [varchar](4000) NOT NULL,
 [Exception] [varchar](2000) NULL,
 [SCUser] [varchar](255) NULL,
 [SCItemId] [varchar](38) NULL,
 [RawUrl] [varchar](255) NULL
) ON [PRIMARY]
Secondly, we need a custom version of the log4net.Appender.ADONetAppender class where we simply add the values of those 3 into the Properties collection.
I decided to do it only if my Context Site is resolved properly and the logging levels indicate either ERROR or FATAL levels:
using log4net.Appender;
using log4net.spi;

namespace Project.Shell.System
{
   public class SitecoreDatabaseLogAppender : ADONetAppender
   {
      protected override void Append(LoggingEvent loggingEvent)
      {
         if (Sitecore.Context.Site != null &&
            (loggingEvent.Level == Level.FATAL || loggingEvent.Level == Level.ERROR))
         {
            var properties = loggingEvent.Properties;

            if (Sitecore.Context.User != null)
            {
               properties["scuser"] = Sitecore.Context.User.Name;
            }

            if (Sitecore.Context.Item != null)
            {
               properties["scitemid"] = Sitecore.Context.Item.ID.ToString();
            }

            properties["rawurl"] = Sitecore.Web.WebUtil.GetServerUrl() + Sitecore.Web.WebUtil.GetRawUrl();
         }

         base.Append(loggingEvent);
      }
   }
}
Pretty simple, huh?
Afterwards, we just need to tweak our configuration a bit:
1. Specify the reference to the new custom “SitecoreDatabaseAppender” class:
<appender name="ADONetAppender_SqlServer" type="Project.Shell.System.SitecoreDatabaseLogAppender, Project.Shell" >
2. Extend CommandText value to include 3 new parameter we are adding:
<param name="CommandText" value="INSERT INTO Log ([Date],[Thread],[Level],[Logger],[Message],[Exception], [SCUser], [SCItemId], [RawUrl]) VALUES (@log_date, @thread, @log_level, @logger, @message, @exception, @scuser, @scitemid, @rawurl)" />
3. Define the way you want log4net parsing engine to process these parameters:
Same story here. Make sure that the value of the size parameter matches the database column size.
<param name="Parameter">
               <
param name="ParameterName" value="@scuser" />
               <
dbType value="String" />
               <
size value="255" />
               <
layout type="Project.Shell.System.PropertyLayout,Project.Shell">                   <param name="PropertyName" value="scuser" />
               </
layout>
</
param>
<
param name="Parameter">
               <
param name="ParameterName" value="@scitemid" />
               <
dbType value="String" />
               <
size value="38" />
               <
layout type="Project.Shell.System.PropertyLayout,Project.Shell">
                  <
param name="PropertyName" value="scitemid" />
               </
layout>
</
param>
<
param name="Parameter">
               <
param name="ParameterName" value="@rawurl" />
               <
dbType value="String" />
               <
size value="255" />
               <
layout type="Project.Shell.System.PropertyLayout,Project.Shell">                   <param name="PropertyName" value="rawurl" />
               </
layout>
</
param>


You may also notice that I am using a custom type for the layout parameter. The reason for that is that I could not find a proper way of extracting the properties appended by SitecoreDatabaseLogAppender with default layouts. So I created a custom one which is able to extract those values with ease.

4. This means that you should also compile the following class:
using System;
using System.Text;
using log4net.Layout;
using log4net.spi;

namespace BayNET.Shell.System
{
   public class PropertyLayout : LayoutSkeleton
   {
      // Fields
      protected const int BUF_SIZE = 0x100;
      private StringBuilder m_sbuf = new StringBuilder(0x100);
      protected const int MAX_CAPACITY = 0x400;
      private string m_propertyName;


      public string PropertyName
      {
         get
         {
            return m_propertyName;
         }
         set
         {
            m_propertyName = value;
         }
      }

      public override bool IgnoresException
      {
         get
         {
            return false;
         }
      }

      public override void ActivateOptions()
      {
      }

      public override string Format(LoggingEvent loggingEvent)
      {
         if (loggingEvent == null)
         {
            throw new ArgumentNullException("loggingEvent");
         }
         if (m_sbuf.Capacity > 0x400)
         {
            m_sbuf = new StringBuilder(0x100);
         }
         else
         {
            m_sbuf.Length = 0;
         }

         if (!String.IsNullOrEmpty(PropertyName))
         {
            m_sbuf.Append(loggingEvent.Properties[PropertyName]);
         }
         return m_sbuf.ToString();
      }

   }
}

That should be it. Now you can happily observe all these 3 parameters being written in the log when en error happens. Isn’t that sweet?
image

3 comments:

Philip Andersen said...

I really don't understand why Sitecore still uses the standard Log4Net namespaces, since it makes it difficult to implement your own log4net logger. Futhermore, if I recall, you can only use the rootlooger with Sitecore.

Often you need to implement your own logger since you might want logdata from e.g. 3rd-party users etc. Especially if you don't want to mix Sitecore logging with your own loggin.

Alex Shyba said...

Hi Philip, it should be possible. Check out how WebDAV is using its own logger, this could be a good start for you.

david said...

Hi Alex, I've implemented your solution, but noticed that the namespace log4net.spi was renamed to log4net.Core prior to 08/30/2007. What version of log4net are you using? The newest versions do not contain that namespace and do not seem to function correctly. Thanks in advance.