http://www.perlmonks.org?node_id=487618

monsieur_champs has asked for the wisdom of the Perl Monks concerning the following question:

Felows

I'm trying to win a benchmark against a Tomcat application server, and choosed my weapons from ModPerl, Catalyst, Class::DBI, DBD::Oracle, Apache, Template Toolkit and a Session Plugin for Catalyst. The database was chosen by the client, is an Oracle 9i (9.0.2.0.4) running on Debian Linux 3.3 stable/testing.

UPDATE:Thanks to all prayers and cerimonials indicated to me by the honoured and wise monks that looked at me on this moment of pain, the application is performing quite well now: today's benchmark just hit 2500 answers per minute, or 41.7 answers per second (!!).

UPDATE #2:Unfortunatelly, the project will became a Java application, since the client was afraid about the riscs. I can't blame them, because they allways used Java, and this would be the first Perl Application running there. Anyway, my reputation as a programmer was preserved (thanks to all Monastery Inhabitants that helped me) and so is Perl's reputation too.

The test consists on a simple task: just insert lines on a table, and fetch them out (in a two tasks test).

The table is:

Nome Nulo? Tipo ---------------------- -------- --------------- COD_SIS NOT NULL NUMBER IND_EXCL NOT NULL CHAR(1) VAL_SGL NOT NULL VARCHAR2(4) DTH_CRCO NOT NULL DATE DESC_SIS NOT NULL VARCHAR2(450) NOM_PRPT NOT NULL VARCHAR2(120) IND_CGLD NOT NULL CHAR(1) DTH_VRFC_NOTE DATE IND_REQR_COMP_DESENV NOT NULL CHAR(1) IND_REQR_DIRT_CTLG NOT NULL CHAR(1)

I just can't express my frustration in words, and need to humbly declare my incompetence to build a fast application than the Java/Tomcat. The benchmark was made with JMeter, a nice and fair tool for web application benchmarking, IMHO. Java is answering 10 times better than ModPerl, and I don't know what to do about this.

For the number-driven monks, Java is answering (on the same machine, while Apache/Perl is not running, and vice-versa for Apache/Perl benchmarking) at 100 queries per minute ratio. With Perl, I don't even hit 27 queries per minute.

Thrusting this is just a matter of choosing the right weapons and fighting well, I put my fate into my (Brothers|Sisters)-in-Perl, toghether with the outputs from Apache::DProf and DBI::ProfileDumper::Apache, hoping a enlighted monk can help me out of this Devel::Prof::Hell again to Perl::Heaven.

Any suggestions and tips are welcome. I need to win this battle, so I can keep this job and create more opportunities at this company.

