Skip Menu |
 

Preferred bug tracker

Please visit the preferred bug tracker to report your issue.

This queue is for tickets about the devel-nytprof CPAN distribution.

Report information
The Basics
Id: 65200
Status: resolved
Priority: 0/
Queue: devel-nytprof

People
Owner: Nobody in particular
Requestors: mmusgrove [...] cpan.org
Cc:
AdminCc:

Bug Information
Severity: Normal
Broken in: 4.06
Fixed in: (no value)



Subject: Devel::NYTProf::Apache with trace > 0
Download (untitled) / with headers
text/plain 804b
I wanted to profile an application suite running Apache 2 with mod_perl2 so I enabled Devel::NYTProf::Apache in my httpd.conf. PerlSetEnv NYTPROF trace=2:file=/tmp/mm-nytprof.out PerlModule Devel::NYTProf::Apache I was seeing issues where "NYTProf is confused about CV" multiple times for each thing that I did in my app. If I try to convert the out files to html, it is very clear that something bad happened. (The top 15 subroutines doesn't get populated, the subroutine exclusive time treemap is empty, etc.) I bumped it up to trace=4 and captured one instance of it occurring (attached as trace4.txt). I'm not sure what other information you need from me to assist you. I have verified that when trace=0, the problem does not happen and the resulting html output is as pretty as usual.
Subject: trace4.txt
Download trace4.txt
text/plain 2.5k
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 "^B" 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
Subject: Re: [rt.cpan.org #65200] Devel::NYTProf::Apache with trace > 0
Date: Fri, 28 Jan 2011 09:37:57 +0000
To: Matthew Musgrove via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
On Thu, Jan 27, 2011 at 05:57:46PM -0500, Matthew Musgrove via RT wrote: Show quoted text
> 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)
Thanks for the report. Please try this change just to give me more infomation: --- NYTProf.xs (revision 1407) +++ NYTProf.xs (working copy) @@ -2639,8 +2639,10 @@ logwarn("NYTProf is confused about CV %p called as %s at %s line %d (please report as a bug)\n", (void*)called_cv, SvPV_nolen(sub_sv), OutCopFILE(prev_cop), (int)CopLINE(prev_cop)); /* looks like Class::MOP doesn't give the CV GV stash a name */ - if (trace_level >= 2) + if (trace_level >= 2) { sv_dump((SV*)called_cv); /* coredumps in Perl_do_gvgv_dump, looks line GvXPVGV is false, presumably on a Class::MOP wierdo sub */ + sv_dump((SV*)gv); + } } } Tim.
Thanks Tim. Here's the latest dump from running at trace=2. NYTProf is confused about CV 0x2b41eac6afb8 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(0x2b41eac6fa40) at 0x2b41eac6afb8 REFCNT = 2 FLAGS = (POK,pPOK,CONST) PROTOTYPE = "" COMP_STASH = 0x2b41eabb46f8 "ModPerl::RegistryCooker" XSUB = 0x2b41dc1665b0 XSUBANY = 0x2b41eac41308 (CONST SV) SV = IV(0x2b41eac41300) at 0x2b41eac41308 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0 GVGV::GV = 0x2b41eac41518 "" 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) SV = IV(0x2b41eac41510) at 0x2b41eac41518 REFCNT = 1 FLAGS = (ROK) RV = 0x2b41eac41308 SV = IV(0x2b41eac41300) at 0x2b41eac41308 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0
Subject: Re: [rt.cpan.org #65200] Devel::NYTProf::Apache with trace > 0
Date: Tue, 1 Feb 2011 13:25:15 +0000
To: Matthew Musgrove via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
Download (untitled) / with headers
text/plain 576b
On Fri, Jan 28, 2011 at 11:08:31AM -0500, Matthew Musgrove via RT wrote: Show quoted text
> Queue: devel-nytprof > Ticket <URL: https://rt.cpan.org/Ticket/Display.html?id=65200 > > > Thanks Tim. Here's the latest dump from running at trace=2. > > SV = IV(0x2b41eac41510) at 0x2b41eac41518 > REFCNT = 1 > FLAGS = (ROK) > RV = 0x2b41eac41308 > SV = IV(0x2b41eac41300) at 0x2b41eac41308 > REFCNT = 2 > FLAGS = (PADMY,IOK,READONLY,pIOK) > IV = 0
Great. Now after the sv_dump((SV*)gv); add sv_dump((SV*)SvRV(gv)); and re-run. Thanks. Tim.
NYTProf is confused about CV 0x2b397579fdd0 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(0x2b39757a4690) at 0x2b397579fdd0 REFCNT = 2 FLAGS = (POK,pPOK,CONST) PROTOTYPE = "" COMP_STASH = 0x2b39756e95a0 "ModPerl::RegistryCooker" XSUB = 0x2b39674715b0 XSUBANY = 0x2b3975776280 (CONST SV) SV = IV(0x2b3975776278) at 0x2b3975776280 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0 GVGV::GV = 0x2b3975776490 "" 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) SV = IV(0x2b3975776488) at 0x2b3975776490 REFCNT = 1 FLAGS = (ROK) RV = 0x2b3975776280 SV = IV(0x2b3975776278) at 0x2b3975776280 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0 SV = IV(0x2b3975776278) at 0x2b3975776280 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0
Subject: Re: [rt.cpan.org #65200] Devel::NYTProf::Apache with trace > 0
Date: Tue, 1 Feb 2011 21:46:09 +0000
To: Matthew Musgrove via RT <bug-devel-nytprof [...] rt.cpan.org>
From: Tim Bunce <Tim.Bunce [...] pobox.com>
Download (untitled) / with headers
text/plain 391b
Hi Matthew. Show quoted text
> 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)
Please hack RegistryCooker.pm to log the class of the object that should_reset_inc_hash() is called on. Thanks. Tim.
Download (untitled) / with headers
text/plain 1.5k
Howdy Tim, I've never peered inside ModPerl::RegistryCooker before. I used $self->log_error("should_reset_inc_hash $package"). I hope that was what you were asking for. [Tue Feb 01 22:23:44 2011] [error] should_reset_inc_hash ModPerl::ROOT::ModPerl::Registry::view_mm_2dnms_vobs_NMS_nms_www_cgi_2dbin_security_login_2ecgi Marking 'Apache2::RequestRec::log_error' as xsub Marking 'Apache2::RequestRec::notes' as xsub Marking 'APR::Table::set' as xsub NYTProf is confused about CV 0x2b7915c79368 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 226 (please report as a bug) SV = PVCV(0x2b7915c7ddf0) at 0x2b7915c79368 REFCNT = 2 FLAGS = (POK,pPOK,CONST) PROTOTYPE = "" COMP_STASH = 0x2b7915bc2850 "ModPerl::RegistryCooker" XSUB = 0x2b791bfc25b0 XSUBANY = 0x2b7915c4f810 (CONST SV) SV = IV(0x2b7915c4f808) at 0x2b7915c4f810 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0 GVGV::GV = 0x2b7915c4fa20 "" 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) SV = IV(0x2b7915c4fa18) at 0x2b7915c4fa20 REFCNT = 1 FLAGS = (ROK) RV = 0x2b7915c4f810 SV = IV(0x2b7915c4f808) at 0x2b7915c4f810 REFCNT = 2 FLAGS = (PADMY,IOK,READONLY,pIOK) IV = 0 It looks like my login script is the package in question. I hope that I haven't missed anything in my conversion from CGI to mod_perl to waste your time.


This service is sponsored and maintained by Best Practical Solutions and runs on Perl.org infrastructure.

Please report any issues with rt.cpan.org to rt-cpan-admin@bestpractical.com.