Appended to this message are are some basic profiles of the script when 
run with TT 2.06/a-d.  I installed each release, deleted the compiled 
templates, requested the script twice with the -d:DProf option enabled 
(once to compile the templates and once to get profiling data), and ran 
"dprofpp" without any options to get a list of the 15 most expensive 
functions.

The reason for the slowdown in 2.06d is pretty clear: the 
Template::Filters::html_filter_factory function became many times slower 
in that release.  That function doesn't make an appearance on the 2.06 
list but does appear on the lists for the other developer releases, so 
it may also be part of the general slowdown seen in the developer releases.

-myk


2.06:

Total Elapsed Time = 1.958218 Seconds
  User+System Time = 1.472858 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 27.0   0.398  2.843    542   0.0007 0.0052  Template::Provider::__ANON__
 19.6   0.290  0.222  32231   0.0000 0.0000  Template::Stash::XS::get
 16.0   0.237  0.393     26   0.0091 0.0151  main::BEGIN
 9.51   0.140  3.020    540   0.0003 0.0056  Template::Context::process
 8.83   0.130  0.120   4950   0.0000 0.0000  Template::Iterator::get_next
 8.15   0.120  0.111   4375   0.0000 0.0000  Template::Filters::__ANON__
 3.39   0.050  0.049    502   0.0001 0.0001  Template::Config::load
 2.72   0.040  0.039    486   0.0001 0.0001  main::DiffDate
 2.72   0.040  0.031   4465   0.0000 0.0000  Template::Context::filter
 2.04   0.030  0.029    497   0.0001 0.0001  Template::Iterator::get_first
 2.04   0.030  0.043    497   0.0001 0.0001  Template::Config::iterator
 2.04   0.030  1.145     11   0.0027 0.1041  Template::BEGIN
 1.36   0.020  0.017   1547   0.0000 0.0000  Template::Stash::XS::set
 1.36   0.020  0.016   1954   0.0000 0.0000  Template::Iterator::AUTOLOAD
 1.36   0.020  0.020      3   0.0067 0.0066  Template::Stash::XS::BEGIN


2.06a:

Total Elapsed Time = 2.766433 Seconds
  User+System Time = 2.026433 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 18.9   0.384  4.184    542   0.0007 0.0077  Template::Provider::__ANON__
 14.3   0.290  0.336  32231   0.0000 0.0000  Template::Stash::XS::get
 10.8   0.219  0.386     26   0.0084 0.0149  main::BEGIN
 7.90   0.160  0.237   4465   0.0000 0.0001  Template::Filters::fetch
 7.40   0.150  0.145   4950   0.0000 0.0000  Template::Iterator::get_next
 5.92   0.120  4.358    540   0.0002 0.0081  Template::Context::process
 4.44   0.090  0.086   4375   0.0000 0.0000  
Template::Filters::html_filter_fac
                                             tory
 4.44   0.090  0.086   4375   0.0000 0.0000  Template::Filters::__ANON__
 4.44   0.090  0.318   4465   0.0000 0.0001  Template::Context::filter
 3.45   0.070  0.066   4374   0.0000 0.0000  main::__ANON__
 2.96   0.060  0.059    502   0.0001 0.0001  Template::Config::load
 1.48   0.030  0.030    497   0.0001 0.0001  Template::Iterator::get_first
 1.48   0.030  0.068    551   0.0001 0.0001  Template::Context::BEGIN
 1.48   0.030  0.056    497   0.0001 0.0001  Template::Config::iterator
 0.99   0.020  0.018   1602   0.0000 0.0000  UNIVERSAL::isa


2.06b:

-rw-r--r--    1 apache   apache     880853 Feb  8 14:38 tmon.out
Total Elapsed Time = 2.793048 Seconds
  User+System Time = 2.076436 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 22.3   0.463  4.264    542   0.0009 0.0079  Template::Provider::__ANON__
 17.8   0.370  0.466  32231   0.0000 0.0000  Template::Stash::XS::get
 10.5   0.219  0.406     26   0.0084 0.0156  main::BEGIN
 8.19   0.170  4.468    540   0.0003 0.0083  Template::Context::process
 7.71   0.160  0.155   4950   0.0000 0.0000  Template::Iterator::get_next
 6.74   0.140  0.187   4465   0.0000 0.0000  Template::Filters::fetch
 3.85   0.080  0.076   4374   0.0000 0.0000  main::__ANON__
 2.89   0.060  0.056   4375   0.0000 0.0000  
