Welcome!

ColdFusion Authors: Maureen O'Gara, Hovhannes Avoyan, Yakov Fain, Pat Romanski, Liz McMillan

Related Topics: ColdFusion

ColdFusion: Article

CFDJ Feature Story - Debugging ColdFusion MX7

That necessary evil that none of us dare turn on in our production environments unless it is absolutely necessary

So the actual output would look something like:

SQL Queries

qryFoo2 (Datasource=, Time=0ms, Records=1) in C:\Inetpub\
wwwroot\foo.cfm @ 23:23:30.030
Select * from qryFoo

Scope Variables

CGI Variables:
AUTH_PASSWORD=
AUTH_TYPE=
AUTH_USER=
CERT_COOKIE=
CERT_FLAGS=
CERT_ISSUER=
CERT_KEYSIZE=

Cookie Variables
CFADMIN_LASTPAGE=/CFIDE/administrator/debugging/index.cfm
JSESSIONID=8430c64ef280$C7$06$E
Debug Rendering Time: 78 ms

Note the "Debug Rendering Time" listed above. "Debug Rendering Time" is in addition to the processing time required to deliver the rest of the page.

Some of the new features like <CFTRACE> will help you track program flow and efficiency. Adding a Trace will look something like:

<cftrace abort="no" inline="yes" type="warning" var="FooTrace" text="This is a trace">

And will output something like :

We can use <CFTRACE> in our code to get an idea of how our application is performing as we are utilizing it. Utilizing this method should step up your performance investigation and just like the use of getTickCount() should be removed from your final release. A partner to <CFTRACE>, and speaking of getTickCount(), is a new mechanism that performs the same functions that we used to use "getTickCount()" functions for, <CFTIMER>. It's a bit leaner than the use of getTickCount() and can be rendered in debug, outline, inline, and comment form. Here is an example of its use:

<cftimer Label="timerFoo" type="DEBUG">
   <cfquery name="qryFoo2" dbtype="query">
    Select * from qryFoo
   </cfquery>
</cftimer>

Here's an example of its output:

CFTimer Times

[31ms] timerFoo

My favorite, for performance debugging though, is a little used command-line tool called CFSTAT. It wasn't really advertised as part of the application server but has been shipped with it since at least version 4. It can be found in the \bin directory of your CFMX root. Its utilization is simple: CFSTAT <space> interval (in seconds).

CFSTAT 2 … the 2 referring to a 2 second interval

CFSTAT will deliver:

1.  Pages per second - now and high

  • This is how many requests came in during the last interval.
2.  Database requests per second - now and high
  • This will show how many query requests were performed by CF including any query manipulation you do on your own.
  • Note that this name is misleading and in reality reflects all query requests, locally built and externally requested.
3.  Cache Pops per second - now and high
  • "Cache Pops" refers to pulling data from cache.
  • i.e., a <CFQUERY> that may be utilizing the "cachedwithin" attribute.
4.  Requests queued
  • The number of requests still waiting to be processed.
5.  Running requests
  • The number of requests that are currently being processed.
6.  Requests timed out
  • The number of requests that exceeded your administrator time out settings.
7.  Average queue time
  • The average amount of time a request was in the queue waiting to be processed (in milliseconds).
8.  Average request time
  • The average amount of time it is currently taking to process requests ( in milliseconds).
9.  Average DB time
  • The average time required to process your query requests.
  • Note that this name is misleading and in reality reflects all query requests, local built, and externally requested.
10.  Bytes in per second
  • The amount of data received by the CF Server (in bytes).
11.  Bytes out per second
  • The amount of data transmitted back to the requesting browser (including whitespace) (also in bytes).
Just like any tool, the results need to be interpreted. There are numerous ways to read CFSTAT and my best recommendation would be to turn it on and watch it for a while. As you watch it, you'll start to see the patterns and can then investigate them. As you watch your output, you might start to notice something like DB/sec reaching a maximum number. That maximum number happens to coincide with the maximum number of simultaneous threads you have set in the CF Administrator. You might also find that the average DB time is higher than you expected and seems to grow with the Bytes Out/sec, indicating that your bandwidth is being affected by your output and is also possibly affecting access to your database. These are only examples of what you could find, not necessarily what you will find.

In this article I directed my focus on the performance aspects of the CFMX debugging features more so than the generic ones. However, if you have any questions about how to go about writing some custom debugging features of your own, or would like to share some of your how-tos, please feel free to e-mail me at Jason@Heaslet.net

Comments (1) View Comments

Share your thoughts on this story.

Add your comment
You must be signed in to add a comment. Sign-in | Register

In accordance with our Comment Policy, we encourage comments that are on topic, relevant and to-the-point. We will remove comments that include profanity, personal attacks, racial slurs, threats of violence, or other inappropriate material that violates our Terms and Conditions, and will block users who make repeated violations. We ask all readers to expect diversity of opinion and to treat one another with dignity and respect.


Most Recent Comments
CFDJ News Desk 10/19/05 09:03:46 PM EDT

Debugging ColdFusion MX7 Debugging. That necessary evil that none of us dare turn on in our production environments unless it is absolutely necessary. We all wonder what all that stuff does don't we? Well, let's investigate what some of it does, and what it means.