################################################## DBI Profile Data (DBI::ProfileDumper::Apache 1.0) ################################################## Program : /dev/null Path : [ DBIprofile_Statement ] Total Records : 5 (showing 5, sorted by total) Total Count : 3898 Total Runtime : 1.368898 seconds #####[ 1 ]########################################################### Count : 2348 Total Time : 0.625598 seconds Longest Time : 0.066659 seconds Shortest Time : 0.000004 seconds Average Time : 0.000266 seconds Key 1 : #####[ 2 ]########################################################### Count : 1151 Total Time : 0.461348 seconds Longest Time : 0.109629 seconds Shortest Time : 0.000022 seconds Average Time : 0.000401 seconds Key 1 : SELECT ind_excl, ind_cgld, val_sgl, desc_sis, dth_vrfc_note, dth_crco, nom_prpt, ind_reqr_comp_desenv, ind_reqr_dirt_ctlg FROM TBGF0037 WHERE cod_sis=? #####[ 3 ]########################################################### Count : 3 Total Time : 0.225426 seconds Longest Time : 0.225036 seconds Shortest Time : 0.000083 seconds Average Time : 0.075142 seconds Key 1 : INSERT INTO TBGF0037 (cod_sis, ind_excl, ind_reqr_dirt_ctlg, val_sgl, ind_cgld, ind_reqr_comp_desenv, dth_crco, nom_pr +pt, dth_vrfc_note, desc_sis) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?) #####[ 4 ]########################################################### Count : 5 Total Time : 0.045541 seconds Longest Time : 0.024365 seconds Shortest Time : 0.000024 seconds Average Time : 0.009108 seconds Key 1 : SELECT TBGF0037_seq.NEXTVAL from DUAL #####[ 5 ]########################################################### Count : 391 Total Time : 0.010985 seconds Longest Time : 0.001773 seconds Shortest Time : 0.000012 seconds Average Time : 0.000028 seconds Key 1 : SELECT cod_sis FROM TBGF0037 ################################################## ################################################## # TMON Insert Profile ################################################## Total Elapsed Time = 26.59694 Seconds User+System Time = 1.656940 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 33.5 0.556 1.325 3443 0.0002 0.0004 Class::Accessor::__ANON__ 10.3 0.172 0.172 28807 0.0000 0.0000 Class::DBI::Column::__ANO +N__ 9.60 0.159 0.159 391 0.0004 0.0004 DBD::Oracle::st::_prepare 8.39 0.139 0.139 387 0.0004 0.0004 DBI::st::execute 7.79 0.129 0.909 3 0.0431 0.3029 Catalyst::Engine::Apache: +:MP13::Base::handler 4.59 0.076 0.233 387 0.0002 0.0006 DBIx::ContextualFetch::st +::_untaint_execute 4.53 0.075 0.140 2 0.0376 0.0701 Class::DBI::retrieve_all 3.98 0.066 1.532 3471 0.0000 0.0004 Template::Stash::XS::get 2.72 0.045 0.295 387 0.0001 0.0008 DBD::Oracle::db::ping 2.35 0.039 0.039 384 0.0001 0.0001 DBI::st::fetchrow_array 2.29 0.038 0.038 391 0.0001 0.0001 DBI::_new_sth 1.81 0.030 0.030 3 0.0100 0.0100 Template::Context::includ +e 1.75 0.029 0.029 383 0.0001 0.0001 Class::Date::string 1.75 0.029 0.029 384 0.0001 0.0001 DBI::st::finish 1.69 0.028 0.028 774 0.0000 0.0000 DBI::common::DESTROY ################################################## ################################################## DBI Profile Data (DBI::ProfileDumper::Apache 1.0) ################################################## Program : /dev/null Path : [ DBIprofile_Statement ] Total Records : 3 (showing 3, sorted by total) Total Count : 1957 Total Runtime : 0.615580 seconds #####[ 1 ]########################################################### Count : 1181 Total Time : 0.322572 seconds Longest Time : 0.052478 seconds Shortest Time : 0.000003 seconds Average Time : 0.000273 seconds Key 1 : #####[ 2 ]########################################################### Count : 579 Total Time : 0.286691 seconds Longest Time : 0.109583 seconds Shortest Time : 0.000024 seconds Average Time : 0.000495 seconds Key 1 : SELECT ind_excl, ind_cgld, val_sgl, desc_sis, dth_vrfc_note, dth_crco, nom_prpt, ind_reqr_comp_desenv, ind_reqr_dirt_ctlg FROM TBGF0037 WHERE cod_sis=? #####[ 3 ]########################################################### Count : 197 Total Time : 0.006317 seconds Longest Time : 0.001895 seconds Shortest Time : 0.000009 seconds Average Time : 0.000032 seconds Key 1 : SELECT cod_sis FROM TBGF0037 ################################################## # TMON List Profile ################################################## Total Elapsed Time = 9.674284 Seconds User+System Time = 0.934284 Seconds Exclusive Times %Time ExclSec CumulS #Calls sec/call Csec/c Name 44.3 0.414 0.774 1726 0.0002 0.0004 Class::Accessor::__ANON__ 16.7 0.156 0.156 14395 0.0000 0.0000 Class::DBI::Column::__ANO +N__ 8.56 0.080 0.080 194 0.0004 0.0004 DBD::Oracle::st::_prepare 5.03 0.047 0.944 1 0.0475 0.9443 Catalyst::Engine::Apache: +:MP13::Base::handler 4.28 0.040 0.040 193 0.0002 0.0002 DBI::st::execute 4.17 0.039 0.087 1 0.0388 0.0875 Class::DBI::retrieve_all 2.14 0.020 0.020 1 0.0200 0.0200 DynaLoader::bootstrap 2.14 0.020 0.020 1 0.0200 0.0200 DBD::Oracle::db::_login 2.14 0.020 0.020 193 0.0001 0.0001 DBD::_::db::prepare_cache +d 2.03 0.019 0.068 193 0.0001 0.0004 DBIx::ContextualFetch::st +::_untaint_execute 1.82 0.017 0.878 1731 0.0000 0.0005 Template::Stash::XS::get 1.07 0.010 0.010 1 0.0100 0.0100 Template::Context::includ +e 1.07 0.010 0.010 5 0.0020 0.0020 base::import 1.07 0.010 0.010 192 0.0001 0.0001 DBI::st::finish 1.07 0.010 0.010 192 0.0001 0.0001 Class::Date::string ##################################################