Introduction to Logging - Mach-II/Mach-II-Framework GitHub Wiki
- Overview
- Getting Started
- Logging Architecture Overview
- Bundled Mach-II Loggers
- Custom Messages
- Using the Generic Channel Filter
- Using Type Shortcuts When Defining Loggers
- Multiple Loggers
- Additional Resources
A logging package was introduced in Mach-II 1.6 to give developers a full blown logging package with extensibility to customize and comes bundled with a few loggers. One specific logger, MachIILogger, logs what happens for each request lifecycle and output a stack of debugging data to the developer. With all the different plugins, filters, subroutines, views, etc. that may be used in a typical event, it can be difficult and time consuming to follow what all happened when a user goes to the home page.
In earlier versions of Mach-II, the trace plugin existed to help developers debug, but was not the best solution. This plugin basically used the postProcess plugin point hook to append an execution list of items (core files, filters, etc.) that ran to the bottom of your output. The trace plugin can still be found at MachII.plugins.TracePlugin, but has been deprecated in favor of the logging package which provides much greater flexibility in both what output is shown and where it is written.
This tutorial will show you how to use the Logging Property and how to alter the defaults to your liking. This tutorial assumes you already have a basic understanding of Mach-II (editing the config.xml, calling an event, etc.).
The simplest way to add the Logging Property is to put the following line of xml within the <properties> section of your config.xml file:
<property name="Logging" type="MachII.logging.LoggingProperty" />Adding the above code and then reloading your Mach-II application (if your application is not in dynamic reload mode) will show something like the image below at the bottom of your page in a browser.
The output will show each filter, plugin, listener, view and even Mach-II core files that are accessed. Below that list you can also see the event name, module name, Mach-II version and a time stamp. This is the output you get using the default settings of the LoggingProperty.
Logging is a cross-cutting concern in applications. A cross-cutting concern often means a "component" of a system that cannot easily be cleanly "decomposed" from the rest of the system. Since logging easily cuts through multiple layers of an applications, the Mach-II logging is application wide. This means that a base application and all Mach-II modules share the same logging registry. A logger registered in one module will be available in the base application and any other modules in your application.
Before we get into the details, it would be a good idea to understand the logging terms we use and the fundamental architecture behind Mach-II logging.
A log message is a string of data to indicate a specific action has occurred. Each message is logged at a specified logging level which indicates the severity of the message from being rather benign (debug information) to something exceptional (an unhandled exception occurred). The Mach-II framework logs messages for you as specific points in the request lifecycle which can help you debug an error in your application
When you log a message, it is 'broadcasted' on channel. A channel is similar to channels on a television, channels allow you to log messages to specific places. Later on we'll find out that concrete logging implementations can be configured to listen for messages on all or just some channels. Typically, the logging channel is the dot path of the CFC that is logging the message. The channel is set into the log when you ask the LogFactory for a log. This allows you to just log a message without worrying about passing in the channel name each time you log a message.
The logging level indicates the severity of the message. It would be unlikely that all messages deserve the same attention as other messages. For example, an unhandled exception should be logged at more severe logging level than message that indicates that a variable was set. (Definitions pulled from Apache Commons Logging User Guide)
| Log Level | Description |
|---|---|
| trace | More detailed information. |
| debug | Detailed information on the flow through the system. |
| info | Interesting runtime events (startup/shutdown). |
| warn | Use of deprecated APIs, poor use of API, 'almost' errors, other runtime situations that are undesirable or unexpected, but not necessarily "wrong". |
| error | Other runtime errors or unexpected conditions. Expect these to be immediately visible on a status console. |
| fatal | Severe errors that cause premature termination. |
A logger is a CFC that listens for log messages. It is the responsibility of the logger to decide whether it is accepting messages at that particular logging level and channel. If you were able to set which logger you wanted to log a message to in your CFCs, it would strongly couple your logging implementation to your CFCs. By abstracting this type of configuration when you define a logger, it reduces the configuration out of your model. This lets you remain flexible when your logging requirements change.
As we will see in the below examples, the <property name="logging" type="MachII.logging.LoggingProperty"/> value refers to the LoggingProperty.cfc found in the Mach-II core directory. It is a high-level wrapper for the actual Logger. Different Loggers can be used depending on where and how you would like to see the output. For example, if you would like to write the above output to a CFML log file instead of at the bottom of the view, you can do that with the CFLogLogger.
The default logger used is the MachIILogger. It outputs the data at the bottom of your output as shown above. Each logger will generally have it's own set of parameters depending on its purpose.
The Notes section of the comments in the MachII.logging.loggers.MachIILog.Logger shows all the configuration options available for this logger:
<property name="Logging" type="MachII.logging.LoggingProperty">
<parameters>
<parameter name="MachIILog">
<struct>
<key name="type" value="MachII.logging.loggers.MachIILog.Logger" />
<!-- Optional and defaults to true -->
<key name="loggingEnabled" value="true|false" />
<!-- - OR - (supported in Mach-II 1.8+) -->
<key name="loggingEnabled">
<struct>
<!-- All key names prefixed with 'group:' indicate environment groups -->
<key name="group:development,qa" value="false"/>
<!-- Explicitly setting environment names of 'prod' and 'prodFailOver' -->
<key name="prod,prodFailOver" value="true"/>
</struct>
</key>
<!-- Optional and defaults to 'fatal' -->
<key name="loggingLevel" value="all|trace|debug|info|warn|error|fatal|off" />
<!-- Optional and defaults to the default display template if not defined -->
<key name="displayOutputTemplateFile" value="/path/to/customOutputTemplate.cfm" />
<!--
Optional and defaults to 'false';
Shows output only if CF's debug mode is enabled
-->
<key name="debugModeOnly" value="false" />
<!--
Optional and defaults to 'suppressDebug'
Name of event arg that suppresses debug output
(useful when a request returns xml, json or images)
-->
<key name="suppressDebugArg" value="suppressDebug" />
<!-- Optional -->
<key name="filter" value="list,of,filter,criteria" />
<!-- - OR - --->
<key name="filter">
<array>
<element value="array" />
<element value="of" />
<element value="filter" />
<element value="criteria" />
</array>
</key>
<!--
Optional and defaults to not being used
Can provide a list of absolute IPs such as "127.0.0.1,127.0.0.2,127.0.0.3,127.0.0.5"
or may use range notation, "127.0.0.[1-3,5]"
-->
<key name="debugIPs" value="list,of,ip,addresses" />
<!-- - OR - -->
<key name="debugIPs">
<array>
<element value="array" />
<element value="of" />
<element value="ip" />
<element value="addresses" />
</array>
</key>
</struct>
</parameter>
</parameters>
</property>Each <key> tag above will translate to a structure item used by the Logger component. There are comments for each of the optional settings and the defaults are noted.
| Key Name | Description | Req. | Values | Default Value |
|---|---|---|---|---|
| type | Refers to the location of the logger CFC in dot notation | yes | CFC dot path | n/a |
| loggingEnabled | Turns logging on or off | no | boolean or struct of environment names / groups (prefixed with group:) with corresponding booleans (struct supported in Mach-II 1.8+) |
true |
| loggingLevel | Defines which level and higher of logging messages you want to see | no | all, trace, debug, info, warn, error, fatal, off | fatal |
| displayOutputTemplateFile | The location of the template that formats the output. If you do choose to customize this, pay attention to the comments on the default version. They have a warning about putting any new variables into a structure named "local" so as to keep them var scoped. This is because this template is rendered inside a CFC function via a cfinclude statement. | no | slash path to template |
/MachII/logging/ loggers/MachIILog/ defaultOutputTemplate.cfm
|
| debugModeOnly | Allows you to control the logging output based on setting in your CFML server's Enable Request Debugging Output settings | no | boolean | false |
| suppressDebugArg | Name of a variable that you can set within an event to disable the logging output regardless of other settings. For example, using <event-arg name="suppressDebug" value="true" /> within an <event-handler> will cause the logging output to not show. |
no | name of event-arg | supressDebug |
| filter | Allows you to limit the output based on string matches. To apply more than one either use a comma delimited list or an array as shown above. Not defining this results in no filtering by channel | no | array or list | none |
| debugIPs | Enables debug output for specified IP addresses and ranges (1.9+) | no | array or list | none |
The CF Logger will write the output to a .log file found in the logs directory of your CFML engine installation. The Notes section of the comments in the MachII.logging.loggers.CFLog.Logger shows all the configuration options available for this logger:
<property name="Logging" type="MachII.logging.LoggingProperty">
<parameters>
<parameter name="MachIILog">
<struct>
<key name="type" value="MachII.logging.loggers.CFLog.Logger" />
<!-- Optional and defaults to true -->
<key name="loggingEnabled" value="true|false" />
<!-- - OR - (supported in Mach-II 1.8+) -->
<key name="loggingEnabled">
<struct>
<!-- All key names prefixed with 'group:' indicate environment groups -->
<key name="group:development,qa" value="false"/>
<!-- Explicitly setting environment names of 'prod' and 'prodFailOver' -->
<key name="prod,prodFailOver" value="true"/>
</struct>
</key>
<!-- Optional and defaults to 'fatal' -->
<key name="loggingLevel" value="all|trace|debug|info|warn|error|fatal|off" />
<!-- Optional and defaults to the application.log if not defined -->
<key name="logFile" value="nameOfCFLogFile" />
<!--
Optional and defaults to 'false'
logs messages only if CF's debug mode is enabled
-->
<key name="debugModeOnly" value="false" />
<!-- Optional -->
<key name="filter" value="list,of,filter,criteria" />
<!-- - OR - -->
<key name="filter">
<array>
<element value="array" />
<element value="of" />
<element value="filter" />
<element value="criteria" />
</array>
</key>
</struct>
</parameter>
</parameters>
</property>All of these <key> parameters are the same as the MachII Logger (see above) except one new one. The logFile key is optional and will default to 'application' meaning the output will be written to the application.log file.
| Key Name | Description | Required | Values | Default Value |
|---|---|---|---|---|
| typ | Refers to the location of the logger CFC in dot notation | yes | CFC dot path | n/a |
| loggingEnabled | Turns logging on or off | no | boolean or struct of environment names / groups (prefixed with group:) with corresponding booleans (struct supported in Mach-II 1.8+) |
true |
| loggingLevel | Defines which level and higher of logging messages you want to see | no | all, trace, debug, info, warn, error, fatal, off | fatal |
| logFile | Refers to the name of the .log file in which to write the output. | no | valid file name | application |
| debugModeOnly | Allows you to control the logging output based on setting in your CFML server's Enable Request Debugging Output settings | no | boolean | false |
| filter | Allows you to limit the output based on string matches. To apply more than one either use a comma delimited list or an array as shown above. Not defining this results in no filtering by channel | no | array or list | none |
The Email Logger will send the output to one or more email addresses specified. The Notes section of the comments in the MachII.logging.loggers.EmailLog.Logger shows all the configuration options available for this logger:
<property name="Logging" type="MachII.logging.LoggingProperty">
<parameters>
<parameter name="EmailLog">
<struct>
<key name="type" value="MachII.logging.loggers.EmailLog.Logger" />
<!-- Optional and defaults to true -->
<key name="loggingEnabled" value="true|false" />
<!-- - OR - (supported in Mach-II 1.8+) -->
<key name="loggingEnabled">
<struct>
<!-- All key names prefixed with 'group:' indicate environment groups -->
<key name="group:development,qa" value="false"/>
<!-- Explicitly setting environment names of 'prod' and 'prodFailOver' -->
<key name="prod,prodFailOver" value="true"/>
</struct>
</key>
<!-- Optional and defaults to 'debug' -->
<key name="loggingLevel" value="all|trace|debug|info|warn|error|fatal|off" />
<!-- Optional - defaults to 'fatal' -->
<key name="loggingLevelEmailTrigger" value="all|trace|debug|info|warn|error|fatal|off" />
<!-- Optional and defaults to the default display template if not defined -->
<key name="emailTemplateFile" value="/path/to/customEmailTemplate.cfm" />
<!-- Required - list of email addresses to send the log report to -->
<key name="to" value="list,of,email,addresses" />
<!-- Required - email address to send the log report from -->
<key name="from" value="[email protected]" />
<!--
Optional - the name of the subject of the log report email
defaults to 'Application Log'
-->
<key name="subject" value="Application Log" />
<!--
Optional - list of mail server names or IPs defaults to mail
server specified in the CFML admin
-->
<key name="servers" value="mail.example.com" />
<!-- Optional - mail type for the cfmail (default: text/html) -->
<key name="mailType" value="text/html" />
<!-- Optional - username to use for all servers -->
<key name="username" value="" />
<!-- Optional - password to use for all servers -->
<key name="password" value="" />
<!-- Optional - charset to use and defaults to 'utf-8' -->
<key name="charset" value="utf-8" />
<!-- Optional - enable/disable spool enable for mail and defaults to 'true' -->
<key name="spoolenable" value="true" />
<!-- Optional - value to wait for mail server and defaults to 60 -->
<key name="timeout" value="60" />
<!-- Optional - Take the text of the first message that caused
the trigger and append it to the subject -->
<key name="appendMessageToSubject" value="false" />
<!-- Optional -->
<key name="filter" value="list,of,filter,criteria" />
<!-- - OR - -->
<key name="filter">
<array>
<element value="array" />
<element value="of" />
<element value="filter" />
<element value="criteria" />
</array>
</key>
</struct>
</parameter>
</parameters>
</property>Most of these <key> parameters are the same as the MachII Logger (see above). New keys are noted below:
| Key Name | Description | Required | Values | Default Value |
|---|---|---|---|---|
| type | Refers to the location of the logger CFC in dot notation | yes | CFC dot path | n/a |
| loggingEnabled | Turns logging on or off | no | boolean or struct of environment names / groups (prefixed with group:) with corresponding booleans |
true |
| loggingLevel | Defines which level and higher of logging messages you want to see | no | all, trace, debug, info, warn, error, fatal, off | debug |
| loggingLevelEmailTrigger | Defines which level and higher of logging messages triggers an email (1.8+) | no | all, trace, debug, info, warn, error, fatal, off | fatal |
| emailTemplateFile | The location of the template that formats the email. | no | slash path to template |
/machii/logging /loggers/EmailLog /defaultEmailTemplate.cfm
|
| to | A comma delimted list of one or more email addresses to send the log email to. | yes | valid email address(es) | n/a |
| from | Email address to send the email from. | yes | valid email address | n/a |
| subject | The subject of the email that will be sent. | no | string | Application Log |
| servers | A comma delimited list of server names or IP addresses. | no | valid server name or IP | Mail servers specified in CF Administrator |
| mailType | The mail type for cfmail (1.8+). | no | MIME type | text/html |
| username | The username to use for all servers (1.8+) | no | string | |
| password | The password to use for all servers (1.8+) | no | string | |
| charset | The charset to use when sending mail (1.8+) | no | string | utf-8 |
| spoolenable | Enable/disable spool enable for sending mail (1.8+) | no | boolean | true |
| timeout | Time to wait for mail server to send mail (1.8+) | no | numeric | 60 |
| appendMessageToSubject | Take the text of the first message that caused the trigger and append it to the subject (1.9+) | no | boolean | false |
| filter | Allows you to limit the output based on string matches. To apply more than one either use a comma delimited list or an array as shown above. Not defining this results in no filtering by channel | no | array or list | none |
Available in Mach-II 1.9+
The Log4j Logger will send the output to Log4j based on the configuration you supply.
Log4j runs as a singleton for your entire Java classloader. BE CAREFUL with your log4j configuration files. It is possible to stomp settings for other objects using log4j by using this Mach-II logger. The settings specified for this logger are ADDED to the running configuration and effectively the last setting wins when there is a conflict.
Configuration options available for this logger:
<property name="Logging" type="MachII.logging.LoggingProperty">
<parameters>
<parameter name="MachIILog">
<struct>
<key name="type" value="MachII.logging.loggers.Log4j.Logger" />
<!-- Optional and defaults to true -->
<key name="loggingEnabled" value="true|false" />
<!-- - OR - (supported in Mach-II 1.8+) -->
<key name="loggingEnabled">
<struct>
<!-- All key names prefixed with 'group:' indicate environment groups -->
<key name="group:development,qa" value="false"/>
<!-- Explicitly setting environment names of 'prod' and 'prodFailOver' -->
<key name="prod,prodFailOver" value="true"/>
</struct>
</key>
<!-- Optional and defaults to 'fatal' -->
<key name="loggingLevel" value="all|trace|debug|info|warn|error|fatal|off" />
<!-- Optional, if supplied must be either of type .properties or .xml -->
<key name="configFile" value="/path/to/config/file" />
<!--
Optional and defaults to 'false'
logs messages only if CF's debug mode is enabled
-->
<key name="debugModeOnly" value="false" />
<!-- Optional -->
<key name="filter" value="list,of,filter,criteria" />
<!-- - OR - -->
<key name="filter">
<array>
<element value="array" />
<element value="of" />
<element value="filter" />
<element value="criteria" />
</array>
</key>
</struct>
</parameter>
</parameters>
</property>All of these <key> parameters are the same as the MachII Logger (see above) except 'configFile'.
| Key Name | Description | Required | Values | Default Value |
|---|---|---|---|---|
| type | Refers to the location of the logger CFC in dot notation | yes | CFC dot path | n/a |
| loggingEnabled | Turns logging on or off | no | boolean or struct of environment names / groups (prefixed with group:) with corresponding booleans (struct supported in Mach-II 1.8+) |
true |
| loggingLevel | Defines which level and higher of logging messages you want to see | no | all, trace, debug, info, warn, error, fatal, off | fatal |
| configFile | Refers to the path and file for the log4j configuration | no | valid path and file name | none |
| debugModeOnly | Allows you to control the logging output based on setting in your CFML server's Enable Request Debugging Output settings | no | boolean | false |
| filter | Allows you to limit the output based on string matches. To apply more than one either use a comma delimited list or an array as shown above. Not defining this results in no filtering by channel | no | array or list | none |
Example of a simple log4j configuration:
log4j.category.myCategory=INFO, myAppen
log4j.additivity.myCategory=false
log4j.appender.myAppen =org.apache.log4j.RollingFileAppender
log4j.appender.myAppen.File=/path/to/myfile.log
log4j.appender.myAppen.layout=org.apache.log4j.PatternLayout
log4j.appender.myAppen.layout.ConversionPattern=%-4r [%t] %-5p %c - %m%n
log4j.appender.myAppen.MaxFileSize=100KB
log4j.appender.myAppen.MaxBackupIndex=1
If you wish to get more detail than the provided log output, you can simply add your own custom messages within your code. For example, in a listener that processes a login attempt, you could add the following to write some more detail:
<cfset getLog().info("User #arguments.event.getArg('userName')#
login attempt on #DateFormat(Now(),'m/d/yyyy')# at #TimeFormat(Now(),'h:mm tt')#")
/>When a message is logged, it will be broadcasted to all registered loggers. It is the duty of the logger to decide what it will do with the message based on logging level and/or channel filters. You cannot log to a specific logger.
Sometimes it is necessary to perform some complex logic in order to construct a logging message. This can incur some performance overhead especially if the message is only logged when the application is in a specific state (e.g. debugging or development mode). The caching package offers several messages that check whether any of the registered loggers are listening for messages at the requested level.
<cfif operationFailed AND getLog().isInfoEnabled()>
<!--- Make calls that take a while in order to construct the logging message --->
<cfset someValue = variables.someService.callThatTakesAWhileToComplete(arguments.event.getArg('userName') />
<cfset getLog().info("Tried to complete an operation which failed and logged as
id '#someValue#' on #DateFormat(Now(),'m/d/yyyy')# at #TimeFormat(Now(),'h:mm tt')#") />
</cfif>You can always call isLOGGINGLEVELenabled() to check whether any loggers are listening for messages at that level.
Additional data can be appended with the logging message by using the the additionInformation argument when logging a message:
getLog().trace("Passed in data", arguments)In the above example, we want to log (for debugging purposes) the passed in arguments to some method call with the logging message. The additionalInformation argument accepts any CFML datatype (CFCs, struct, array, string, query).
The MachIILogger, EmailLogger and CFLogLogger by default uses a generic channel filter for filtering on channel names.
Channel filter negation and wildcard are as follows:
| Notation Character | Description |
|---|---|
| ! | Do not match (can only occur at the beginning of a pattern string) |
| * | Wildcard (can only occur at the end of a pattern string in Mach-II 1.6 and anywhere in the pattern in Mach-II 1.8+) |
Examples on how to use a filter are as follows:
| Pattern | Description |
|---|---|
| * | Matches everything (unless you have another pattern that specifies not to match a channel name) |
| !* | Nothing (unless you have another pattern that matches) |
| MachII.* | Matches all channels that start with MachII.
|
| !myApp.model.* | Does not match any channels that start with myApp.model.
|
| MachII | Matches only 'MachII' literal not MachII.framework.etc - exact channel name |
Filters are read in the order listed, so providing something like the following will show only matches to MachII.framework.ViewContext (note that string matches are not case sensitive).
<key name="filter" value="!*,MachII.framework.ViewContext" />In Mach-II 1.6, you have to do define the complete type to the logger you want to use MachII.logging.loggers.MachIILog.Logger:
<parameter name="MachIILog">
<struct>
<key name="type" value="MachII.logging.loggers.MachIILog.Logger"/>
<key name="loggingLevel" value="all"/>
</struct>
</parameter>Beginning with Mach-II Simplicity (1.8), you can use type shortcuts like this:
<parameter name="MachIILog">
<struct>
<key name="type" value="MachIILogger"/>
<key name="loggingLevel" value="all"/>
</struct>
</parameter>The follow shortcuts are available as of Mach-II Simplicity and will be expanded when additional loggers are added:
| Shortcut Name | Full Type Dot Path |
|---|---|
| MachIILogger | MachII.logging.loggers.MachIILog.Logger |
| EmailLogger | MachII.logging.loggers.EmailLog.Logger |
| CFLogLogger | MachII.logging.loggers.CFLog.Logger |
Please note well that type shortcuts do not work with Mach-II 1.6 and work in Mach-II 1.8 or higher.
If you wish to both receive emails and have logging output entered into a log file, you can use 2 loggers at once. Note that the parameter names must be unique.
Here is a sample setup of how to do this (with some optional keys omitted). The email part of this logging will only send if the logging level is fatal. The CFLog will only send messages that have been logged as the myApp channel. This is a good way to see what filters, plugins and listeners are accessed.
<property name="Logging" type="MachII.logging.LoggingProperty">
<parameters>
<parameter name="MachIIEmailLog">
<struct>
<key name="type" value="MachII.logging.loggers.EmailLog.Logger" />
<key name="loggingEnabled" value="true" />
<key name="loggingLevel" value="fatal" />
<key name="to" value="[email protected]" />
<key name="from" value="[email protected]" />
<key name="subject" value="Mach II Log" />
</struct>
</parameter>
<parameter name="MachIICFLog">
<struct>
<key name="type" value="MachII.logging.loggers.CFLog.Logger" />
<key name="loggingEnabled" value="true" />
<key name="loggingLevel" value="all" />
<key name="logFile" value="MachIICFLog" />
<key name="filter">
<array>
<element value="!*" />
<element value="myApp.*" />
</array>
</key>
</struct>
</parameter>
</parameters>
</property>- [How do I use the MachII.util.UtilityConnector to leverage caching and logging within ColdSpring or other bean factories?] idwiki_FAQUsingUtilityConnector
Special thanks to Matt Williams (mgw4jc@…) for initially contributing this entry.