Wednesday, November 18, 2015

Custom Sitecore Log files

Starting with Sitecore 6.2, and especially since Sitecore 7 we've seen an increase in specific log files: WebDAV, Crawling, Search, Publishing, FXM. This is completely configurable, and can be leveraged to keep your application logic separate from the Sitecore log file while still using Sitecore's logging capabilities.
To create a custom log file, you need to do the following three things:

1. Add an appender in the <log4net> section of web.config (or Sitecore.config after 8.1).

   <appender name="MyAppender" type="log4net.Appender.SitecoreLogFileAppender, Sitecore.Logging">
      <file value="$(dataFolder)/logs/MyLog.log.{date}.txt" />
      <appendToFile value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%4t %d{ABSOLUTE} %-5p %m%n" />
      <encoding value="utf-8" />

These are the values Sitecore uses for its log file.  You might want to add <immediateFlush>true</immediateFlush> if you want to avoid waiting for the buffer to flush.

2. Reference the Appender in a logger element.

          <logger name="My.Namespace" additivity="false">
 <level value="INFO" />
 <appender-ref ref="MyAppender" />

Name the logger after your root namespace. If you want to divide different parts of your application into separate logs, you can drive this by being more specific in your namespace.  The level value control what types of messages get written. You can use Debug messages in your classes, and only show this information if you set level to DEBUG.  INFO is the normal setting, which also shows FATAL, ERROR, and WARNING messages, as well as Sitecore's custom AUDIT message.

3. Write messages using Sitecore's log class, passing a reference to the current object.

Log.Info("Your message", this);
Log.Debug("Your message", this);
Log.Error(exception, this);  
Log.Audit("Your message", this);

The Log.Debug message will only show up if logging is set to DEBUG, which makes this setting ideal for detailed instrumentation.  In addition, AUDIT captures information about who performed the action, writing the results as an INFO messages with the domain and username of the user performing the action.

A few additional notes:
1.  With Sitecore 8.1, the Log4Net section is moved inside the <sitecore> configuration node, which means it can be added to using Sitecore App_Config/Include patch config files.
2.  You can have several loggers point to the same appender, which might allow you to group your info with that of a specific Sitecore namespace, of to run part of your application with DEBUG logging, and the rest with INFO logging.
3. Sitecore Log Analyzer is a great tool for working with log data once you've collected it.  For example, it allows you to view just errors, or just one kind of error.
4. Log4Net documentation recommends checking if a log message is enabled before writing to it, to save on milliseconds of processing time for creating the string message (e.g. for concatenating a string). This is no longer possible with Sitecore's wrapper around log4net, as Log.IsDebugEnabled(), for example, is a static method, so there is no way to examine the level setting for a given namespace.

Props to Mark Ursino for blogging about custom log files way back in 2011, and to Kamraz Juman   for pointing out the Log.Info("message", this) syntax in the comments.

No comments:

Post a Comment