Click to visit our sponsors
ColdFusion MX Performance Profiling
Summary
Do you use thegetTickCount() method to measure your CFML application's performance? There is a better way. Since the release of Coldfusion MX, the entire ColdFusion server has been built using Java. In this tutorial, we'll examine how a Java Servlet Filter can be used to measure the performance of your CFML application pages.
Note: This tutorial uses a product from ColdBeans Software. The author has not been paid, nor has been endorsed by ColdBeans Software for this tutorial.
What is a filter?
According to the J2EE specification, a Filter is an object than perform filtering tasks on either the request to a resource (a servlet or static content), or on the response from a resource, or both. Basically, this is a mechanism that can execute code before and after an HTTP request. In this example, we will install a filter on your CFMX server to capture profiling data on all HTTP requests to pages that end in '.cfm'.
The Profile Filter
ColdBeans Software has developed a small, inexpensive servlet called the Profile Filter. This servlet can be purchased for approximately $50 per server installation. You can download the trial edition of the filter here.
The installation
You will need to copy the profflt.jar file into your [web-inf]/lib directory. In a typical CFMX/JRun installation, the full directory might look like this:
c:\jrun4\servers\cfusion\cfusion-ear\cfusion-war\WEB-INF\lib
After copying the file there, you'll need to modify your web.xml file. In a typical CFMX/JRun installation, the full directory might look like this:
c:\jrun4\servers\cfusion\cfusion-ear\cfusion-war\WEB-INF\web.xml
Specifically, we are going to add some information to the web.xml file so that the Profile Filter servlet can work for us. Add the following lines to the file, just above the closing </web-app> tag.
<filter>
<filter-name>profileFilter</filter-name>
<filter-class>com.cj.profile.profileFilter</filter-class>
</filter>
<filter-mapping>
<filter-name>profileFilter</filter-name>
<url-pattern>*.cfm</url-pattern>
</filter-mapping>
<servlet>
<servlet-name>Profile</servlet-name>
<servlet-class>com.cj.profile.ProfileServlet</servlet-class>
</servlet>
<servlet-mapping>
<servlet-name>Profile</servlet-name>
<url-pattern>/servlet/Profile</url-pattern>
</servlet-mapping>
You may want to add additional url-patterns to the filter such as (.cfc, .jsp) to capture profiling data on these file types as well.
Optional Parameters
The Profile Servlet supports an additional option to capture the performance differences when passing in query strings to a specific CFML tempalte. This is essential in Fusebox applications where all requests are driven through index.cfm. To configure profiling for independant query strings, modify the <filter> section to look like this:
<filter>
<filter-name>profileFilter</filter-name>
<filter-class>com.cj.profile.profileFilter</filter-class>
<init-param>
<param-name>query</param-name>
<param-value>true</param-value>
</init-param>
</filter>
Why is this better than getTickCount()?
Because this java servlet is executed as a filter, it begins it's count just before the CFMX engine receives the request to process the page. Additionally, this servlet stops the execution timer after the CFMX engine has completely finished processing and is ready to return the result back to the user. Because of this, the Profile Servlet captures the entire execution cycle of the page outside of the mechanisms of ColdFusion, and includes any additional overhead processing that the CFMX engine is performing (such as debugging).
If you have enabled debugging on your server, the CFMX engine will capture debugging info for each and every CFM request regardless of whether or not your IP is listed in the 'Debugging IPs' section of the CF Administrator. The 'Debugging IPs' section is only used to conditionally determine which browsers to send the debugging data to.
As you'll see later in this tutorial, the Profile Filter also captures frequency, average, minimum, and maximum execution times for each unique URI (CFM template). To accomplish this with getTickCount(), you'd have to add some additional application code and store information in the server scope or in a database. You'd also have to do this on each and every request.
From a performance overhead perspective, this servlet executes very quickly, and only uses a small amount of RAM to and store profile data. I have been using this servlet for over 6 months in a production environment with no noticeable impact on our servers.
In short, the data captured by the Profile Filter is much more reliable than getTickCount() and more accurately represents what your end users will see.
This is not to say that getTickCount() doesn't have a place in your code. But if you want to measure the entire template's execution time, the Profile Servlet is far and away the better choice.
OK, so now what?
Once you have modified your web.xml file and restarted your ColdFusion server, you will probably want to visit a few pages on your server. Once you have done that, you can navigate to: http://servername/servlet/Profile.
You should see a web page that looks like this:
| URI | Requests | Min. time | Avg. time | Max. time |
| /lighthouse/calendar/index.cfm ... | 2 | 78 | 500.0 | 922 |
| /lighthouse/calendar/entry_det ... | 1 | 172 | 172.0 | 172 |
| /lighthouse/profile/index.cfm? | 1 | 234 | 234.0 | 234 |
| /lighthouse/calendar/index.cfm ... | 5 | 78 | 96.8 | 110 |
| /lighthouse/calendar/entry_det ... | 1 | 328 | 328.0 | 328 |
| /lighthouse/news/index.cfm? | 2 | 141 | 203.5 | 266 |
| /lighthouse/calendar/index.cfm ... | 1 | 78 | 78.0 | 78 |
| /lighthouse/calendar/index.cfm ... | 1 | 63 | 63.0 | 63 |
| /lighthouse/calendar/index.cfm ... | 11 | 93 | 201.63636363636363 | 610 |
| /lighthouse/calendar/entry_det ... | 1 | 156 | 156.0 | 156 |
You'll notice that there are 5 columns displayed in a very basic HTML table. These columns represent each URI, the number of requests for the URL, and the Minimum, Average, and Maximum execution times for that URI. If you have enabled query parameters, you'll notice that each different query parameter is represented as a unique URI. This again is essential to monitoring the performance of Fusebox applications, but you might find it useful to debug performance related to excessive database content.
But how do I use this data?
When I first downloaded the trial of the Profile Servlet, this was all I could get. I wrote to the authors and requested two additional features, which they gladly implemented. You can navigate to the servlet and pass in an query string of ?XML and the results will be returned in an XML document. You can also pass another query string of ?RESET to have the servlet reset the profiling data (which is kept in memory). Here is an examle of the XML data:
http://servername/servlet/Profile?xml
<?xml version="1.0" encoding="ISO-8859-1" ?>
<profile>
<record>
<uri>/lighthouse/calendar/index.cfm?ThisCal=5-1-2005</uri>
<count>2</count>
<minTime>78</minTime>
<avgTime>500.0</avgTime>
<maxTime>922</maxTime>
</record>
<record>
<uri>/lighthouse/calendar/entry_detail.cfm?event_id=35F908A5-CEC9-4815-B989-1AA54E4C9305</uri>
<count>1</count>
<minTime>172</minTime>
<avgTime>172.0</avgTime>
<maxTime>172</maxTime>
</record>
<record>
<uri>/lighthouse/profile/index.cfm?</uri>
<count>1</count>
<minTime>234</minTime>
<avgTime>234.0</avgTime>
<maxTime>234</maxTime>
</record>
<record>
<uri>/lighthouse/calendar/index.cfm?ThisCal=4-1-2005</uri>
<count>5</count>
<minTime>78</minTime>
<avgTime>96.8</avgTime>
<maxTime>110</maxTime>
</record>
<record>
<uri>/lighthouse/calendar/entry_detail.cfm?event_id=641D84E6-BA69-4FB6-AA6D-00E9E8208AA4</uri>
<count>1</count>
<minTime>328</minTime>
<avgTime>328.0</avgTime>
<maxTime>328</maxTime>
</record>
...
</profile>
As you can see, this XML output is very straightforward. It would be quite easy to have a CFML template visit this page and convert the XML into a structure, or even a query object. From there, you can log this data, or store it in a database.
The Downside
Yes, there is always a downside. There are two significant limitations of this servlet that I can think of.
- If your JRun server crashes or is restarted, all performance profiling data will be lost since the last collection.
- If you are using an ISP to host your CFMX applications, you'll have to work with them to get the Profile Servlet installed. Even then, if you are sharing a JRun server with other customers, it would be difficult to filter out other customer's CFM applications from the profiling data.
Next steps
I am currently writing a CFML Application for server administrators (or team leads) that will use the Profile Filter to capture, persist, and reset the profile data via a scheduled task. This data can then be queried and reported on to show some very important information, such as:
- Total CFM pages requested in a given time period
- The top 10 most requested CFM templates in a given time period
- The slowest 10 CFML templates in a given time period, based upon average execution time
-
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: 10,685
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: 9,107
Posted Date: Friday, January 28, 2005
