I ran into an interesting problem while developing two custom debug templates. The CFMX debugger provides information on all the templates executed in a request, including the execution time for the template and the “parent” or caller for each template.
Interestingly, there is one situation with ColdFusion Components where the parent template itself will never appear in the template list, seemingly to indicate it’s called from a template that is not executed within the request.
A typical debug query for a small request might look like this.
| Debug Data – query | |||
|---|---|---|---|
| TIME | PARENT | TEMPLATE | |
| 1 | 0 | [empty string] | C:\CFMX\wwwroot\MachWiki\Application.cfm |
| 2 | 421 | [empty string] | C:\CFMX\wwwroot\MachWiki\index.cfm |
| 3 | 421 | C:\CFMX\wwwroot\MachWiki\index.cfm | C:\CFMX\wwwroot\MachWiki\mach-ii.cfm |
This represents a request where first Application.cfm was run directly by the CFMX servlet, then index.cfm also by the CFMX servlet, and then mach-ii.cfm by index.cfm.
For CFC’s, the parent is still an absolute path to the template, but the “template” column contains more information. A typical CFC template value might be “CFC[ C:\CFMX\wwwroot\MachII\framework\EventContext.cfc | announceEvent(loadedTerm, [complex value]) ] from C:\CFMX\wwwroot\MachWiki\model\Wiki.cfc”. For this particular template, the parent was “C:\CFMX\wwwroot\MachII\framework\Listener.cfc”.
This template is a call to announceEvent() inside EventContext.cfc. According to the Parent template the call is made from Listener.cfc. This is actually correct, the call to announceEvent() is located inside the Listener.cfc file. However, Listener.cfc never appears inside the template list for this request.
After delving into the Mach-II templates and Sean Corfield’s example I found that Wiki.cfc is a subcomponent of Listener.cfc and the call is made on Wiki.cfc, but resolves to a function that is inherited from Listener.cfc. This results in a parent template that never exists in the executed template list
The reason I’m looking into this is to deduct the execution time for each template from it’s parent in order to determine the actual execution time of each template excluding the templates it calls. For this reason I needed to map every parent to a template that existed in the request.
Luckily, the solution was rather straightforward upon examination of the full details provided in the “Template” field for the debug query. The last part of the field has “from C:\CFMX\wwwroot\MachWiki\model\Wiki.cfc”. This is the template that is actually included in the template list and appropriate for following the execution path. A little string manipulation is all that was required to extract this.
So the final conclusion after this very long winded post is don’t rely on the “Parent” field in debug data for CFC’s, instead use the “From” section of the template name.
For anyone interested, the following is a snippet of code from the debug template I’m working on. I’ll be posting two complete templates later on that are much prettier and more functional. The code here simply lists all templates processed and the time actually spent on each, excluding the templates it calls.
SELECT
template,
parent,
Sum(endTime - StartTime) AS executionTime
FROM qEvents
WHERE type = 'Template'
GROUP BY template, parent
ORDER BY StartTime asc
| #tStruct[template].executionTime# | #tStruct[template].count# | #template# |
Total: #tet#
Debug Time: #debugEnd-debugStart#