JRun Metrics Logging
JRun Metrics Logging

JRun Metrics Logging

Summary

Since the release of ColdFusion MX, the preferred method of installation involves the use of a J2EE server. At my company, we use the bundled JRun 4 J2EE application server. One of the nicer features of this product is the ability to generate a custom log file that contains server metrics. In this tutorial, I'll demonstrate how you can enable these custom JRun performanace metrics that are easily imported into an excel spreadsheet.

Note: This turotial assumes that you are using JRun 4, Updater 2 or later. While the information contained within may be useful for those of you running CFMX Standalone installations, it has not been tested in that configuration.

Tutorial

The JRun J2EE Application server allows you to create and manage multiple JRun Server instances, typically called servers. When you install CFMX 6.1 using the JRun J2EE option (option 2), the installer package will create a specific JRun Server instance named cfusion. You can create as many of these server instances that you like, but be cautious of server resources and expected load.

All JRun Servers will write log files to the [jrun-root]/logs directory. A default installation will show an errors log and a standard output log.

For each JRun server instance that you create, you will have a jrun.xml file. This file is typically located at:


You'll want to modify this file to enable metrics logging, and to create a specific log for each type of event that you wish to monitor. Be aware that you will need to restart your JRun Server for any changes to take affect. Be sure to make a backup copy of this file before you start modifying it.

First, let's turn on the metrics logging service. Look for the following section:

[jrun-root]/servers/[jrun-server-name]/SERVER-INF/jrun.xml
<!-- ================================================================== -->
<!-- This Service provides metrics information -->
<!-- ================================================================== -->
<!-- To enable metrics: uncomment this service
and in LoggerService set metricsEnabled to true -->
 
<!--
<service class="jrunx.metrics.MetricsService" name="MetricsService">
  <attribute name="bindToJNDI">true</attribute>
</service>
-->

And uncomment the service so that the section looks like this:

<!-- ================================================================== -->
<!-- This Service provides metrics information -->
<!-- ================================================================== -->
<!-- To enable metrics: uncomment this service
and in LoggerService set metricsEnabled to true -->
 
<service class="jrunx.metrics.MetricsService" name="MetricsService">
  <attribute name="bindToJNDI">true</attribute>
</service>

At this point, you have simple enabled metrics logging, and the default metrics output will be sent to the [jrun-root]logs/[jrun-server-name]-out.log. Next, we'll want to instruct JRun to use specific logs for each type of logging event. Again, look in the jrun.xml file for this section.

<!-- ================================================================== -->
<!-- This Service represents JRun's logging facility -->
<!-- ================================================================== -->
 
  <service class="jrunx.logger.LoggerService" name="LoggerService">
    <attribute name="errorEnabled">true</attribute>
    <attribute name="warningEnabled">true</attribute>
    <attribute name="infoEnabled">true</attribute>
    <attribute name="debugEnabled">false</attribute>

The default values for the errorEnabled, warningEnabled, infoEnabled, and debugEnabled may be different than what you see here. It may be useful to enable all options, but for our servers, we enable eveything except the 'debug' information. If enabled, debug output will be very verbose, and should only be enabled when troubleshooting a specific problem.

Now, let's enable the metricsEnabled attribute and add a few lines. Modify your jrun.xml to look like this:

<!-- ================================================================== -->
<!-- This Service represents JRun's logging facility -->
<!-- ================================================================== -->
 
<service class="jrunx.logger.LoggerService" name="LoggerService">
    <attribute name="errorEnabled">true</attribute>
    <attribute name="warningEnabled">true</attribute>
    <attribute name="infoEnabled">true</attribute>
    <attribute name="debugEnabled">false</attribute>
 
    <!-- Enable Metrics -->
    <attribute name="metricsEnabled">true</attribute>
    <attribute name="metricsLogFrequency">60</attribute>
    <attribute name="metricsFormat">{jrpp.listenTh} {jrpp.idleTh} {jrpp.delayTh} {jrpp.busyTh} {jrpp.totalTh} {jrpp.droppedRq} {jrpp.handledRq} {jrpp.handledMs} {jrpp.delayRq} {jrpp.delayMs} {sessions} {freeMemory} {totalMemory}</attribute>

These settings will enable Metrics information to be logged at a specific frequency. The frequency value is in seconds, and you can change this to log an entry as often as you wish.

The 'metricsFormat' attribute allows you to specify which metric information you want displayed, and how you want the output formatted. In this example, I am using a majority of the metrics information, and separating each column with a tab character. You may choose to separate with a comma, or a semi-colon, the choice is up to you. I find that the tab separated columns are easy to read, and easy to import into Excel for data analysis.

What do these columns represent?

You probably noticed that the 'metricsFormat' attribute contains several entries that are contained in curly braces. These are variables that the JRun Metrics service makes available for logging. For an explanation of these entries, please visit: http://livedocs.macromedia.com/jrun/4/JRun_Administrators_Guide/netmon2.htm.

Separate Log Files please

As I mentioned earlier, the [jrun-root]/servers/[jrun-server-name]-out.log will get all of the default output. But now that we have expressly asked to see other data (errors, warnings, info, debugging, metrics), it would be useful to have a specific log file for each type of entry. We'll continue modifying the jrun.xml file with the following entries.

<!-- ================================================================== -->
<!-- This Service represents JRun's logging facility -->
<!-- ================================================================== -->
 
