Getting started with LogBox and ColdBox

I've been working on a ColdBox 3 site and decided to give in the in-built logging (with LogBox) a go. I thought I'd do a quick blog post to demonstrate how to use it as I found the docs a little bit confusing. LogBox can be used standalone, whereas when you use it with ColdBox a lot of the work is done for you.

By default ColdBox is configured with logging enabled and outputs to the console. Here's my Coldbox.cfc just to prove that I'm not cheating!

<cfcomponent output="false" hint="My App Configuration">
<cfscript>
// Configure ColdBox Application
function configure(){

  // coldbox directives
  coldbox = {
    //Application Setup
    appName         = "SimpleLoggingApp",
    
    //Development Settings
    debugMode        = true,
    debugPassword      = "",
    reinitPassword      = "",
    handlersIndexAutoReload = true,
    configAutoReload    = false,
    
    //Implicit Events
    defaultEvent      = "general.index",
    requestStartHandler    = "",
    requestEndHandler    = "",
    applicationStartHandler = "",
    applicationEndHandler  = "",
    sessionStartHandler   = "",
    sessionEndHandler    = "",
    missingTemplateHandler  = "",
    
    //Error/Exception Handling
    exceptionHandler    = "",
    onInvalidEvent      = "",
    customErrorTemplate    = "",
      
    //Application Aspects
    handlerCaching       = false,
    eventCaching      = false
  };
  
  //Layout Settings
  layoutSettings = {
    defaultLayout = "Layout.Main.cfm"
  };
  
  //Register interceptors as an array, we need order
  interceptors = [
     //Autowire
     {class="coldbox.system.interceptors.Autowire"}
  ];  
}
  
</cfscript>
</cfcomponent>

In my handler all I have to do is call the logger object.

<cfcomponent output="false">

  <!--- Default Action --->
  <cffunction name="index" returntype="void" output="false" hint="My main event">
    <cfargument name="event" required="true">
    <cfset var rc = event.getCollection()>
    <!--- tell the LogBox instance to log an info message --->
    <cfset log.info("Event Handler Called")>
    
    <cfset rc.welcomeMessage = "Welcome to ColdBox!">  
    
    <cfset event.setView("General/index")>
  </cffunction>

<!------------------------------------------- PRIVATE EVENTS ------------------------------------------>

  
</cfcomponent>

Sure enough in my console I can see this:

[localhost CF9.01]:INFO simplelogging.handlers.General Event Handler Called ExtraInfo: 

Pretty sweet, huh. We can also output some extra information.

<cfcomponent output="false">

  <!--- Default Action --->
  <cffunction name="index" returntype="void" output="false" hint="My main event">
    <cfargument name="event" required="true">
    <cfset var rc = event.getCollection()>
    <!--- tell the LogBox instance to log an info message --->
    <cfset log.info("Event Handler Called", {time=Now(), rc=rc})>
    
    <cfset rc.welcomeMessage = "Welcome to ColdBox!">  
    
    <cfset event.setView("General/index")>
  </cffunction>

<!------------------------------------------- PRIVATE EVENTS ------------------------------------------>

  
</cfcomponent>

The output is:

[localhost CF9.01]:INFO simplelogging.handlers.General Event Handler Called ExtraInfo: {TIME={{ts '2010-12-02 14:07:56'}},RC={{event={general.index}}}}

There are also different types of messages I can use:

<cfcomponent output="false">

  <!--- Default Action --->
  <cffunction name="index" returntype="void" output="false" hint="My main event">
    <cfargument name="event" required="true">
    <cfset var rc = event.getCollection()>
    <!--- tell the LogBox instance to log an info message --->
    <cfset log.info("Everything OK")>
    <cfset log.warn("Watch out!")>
    <cfset log.error("Too late")>
    <cfset log.fatal("**KABOOOM**")>
    
    <cfset rc.welcomeMessage = "Welcome to ColdBox!">  
    
    <cfset event.setView("General/index")>
  </cffunction>

<!------------------------------------------- PRIVATE EVENTS ------------------------------------------>

  
</cfcomponent>

When I run the event I get the following in my console.

