Wednesday, September 21, 2005

Using log4j in ColdFusion

I went to an interview last Thursday and in the course of it the lead developer and I (my job had apparently been filled!) got into a two hour discussion about caching cfcs with oscache, working with coldspring, aop, and using log4j in coldfusion. Although the interview part didn’t lead to much, I did leave thinking about a lot of cool things, especially pressing being incorporating log4j into a side project that I’m getting pretty heavily involved in. I’ve worked with log4j in java, and it’s super simple, very fast, easy to configure, and I’ve been thinking of using it in cf, but basically haven’t tried. Although I think cflog is just a wrapper around log4j anyway, by using it directly you gain the benefit of setting the max size of the log file created, along with configuration of backup files, the level of logging to output (debug, info, warn, error, fatal), and formatting of the messages. Also, most importantly, it’s really easy to turn on and off, and since log4j is built to be extremely fast the cost of log statements in your code is marginal. So if I’ve peeked you interest, here’s a little rundown of how to get log4j running, with some extra links at the end of the post, including a link to an excellent tutorial on ColdFusion Developer’s Journal, which to be honest, much of this is a paraphrasing anyhow. So on to the code…

The first thing to know is ColdFusion comes with an older version of log4j which uses the now depreciated concept of categories, now known as loggers, but for simplicity’s sake, these are the same thing. An instance of one of these represents a logging space which you are free to name and configure at will. It’s advisable to use package naming conventions with loggers, sorry categories, as this is the norm in java. Also worth noting is that loggers are hierarchical, meaning that a logger named ‘myco.foo’ inherits configuration properties from the logger ‘myco’, if it exists. You perform logging through one of the printing methods debug, info, warn, error, fatal. These are directly related to the standard logging levels DEBUG < INFO < WARN < ERROR < FATAL, meaning the level is ascending. A logging method is considered enabled if it is equal to or grater that the current logging level. So if the logging level is set to WARN, myLogger.error(‘Uh oh, big problem occurred’), will output to your log file, but myLogger.info(‘ran method x()’) will not. The last 2 components to logging are patterns, which I’m going to completely skip, and just give you the logging pattern that you’re pretty much gonna use anyway, and appenders, which you output your logging to. Appenders can be a console, file, a socket server, JMS, NT Event Log, and the Unix System Log, you can start to see the incredible flexibility here. All that’s left is to create a config file and start logging!

I like to use a properties file, the format I mentioned when discussing classloaders, but you can also use an xml file. Here’s a sample properties file called logger.properties:

# create a category called myco.foo, set it’s level to INFO, and set the appender to myAppen (you can name this anything, but keep it simple)
log4j.category.myco.foo=INFO, myAppen
# myAppen is set to be a FileAppender.
log4j.appender.myAppen =org.apache.log4j.RollingFileAppender
log4j.appender.myAppen.File=/usr/local/cf7/htdocs/sampleApp/logs/sample.log
# we’ll use a standard layout
log4j.appender.myAppen.layout=org.apache.log4j.PatternLayout
log4j.appender.myAppen.layout.ConversionPattern=%-4r [%t] %-5p %c - %m%n
# and set the filesize limit and backup file
log4j.appender.myAppen.MaxFileSize=100KB
log4j.appender.myAppen.MaxBackupIndex=1


Now to get log4j running you just need to load this config file. The best place for this is probably in Application.cfm, as apposed to somewhere buried in your code. One thing to note, though. Once log4j is configured, it’s going to be running until you’re cf server/instance is restarted, so if you want to stop logging, you’ll need to remove the configuration code and restart cf. So here’s my Application.cfc:

<cfscript>
   if (NOT IsDefined("application.loggerInit")) {
       configurator = CreateObject("java", "org.apache.log4j.PropertyConfigurator");
configurator.configure('/usr/local/cf7/htdocs/sampleApp/logs/logger.properties');
       application.loggerInit = true;
   }
</cfscript>


Just a few things to note. I’m checking to see if if I’ve already initialized log4j, I created a ‘logs’ inside my sampleApps app folder, which contains my logger.properties config file and the samle.log file which will be created, and I’m using absolute path names in Application.cfm and in my config file. You could work around this, but… So now, you’re ready to begin logging! Let’s log a cfc being created. First I’ll retrieve the logger I created from an org.apache.log4j.Category instance and store it so other methods can use it, then use the ‘info’ method to do the logging:

<cfcomponent name="myCFC">
   <cffunction name="init" returntype="myCFC">
       <cfset var category = CreateObject("java", "org.apache.log4j.Category") />
       <cfset variables.logger = category.getInstance('myco.foo') />
       <cfset variables.logger.info('myCfc created") />
       <cfreturn this />
   </cffunction>
</cfcomponent>


And that’s all there is to it! Sorry about the length of the post, hopefully it’s not too much to consume, but has given you some ideas to get rolling. Happy logging!

introduction to log4j: http://logging.apache.org/log4j/docs/manual.html
log4j PatternLayout Class: http://logging.apache.org/log4j/docs/api/org/apache/log4j/PatternLayout.html
ColdFusion Developer's Journal article on log4j: http://cfdj.sys-con.com/read/42122.htm

5 Comments:

Blogger PaulH said...

cool, pretty interesting read. have you ever use log4j w/a db "appender"? i'm still having some conceptual problems setting it up.

7:37 AM  
Blogger Chris Scott said...

can't say I've logged into a database appender before, but I'd check go through the log4j site at www.apache.org, the documentation is really pretty straight forward

12:23 PM  
Anonymous Rich Rein said...

I am setting this up for the first time, with the intent of having different config files in different environments. My intent behind this is to log much more in dev (including info types, whereas in prod I will have it more restricted) to help with my debugging, and to allow the ability to turn on additional logging for certain pieces in prod when trouble arises. Is it always true that the logging will follow the pattern of a more specific category if one is available (com.foo), traverse up the tree (com), as well as the root level handler? I was hoping to be able to just have the most specific handler perform the log event, much like the cfcatch functionality in CF, rather than have specific logging events go to the file I specify as well as the standard output (my root level handler).

Also, I assume that you will have to reload the application-level configurator object for changes in the config file to be picked up, correct? In essence, if I want to make a change in my prod configuration to also log info and warn type logging events for a specific category, it would be beneficial to me to write some sort of utility to update the config file and reload the application-level initialization of the configurator?

9:43 AM  
Anonymous Miles said...

Instead of calling
configurator.configure('path_to_config');


you can call
configurator.configureAndWatch('path_to_config', poll_time);


which will periodically check if there are any changes to the config file (it creates a thread to do this), where poll_time is the amount of milliseconds to wait milliseconds to wait between checks.

11:12 PM  
Blogger Eric Knipp said...

I have put together some blog posts that cover ColdFusion & Log4j, specifically using a DB appender .. check it out on my blog

http://erichk.instantspot.com/blog/

9:01 PM  

Post a Comment

<< Home