Movable Type.org

Sometimes there can be nothing more frustrating than trying to troubleshoot publishing performance. Often users must resort to the brute force method of debugging, such as:

• embedding print STDERR statements in Movable Type's source code - but how many people know how to do that?

• blocking out huge swaths of code using the <mt:ignore> tag to hone in on the root cause - a cumbersome and time consuming process.

• turning on performance logging - a feature whose output was intended for machines and as a result is sometimes too verbose or difficult to read by mere mortals.

To help our users find a more elegant and efficient way to debug their templates and optimize their system, we have developed a simple tool that can more quickly and effectively help users hone in on those aspects of their templates that are the bottlenecks in their publishing system. The tool is a simple command line tool that outputs four very useful things:

1. the output from the template itself - very the accuracy of the template's output yourself.

2. a table of all the template tags invoked by the template - this table not only shows the template tag name, but also the average time it took to process each one.

3. total build time and total number of queries executed - when trying to find the template at the root of your performance problem, this will help you to quickly identify the outlier.

4. a table of all the SQL statements made during the publishing process - an effective way to find the actual query that is problematic.

Check out this sample output:

<template output omitted>
Template Tag Utilization:
.----------+----------------------+--------+---------+--------+--------+-------.
| Time     | Tag                  | Calls  | Avg     | SQL    | Hits   | Miss  |
+----------+----------------------+--------+---------+--------+--------+-------+
| 0.083    | entryassets          | 20     | 0.004   | 40     | 20     | 20    |
| 0.040    | entries              | 8      | 0.005   | 12     | 16     | 4     |
| 0.027    | assetproperty        | 16     | 0.002   | 16     | 0      | 0     |
| 0.020    | include              | 6      | 0.003   | 7      | 3      | 3     |
| 0.019    | categories           | 4      | 0.005   | 5      | 20     | 5     |
| 0.014    | assetthumbnaillink   | 4      | 0.003   | 4      | 4      | 0     |
| 0.010    | keyvalues            | 4      | 0.002   | 0      | 0      | 0     |
| 0.006    | collatesetfield      | 32     | 0.000   | 0      | 0      | 0     |
| 0.004    | setvarblock          | 28     | 0.000   | 0      | 0      | 0     |
| 0.004    | gridcell             | 8      | 0.000   | 0      | 0      | 0     |
                                   -- snip--
'----------+----------------------+--------+---------+--------+--------+-------'
  Total Queries: 86
  Total Build Time: 0.261901
.------------------------------------------------------------------+-----------.
| Query                                                            | Number    |
+------------------------------------------------------------------+-----------+
| RAMCACHE_GET ?                                                   | 63        |
| RAMCACHE_ADD ?                                                   | 32        |
| SELECT asset_id FROM mt_asset, mt_objectasset WHERE (objectasse- | 20        |
| t_object_ds = ?) AND (objectasset_asset_id = asset_id) AND (obj- |           |
| ectasset_object_id = ?)                                          |           |
| SELECT asset_id, asset_blog_id, asset_class, asset_created_by, - | 20        |
| asset_created_on, asset_description, asset_file_ext, asset_file- |           |
| _name, asset_file_path, asset_label, asset_mime_type, asset_mod- |           |
| ified_by, asset_modified_on, asset_parent, asset_url FROM mt_as- |           |
| set WHERE (asset_id IN (?))                                      |           |
| SELECT asset_meta_asset_id, asset_meta_type, asset_meta_vchar, - | 20        |
| asset_meta_vchar_idx, asset_meta_vdatetime, asset_meta_vdatetim- |           |
| e_idx, asset_meta_vinteger, asset_meta_vinteger_idx, asset_meta- |           |
| _vfloat, asset_meta_vfloat_idx, asset_meta_vblob, asset_meta_vc- |           |
| lob FROM mt_asset_meta WHERE (asset_meta_asset_id = ?)           |           |
                                   -- snip--
'------------------------------------------------------------------+-----------'

Using the tool is relatively straight forward: all you need to do is give the tool the ID of the template you want to debug, in addition to any other contextual information that template might need, e.g. a category ID if you are publishing a category archive. Running the tool with the conventional --help flag will tell you all of the possible options.

• Download mt-tmpl-test now

Keep reading behind the cut to learn more specifically how to use this tool.