[localhost CF9.01]:INFO simplelogging.handlers.General Everything OK ExtraInfo: 
[localhost CF9.01]:WARN simplelogging.handlers.General Watch out! ExtraInfo: 
[localhost CF9.01]:ERROR simplelogging.handlers.General Too late ExtraInfo: 
[localhost CF9.01]:FATAL simplelogging.handlers.General **KABOOOM** ExtraInfo: 

Great now we can categorise logged messages, but logging to console might not suit your needs. Luckily, ColdBox has various different "appenders" which let you choose how you want to display the logged information. Let's configure ColdBox so that the logging information is output to the browser instead by adding a logBox struct to the ColdBox.cfc

<cfcomponent output="false" hint="My App Configuration">
<cfscript>
// Configure ColdBox Application
function configure(){

  // coldbox directives
  coldbox = {
    //Application Setup
    appName         = "SimpleLoggingApp",
    
    //Development Settings
    debugMode        = true,
    debugPassword      = "",
    reinitPassword      = "",
    handlersIndexAutoReload = true,
    configAutoReload    = false,
    
    //Implicit Events
    defaultEvent      = "general.index",
    requestStartHandler    = "",
    requestEndHandler    = "",
    applicationStartHandler = "",
    applicationEndHandler  = "",
    sessionStartHandler   = "",
    sessionEndHandler    = "",
    missingTemplateHandler  = "",
    
    //Error/Exception Handling
    exceptionHandler    = "",
    onInvalidEvent      = "",
    customErrorTemplate    = "",
      
    //Application Aspects
    handlerCaching       = false,
    eventCaching      = false
  };
  
  //Layout Settings
  layoutSettings = {
    defaultLayout = "Layout.Main.cfm"
  };
  
  //Register interceptors as an array, we need order
  interceptors = [
     //Autowire
     {class="coldbox.system.interceptors.Autowire"}
  ];  
  
  // configure LogBox
  logBox = {
    appenders = {
      coldboxTracer = { 
        class="coldbox.system.logging.appenders.ColdboxTracerAppender"
      }
    },
    root = { levelmax="DEBUG", levelMin="FATAL", appenders="*" }
  };

}
  
</cfscript>
</cfcomponent>

You'll need to reload the ColdBox framework to pick up the new settings, but when you do you'll see that a new "ColdBox Tracer Messages" section has appeared in the Debugging info in your browser. The super sharp eyed amongest you may have noticed that I set the max logging level to DEBUG. This means that I can make use of the debug status which by default is disabled in ColdBox. To use the debug level simply call:

<cfset log.debug("testing 1,2,3")>

So, we've got some pretty powerful logging going on now, but in production we're not going to want to output to the Console or browser window, instead we want to log to a file so let's add the AsyncRollingFileAppender (Note: Normally, you wouldn't have the ColdboxTracerAppender and the AsyncRollingFileAppender enabled but this is a demo so what the heck!)

 
 // configure logbox
  logBox = {
    appenders = {
      // ColdboxTracerAppender outputs to the browser
      coldboxTracer = { 
        class="coldbox.system.logging.appenders.ColdboxTracerAppender"
      },
      // AsyncRollingFileAppender outputs to the logs/MYERRORLOG.log file
      myErrorLog = {
        class="coldbox.system.logging.appenders.AsyncRollingFileAppender",
        levelMax="WARN",
        levelMin="FATAL",
        properties={
          filePath="/#appMapping#/logs",
          autoExpand="true",
          fileMaxSize="3000",
          fileMaxArchives="5"
        }
      }      
    },
    root = { levelmax="DEBUG", levelMin="FATAL", appenders="*" }
  };

If we reload the config again and check out the logs folder (ColdBox will create it if doesn't exist) and you'll see a file called MYERRORLOG.log which contains:

"Severity","Appender","Date","Time","Category","Message"
"WARN","MYERRORLOG","12/02/2010","14:28:53","simplelogging.handlers.General","Watch out!"
"ERROR","MYERRORLOG","12/02/2010","14:28:53","simplelogging.handlers.General","Too late"
"FATAL","MYERRORLOG","12/02/2010","14:28:53","simplelogging.handlers.General","**KABOOOM**"

So what happened to the DEBUG and INFO messages? Well, when I configured the AsyncRollingFileAppender I set the max logging level to WARN. Anything lower than this is ignored. This is really cool for choosing which types of message you need to log in production.

Logging is a really powerful tool that tends to be overlooked as it's a pain to set up - but you've got no excuses now!