Template::Filters::html_filter_fac
                                             tory
 2.89   0.060  0.058   1954   0.0000 0.0000  Template::Iterator::AUTOLOAD
 2.41   0.050  0.228   4465   0.0000 0.0001  Template::Context::filter
 1.44   0.030  0.026   4375   0.0000 0.0000  Template::Filters::__ANON__
 1.44   0.030  0.029    502   0.0001 0.0001  Template::Config::load
 1.44   0.030  1.630     11   0.0027 0.1482  Template::BEGIN
 0.96   0.020  0.020    486   0.0000 0.0000  main::DiffDate
 0.96   0.020  0.019    540   0.0000 0.0000  Template::Stash::update


2.06c:

-rw-r--r--    1 apache   apache     880973 Feb  8 14:39 tmon.out
Total Elapsed Time = 2.506261 Seconds
  User+System Time = 1.889649 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 19.6   0.372  3.941    542   0.0007 0.0073  Template::Provider::__ANON__
 18.5   0.350  0.394  32231   0.0000 0.0000  Template::Stash::XS::get
 11.5   0.218  0.405     26   0.0084 0.0156  main::BEGIN
 7.41   0.140  0.133   4950   0.0000 0.0000  Template::Iterator::get_next
 6.88   0.130  0.123   4375   0.0000 0.0000  
Template::Filters::html_filter_fac
                                             tory
 6.35   0.120  4.092    540   0.0002 0.0076  Template::Context::process
 5.82   0.110  0.220   4465   0.0000 0.0000  Template::Filters::fetch
 5.29   0.100  0.307   4465   0.0000 0.0001  Template::Context::filter
 4.23   0.080  0.073   4375   0.0000 0.0000  Template::Filters::__ANON__
 3.70   0.070  0.063   4374   0.0000 0.0000  main::__ANON__
 2.12   0.040  0.038    502   0.0001 0.0001  Template::Iterator::BEGIN
 2.12   0.040  0.039    502   0.0001 0.0001  Template::Config::load
 2.12   0.040  1.520     11   0.0036 0.1382  Template::BEGIN
 1.59   0.030  0.027   1954   0.0000 0.0000  Template::Iterator::AUTOLOAD
 1.59   0.030  0.029    486   0.0001 0.0001  main::DiffDate


2.06d:

-rw-r--r--    1 apache   apache    1092237 Feb  8 14:40 tmon.out
Total Elapsed Time = 3.724526 Seconds
  User+System Time = 3.234526 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 34.9   1.130  1.461   4375   0.0003 0.0003  
Template::Filters::html_filter_fac
                                             tory
 12.7   0.411  8.204    542   0.0008 0.0151  Template::Provider::__ANON__
 6.80   0.220  0.344   4375   0.0001 0.0001  diagnostics::death_trap
 6.49   0.210  0.244  32231   0.0000 0.0000  Template::Stash::XS::get
 6.43   0.208  0.385     26   0.0080 0.0148  main::BEGIN
 4.95   0.160  0.153   4950   0.0000 0.0000  Template::Iterator::get_next
 4.95   0.160  1.608   4465   0.0000 0.0004  Template::Filters::fetch
 4.02   0.130  0.123   4375   0.0000 0.0000  HTML::Entities::encode_entities
 4.02   0.130  1.724   4465   0.0000 0.0004  Template::Context::filter
 3.40   0.110  0.103   4375   0.0000 0.0000  CGI::Carp::realdie
 3.09   0.100  8.354    540   0.0002 0.0155  Template::Context::process
 1.85   0.060  0.053   4374   0.0000 0.0000  main::__ANON__
 1.55   0.050  0.047   1954   0.0000 0.0000  Template::Iterator::AUTOLOAD
 1.24   0.040  0.039    502   0.0001 0.0001  Template::Config::load
 0.93   0.030  0.030      6   0.0050 0.0050  
Template::Provider::_load_compiled






Reply via email to