<service class="jrunx.logger.LoggerService" name="LoggerService">
  <attribute name="errorEnabled">true</attribute>
  <attribute name="warningEnabled">true</attribute>
  <attribute name="infoEnabled">true</attribute>
  <attribute name="debugEnabled">false</attribute>
 
  <!-- Enable Metrics -->
  <attribute name="metricsEnabled">true</attribute>
  <attribute name="metricsLogFrequency">60</attribute>
  <attribute name="metricsFormat">{jrpp.listenTh} {jrpp.idleTh} {jrpp.delayTh} {jrpp.busyTh} {jrpp.totalTh} {jrpp.droppedRq} {jrpp.handledRq} {jrpp.handledMs} {jrpp.delayRq} {jrpp.delayMs} {sessions} {freeMemory} {totalMemory}</attribute>
 
  <service class="jrunx.logger.ThreadedLogEventHandler" name="ThreadedLogEventHandler">
 
    <!-- Standard Out -->
    <service class="jrunx.logger.ConsoleLogEventHandler" name=":service=ConsoleLogEventHandler" />
 
    <!-- Log Files -->
    <service class="jrunx.logger.FileLogEventHandler" name="FileLogEventHandler">
      <attribute name="heading"># Created by JRun on {date d/mm/yyyy HH:mm:ss}</attribute>
      <attribute name="format">{date dd/mm/yyyy} {date HH:mm:ss} {log.message}</attribute>
      <attribute name="filename">{jrun.rootdir}/logs/{jrun.server.name}-{log.level}.log</attribute>
      <attribute name="rotationSize">5000k</attribute>
      <attribute name="rotationFiles">20</attribute>
      <attribute name="closeDelay">5000</attribute>
      <attribute name="deleteOnExit">false</attribute>
    </service>
 
  </service>
</service>

OK, so there's a lot here, but this shows the entire 'Logging' service sectio of the jrun.xmlfile.

The line: <service class="jrunx.logger.ThreadedLogEventHandler" name="ThreadedLogEventHandler"> is the opening tag for the ThreadedLogEventHandler container. This container will allow us to define specific attributes for both the 'ConsoleLogEventHandler' and the 'FileLogEventHandler'. We aren't really too worried about the format of console logs, but we are very interested in the file logging section.

Under the <service class="jrunx.logger.FileLogEventHandler" name="FileLogEventHandler"> section, there are several attributes that are important to us. They are:

heading
Specified the string of text to be written on the first line of all new files.
format
Specifies that each line written to a log file will begin with the current date, time, and then the specific logging message.
filename
This is where we explicity tell JRun to give us a unique log file for each type of logging level. Notice the format of {jrun.server.name}-{log.level}. This will mean that you'll get log files like this:
  • cfusion-err.log
  • cfusion-info.log
  • cfusion-metrics.log
  • cfusion-out.log
  • cfusion-user.log
rotationSize
Specifies how big each log file can grow to before rotating the log files.
rotationFiles
Specifies how many rotations (old log files) to keep before deleting older log files.
closeDelay
Specifies the number of milliseconds of idle time to wait before closing a log file. If this value is too short, you will see an increase in file I/O as JRun will have to constantly open and close the log file.
deleteOnExit
Specifies whether or not the JRun server should delete the log files when the server is shut down.
For more information about the FileLogEventHandler attributes, please visit: http://livedocs.macromedia.com/jrun/4/JRun_Administrators_Guide/logging.htm.

The results:

Here is a sample output of my metrics log file:

# Created by JRun on 03/28/2005 02:03
28/03/2005	14:03:07	1	0	0	0	1	0	0	0	0	0	0	250029	258560
28/03/2005	14:03:17	1	0	0	0	1	0	0	0	0	0	0	249955	258560
28/03/2005	14:03:27	1	0	0	0	1	0	0	0	0	0	0	249955	258560
28/03/2005	14:03:37	1	2	0	0	3	0	6	5409	0	0	1	233542	258560
28/03/2005	14:03:47	1	2	0	0	3	0	3	593	0	0	1	245748	258560
28/03/2005	14:03:57	1	2	0	0	3	0	10	2580	0	0	1	244045	255808
28/04/2005	14:04:07	1	2	0	0	3	0	2	516	0	0	1	238207	255808
28/04/2005	14:04:17	1	2	0	0	3	0	0	0	0	0	1	238020	255808

Unfortunately, JRun does not provide a mechanism to provide a custom header for the metrics log only. You'll have to use the default file header for all log files. But it should be obvious that this data can easily be imported into Excel, or read by the <CFFILE> tag and imported into a database for analysis and reporting.



All ColdFusion Tutorials By Author: Damon Gentry
  • ColdFusion Performance Profiling
    Do you use the getTickCount() method to measure your CFML applications performance? There is a better way. Since the release of Coldfusion MX, the entire ColdFusion server has been built using Java. In this tutorial, well examine how a Java Servlet Filter can be used to measure the performance of your CFML application pages.
    Author: Damon Gentry
    Views: 8,544
    Posted Date: Friday, January 28, 2005
  • JRun Metrics Logging
    Since the release of ColdFusion MX, the preferred method of installation involves the use of a J2EE server. At my company, we use the bundled JRun 4 J2EE application server. One of the nicer features of this product is the ability to generate a custom log file that contains server metrics. In this tutorial, Ill demonstrate how you can enable these custom JRun performanace metrics that are easily imported into an excel spreadsheet.
    Author: Damon Gentry
    Views: 7,515
    Posted Date: Friday, January 28, 2005