Wednesday, 22 March, 2017

How Umbraco Is Configured for Logging

A quick introduction on how logging works in Umbraco 7.5+

Preamble

Umbraco uses Log4Net (logging.apache.org/log4net/) to log information. Log4Net is an open source Apache Foundation Software project built with speed and flexibility in mind. As the name suggests it’s a .NET library, based on the Log4J library, and can therefore be included in any .NET application, not just Umbraco.

It’s claim of being flexible isn’t an empty one. Log4Net has the ability to log to the console and terminal windows, to the Windows event log, to databases, to log over UDP and SMTP, and, of course, the file system.

In this post I'm focusing solely on the Umbraco set-up, which logs to the file system. You can find more information on Log4Net and how to do more advanced things with it on my Papaly links board: papaly.com/anthonyvick/eo0zG/UmbracoLog4Net.

The Configuration File

Umbraco configures Log4Net using an xml file usually located at config\log4net.config. You can check this by opening your project’s web.config and searching for Log4Net. There should be a configuration section named log4net like:

<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" requirePermission="false"/>

pointing to:

<log4net configSource="config\log4net.config"/>

which in turn references the configuration file config\log4net.config. Keep in mind if your logs aren’t where you’d expect them that this is configurable and the configuration file may have been moved.

The Log4Net.Config File

A copy of what you can expect to find in you log4net.config file is copied below. Notice the <root> and <appender> elements, we'll be going over those in a moment.

<log4net> 
    <root> 
        <priority value="Info"/> 
        <appender-ref ref="AsynchronousLog4NetAppender" /> 
    </root> 

    <appender name="rollingFile" type="log4net.Appender.RollingFileAppender"> 
        <file type="log4net.Util.PatternString" value="App_Data\Logs\UmbracoTraceLog.%property{log4net:HostName}.txt" />
        <lockingModel type="log4net.Appender.FileAppender+MinimalLock" /> 
        <appendToFile value="true" /> 
        <rollingStyle value="Date" /> 
        <maximumFileSize value="5MB" /> 
        <layout type="log4net.Layout.PatternLayout"> 
            <conversionPattern value=" %date [P%property{processId}/D%property{appDomainId}/T%thread] %-5level %logger - %message%newline" /> 
        </layout> 
        <encoding value="utf-8" /> 
    </appender> 
    <appender name="AsynchronousLog4NetAppender" type="Umbraco.Core.Logging.ParallelForwardingAppender,Umbraco.Core"> 
        <appender-ref ref="rollingFile" /> 
    </appender> 
</log4net>

The Root Element

The root element provides the logger’s top level configuration settings.

<root> 
  <priority value="Info"/> 
  <appender-ref ref="AsynchronousLog4NetAppender" /> 
</root>

The value sets which log messages are going to be logged. The options are: Off, fatal, error, warn, info, debug, and all. Setting the value to Info will prevent debug (level) messages appearing in the log. The <appender-ref> element sets the default logger implementation.

The Appender

Think of Appenders as defining how log information should be output. The AsynchronousLog4NetAppender appender entry, referenced in the root element, merely points the log implementation at another Appender definition:

<appender name="AsynchronousLog4NetAppender" type="Umbraco.Core.Logging.ParallelForwardingAppender,Umbraco.Core"> <appender-ref ref="rollingFile" /> </appender>

The rollingfile Appender type referenced above implements file based logging. Notice the file <file> element specifies a PatternString type with a log path pointing to the app_data folder. This is where the Umbraco logs will be placed; by default creates logs under /App_Data/Logs/UmbracoTraceLog.[MachineName].txt.

<appender name="rollingFile" type="log4net.Appender.RollingFileAppender">
  <file type="log4net.Util.PatternString" value="App_Data\Logs\UmbracoTraceLog.%property{log4net:HostName}.txt" /> 
  <lockingModel type="log4net.Appender.FileAppender+MinimalLock" /> 
  <appendToFile value="true" /> <rollingStyle value="Date" /> 
  <maximumFileSize value="5MB" /> 
  ... <encoding value="utf-8" /> 
</appender>

  • The PatternString type allows the use of format specifiers to be used (think C printf commands).
  • Log4net:HostName is a default value provided by Log4Net library and is recommended for use in the filename when Umbraco is installed to Cloud based environments to prevent problems with log files.
  • LockingModel specifies a minimal file lock, allowing multiple appenders to access the file;
  • MaximumFileSize closes the files and creates a new one when the file size is reached.

You may wish to consider adding a <maxSizeRollBackups> element, like <maxSizeRollBackups value="5"/>, to start deleting log files once a maximum number have been created to save disk space.

What The Log Entries Look Like

The log entries will look like this:

2018-03-21 14:27:31,725 [P3568/D2/T17] INFO JAGC.ViewModel.HomeModel - Showing landing page. Home.

The layout element specifies the format of each individual log entry.

<layout type="log4net.Layout.PatternLayout"> 
  <conversionPattern value=" %date [P%property{processId}/D%property{appDomainId}/T%thread] %-5level %logger - %message%newline" /> 
</layout>

The % format specifiers or tags are used to include “dynamic” information in the log string.

  • %date outputs the date;
  • %property outputs an Umbraco defined Log4Net property (see Umbraco Logger.cs source code) ;
  • %Logger outputs the type information of object calling the log
  • %Message the log message %newline creates a newline break.

You can lookup all the format specifiers at: logging.apache.org/log4net/release/sdk/?topic=html/Tlog4netLayout_PatternLayout.htm

How To Write Out to The Log File

Log entries can be added using to your controllers or Razor views using commands like this:

using Umbraco.Core.Logging;
LogHelper.Error(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType, "JAGC was here"); 
LogHelper.Warn(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType, "JAGC was here"); 
LogHelper.Info(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType, "JAGC was here"); 
LogHelper.Debug(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType, "JAGC was here");

@using Umbraco.Core.Logging
LogHelper.Warn(this.GetType(), "Document type alias for landingPage missing.");

Wrapping Up

You should now understand how Umbraco implements logging and how to write your own log statements out to Umbraco's log.

While it may take a little while to get to grips with Log4Net its versatility soon makes it clear why the Umbraco team decided to use it. Do you have a namespace or class you'd like to log to a separate file? you can do that; want to receive an email if your live website throws an exception? you can do that too.

Find out more about Umbraco and Log4Net by following the links on my Papaly board here: papaly.com/anthonyvick/eo0zG/UmbracoLog4Net.

Want to Thank Me?

Did you like this article? Was it helpful? Why not buy me a coffee on Paypal? Buy me a coffee?