Hello fellow monks,

I've given in to a dirty little sin -- I decided to do a quick comparison of templating systems. I'm using several different ones in diverse web applications and frameworks, but I wanted to try them in a simple setup to isolate any impact of other factors. So far I'm just processing a minimal HTML template with a simple variable 1000 times through Benchmark's timethis() function, like so:

use Template;
use Benchmark qw(:all);
use strict;
use warnings;

sub doit;

my $hello_world = 'Hello, World!';

doit();
timethis(1000, \&doit);

sub doit {
    my $tt = Template->new(INCLUDE_PATH => '', CACHE_SIZE => 50);
    my $vars = {
        HELLO_WORLD => $hello_world,
    };
    $tt->process('Templates/tt_var.html', $vars);
    return 0;
}
[download]

Apart from being a rather dumb and pointless initial test, the problem here is that Template Toolkit is much slower than HTML::Template and Petal, as shown by time ./tt.pl 1>/dev/null:

real 0m0.710s -- HTML::Template (cache)
real 0m1.052s -- Petal (cache)
real 0m1.969s -- HTML::Template (nocache)
real 0m7.026s -- TemplateToolkit (supposedly caching?)
real 0m17.645s -- Petal (nocache)
[download]

(Cache is just the default built-in memory cache for those templating systems.) So I run DProf:

$ time perl -d:DProf ./tt.pl 1>/dev/null; dprofpp tmon.out

real    0m10.172s
user    0m9.633s
sys     0m0.480s
Total Elapsed Time = 7.412607 Seconds
  User+System Time = 7.442607 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 23.6   1.761  2.531   1001   0.0018 0.0025  Template::Parser::_parse
 11.3   0.847  0.847   1001   0.0008 0.0008  Template::Document::new
 4.55   0.339  8.027   1001   0.0003 0.0080  main::doit
 4.22   0.314  0.314   2002   0.0002 0.0002  Template::Parser::tokenis
+e_directi
                                             ve
 4.12   0.307  0.716  20020   0.0000 0.0000  Template::Grammar::__ANON
+__
 3.74   0.278  0.599   1001   0.0003 0.0006  Template::Parser::split_t
+ext
 3.72   0.277  0.277   1001   0.0003 0.0003  Template::Provider::_temp
+late_cont
                                             ent
 3.44   0.256  1.234   6006   0.0000 0.0002  Template::Base::new
 3.08   0.229  0.358   7007   0.0000 0.0001  Template::Config::load
 2.58   0.192  0.778   1001   0.0002 0.0008  Template::Context::_init
 2.16   0.161  0.161   3003   0.0001 0.0001  Template::Directive::text
 2.11   0.157  0.365   1001   0.0002 0.0004  Template::Context::proces
+s
 1.68   0.125  5.729   2002   0.0001 0.0029  Template::Context::templa
+te
 1.64   0.122  5.368   1001   0.0001 0.0054  Template::Provider::_fetc
+h
 1.57   0.117  0.117   1001   0.0001 0.0001  Template::Provider::_init
[download]

... but I confess I'm too ignorant about TT's code to understand the output. What I'd like to know from somebody with more knowledge of the TT code is if TT is indeed using memory caching here, and if so, why it is so much slower than the other modules? (I'd expect it not to be.)

Please note I'm not interested in a flamewar about different templating systems – all of which have good and bad sides – I'm just curious as to why I'm getting the results I do.

Thanks for any insight!