mod_perl2 & Devel::NYTProf
This week I’ve been trying to switch us over to using mod_perl2. I wanted to cache database handles as much as possible so one of the first things that I did was edit my startup.pl and add:
use Apache::DBI;
Most stuff just works. When I find something that is only slightly broken, I fix it. When I find something that is horribly broken, I just create a Location in httpd.conf to tell Apache to run that as plain CGI and I’ll update them later.
The entire application suite feels faster. I suspect much of the speed up is due to caching database handles but I’d like to profile it. I have no problems profiling CGI with Devel::NYTProf. When I configure httpd.conf to use Devel::NYTProf::Apache like this I get issues.
PerlSetEnv NYTPROF trace=2:file=/tmp/mm-nytprof.out:addpid=1:start=begin:use_db_sub=1
PerlModule Devel::NYTProf::Apache
I guess I’ll have to file a bug report. Here is just one of the many issues showing up in the error log:
Marking 'Apache2::RequestRec::args' as xsub
Marking 'CGI::Cookie::CORE:subst' as sop
Marking 'CGI::Cookie::CORE:substcont' as sop
NYTProf is confused about CV 0x2ac1ed3023e0 called as /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm at /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm line 225 (please report as a bug)
SV = PVCV(0x2ac1ed2b49d0) at 0x2ac1ed3023e0
REFCNT = 2
FLAGS = (POK,pPOK,CONST)
PROTOTYPE = ""
COMP_STASH = 0x2ac1ed240ad0 "ModPerl::RegistryCooker"
XSUB = 0x2ac1d2d845b0
XSUBANY = 0x2ac1ed2d0da8 (CONST SV)
SV = IV(0x2ac1ed2d0da0) at 0x2ac1ed2d0da8
REFCNT = 2
FLAGS = (PADMY,IOK,READONLY,pIOK)
IV = 0
GVGV::GV = 0x2ac1ed2d2910 ""
FILE = "/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm"
DEPTH = 0
FLAGS = 0xc00
OUTSIDE_SEQ = 0
PADLIST = 0x0
OUTSIDE = 0x0 (null)
unknown entersub xsub assumed to be anon called_cv '/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm'
Is there a way to tell Devel::NYTProf not to profile ModPerl::RegistryCooker?
Hi,
A complete tangent...
Check out: DBIx::Connector instead of Apache::DBI - it will work in more environments than just mod_perl2.
Also you may want to look at Plack - you can still run under Apache2/Mod_perl2 - it means development and testing are easier, and if you do then want to use something faster (Like FCGI or Starman) it's easy to switch.
Hope that helps.
Leo
I'd second the motion regarding Plack. If you are going to the trouble of porting and testing, you should really consider giving yourself the flexibility for the future. Most of the web development energy is moving away from mod_perl1/2 based systems and mod_perl2 hasn't been updated on cpan for years (in fact, mod_perl1 has seen more updates than mod_perl2). Additionally, I don't really see Apache as a great partner for Perl, so there's no reason to hitch our ship to a single web server.
My two cents at least.
I met David Wheeler at PgWest 2010 and talked about DBIx::Connector with him. We are heavily considering using it.
In the first pass, we just want to get everything working. (It's easier to get manager buy in for small, incremental changes than it is do everything at once.) After two days, I'm at about 90% completion. (Half of one of those days was spent trying to track down why Devel::NYTProf was getting confused.)
As for Plack, we'd have to spend much more time than it will take to complete the mod_perl2 conversion. It's on list of things to consider but it isn't going to happen in next few weeks.
> Additionally, I don't really see Apache as a great partner for Perl
But Perl is a great partner for Apache! With modperl you can hook perl handlers at any phase of the Apache HTTP lifecycle (access, authentication, authorization, input/output filters, etc.), which is really more convenient than writing mod_* extensions in C! See http://perl.apache.org/docs/2.0/user/handlers/http.html
I've removed Apache::DBI and updated the place where we grab database handles to use DBI->connect_cached instead. We're going to test using DBIx::Connector in some of our services before we decide to roll it into everything else.
The NYTProf confusion around ModPerl::RegistryCooker only shows up if trace is enabled. This is at trace 2:
NYTProf is confused about CV 0x2ac1ed3023e0 called as /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm at /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm line 225 (please report as a bug)
SV = PVCV(0x2ac1ed2b49d0) at 0x2ac1ed3023e0
REFCNT = 2
FLAGS = (POK,pPOK,CONST)
PROTOTYPE = ""
COMP_STASH = 0x2ac1ed240ad0 "ModPerl::RegistryCooker"
XSUB = 0x2ac1d2d845b0
XSUBANY = 0x2ac1ed2d0da8 (CONST SV)
SV = IV(0x2ac1ed2d0da0) at 0x2ac1ed2d0da8
REFCNT = 2
FLAGS = (PADMY,IOK,READONLY,pIOK)
IV = 0
GVGV::GV = 0x2ac1ed2d2910 ""
FILE = "/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm"
DEPTH = 0
FLAGS = 0xc00
OUTSIDE_SEQ = 0
PADLIST = 0x0
OUTSIDE = 0x0 (null)
unknown entersub xsub assumed to be anon called_cv '/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm'
Even more interesting is that when log=/path/to/file is used, the first and last line go to the log file but the dump in the middle goes to the normal error log.
Here it is at trace 4:
4 >> entersub at 43:207 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2440, ac0)
4 -> sub ModPerl::RegistryCooker::error_check from ModPerl::RegistryCooker::run @43:207 (d1, oh 1311430.000000t, sub 1.088200s) #29687
4 >> entersub at 43:213 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2688, ac0)
4 ->xsub ModPerl::Global::special_list_call from ModPerl::RegistryCooker::run @43:213 (d1, oh 1311510.000000t, sub 1.088212s) #29688
4 >> entersub at 43:216 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2888, ac0)
4 -> sub ModPerl::RegistryCooker::error_check from ModPerl::RegistryCooker::run @43:216 (d1, oh 1311530.000000t, sub 1.088226s) #29689
4 >> entersub at 43:225 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2416, ac0)
NYTProf is confused about CV 0x2ab2388a0568 called as /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm at /opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm line 225 (please report as a bug)
SV = PVCV(0x2ab2388a3e00) at 0x2ab2388a0568
REFCNT = 2
FLAGS = (POK,pPOK,CONST)
PROTOTYPE = ""
COMP_STASH = 0x2ab2387e8b98 "ModPerl::RegistryCooker"
XSUB = 0x2ab21f4455b0
XSUBANY = 0x2ab238875a38 (CONST SV)
SV = IV(0x2ab238875a30) at 0x2ab238875a38
REFCNT = 2
FLAGS = (PADMY,IOK,READONLY,pIOK)
IV = 0
GVGV::GV = 0x2ab238875c48 ""
FILE = "/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm"
DEPTH = 0
FLAGS = 0xc00
OUTSIDE_SEQ = 0
PADLIST = 0x0
OUTSIDE = 0x0 (null)
unknown entersub xsub assumed to be anon called_cv '/opt/perl/lib/site_perl/5.12.3/x86_64-linux-thread-multi/ModPerl/RegistryCooker.pm'
4 ->xsub ModPerl::RegistryCooker::__UNKNOWN__[xsub,0x2ab2388a0568] from ModPerl::RegistryCooker::run @43:225 (d1, oh 1311600.000000t, sub 1.088239s) #29690
4 >> entersub at 43:237 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2616, ac0)
4 ->xsub ModPerl::RegistryCooker::NOP from ModPerl::RegistryCooker::run @43:237 (d1, oh 1311610.000000t, sub 1.088318s) #29691
4 >> entersub at 43:239 from ModPerl::RegistryCooker::run (inherited) (seix 1640->2816, ac0)
4 ->xsub ModPerl::RegistryCooker::NOP from ModPerl::RegistryCooker::run @43:239 (d1, oh 1311620.000000t, sub 1.088326s) #29692
3 >> entersub at 43:171 from ModPerl::RegistryCooker::default_handler (inherited) (seix 728->1856, ac0)
3 ->xsub Apache2::RequestRec::status from ModPerl::RegistryCooker::default_handler @43:171 (d1, oh 1311660.000000t, sub 1.088405s) #29693
NOTE: With trace disabled, NYTProf does not get confused.
Bug reported: https://rt.cpan.org/Ticket/Display.html?id=65200
*Most of the web development energy is moving away from mod_perl1/2 based systems and mod_perl2 hasn't been updated on cpan for years (in fact, mod_perl1 has seen more updates than mod_perl2).*
Actually a mod_perl 2.0.5 release candidate is being tested right now, and development has been fairly steady over the past couple of years. I'd encourage you guys (Ranguard and John) to research this at http://perl.apache.org/maillist/index.html and see for yourselves. It is easy to make generalized statements like this when you aren't involved in a project, but the problem is they can be interpreted as FUD, which generally makes everybody involved look bad.
I'm a fan of Plack myself, but mod_perl has a very solid future ahead of it still. The reason you haven't seen a lot of mod_perl 2 releases is that it is stable, and the commits over the past couple years have been focused on keeping it stable and fast on as many platforms as possible.
Thanks for filing the RT ticket about this issue. I'd suggest posting to the mailing list also; there are a lot of very bright mod_perl experts there who can likely help you with this issue.