[Catalyst] Catalyst Performance issues

Sat Oct 7 16:44:17 CEST 2006

Hi everyone,

Recently I've been facing some performance issues in my Catalyst
application and the situation worries me a little bit.

The first optimization I tried was to start prefetching everything I
could and it indeed improved the performance quite a bit (by a factor
of 2 or so). But it still isn't enough.

I've got pages that take 3-4 seconds to render with a single user
using the application while the database query takes something between
0.15-0.20s to complete. Whenever the application faces a moderate
amount of usage, users start complaining.

So, in my quest for optimization, I tried profiling my Catalyst
application. It saddened me a little bit to find out that, apparently,
at least 60% of the time (probably more) is spent inside Catalyst, TT
and DBIC internal routines (a big cycle eater is Class::C3).
Particularly, URI handling seems to take a lot of time (maybe this was
influenced by the fact that I profiled using the builtin server).

I'd like to know if there are any performance tips or really just how
do you get acceptable performance from your Catalyst application in
moderately complex or large pages (especially regarding pages where
there might be hundreds or records fetched from the database).

Thanks for any help and just in case it might be useful in order to
diagnose what I could've done wrong, here's the profiling output of
"dprofpp -R -O 50" for my application:

Total Elapsed Time = 298.9974 Seconds
  User+System Time = 44.42747 Seconds
Exclusive Times
%Time ExclSec CumulS #Calls sec/call Csec/c  Name
 7.52   3.341  0.010  33082   0.0001 0.0000  next::method
 7.00   3.109 38.560  86056   0.0000 0.0004  Template::Stash::XS::get
 6.32   2.809  3.041   5163   0.0005 0.0006  DBIx::Class::ResultSet::_collapse_
                                             result
 3.78   1.680  5.675  18010   0.0001 0.0003  URI::_generic::abs
 3.05   1.357  1.581  63205   0.0000 0.0000  URI::_generic::authority
 2.98   1.325  2.958  36156   0.0000 0.0001  URI::new
 2.69   1.194  1.296  54137   0.0000 0.0000  URI::_generic::path
 2.37   1.052 12.538   9005   0.0001 0.0014  Catalyst::uri_for
 2.27   1.008  1.647  72169   0.0000 0.0000  URI::_scheme
 2.16   0.959  1.247    174   0.0055 0.0072  Class::C3::_calculate_method_dispa
                                             tch_table
 2.09   0.930  0.930   5128   0.0002 0.0002  Template::Stash::clone
 1.87   0.833  0.939  36156   0.0000 0.0000  URI::_init
 1.84   0.819  0.819 115481   0.0000 0.0000  DBIx::Class::AccessorGroup::get_si
                                             mple
 1.77   0.785  0.908   9256   0.0001 0.0001  Params::Validate::_validate
 1.69   0.751  4.116  11295   0.0001 0.0004  DBIx::Class::Row::inflate_result
 1.54   0.686  2.718   2649   0.0003 0.0010  DateTime::new
 1.36   0.605  0.621    250   0.0024 0.0025  Algorithm::C3::merge
 1.24   0.550  0.853   3748   0.0001 0.0002  DBIx::Class::ResultSet::search_rs
 1.20   0.533  4.199  32805   0.0000 0.0001  DBIx::Class::InflateColumn::get_co
                                             lumn
 1.19   0.527  0.527   1260   0.0004 0.0004  NEXT::ELSEWHERE::ancestors
 1.13   0.504 18.551      3   0.1679 6.1838  Template::Document::__ANON__(9e3)
 1.08   0.482 45.518   1356   0.0004 0.0336  NEXT::AUTOLOAD
 1.07   0.476  0.476  16836   0.0000 0.0000  Template::Stash::XS::set
 1.04   0.460  1.743   9029   0.0001 0.0002  URI::_server::canonical
 0.99   0.439 13.844      5   0.0878 2.7688  Template::Document::__ANON__(8d0)
 0.94   0.416  0.416  27151   0.0000 0.0000  URI::implementor
 0.83   0.368  0.368  46161   0.0000 0.0000  Scalar::Util::blessed
 0.81   0.362  0.538  11724   0.0000 0.0000  DBIx::Class::Schema::source
 0.79   0.350  0.468     35   0.0100 0.0134  Template::Parser::_parse
 0.77   0.341  4.838    898   0.0004 0.0054  Template::Document::__ANON__(91f)
 0.76   0.339  0.420   3645   0.0001 0.0001  DBIx::Class::ResultSet::_resolved_
                                             attrs
 0.76   0.338  1.853  63059   0.0000 0.0000  URI::scheme
 0.75   0.331  1.998   3532   0.0001 0.0006  DBIx::Class::Relationship::Base::r
                                             elated_resultset
 0.74   0.328  2.325   9029   0.0000 0.0003  URI::http::canonical
 0.73   0.326  0.326  27112   0.0000 0.0000  URI::_generic::_check_path
 0.69   0.307  8.311   3213   0.0001 0.0026  DBIx::Class::ResultSet::next
 0.69   0.307 42.798   1057   0.0003 0.0405  Template::Context::process
 0.64   0.286  6.734      3   0.0955 2.2447  Template::Document::__ANON__(97f)
 0.62   0.277  0.363   5726   0.0000 0.0001  DBIx::Class::ResultSet::new
 0.58   0.256  0.256  27040   0.0000 0.0000  URI::clone
 0.58   0.256  0.569   9054   0.0000 0.0001  URI::_server::host
 0.54   0.241  0.433   4450   0.0001 0.0001  DateTime::_calc_utc_rd
 0.52   0.233  3.289   2612   0.0001 0.0013  DateTime::Format::Builder::Parser:
                                             :generic::__ANON__(8c9)
 0.52   0.233  0.854   4451   0.0001 0.0002  DateTime::TimeZone::new
 0.50   0.224  0.365   9054   0.0000 0.0000  URI::_server::_port
 0.48   0.212  0.212   9072   0.0000 0.0000  URI::_query::query
 0.47   0.210  0.430  35011   0.0000 0.0000  DBIx::Class::AccessorGroup::__ANON
                                             __(3d5)
 0.47   0.210  0.210    174   0.0012 0.0012  Class::C3::_remove_method_dispatch

-Nilson Santos F. Jr.