The display of tags and their execution time also supports the same filter time, so we see in this particular example that the CFQUERY tag is clearly the longest running tag in the request-indeed it is the same time shown for the "template as a whole", so it's clearly the biggest thing the template does. (The highlighting of CFMODULE reflects an anomaly which will be resolved before the final release.)

Drilling Down to View All Executions of a Given Tag in the Request
Again, at this point one may be tempted to go edit the template and find the CFQUERY tag (it does say there's only one in the template), but we don't technically know which file it occurs in (there are four files making up this request). Still, most CFML developers would again happily rely on their traditional experience at this point to root through the files to find the tag and attack it. But they don't have to waste their time!

The profiler helps save that time and hassle in a couple more ways, providing still more powerful profiling information. While the CFQUERY tag is clearly our focus, let's take a moment instead to view what we could see about a tag that shows having been executed in several places within a template (or across many files within the request).

For instance, notice that the CFOUTPUT tag shows at the top of the list of Figure 2. The list is sorted by default by the "hit rate" or number of times a given tag is executed within the request (across all files). Even though it's not a performance concern, let's take a look at drilling down to view the details about all uses of CFOUTPUT (since there's only one occurrence of CFQUERY, which we'll come back to in a moment).

In Figure 3, we see that the 13 executions of CFOUTPUT are spread across two templates (layout.cfm and results.cfm), and notice further that we see the specific line number and number of times executed for that tag for each line (totaling to the 13 that were listed for CFOUTPUT at the top of Figure 2), as well as the time spent (min, max, total, and average) for that tag on that line in that file, across the entire request. Again, potentially powerful stuff!

But the CFOUTPUT tag doesn't show much in terms of the time values displayed (their values weren't even enough to register). I just wanted to diverge for a moment to just show this additional level of functionality available in the profiler. It could come in handy in other circumstances.

Indeed, we could drill down one more time into any one of those files listed (clicking on the file name) to see a further detail display for just that file (for this request), showing the same columns but listing all the tags in that one file. In the interest of time, I'll skip showing that screen.

Going back to the CFQUERY tag identified in Figure 2, if we were to drill down on that page to view the details about the use of CFQUERY across all files in the given request, it would show the details in Figure 4.

Notice that there's a slight (and useful!) difference in Figure 4 compared to Figure 3. Since it is a CFQUERY being displayed, the profiler goes a step further and shows the specific SQL statement associated with that CFQUERY on that line. Nice.

Displaying the Selected Tag's Source Page Context
So at this point we know that we have a rather long-running query at line 34 of results.cfm. Again most CFML developers would be itching to open their editor at this point to get to work on the code! But you may be tickled to learn that if we were still doing analysis at this point (or didn't have ready access to the source, such as on a remote box), we don't have to open the template in an editor to view the code.

The profiler itself offers a simple and useful display of the given tag, in the context of its source. Notice the § symbol displayed to the left of the filename shown in Figure 4. That acts as a hyperlink (different from clicking on the filename) which when clicked will display the CFML for that file, highlighting specifically the line number selected. Figure 5 shows how it opens to displaying line 34, as expected.

Turning to the Code to Tweak and Tune: Attempt 1
So, that's enough of the overview of how to use and understand the profiler displays. Let's use the information we've seen to now actually tune this application and review the results with the profiler. Even without opening an editor, we see in Figure 5 that there are a couple of issues with the CFQUERY and its SQL. Can you spot the possible opportunities for improvement?

Even without too much consideration, it's reasonable to question the use of "select *", which seem a shortcut but really asks the database to gather all the columns in the given table, brings that across the database connection (and network, if the DB is on another box), and then causes the CFML engine to store the results in memory as a recordset. If there are any columns we don't really use, that could be a lot of extra, needless work.

We can scroll down in the display of Figure 5 (or in the editor, if we've gone ahead to open the template), and see that the only fields used in the request are firstnname, lastname, and phone. Would changing the Select to just return those columns make a difference? We could look at the page's debugging output to see what other columns are gathered by the Select * (or open the database or a database viewing tool) to determine if there are enough more columns to justify changing from Select *. But with a powerful profiling tool (and existing load test scripts) at hand, it's easy enough to go ahead and try the change and see what impact it makes.

To clear out the current profiling details from the previous load test, we can click on the "Requests Avail." link that's displayed on the left of all screens, which will return us to the top list (as in Figure 1). At the bottom right below the list of requests is an available "clear all" link which will clear the cache of profiling information. I then made the change to the CFML code and reran the load test. The result of then hitting "get latest profiles" is shown in Figure 6.

Ah! We clearly see a change. The number of requests that exceed the 100 ms filter has clearly decreased. That's a good sign, and for such a small change! But notice that we still see the result.cfm page showing up consistently at the top of the list as the longest running requests. Again, I know my test ran many other pages. We may be happy at this point, but what else might we readily try?

Lest some quibble about the query taking more than 100 MS, let's not be too concerned. What I got during my test on my machine - loaded with other processes including the load tester itself, and even if compared to running the code on CF on my box - isn't really significant here. What matters is whether things on this setup can be improved by making changes to the code.