Many moons ago, I reported on how you could write a template to parse your server.log file for slow page reports. In case you didn't know - the ColdFusion Administrator lets you log files that take too long to process. This setting is found in the Logging Settings page as seen in the following screen shot:
Once enabled, ColdFusion will log any page that takes longer than the specified time. Note that it won't abort the process, it will just log it. If you want to abort a process, you need to use the Timeout Requests setting in the main settings page.
So if you read the old blog entry, you will note that I hard coded the file name, hard coded the timeout value, and used a loop over a hard coded end of line delimiter. This all becomes quite a bit easier in ColdFusion 8. (But to be fair, some of what I've changed could have been done in CF7 as well.)
First off - there are two ways you can find your server.log file. The best way, if you know your CF Admin password, is via the CF Admin API:
<cfinvoke component="cfide.adminapi.administrator" method="login"
adminPassword="admin" adminUserId="admin">
<cfinvoke component="cfide.adminapi.debugging" method="getLogProperty" propertyName="logdirectory" returnvariable="logdir">
If you don't have access to the CF Admin, you can still make a very good guess. The ColdFusion Server variable, rootdir, points to where CF was installed, but note that it is possible to change where CF stores it's log files. Here is the alternate version:
<cfset logdir = server.coldfusion.rootdir & "/logs/">
Now lets complete the filename and ensure it even exists:
<cfset filename = logdir & "/server.log">
<cfif not fileExists(filename)>
<cfoutput>
Can't find #filename#
</cfoutput>
<cfabort>
</cfif>
So far so good. Now we need to read in the file and begin storing our data for the report.
<cfset fileData = structNew()>
<cfloop file="#filename#" index="line">
<cfif findNoCase("second warning limit", line)>
<cfset template = rereplace(line, ".*?processing template: (.*?), completed.*", "\1")>
<cfset time = rereplace(line, ".*?completed in ([0-9,]*?) seconds,.*", "\1")>
<cfset time = replace(time, ",", "", "all")>
<cfif not structKeyExists(fileData, template)>
<cfset fileData[template] = structNew()>
<cfset fileData[template].hitCount = 0>
<cfset fileData[template].total = 0>
<cfset fileData[template].max = 0>
</cfif>
<cfset fileData[template].hitCount = fileData[template].hitCount + 1>
<cfset fileData[template].total = fileData[template].total + time>
<cfif time gt fileData[template].max>
<cfset fileData[template].max = time>
</cfif>
</cfif>
</cfloop>
A lot of the code above is the same as the previous version, but do note the new cfloop:
<cfloop file="#filename#" index="line">
That's it! The complete code listing is below. I removed the cfdocument tags so I could see the result in HTML. I'd show you a sample output, but unfortunately my pages run so fast that they complete in negative time. (Ahem.)
<cfinvoke component="cfide.adminapi.administrator" method="login"
adminPassword="admin" adminUserId="admin">
<cfinvoke component="cfide.adminapi.debugging" method="getLogProperty" propertyName="logdirectory" returnvariable="logdir">
<!---
<cfset logdir = server.coldfusion.rootdir & "/logs/">
--->
<cfset filename = logdir & "/server.log">
<cfif not fileExists(filename)>
<cfoutput>
Can't find #filename#
</cfoutput>
<cfabort>
</cfif>
<cfset fileData = structNew()>
<cfloop file="#filename#" index="line">
<cfif findNoCase("second warning limit", line)>
<cfset template = rereplace(line, ".?processing template: (.?), completed.", "\1")>
<cfset time = rereplace(line, ".?completed in ([0-9,]?) seconds,.", "\1")>
<cfset time = replace(time, ",", "", "all")>
<cfif not structKeyExists(fileData, template)>
<cfset fileData[template] = structNew()>
<cfset fileData[template].hitCount = 0>
<cfset fileData[template].total = 0>
<cfset fileData[template].max = 0>
</cfif>
<cfset fileData[template].hitCount = fileData[template].hitCount + 1>
<cfset fileData[template].total = fileData[template].total + time>
<cfif time gt fileData[template].max>
<cfset fileData[template].max = time>
</cfif>
</cfif>
</cfloop>
<cfoutput><h2>#structCount(fileData)# Total File</h2></cfoutput>
<table width="100%" cellpadding="10" border="1">
<tr>
<th>Template</th>
<th>Times in Log</th>
<th>Avg Execution Time</th>
<th>Max Execution Time</th>
</tr>
<cfloop item="temp" collection="#fileData#">
<cfset average = fileData[temp].total / fileData[temp].hitcount>
<cfif average gt 200>
<cfset style = "color: red">
<cfelse>
<cfset style = "">
</cfif>
<cfoutput>
<tr style="#style#">
<td><b>#temp#</b></td>
<td>#fileData[temp].hitCount#</td>
<td>#numberFormat(average,"9.99")#</td>
<td>#fileData[temp].max#</td>
</tr>
</cfoutput>
</cfloop>
</table>